Profiler.php — Matomo Analytics – Powerful, Privacy-First Insights for WordPress 4.0.2

matomo / app / core / Profiler.php

matomo / app / core Last commit date

API 5 years ago Access 5 years ago Application 5 years ago Archive 5 years ago ArchiveProcessor 5 years ago Archiver 5 years ago AssetManager 5 years ago Auth 5 years ago Category 5 years ago CliMulti 5 years ago Columns 5 years ago Composer 5 years ago Concurrency 5 years ago Config 5 years ago Container 5 years ago CronArchive 5 years ago DataAccess 5 years ago DataFiles 5 years ago DataTable 5 years ago Db 5 years ago DeviceDetector 5 years ago Email 5 years ago Exception 5 years ago Http 5 years ago Intl 5 years ago Mail 5 years ago Measurable 5 years ago Menu 5 years ago Metrics 5 years ago Notification 5 years ago Period 5 years ago Plugin 5 years ago ProfessionalServices 5 years ago Report 5 years ago ReportRenderer 5 years ago Scheduler 5 years ago Segment 5 years ago Session 5 years ago Settings 5 years ago Tracker 5 years ago Translation 5 years ago UpdateCheck 5 years ago Updater 5 years ago Updates 5 years ago Validators 5 years ago View 5 years ago ViewDataTable 5 years ago Visualization 5 years ago Widget 5 years ago .htaccess 6 years ago Access.php 5 years ago Archive.php 5 years ago ArchiveProcessor.php 5 years ago AssetManager.php 5 years ago Auth.php 5 years ago AuthResult.php 5 years ago BaseFactory.php 5 years ago Cache.php 5 years ago CacheId.php 5 years ago CliMulti.php 5 years ago Common.php 5 years ago Config.php 5 years ago Console.php 5 years ago Context.php 5 years ago Cookie.php 5 years ago CronArchive.php 5 years ago DataArray.php 5 years ago DataTable.php 5 years ago Date.php 5 years ago Db.php 5 years ago DbHelper.php 5 years ago Development.php 5 years ago ErrorHandler.php 5 years ago EventDispatcher.php 5 years ago ExceptionHandler.php 5 years ago FileIntegrity.php 5 years ago Filechecks.php 5 years ago Filesystem.php 5 years ago FrontController.php 5 years ago Http.php 5 years ago IP.php 5 years ago Log.php 5 years ago LogDeleter.php 5 years ago Mail.php 5 years ago Metrics.php 5 years ago NoAccessException.php 5 years ago Nonce.php 5 years ago Notification.php 5 years ago NumberFormatter.php 5 years ago Option.php 5 years ago Period.php 5 years ago Piwik.php 5 years ago Plugin.php 5 years ago Profiler.php 5 years ago ProxyHeaders.php 5 years ago ProxyHttp.php 5 years ago QuickForm2.php 5 years ago RankingQuery.php 5 years ago ReportRenderer.php 5 years ago Segment.php 5 years ago Sequence.php 5 years ago Session.php 5 years ago SettingsPiwik.php 5 years ago SettingsServer.php 5 years ago Singleton.php 5 years ago Site.php 5 years ago TCPDF.php 5 years ago Theme.php 5 years ago Timer.php 5 years ago Tracker.php 5 years ago Twig.php 5 years ago Unzip.php 5 years ago UpdateCheck.php 5 years ago Updater.php 5 years ago UpdaterErrorException.php 5 years ago Updates.php 5 years ago Url.php 5 years ago UrlHelper.php 5 years ago Version.php 5 years ago View.php 5 years ago bootstrap.php 5 years ago dispatch.php 5 years ago testMinimumPhpVersion.php 5 years ago

Profiler.php

383 lines

