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

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 2 years 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 2 years 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 2 years ago Translation 2 years ago Twig 2 years ago UpdateCheck 2 years ago Updater 2 years ago Updates 2 years 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 2 years ago DbHelper.php 2 years 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 2 years ago Version.php 2 years ago View.php 2 years ago bootstrap.php 2 years ago dispatch.php 2 years ago testMinimumPhpVersion.php 2 years ago

Profiler.php

342 lines

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