Made xhprof scopedProfileIn() work via merging SectionProfiler results

* This works around various pecl/hhvm xhprof extension issues.

Change-Id: I04555db1d0781bafc758ab9965c4af2fab9569f4

diff --git a/includes/profiler/ProfilerXhprof.php b/includes/profiler/ProfilerXhprof.php
index 2fef011..5603aa5 100644 (file)
--- a/includes/profiler/ProfilerXhprof.php
+++ b/includes/profiler/ProfilerXhprof.php
@@ -59,12 +59,17 @@
  * @see https://github.com/facebook/hhvm/blob/master/hphp/doc/profiling.md
  */
 class ProfilerXhprof extends Profiler {
-
        /**
         * @var Xhprof $xhprof
         */
        protected $xhprof;
 
+       /**
+        * Profiler for explicit, arbitrary, frame labels
+        * @var SectionProfiler
+        */
+       protected $sprofiler;
+
        /**
         * Type of report to send when logData() is called.
         * @var string $logType
@@ -93,6 +98,7 @@ class ProfilerXhprof extends Profiler {
                $this->logType = $params['log'];
                $this->visible = $params['visible'];
                $this->xhprof = new Xhprof( $params );
+               $this->sprofiler = new SectionProfiler();
        }
 
        /**
@@ -118,22 +124,7 @@ class ProfilerXhprof extends Profiler {
        }
 
        public function scopedProfileIn( $section ) {
-               static $exists = null;
-               // Only HHVM supports this, not the standard PECL extension
-               if ( $exists === null ) {
-                       $exists = function_exists( 'xhprof_frame_begin' );
-               }
-
-               if ( $exists ) {
-                       xhprof_frame_begin( $section );
-                       return new ScopedCallback( function () {
-                               xhprof_frame_end();
-                       } );
-               }
-
-               return new ScopedCallback( function () {
-                       // no-op
-               } );
+               return $this->sprofiler->scopedProfileIn( $section );
        }
 
        /**
@@ -146,9 +137,10 @@ class ProfilerXhprof extends Profiler {
                $metrics = $this->xhprof->getCompleteMetrics();
                $profile = array();
 
+               $main = null; // units in ms
                foreach ( $metrics as $fname => $stats ) {
                        // Convert elapsed times from μs to ms to match ProfilerStandard
-                       $profile[] = array(
+                       $entry = array(
                                'name' => $fname,
                                'calls' => $stats['ct'],
                                'real' => $stats['wt']['total'] / 1000,
@@ -160,6 +152,19 @@ class ProfilerXhprof extends Profiler {
                                'min_real' => $stats['wt']['min'] / 1000,
                                'max_real' => $stats['wt']['max'] / 1000
                        );
+                       $profile[] = $entry;
+                       if ( $fname === 'main()' ) {
+                               $main = $entry;
+                       }
+               }
+
+               // Merge in all of the custom profile sections
+               foreach ( $this->sprofiler->getFunctionStats() as $stats ) {
+                       // @note: getFunctionStats() values already in ms
+                       $stats['%real'] = $stats['real'] / $main['real'];
+                       $stats['%cpu'] = $main['cpu'] ? $stats['cpu'] / $main['cpu'] * 100 : 0;
+                       $stats['%memory'] = $main['memory'] ? $stats['memory'] / $main['memory'] * 100 : 0;
+                       $profile[] = $stats; // assume no section names collide with $metrics
                }
 
                return $profile;

diff --git a/includes/profiler/SectionProfiler.php b/includes/profiler/SectionProfiler.php
index d28c36a..275e986 100644 (file)
--- a/includes/profiler/SectionProfiler.php
+++ b/includes/profiler/SectionProfiler.php
@@ -93,6 +93,8 @@ class SectionProfiler {
         *   - %cpu    : percent real time
         *   - memory  : memory used (bytes)
         *   - %memory : percent memory used
+        *   - min_real : min real time in a call (ms)
+        *   - max_real : max real time in a call (ms)
         */
        public function getFunctionStats() {
                $this->collateData();
@@ -112,6 +114,8 @@ class SectionProfiler {
                                '%cpu' => $totalCpu ? 100 * $data['cpu'] / $totalCpu : 0,
                                'memory' => $data['memory'],
                                '%memory' => $totalMem ? 100 * $data['memory'] / $totalMem : 0,
+                               'min_real' => 1000 * $data['min_real'],
+                               'max_real' => 1000 * $data['max_real']
                        );
                }
 
@@ -124,6 +128,8 @@ class SectionProfiler {
                        '%cpu' => 100,
                        'memory' => $totalMem,
                        '%memory' => 100,
+                       'min_real' => 1000 * $totalReal,
+                       'max_real' => 1000 * $totalReal
                );
 
                return $profile;
@@ -149,7 +155,9 @@ class SectionProfiler {
                        'cpu'      => 0.0,
                        'real'     => 0.0,
                        'memory'   => 0,
-                       'count'    => 0
+                       'count'    => 0,
+                       'min_real' => 0.0,
+                       'max_real' => 0.0
                );
        }
 
@@ -180,6 +188,8 @@ class SectionProfiler {
                $entry['real'] += $elapsedReal;
                $entry['memory'] += $memChange > 0 ? $memChange : 0;
                $entry['count']++;
+               $entry['min_real'] = min( $entry['min_real'], $elapsedReal );
+               $entry['max_real'] = max( $entry['max_real'], $elapsedReal );
        }
 
        /**