Merge "Log to DBPerformance log when many LB connections are acquired"
[lhc/web/wiklou.git] / includes / profiler / ProfilerXhprof.php
index 88196db..7a50497 100644 (file)
@@ -21,9 +21,6 @@
 /**
  * Profiler wrapper for XHProf extension.
  *
- * Mimics the output of ProfilerStandard using data collected via the XHProf
- * PHP extension.
- *
  * @code
  * $wgProfiler['class'] = 'ProfilerXhprof';
  * $wgProfiler['flags'] = XHPROF_FLAGS_NO_BUILTINS;
  * $wgProfiler['output'] = 'udp';
  * @endcode
  *
- * Rather than obeying wfProfileIn() and wfProfileOut() calls placed in the
- * application code, ProfilerXhprof profiles all functions using the XHProf
- * PHP extenstion. For PHP5 users, this extension can be installed via PECL or
- * your operating system's package manager. XHProf support is built into HHVM.
+ * ProfilerXhprof profiles all functions using the XHProf PHP extenstion.
+ * For PHP5 users, this extension can be installed via PECL or your operating
+ * system's package manager. XHProf support is built into HHVM.
  *
  * To restrict the functions for which profiling data is collected, you can
  * use either a whitelist ($wgProfiler['include']) or a blacklist
  * @see https://github.com/facebook/hhvm/blob/master/hphp/doc/profiling.md
  */
 class ProfilerXhprof extends Profiler {
-
        /**
         * @var Xhprof $xhprof
         */
        protected $xhprof;
 
        /**
-        * Type of report to send when logData() is called.
-        * @var string $logType
-        */
-       protected $logType;
-
-       /**
-        * Should profile report sent to in page content be visible?
-        * @var bool $visible
+        * Profiler for explicit, arbitrary, frame labels
+        * @var SectionProfiler
         */
-       protected $visible;
+       protected $sprofiler;
 
        /**
         * @param array $params
         * @see Xhprof::__construct()
         */
        public function __construct( array $params = array() ) {
-               $params = array_merge(
-                       array(
-                               'log' => 'text',
-                               'visible' => false
-                       ),
-                       $params
-               );
                parent::__construct( $params );
-               $this->logType = $params['log'];
-               $this->visible = $params['visible'];
                $this->xhprof = new Xhprof( $params );
-       }
-
-       public function isStub() {
-               return false;
-       }
-
-       /**
-        * No-op for xhprof profiling.
-        *
-        * Use the 'include' configuration key instead if you need to constrain
-        * the functions that are profiled.
-        *
-        * @param string $functionname
-        */
-       public function profileIn( $functionname ) {
-       }
-
-       /**
-        * No-op for xhprof profiling.
-        *
-        * Use the 'include' configuration key instead if you need to constrain
-        * the functions that are profiled.
-        *
-        * @param string $functionname
-        */
-       public function profileOut( $functionname ) {
+               $this->sprofiler = new SectionProfiler();
        }
 
        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() use ( $section ) {
-                               xhprof_frame_end();
-                       } );
-               }
-
-               return null;
+               return $this->sprofiler->scopedProfileIn( $section );
        }
 
        /**
@@ -148,9 +90,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(
+                       // Convert elapsed times from μs to ms to match interface
+                       $entry = array(
                                'name' => $fname,
                                'calls' => $stats['ct'],
                                'real' => $stats['wt']['total'] / 1000,
@@ -159,9 +102,27 @@ class ProfilerXhprof extends Profiler {
                                '%cpu' => isset( $stats['cpu'] ) ? $stats['cpu']['percent'] : 0,
                                'memory' => isset( $stats['mu'] ) ? $stats['mu']['total'] : 0,
                                '%memory' => isset( $stats['mu'] ) ? $stats['mu']['percent'] : 0,
-                               'min' => $stats['wt']['min'] / 1000,
-                               'max' => $stats['wt']['max'] / 1000
+                               '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 ) {
+                       if ( $stats['name'] === '-total' ) {
+                               // Discard section profiler running totals
+                               continue;
+                       }
+
+                       // @note: getFunctionStats() values already in ms
+                       $stats['%real'] = $main['real'] ? $stats['real'] / $main['real'] * 100 : 0;
+                       $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;
@@ -193,8 +154,13 @@ class ProfilerXhprof extends Profiler {
         * @return string
         */
        protected function getFunctionReport() {
-               $data = $this->xhprof->getInclusiveMetrics();
-               uasort( $data, Xhprof::makeSortFunction( 'wt', 'total' ) );
+               $data = $this->getFunctionStats();
+               usort( $data, function( $a, $b ) {
+                       if ( $a['real'] === $b['real'] ) {
+                               return 0;
+                       }
+                       return ( $a['real'] > $b['real'] ) ? -1 : 1; // descending
+               } );
 
                $width = 140;
                $nameWidth = $width - 65;
@@ -203,50 +169,18 @@ class ProfilerXhprof extends Profiler {
                $out[] = sprintf( "%-{$nameWidth}s %6s %9s %9s %9s %9s %7s %9s",
                        'Name', 'Calls', 'Total', 'Min', 'Each', 'Max', '%', 'Mem'
                );
-               foreach ( $data as $func => $stats ) {
-                       $out[] = sprintf( $format,
-                               $func,
-                               $stats['ct'],
-                               $stats['wt']['total'],
-                               $stats['wt']['min'],
-                               $stats['wt']['mean'],
-                               $stats['wt']['max'],
-                               $stats['wt']['percent'],
-                               isset( $stats['mu'] ) ? $stats['mu']['total'] : 0
-                       );
-               }
-               return implode( "\n", $out );
-       }
-
-       /**
-        * Get a brief report of profiled functions sorted by inclusive wall clock
-        * time in descending order.
-        *
-        * Each line of the report includes this data:
-        * - Percentage of total wall clock time spent in function
-        * - Total wall clock time spent in function in seconds
-        * - Number of times function was called
-        * - Function name
-        *
-        * @param string $header Header text to prepend to report
-        * @param string $footer Footer text to append to report
-        * @return string
-        */
-       protected function getSummaryReport( $header = '', $footer = '' ) {
-               $data = $this->xhprof->getInclusiveMetrics();
-               uasort( $data, Xhprof::makeSortFunction( 'wt', 'total' ) );
-
-               $format = '%6.2f%% %3.6f %6d - %s';
-               $out = array( $header );
-               foreach ( $data as $func => $stats ) {
+               foreach ( $data as $stats ) {
                        $out[] = sprintf( $format,
-                               $stats['wt']['percent'],
-                               $stats['wt']['total'] / 1e6,
-                               $stats['ct'],
-                               $func
+                               $stats['name'],
+                               $stats['calls'],
+                               $stats['real'] * 1000,
+                               $stats['min_real'] * 1000,
+                               $stats['real'] / $stats['calls'] * 1000,
+                               $stats['max_real'] * 1000,
+                               $stats['%real'],
+                               $stats['memory']
                        );
                }
-               $out[] = $footer;
                return implode( "\n", $out );
        }
 }