includes/profiler/ProfilerXhprof.php

   1 <?php
   2 /**
   3  * Copyright 2014 Wikimedia Foundation and contributors
   4  *
   5  * This program is free software; you can redistribute it and/or modify
   6  * it under the terms of the GNU General Public License as published by
   7  * the Free Software Foundation; either version 2 of the License, or
   8  * (at your option) any later version.
   9  *
  10  * This program is distributed in the hope that it will be useful,
  11  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  12  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  13  * GNU General Public License for more details.
  14  *
  15  * You should have received a copy of the GNU General Public License along
  16  * with this program; if not, write to the Free Software Foundation, Inc.,
  17  * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
  18  * http://www.gnu.org/copyleft/gpl.html
  19  *
  20  * @file
  21  */
  22
  23 /**
  24  * Profiler that captures all function calls from the XHProf PHP extension.
  25  *
  26  * This extension can be installed via PECL or your operating system's package manager.
  27  * This also supports the Tideways-XHProf PHP extension.
  28  *
  29  * @ingroup Profiler
  30  * @see $wgProfiler
  31  * @see https://php.net/xhprof
  32  * @see https://github.com/tideways/php-xhprof-extension
  33  */
  34 class ProfilerXhprof extends Profiler {
  35         /**
  36          * @var XhprofData|null
  37          */
  38         protected $xhprofData;
  39
  40         /**
  41          * Profiler for explicit, arbitrary, frame labels
  42          * @var SectionProfiler
  43          */
  44         protected $sprofiler;
  45
  46         /**
  47          * @see $wgProfiler
  48          * @param array $params Associative array of parameters:
  49          *  - int flags: Bitmask of constants from the XHProf or Tideways-XHProf extension
  50          *    that will be passed to its enable function,
  51          *    such as `XHPROF_FLAGS_CPU | XHPROF_FLAGS_MEMORY | XHPROF_FLAGS_NO_BUILTINS`.
  52          *    With Tideways-XHProf, use `TIDEWAYS_XHPROF_FLAGS_*` instead.
  53          *  - bool running: If true, it is assumed that the enable function was already
  54          *    called. The `flags` option is ignored in this case.
  55          *    This exists for use with a custom web entrypoint from which the profiler
  56          *    is started before MediaWiki is included.
  57          *  - array include: If set, only function names matching a pattern in this
  58          *    array will be reported. The pattern strings will be matched using
  59          *    the PHP fnmatch() function.
  60          *  - array exclude: If set, function names matching an exact name in this
  61          *    will be skipped over by XHProf. Ignored functions become transparent
  62          *    in the profile. For example, `foo=>ignored=>bar` becomes `foo=>bar`.
  63          *    This option is backed by XHProf's `ignored_functions` option.
  64          *
  65          *    **Note:** The `exclude` option is not supported in Tideways-XHProf.
  66          */
  67         public function __construct( array $params = [] ) {
  68                 parent::__construct( $params );
  69
  70                 // See T180183 and T247332 for why we need the 'running' option.
  71                 if ( empty( $params['running'] ) ) {
  72                         $flags = $params['flags'] ?? 0;
  73                         if ( function_exists( 'xhprof_enable' ) ) {
  74                                 $options = isset( $params['exclude'] )
  75                                         ? [ 'ignored_functions' => $params['exclude'] ]
  76                                         : [];
  77                                 xhprof_enable( $flags, $options );
  78                         } elseif ( function_exists( 'tideways_xhprof_enable' ) ) {
  79                                 if ( isset( $params['exclude'] ) ) {
  80                                         throw new RuntimeException( 'The exclude option is not supported in tideways_xhprof' );
  81                                 }
  82                                 tideways_xhprof_enable( $flags );
  83                         } else {
  84                                 throw new RuntimeException( 'Neither xhprof nor tideways_xhprof is installed' );
  85                         }
  86                 }
  87
  88                 $this->sprofiler = new SectionProfiler();
  89         }
  90
  91         /**
  92          * @return XhprofData
  93          */
  94         public function getXhprofData() {
  95                 if ( !$this->xhprofData ) {
  96                         if ( function_exists( 'xhprof_disable' ) ) {
  97                                 $data = xhprof_disable();
  98                         } elseif ( function_exists( 'tideways_xhprof_disable' ) ) {
  99                                 $data = tideways_xhprof_disable();
 100                         } else {
 101                                 throw new RuntimeException( 'Neither xhprof nor tideways_xhprof is installed' );
 102                         }
 103                         $this->xhprofData = new XhprofData( $data, $this->params );
 104                 }
 105                 return $this->xhprofData;
 106         }
 107
 108         public function scopedProfileIn( $section ) {
 109                 $key = 'section.' . ltrim( $section, '.' );
 110                 return $this->sprofiler->scopedProfileIn( $key );
 111         }
 112
 113         /**
 114          * No-op for xhprof profiling.
 115          */
 116         public function close() {
 117         }
 118
 119         /**
 120          * Check if a function or section should be excluded from the output.
 121          *
 122          * @param string $name Function or section name.
 123          * @return bool
 124          */
 125         private function shouldExclude( $name ) {
 126                 if ( $name === '-total' ) {
 127                         return true;
 128                 }
 129                 if ( !empty( $this->params['include'] ) ) {
 130                         foreach ( $this->params['include'] as $pattern ) {
 131                                 if ( fnmatch( $pattern, $name, FNM_NOESCAPE ) ) {
 132                                         return false;
 133                                 }
 134                         }
 135                         return true;
 136                 }
 137                 if ( !empty( $this->params['exclude'] ) ) {
 138                         foreach ( $this->params['exclude'] as $pattern ) {
 139                                 if ( fnmatch( $pattern, $name, FNM_NOESCAPE ) ) {
 140                                         return true;
 141                                 }
 142                         }
 143                 }
 144                 return false;
 145         }
 146
 147         public function getFunctionStats() {
 148                 $metrics = $this->getXhprofData()->getCompleteMetrics();
 149                 $profile = [];
 150
 151                 $main = null; // units in ms
 152                 foreach ( $metrics as $fname => $stats ) {
 153                         if ( $this->shouldExclude( $fname ) ) {
 154                                 continue;
 155                         }
 156                         // Convert elapsed times from μs to ms to match interface
 157                         $entry = [
 158                                 'name' => $fname,
 159                                 'calls' => $stats['ct'],
 160                                 'real' => $stats['wt']['total'] / 1000,
 161                                 '%real' => $stats['wt']['percent'],
 162                                 'cpu' => ( $stats['cpu']['total'] ?? 0 ) / 1000,
 163                                 '%cpu' => $stats['cpu']['percent'] ?? 0,
 164                                 'memory' => $stats['mu']['total'] ?? 0,
 165                                 '%memory' => $stats['mu']['percent'] ?? 0,
 166                                 'min_real' => $stats['wt']['min'] / 1000,
 167                                 'max_real' => $stats['wt']['max'] / 1000
 168                         ];
 169                         $profile[] = $entry;
 170                         if ( $fname === 'main()' ) {
 171                                 $main = $entry;
 172                         }
 173                 }
 174
 175                 // Merge in all of the custom profile sections
 176                 foreach ( $this->sprofiler->getFunctionStats() as $stats ) {
 177                         if ( $this->shouldExclude( $stats['name'] ) ) {
 178                                 continue;
 179                         }
 180
 181                         // @note: getFunctionStats() values already in ms
 182                         $stats['%real'] = $main['real'] ? $stats['real'] / $main['real'] * 100 : 0;
 183                         $stats['%cpu'] = $main['cpu'] ? $stats['cpu'] / $main['cpu'] * 100 : 0;
 184                         $stats['%memory'] = $main['memory'] ? $stats['memory'] / $main['memory'] * 100 : 0;
 185                         $profile[] = $stats; // assume no section names collide with $metrics
 186                 }
 187
 188                 return $profile;
 189         }
 190
 191         /**
 192          * Returns a profiling output to be stored in debug file
 193          *
 194          * @return string
 195          */
 196         public function getOutput() {
 197                 return $this->getFunctionReport();
 198         }
 199
 200         /**
 201          * Get a report of profiled functions sorted by inclusive wall clock time
 202          * in descending order.
 203          *
 204          * Each line of the report includes this data:
 205          * - Function name
 206          * - Number of times function was called
 207          * - Total wall clock time spent in function in microseconds
 208          * - Minimum wall clock time spent in function in microseconds
 209          * - Average wall clock time spent in function in microseconds
 210          * - Maximum wall clock time spent in function in microseconds
 211          * - Percentage of total wall clock time spent in function
 212          * - Total delta of memory usage from start to end of function in bytes
 213          *
 214          * @return string
 215          */
 216         protected function getFunctionReport() {
 217                 $data = $this->getFunctionStats();
 218                 usort( $data, static function ( $a, $b ) {
 219                         return $b['real'] <=> $a['real']; // descending
 220                 } );
 221
 222                 $width = 140;
 223                 $nameWidth = $width - 65;
 224                 $format = "%-{$nameWidth}s %6d %9d %9d %9d %9d %7.3f%% %9d";
 225                 $out = [];
 226                 $out[] = sprintf( "%-{$nameWidth}s %6s %9s %9s %9s %9s %7s %9s",
 227                         'Name', 'Calls', 'Total', 'Min', 'Each', 'Max', '%', 'Mem'
 228                 );
 229                 foreach ( $data as $stats ) {
 230                         $out[] = sprintf( $format,
 231                                 $stats['name'],
 232                                 $stats['calls'],
 233                                 $stats['real'] * 1000,
 234                                 $stats['min_real'] * 1000,
 235                                 $stats['real'] / $stats['calls'] * 1000,
 236                                 $stats['max_real'] * 1000,
 237                                 $stats['%real'],
 238                                 $stats['memory']
 239                         );
 240                 }
 241                 return implode( "\n", $out );
 242         }
 243
 244         /**
 245          * Retrieve raw data from xhprof
 246          * @return array
 247          */
 248         public function getRawData() {
 249                 return $this->getXhprofData()->getRawData();
 250         }
 251 }