MDL-64543 profiling: Add ability to auto profile only slow scripts
authorBrendan Heywood <brendan@catalyst-au.net>
Thu, 10 Jan 2019 05:26:14 +0000 (16:26 +1100)
committerBrendan Heywood <brendan@catalyst-au.net>
Thu, 14 Mar 2019 00:44:25 +0000 (11:44 +1100)
admin/settings/development.php
lang/en/admin.php
lib/xhprof/readme_moodle.txt
lib/xhprof/xhprof_moodle.php

index 61d82c3..58493dd 100644 (file)
@@ -59,6 +59,8 @@ if ($hassiteconfig) { // speedup for non-admins, add all caps used on this page
     $temp->add(new admin_setting_configcheckbox('profilingallowme', new lang_string('profilingallowme', 'admin'), new lang_string('profilingallowme_help', 'admin'), false));
     // Allow PROFILEALL/PROFILEALLSTOP GPC.
     $temp->add(new admin_setting_configcheckbox('profilingallowall', new lang_string('profilingallowall', 'admin'), new lang_string('profilingallowall_help', 'admin'), false));
+    $temp->add(new admin_setting_configtext('profilingslow', new lang_string('profilingslow', 'admin'),
+        new lang_string('profilingslow_help', 'admin'), 0, PARAM_FLOAT));
     // TODO: Allow to skip PHP functions (XHPROF_FLAGS_NO_BUILTINS)
     // TODO: Allow to skip call_user functions (ignored_functions array)
     // Specify the life time (in minutes) of profiling runs.
index 36c0c7e..5903033 100644 (file)
@@ -982,6 +982,8 @@ $string['profilingincluded'] = 'Profile these';
 $string['profilingincluded_help'] = 'List of (comma separated, absolute skipping wwwroot, callable) URLs that will be automatically profiled. Examples: /index.php, /course/view.php. Also accepts the * wildchar at any position. Examples: /mod/forum/*, /mod/*/view.php.';
 $string['profilinglifetime'] = 'Keep profiling runs';
 $string['profilinglifetime_help'] = 'Specify the time you want to keep information about old profiling runs. Older ones will be pruned periodically. Note that this excludes any profiling run marked as \'reference run\'.';
+$string['profilingslow'] = 'Profile slow pages';
+$string['profilingslow_help'] = 'By setting a minimum time in seconds all pages slower will be profiled. Only profiles which are slower than an existing profile for the same script will be kept. Set to 0 to disable. Note that this observes the exclude settings.';
 $string['protectusernames'] = 'Protect usernames';
 $string['proxybypass'] = 'Proxy bypass hosts';
 $string['proxyhost'] = 'Proxy host';
index c2daa35..8bd8bc5 100644 (file)
@@ -38,4 +38,6 @@ TODO:
 20110318 - MDL-26891 - Eloy Lafuente (stronk7): Implemented earlier profiling runs
 20130621 - MDL-39733 - Eloy Lafuente (stronk7): Export & import of profiling runs
 20160721 - MDL-55292 - Russell Smith (mr-russ): Add support for tideways profiler collection for PHP7
-20171002 - MDL-60313 - Marina Glancy (marinaglancy): Upgrade to 0.9.4 release; patched for PHP7.2
\ No newline at end of file
+20171002 - MDL-60313 - Marina Glancy (marinaglancy): Upgrade to 0.9.4 release; patched for PHP7.2
+20190314 - MDL-64543 - Brendan Heywood (brendanheywood): Add support for conditional slow profiling
+
index 82a1d1a..d007eb0 100644 (file)
@@ -141,7 +141,13 @@ function profiling_start() {
         $profileauto = (mt_rand(1, $CFG->profilingautofrec) === 1);
     }
 
-    // See if the $script matches any of the included patterns
+    // Profile potentially slow pages.
+    $profileslow = false;
+    if (!empty($CFG->profilingslow) && !CLI_SCRIPT) {
+        $profileslow = true;
+    }
+
+    // See if the $script matches any of the included patterns.
     $included = empty($CFG->profilingincluded) ? '' : $CFG->profilingincluded;
     $profileincluded = profiling_string_matches($script, $included);
 
@@ -155,11 +161,19 @@ function profiling_start() {
     // Decide if profile by match must happen (only if profileauto is disabled)
     $profilematch = $profileincluded && !$profileexcluded && empty($CFG->profilingautofrec);
 
-    // If not auto, me, all, match have been detected, nothing to do
-    if (!$profileauto && !$profileme && !$profileall && !$profilematch) {
+    // Decide if slow profile has been excluded.
+    $profileslow = $profileslow && !$profileexcluded;
+
+    // If not auto, me, all, match have been detected, nothing to do.
+    if (!$profileauto && !$profileme && !$profileall && !$profilematch && !$profileslow) {
         return false;
     }
 
+    // If we have only been triggered by a *potentially* slow page then remember this for later.
+    if ((!$profileauto && !$profileme && !$profileall && !$profilematch) && $profileslow) {
+        $CFG->profilepotentialslowpage = microtime(true); // Neither $PAGE or $SESSION are guaranteed here.
+    }
+
     // Arrived here, the script is going to be profiled, let's do it
     $ignore = array('call_user_func', 'call_user_func_array');
     if (extension_loaded('tideways_xhprof')) {
@@ -217,6 +231,24 @@ function profiling_stop() {
         return false;
     }
 
+    // If we only profiled because it was potentially slow then...
+    if ($CFG->profilepotentialslowpage) {
+        $duration = microtime(true) - $CFG->profilepotentialslowpage;
+        if ($duration < $CFG->profilingslow) {
+            // Wasn't slow enough.
+            return false;
+        }
+
+        $sql = "SELECT max(totalexecutiontime)
+                  FROM {profiling}
+                 WHERE url = ?";
+        $slowest = $DB->get_field_sql($sql, array($script));
+        if (!empty($slowest) && $duration * 1000000 < $slowest) {
+            // Already have a worse profile stored.
+            return false;
+        }
+    }
+
     $run = new moodle_xhprofrun();
     $run->prepare_run($script);
     $runid = $run->save_run($data, null);