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

matomo / app / core / Profiler.php

matomo / app / core Last commit date

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

Profiler.php

341 lines

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