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

matomo / app / core / Profiler.php

matomo / app / core Last commit date

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

Profiler.php

390 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	if ($a['sum_time_ms'] == $b['sum_time_ms']) {
104	return 0;
105	}
106	return ($a['sum_time_ms'] < $b['sum_time_ms']) ? -1 : 1;
107	}
108
109	private static function sortTimeDesc($a, $b)
110	{
111	if ($a['sumTimeMs'] == $b['sumTimeMs']) {
112	return 0;
113	}
114	return ($a['sumTimeMs'] < $b['sumTimeMs']) ? -1 : 1;
115	}
116
117	/**
118	* Print profiling report for the tracker
119	*
120	* @param \Piwik\Db $db Tracker database object (or null)
121	*/
122	public static function displayDbTrackerProfile($db = null)
123	{
124	if (is_null($db)) {
125	$db = Tracker::getDatabase();
126	}
127	$tableName = Common::prefixTable('log_profiling');
128
129	$all = $db->fetchAll('SELECT * FROM ' . $tableName);
130	if ($all === false) {
131	return;
132	}
133	uasort($all, 'self::maxSumMsFirst');
134
135	$infoIndexedByQuery = array();
136	foreach ($all as $infoQuery) {
137	$query = $infoQuery['query'];
138	$count = $infoQuery['count'];
139	$sum_time_ms = $infoQuery['sum_time_ms'];
140	$infoIndexedByQuery[$query] = array('count' => $count, 'sumTimeMs' => $sum_time_ms);
141	}
142	self::getSqlProfilingQueryBreakdownOutput($infoIndexedByQuery);
143	}
144
145	/**
146	* Print number of queries and elapsed time
147	*/
148	public static function printQueryCount()
149	{
150	$totalTime = self::getDbElapsedSecs();
151	$queryCount = Profiler::getQueryCount();
152	if ($queryCount > 0) {
153	Log::debug(sprintf("Total queries = %d (total sql time = %.2fs)", $queryCount, $totalTime));
154	}
155	}
156
157	/**
158	* Get total elapsed time (in seconds)
159	*
160	* @return int elapsed time
161	*/
162	public static function getDbElapsedSecs()
163	{
164	$profiler = Db::get()->getProfiler();
165	return $profiler->getTotalElapsedSecs();
166	}
167
168	/**
169	* Get total number of queries
170	*
171	* @return int number of queries
172	*/
173	public static function getQueryCount()
174	{
175	$profiler = Db::get()->getProfiler();
176	return $profiler->getTotalNumQueries();
177	}
178
179	/**
180	* Log a breakdown by query
181	*
182	* @param array $infoIndexedByQuery
183	*/
184	private static function getSqlProfilingQueryBreakdownOutput($infoIndexedByQuery)
185	{
186	$output = '<hr /><strong>Breakdown by query</strong><br/>';
187	foreach ($infoIndexedByQuery as $query => $queryInfo) {
188	$timeMs = round($queryInfo['sumTimeMs'], 1);
189	$count = $queryInfo['count'];
190	$avgTimeString = '';
191	if ($count > 1) {
192	$avgTimeMs = $timeMs / $count;
193	$avgTimeString = " (average = <b>" . round($avgTimeMs, 1) . "ms</b>)";
194	}
195	$query = preg_replace('/([\t\n\r ]+)/', ' ', $query);
196	$output .= "Executed <b>$count</b> time" . ($count == 1 ? '' : 's') . " in <b>" . $timeMs . "ms</b> $avgTimeString <pre>\t$query</pre>";
197	}
198	Log::debug($output);
199	}
200
201	/**
202	* Initializes Profiling via XHProf.
203	* See: https://github.com/piwik/piwik/blob/master/tests/README.xhprof.md
204	*/
205	public static function setupProfilerXHProf($mainRun = false, $setupDuringTracking = false)
206	{
207	if (!$setupDuringTracking
208	&& SettingsServer::isTrackerApiRequest()
209	) {
210	// do not profile Tracker
211	return;
212	}
213
214	if (self::$isXhprofSetup) {
215	return;
216	}
217
218	$hasXhprof = function_exists('xhprof_enable');
219	$hasTidewaysXhprof = function_exists('tideways_xhprof_enable') \|\| function_exists('tideways_enable');
220
221	if (!$hasXhprof && !$hasTidewaysXhprof) {
222	$xhProfPath = PIWIK_INCLUDE_PATH . '/vendor/lox/xhprof/extension/modules/xhprof.so';
223	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.");
224	}
225
226	$outputDir = ini_get("xhprof.output_dir");
227	if (!$outputDir && $hasTidewaysXhprof) {
228	$outputDir = sys_get_temp_dir();
229	}
230
231	if (empty($outputDir)) {
232	throw new Exception("The profiler output dir is not set. Add 'xhprof.output_dir=...' to your php.ini.");
233	}
234	if (!is_writable($outputDir)) {
235	throw new Exception("The profiler output dir '" . ini_get("xhprof.output_dir") . "' should exist and be writable.");
236	}
237
238	if (!function_exists('xhprof_error')) {
239	function xhprof_error($out)
240	{
241	echo substr($out, 0, 300) . '...';
242	}
243	}
244
245	$currentGitBranch = SettingsPiwik::getCurrentGitBranch();
246	$profilerNamespace = "piwik";
247	if ($currentGitBranch != 'master') {
248	$profilerNamespace .= "-" . $currentGitBranch;
249	}
250
251	if ($mainRun) {
252	self::setProfilingRunIds(array());
253	}
254
255	if (function_exists('xhprof_enable')) {
256	xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY);
257	} elseif (function_exists('tideways_enable')) {
258	tideways_enable(TIDEWAYS_FLAGS_MEMORY \| TIDEWAYS_FLAGS_CPU);
259	} elseif (function_exists('tideways_xhprof_enable')) {
260	tideways_xhprof_enable(TIDEWAYS_XHPROF_FLAGS_MEMORY \| TIDEWAYS_XHPROF_FLAGS_CPU);
261	}
262
263	register_shutdown_function(function () use ($profilerNamespace, $mainRun, $outputDir) {
264	if (function_exists('xhprof_disable')) {
265	$xhprofData = xhprof_disable();
266	$xhprofRuns = new XHProfRuns_Default();
267	$runId = $xhprofRuns->save_run($xhprofData, $profilerNamespace);
268	} elseif (function_exists('tideways_xhprof_disable') \|\| function_exists('tideways_disable')) {
269	if (function_exists('tideways_xhprof_disable')) {
270	$xhprofData = tideways_xhprof_disable();
271	} else {
272	$xhprofData = tideways_disable();
273	}
274	$runId = uniqid();
275	file_put_contents(
276	$outputDir . DIRECTORY_SEPARATOR . $runId . '.' . $profilerNamespace . '.xhprof',
277	serialize($xhprofData)
278	);
279	$meta = array('time' => time(), 'instance' => SettingsPiwik::getPiwikInstanceId());
280	if (!empty($_GET)) {
281	$meta['get'] = $_GET;
282	}
283	if (!empty($_POST)) {
284	$meta['post'] = $_POST;
285	}
286	file_put_contents(
287	$outputDir . DIRECTORY_SEPARATOR . $runId . '.' . $profilerNamespace . '.meta',
288	serialize($meta)
289	);
290	}
291
292	if (empty($runId)) {
293	die('could not write profiler run');
294	}
295
296	$runs = Profiler::getProfilingRunIds();
297	array_unshift($runs, $runId);
298
299	if ($mainRun) {
300	Profiler::aggregateXhprofRuns($runs, $profilerNamespace, $saveTo = $runId);
301
302	$baseUrlStored = SettingsPiwik::getPiwikUrl();
303	$host = Url::getHost();
304
305	$out = "\n\n";
306	$baseUrl = "http://" . $host . "/" . @$_SERVER['REQUEST_URI'];
307	if (strlen($baseUrlStored) > strlen($baseUrl)) {
308	$baseUrl = $baseUrlStored;
309	}
310	$baseUrl = $baseUrlStored . "vendor/lox/xhprof/xhprof_html/?source=$profilerNamespace&run=$runId";
311	$baseUrl = Common::sanitizeInputValue($baseUrl);
312
313	$out .= "Profiler report is available at:\n";
314	$out .= "<a href='$baseUrl'>$baseUrl</a>";
315	$out .= "\n\n";
316
317	if (Development::isEnabled()) {
318	$out .= "WARNING: Development mode is enabled. Many runtime optimizations are not applied in development mode. ";
319	$out .= "Unless you intend to profile Matomo in development mode, your profile may not be accurate.";
320	$out .= "\n\n";
321	}
322
323	echo $out;
324	} else {
325	Profiler::setProfilingRunIds($runs);
326	}
327	});
328
329	self::$isXhprofSetup = true;
330	}
331
332	/**
333	* Aggregates xhprof runs w/o normalizing (xhprof_aggregate_runs will always average data which
334	* does not fit Piwik's use case).
335	*/
336	public static function aggregateXhprofRuns($runIds, $profilerNamespace, $saveToRunId)
337	{
338	$xhprofRuns = new XHProfRuns_Default();
339
340	$aggregatedData = array();
341
342	foreach ($runIds as $runId) {
343	$xhprofRunData = $xhprofRuns->get_run($runId, $profilerNamespace, $description);
344
345	foreach ($xhprofRunData as $key => $data) {
346	if (empty($aggregatedData[$key])) {
347	$aggregatedData[$key] = $data;
348	} else {
349	// don't aggregate main() metrics since only the super run has the correct metrics for the entire run
350	if ($key == "main()") {
351	continue;
352	}
353
354	$aggregatedData[$key]["ct"] += $data["ct"]; // call count
355	$aggregatedData[$key]["wt"] += $data["wt"]; // incl. wall time
356	$aggregatedData[$key]["cpu"] += $data["cpu"]; // cpu time
357	$aggregatedData[$key]["mu"] += $data["mu"]; // memory usage
358	$aggregatedData[$key]["pmu"] = max($aggregatedData[$key]["pmu"], $data["pmu"]); // peak mem usage
359	}
360	}
361	}
362
363	$xhprofRuns->save_run($aggregatedData, $profilerNamespace, $saveToRunId);
364	}
365
366	public static function setProfilingRunIds($ids)
367	{
368	file_put_contents(self::getPathToXHProfRunIds(), json_encode($ids));
369	@chmod(self::getPathToXHProfRunIds(), 0777);
370	}
371
372	public static function getProfilingRunIds()
373	{
374	$runIds = file_get_contents(self::getPathToXHProfRunIds());
375	$array = json_decode($runIds, $assoc = true);
376	if (!is_array($array)) {
377	$array = array();
378	}
379	return $array;
380	}
381
382	/**
383	* @return string
384	*/
385	private static function getPathToXHProfRunIds()
386	{
387	return PIWIK_INCLUDE_PATH . '/tmp/cache/tests-xhprof-runs';
388	}
389	}
390