1	<?php
2	/**
3	* Matomo - free/libre analytics platform
4	*
5	* @link https://matomo.org
6	* @license http://www.gnu.org/licenses/gpl-3.0.html GPL v3 or later
7	*
8	*/
9	namespace Piwik;
10
11	use Exception;
12	use XHProfRuns_Default;
13
14	/**
15	* Class Profiler helps with measuring memory, and profiling the database.
16	* To enable set in your config.ini.php
17	* [Debug]
18	* enable_sql_profiler = 1
19	*
20	* [log]
21	* log_writers[] = file
22	* log_level=debug
23	*
24	*/
25	class Profiler
26	{
27	/**
28	* Whether xhprof has been setup or not.
29	*
30	* @var bool
31	*/
32	private static $isXhprofSetup = false;
33
34	/**
35	* Returns memory usage
36	*
37	* @return string
38	*/
39	public static function getMemoryUsage()
40	{
41	$memory = false;
42	if (function_exists('xdebug_memory_usage')) {
43	$memory = xdebug_memory_usage();
44	} elseif (function_exists('memory_get_usage')) {
45	$memory = memory_get_usage();
46	}
47	if ($memory === false) {
48	return "Memory usage function not found.";
49	}
50	$usage = number_format(round($memory / 1024 / 1024, 2), 2);
51	return "$usage Mb";
52	}
53
54	/**
55	* Outputs SQL Profiling reports from Zend
56	*
57	* @throws \Exception
58	*/
59	public static function displayDbProfileReport()
60	{
61	$profiler = Db::get()->getProfiler();
62
63	if (!$profiler->getEnabled()) {
64	// To display the profiler you should enable enable_sql_profiler on your config/config.ini.php file
65	return;
66	}
67
68	$infoIndexedByQuery = array();
69	foreach ($profiler->getQueryProfiles() as $query) {
70	if (isset($infoIndexedByQuery[$query->getQuery()])) {
71	$existing = $infoIndexedByQuery[$query->getQuery()];
72	} else {
73	$existing = array('count' => 0, 'sumTimeMs' => 0);
74	}
75	$new = array('count' => $existing['count'] + 1,
76	'sumTimeMs' => $existing['count'] + $query->getElapsedSecs() * 1000);
77	$infoIndexedByQuery[$query->getQuery()] = $new;
78	}
79
80	uasort($infoIndexedByQuery, 'self::sortTimeDesc');
81
82	$str = '<hr /><strong>SQL Profiler</strong><hr /><strong>Summary</strong><br/>';
83	$totalTime = $profiler->getTotalElapsedSecs();
84	$queryCount = $profiler->getTotalNumQueries();
85	$longestTime = 0;
86	$longestQuery = null;
87	foreach ($profiler->getQueryProfiles() as $query) {
88	if ($query->getElapsedSecs() > $longestTime) {
89	$longestTime = $query->getElapsedSecs();
90	$longestQuery = $query->getQuery();
91	}
92	}
93	$str .= 'Executed ' . $queryCount . ' queries in ' . round($totalTime, 3) . ' seconds';
94	$str .= '(Average query length: ' . round($totalTime / $queryCount, 3) . ' seconds)';
95	$str .= '<br />Queries per second: ' . round($queryCount / $totalTime, 1);
96	$str .= '<br />Longest query length: ' . round($longestTime, 3) . " seconds (<code>$longestQuery</code>)";
97	Log::debug($str);
98	self::getSqlProfilingQueryBreakdownOutput($infoIndexedByQuery);
99	}
100
101	private static function maxSumMsFirst($a, $b)
102	{
103	return $a['sum_time_ms'] < $b['sum_time_ms'];
104	}
105
106	private static function sortTimeDesc($a, $b)
107	{
108	return $a['sumTimeMs'] < $b['sumTimeMs'];
109	}
110
111	/**
112	* Print profiling report for the tracker
113	*
114	* @param \Piwik\Db $db Tracker database object (or null)
115	*/
116	public static function displayDbTrackerProfile($db = null)
117	{
118	if (is_null($db)) {
119	$db = Tracker::getDatabase();
120	}
121	$tableName = Common::prefixTable('log_profiling');
122
123	$all = $db->fetchAll('SELECT * FROM ' . $tableName);
124	if ($all === false) {
125	return;
126	}
127	uasort($all, 'self::maxSumMsFirst');
128
129	$infoIndexedByQuery = array();
130	foreach ($all as $infoQuery) {
131	$query = $infoQuery['query'];
132	$count = $infoQuery['count'];
133	$sum_time_ms = $infoQuery['sum_time_ms'];
134	$infoIndexedByQuery[$query] = array('count' => $count, 'sumTimeMs' => $sum_time_ms);
135	}
136	self::getSqlProfilingQueryBreakdownOutput($infoIndexedByQuery);
137	}
138
139	/**
140	* Print number of queries and elapsed time
141	*/
142	public static function printQueryCount()
143	{
144	$totalTime = self::getDbElapsedSecs();
145	$queryCount = Profiler::getQueryCount();
146	if ($queryCount > 0) {
147	Log::debug(sprintf("Total queries = %d (total sql time = %.2fs)", $queryCount, $totalTime));
148	}
149	}
150
151	/**
152	* Get total elapsed time (in seconds)
153	*
154	* @return int elapsed time
155	*/
156	public static function getDbElapsedSecs()
157	{
158	$profiler = Db::get()->getProfiler();
159	return $profiler->getTotalElapsedSecs();
160	}
161
162	/**
163	* Get total number of queries
164	*
165	* @return int number of queries
166	*/
167	public static function getQueryCount()
168	{
169	$profiler = Db::get()->getProfiler();
170	return $profiler->getTotalNumQueries();
171	}
172
173	/**
174	* Log a breakdown by query
175	*
176	* @param array $infoIndexedByQuery
177	*/
178	private static function getSqlProfilingQueryBreakdownOutput($infoIndexedByQuery)
179	{
180	$output = '<hr /><strong>Breakdown by query</strong><br/>';
181	foreach ($infoIndexedByQuery as $query => $queryInfo) {
182	$timeMs = round($queryInfo['sumTimeMs'], 1);
183	$count = $queryInfo['count'];
184	$avgTimeString = '';
185	if ($count > 1) {
186	$avgTimeMs = $timeMs / $count;
187	$avgTimeString = " (average = <b>" . round($avgTimeMs, 1) . "ms</b>)";
188	}
189	$query = preg_replace('/([\t\n\r ]+)/', ' ', $query);
190	$output .= "Executed <b>$count</b> time" . ($count == 1 ? '' : 's') . " in <b>" . $timeMs . "ms</b> $avgTimeString <pre>\t$query</pre>";
191	}
192	Log::debug($output);
193	}
194
195	/**
196	* Initializes Profiling via XHProf.
197	* See: https://github.com/piwik/piwik/blob/master/tests/README.xhprof.md
198	*/
199	public static function setupProfilerXHProf($mainRun = false, $setupDuringTracking = false)
200	{
201	if (!$setupDuringTracking
202	&& SettingsServer::isTrackerApiRequest()
203	) {
204	// do not profile Tracker
205	return;
206	}
207
208	if (self::$isXhprofSetup) {
209	return;
210	}
211
212	$hasXhprof = function_exists('xhprof_enable');
213	$hasTidewaysXhprof = function_exists('tideways_xhprof_enable') \|\| function_exists('tideways_enable');
214
215	if (!$hasXhprof && !$hasTidewaysXhprof) {
216	$xhProfPath = PIWIK_INCLUDE_PATH . '/vendor/lox/xhprof/extension/modules/xhprof.so';
217	throw new Exception("Cannot find xhprof_enable, make sure to 1) install xhprof: run 'composer install --dev' and build the extension, and 2) add 'extension=$xhProfPath' to your php.ini.");
218	}
219
220	$outputDir = ini_get("xhprof.output_dir");
221	if (!$outputDir && $hasTidewaysXhprof) {
222	$outputDir = sys_get_temp_dir();
223	}
224
225	if (empty($outputDir)) {
226	throw new Exception("The profiler output dir is not set. Add 'xhprof.output_dir=...' to your php.ini.");
227	}
228	if (!is_writable($outputDir)) {
229	throw new Exception("The profiler output dir '" . ini_get("xhprof.output_dir") . "' should exist and be writable.");
230	}
231
232	if (!function_exists('xhprof_error')) {
233	function xhprof_error($out)
234	{
235	echo substr($out, 0, 300) . '...';
236	}
237	}
238
239	$currentGitBranch = SettingsPiwik::getCurrentGitBranch();
240	$profilerNamespace = "piwik";
241	if ($currentGitBranch != 'master') {
242	$profilerNamespace .= "-" . $currentGitBranch;
243	}
244
245	if ($mainRun) {
246	self::setProfilingRunIds(array());
247	}
248
249	if (function_exists('xhprof_enable')) {
250	xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY);
251	} elseif (function_exists('tideways_enable')) {
252	tideways_enable(TIDEWAYS_FLAGS_MEMORY \| TIDEWAYS_FLAGS_CPU);
253	} elseif (function_exists('tideways_xhprof_enable')) {
254	tideways_xhprof_enable(TIDEWAYS_XHPROF_FLAGS_MEMORY \| TIDEWAYS_XHPROF_FLAGS_CPU);
255	}
256
257	register_shutdown_function(function () use ($profilerNamespace, $mainRun, $outputDir) {
258	if (function_exists('xhprof_disable')) {
259	$xhprofData = xhprof_disable();
260	$xhprofRuns = new XHProfRuns_Default();
261	$runId = $xhprofRuns->save_run($xhprofData, $profilerNamespace);
262	} elseif (function_exists('tideways_xhprof_disable') \|\| function_exists('tideways_disable')) {
263	if (function_exists('tideways_xhprof_disable')) {
264	$xhprofData = tideways_xhprof_disable();
265	} else {
266	$xhprofData = tideways_disable();
267	}
268	$runId = uniqid();
269	file_put_contents(
270	$outputDir . DIRECTORY_SEPARATOR . $runId . '.' . $profilerNamespace . '.xhprof',
271	serialize($xhprofData)
272	);
273	$meta = array('time' => time(), 'instance' => SettingsPiwik::getPiwikInstanceId());
274	if (!empty($_GET)) {
275	$meta['get'] = $_GET;
276	}
277	if (!empty($_POST)) {
278	$meta['post'] = $_POST;
279	}
280	file_put_contents(
281	$outputDir . DIRECTORY_SEPARATOR . $runId . '.' . $profilerNamespace . '.meta',
282	serialize($meta)
283	);
284	}
285
286	if (empty($runId)) {
287	die('could not write profiler run');
288	}
289
290	$runs = Profiler::getProfilingRunIds();
291	array_unshift($runs, $runId);
292
293	if ($mainRun) {
294	Profiler::aggregateXhprofRuns($runs, $profilerNamespace, $saveTo = $runId);
295
296	$baseUrlStored = SettingsPiwik::getPiwikUrl();
297	$host = Url::getHost();
298
299	$out = "\n\n";
300	$baseUrl = "http://" . $host . "/" . @$_SERVER['REQUEST_URI'];
301	if (strlen($baseUrlStored) > strlen($baseUrl)) {
302	$baseUrl = $baseUrlStored;
303	}
304	$baseUrl = $baseUrlStored . "vendor/lox/xhprof/xhprof_html/?source=$profilerNamespace&run=$runId";
305
306	$out .= "Profiler report is available at:\n";
307	$out .= "<a href='$baseUrl'>$baseUrl</a>";
308	$out .= "\n\n";
309
310	if (Development::isEnabled()) {
311	$out .= "WARNING: Development mode is enabled. Many runtime optimizations are not applied in development mode. ";
312	$out .= "Unless you intend to profile Matomo in development mode, your profile may not be accurate.";
313	$out .= "\n\n";
314	}
315
316	echo $out;
317	} else {
318	Profiler::setProfilingRunIds($runs);
319	}
320	});
321
322	self::$isXhprofSetup = true;
323	}
324
325	/**
326	* Aggregates xhprof runs w/o normalizing (xhprof_aggregate_runs will always average data which
327	* does not fit Piwik's use case).
328	*/
329	public static function aggregateXhprofRuns($runIds, $profilerNamespace, $saveToRunId)
330	{
331	$xhprofRuns = new XHProfRuns_Default();
332
333	$aggregatedData = array();
334
335	foreach ($runIds as $runId) {
336	$xhprofRunData = $xhprofRuns->get_run($runId, $profilerNamespace, $description);
337
338	foreach ($xhprofRunData as $key => $data) {
339	if (empty($aggregatedData[$key])) {
340	$aggregatedData[$key] = $data;
341	} else {
342	// don't aggregate main() metrics since only the super run has the correct metrics for the entire run
343	if ($key == "main()") {
344	continue;
345	}
346
347	$aggregatedData[$key]["ct"] += $data["ct"]; // call count
348	$aggregatedData[$key]["wt"] += $data["wt"]; // incl. wall time
349	$aggregatedData[$key]["cpu"] += $data["cpu"]; // cpu time
350	$aggregatedData[$key]["mu"] += $data["mu"]; // memory usage
351	$aggregatedData[$key]["pmu"] = max($aggregatedData[$key]["pmu"], $data["pmu"]); // peak mem usage
352	}
353	}
354	}
355
356	$xhprofRuns->save_run($aggregatedData, $profilerNamespace, $saveToRunId);
357	}
358
359	public static function setProfilingRunIds($ids)
360	{
361	file_put_contents(self::getPathToXHProfRunIds(), json_encode($ids));
362	@chmod(self::getPathToXHProfRunIds(), 0777);
363	}
364
365	public static function getProfilingRunIds()
366	{
367	$runIds = file_get_contents(self::getPathToXHProfRunIds());
368	$array = json_decode($runIds, $assoc = true);
369	if (!is_array($array)) {
370	$array = array();
371	}
372	return $array;
373	}
374
375	/**
376	* @return string
377	*/
378	private static function getPathToXHProfRunIds()
379	{
380	return PIWIK_INCLUDE_PATH . '/tmp/cache/tests-xhprof-runs';
381	}
382	}
383