Teknik is a suite of services with attractive and functional interfaces. https://www.teknik.io/
You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

Profiler.php 11KB

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