includes/profiler/ProfilerMwprof.php

   1 <?php
   2 /**
   3  * Profiler class for Mwprof.
   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  * @ingroup Profiler
  22  */
  23
  24 /**
  25  * Profiler class for Mwprof.
  26  *
  27  * Mwprof is a high-performance MediaWiki profiling data collector, designed to
  28  * collect profiling data from multiple hosts running in tandem. This class
  29  * serializes profiling samples into MessagePack arrays and sends them to an
  30  * Mwprof instance via UDP.
  31  *
  32  * @see https://github.com/wikimedia/operations-software-mwprof
  33  * @since 1.23
  34  */
  35 class ProfilerMwprof extends Profiler {
  36         /** @var array Queue of open profile calls with start data */
  37         protected $mWorkStack = array();
  38
  39         /** @var array Map of (function name => aggregate data array) */
  40         protected $mCollated = array();
  41         /** @var array Cache of a standard broken collation entry */
  42         protected $mErrorEntry;
  43
  44         // Message types
  45         const TYPE_SINGLE = 1;
  46         const TYPE_RUNNING = 2;
  47
  48         public function isStub() {
  49                 return false;
  50         }
  51
  52         public function isPersistent() {
  53                 return true;
  54         }
  55
  56         /**
  57          * Start a profiling section.
  58          *
  59          * Marks the beginning of the function or code-block that should be time
  60          * and logged under some specific name.
  61          *
  62          * @param string $inName Section to start
  63          */
  64         public function profileIn( $inName ) {
  65                 $this->mWorkStack[] = array( $inName, count( $this->mWorkStack ),
  66                         $this->getTime(), $this->getTime( 'cpu' ), 0 );
  67         }
  68
  69         /**
  70          * Close a profiling section.
  71          *
  72          * Marks the end of the function or code-block that should be timed and
  73          * logged under some specific name.
  74          *
  75          * @param string $outName Section to close
  76          */
  77         public function profileOut( $outName ) {
  78                 list( $inName, $inCount, $inWall, $inCpu ) = array_pop( $this->mWorkStack );
  79
  80                 // Check for unbalanced profileIn / profileOut calls.
  81                 // Bad entries are logged but not sent.
  82                 if ( $inName !== $outName ) {
  83                         $this->debugGroup( 'ProfilerUnbalanced', json_encode( array( $inName, $outName ) ) );
  84                         return;
  85                 }
  86
  87                 $elapsedCpu = $this->getTime( 'cpu' ) - $inCpu;
  88                 $elapsedWall = $this->getTime() - $inWall;
  89                 $this->updateRunningEntry( $outName, $elapsedCpu, $elapsedWall );
  90                 $this->trxProfiler->recordFunctionCompletion( $outName, $elapsedWall );
  91         }
  92
  93         /**
  94          * Update an entry with timing data.
  95          *
  96          * @param string $name Section name
  97          * @param float $elapsedCpu Elapsed CPU time
  98          * @param float $elapsedWall Elapsed wall-clock time
  99          */
 100         public function updateRunningEntry( $name, $elapsedCpu, $elapsedWall ) {
 101                 // If this is the first measurement for this entry, store plain values.
 102                 // Many profiled functions will only be called once per request.
 103                 if ( !isset( $this->mCollated[$name] ) ) {
 104                         $this->mCollated[$name] = array(
 105                                 'cpu'   => $elapsedCpu,
 106                                 'wall'  => $elapsedWall,
 107                                 'count' => 1,
 108                         );
 109                         return;
 110                 }
 111
 112                 $entry = &$this->mCollated[$name];
 113
 114                 // If it's the second measurement, convert the plain values to
 115                 // RunningStat instances, so we can push the incoming values on top.
 116                 if ( $entry['count'] === 1 ) {
 117                         $cpu = new RunningStat();
 118                         $cpu->push( $entry['cpu'] );
 119                         $entry['cpu'] = $cpu;
 120
 121                         $wall = new RunningStat();
 122                         $wall->push( $entry['wall'] );
 123                         $entry['wall'] = $wall;
 124                 }
 125
 126                 $entry['count']++;
 127                 $entry['cpu']->push( $elapsedCpu );
 128                 $entry['wall']->push( $elapsedWall );
 129         }
 130
 131         /**
 132          * @return array
 133          */
 134         public function getRawData() {
 135                 // This method is called before shutdown in the footer method on Skins.
 136                 // If some outer methods have not yet called wfProfileOut(), work around
 137                 // that by clearing anything in the work stack to just the "-total" entry.
 138                 if ( count( $this->mWorkStack ) > 1 ) {
 139                         $oldWorkStack = $this->mWorkStack;
 140                         $this->mWorkStack = array( $this->mWorkStack[0] ); // just the "-total" one
 141                 } else {
 142                         $oldWorkStack = null;
 143                 }
 144                 $this->close();
 145                 // If this trick is used, then the old work stack is swapped back afterwards.
 146                 // This means that logData() will still make use of all the method data since
 147                 // the missing wfProfileOut() calls should be made by the time it is called.
 148                 if ( $oldWorkStack ) {
 149                         $this->mWorkStack = $oldWorkStack;
 150                 }
 151
 152                 $totalWall = 0.0;
 153                 $profile = array();
 154                 foreach ( $this->mCollated as $fname => $data ) {
 155                         if ( $data['count'] == 1 ) {
 156                                 $profile[] = array(
 157                                         'name' => $fname,
 158                                         'calls' => $data['count'],
 159                                         'elapsed' => $data['wall'] * 1000,
 160                                         'memory' => 0, // not supported
 161                                         'min' => $data['wall'] * 1000,
 162                                         'max' => $data['wall'] * 1000,
 163                                         'overhead' => 0, // not supported
 164                                         'periods' => array() // not supported
 165                                 );
 166                                 $totalWall += $data['wall'];
 167                         } else {
 168                                 $profile[] = array(
 169                                         'name' => $fname,
 170                                         'calls' => $data['count'],
 171                                         'elapsed' => $data['wall']->n * $data['wall']->getMean() * 1000,
 172                                         'memory' => 0, // not supported
 173                                         'min' => $data['wall']->min * 1000,
 174                                         'max' => $data['wall']->max * 1000,
 175                                         'overhead' => 0, // not supported
 176                                         'periods' => array() // not supported
 177                                 );
 178                                 $totalWall += $data['wall']->n * $data['wall']->getMean();
 179                         }
 180                 }
 181                 $totalWall = $totalWall * 1000;
 182
 183                 foreach ( $profile as &$item ) {
 184                         $item['percent'] = $totalWall ? 100 * $item['elapsed'] / $totalWall : 0;
 185                 }
 186
 187                 return $profile;
 188         }
 189
 190         /**
 191          * Serialize profiling data and send to a profiling data aggregator.
 192          *
 193          * Individual entries are represented as arrays and then encoded using
 194          * MessagePack, an efficient binary data-interchange format. Encoded
 195          * entries are accumulated into a buffer and sent in batch via UDP to the
 196          * profiling data aggregator.
 197          */
 198         public function logData() {
 199                 global $wgUDPProfilerHost, $wgUDPProfilerPort;
 200
 201                 $this->close();
 202
 203                 if ( !function_exists( 'socket_create' ) ) {
 204                         return; // avoid fatal
 205                 }
 206
 207                 $sock = socket_create( AF_INET, SOCK_DGRAM, SOL_UDP );
 208                 socket_connect( $sock, $wgUDPProfilerHost, $wgUDPProfilerPort );
 209                 $bufferLength = 0;
 210                 $buffer = '';
 211                 foreach ( $this->mCollated as $name => $entry ) {
 212                         $count = $entry['count'];
 213                         $cpu = $entry['cpu'];
 214                         $wall = $entry['wall'];
 215
 216                         if ( $count === 1 ) {
 217                                 $data = array( self::TYPE_SINGLE, $name, $cpu, $wall );
 218                         } else {
 219                                 $data = array( self::TYPE_RUNNING, $name, $count,
 220                                         $cpu->m1, $cpu->m2, $cpu->min, $cpu->max,
 221                                         $wall->m1, $wall->m2, $wall->min, $wall->max );
 222                         }
 223
 224                         $encoded = MWMessagePack::pack( $data );
 225                         $length = strlen( $encoded );
 226
 227                         // If adding this entry would cause the size of the buffer to
 228                         // exceed the standard ethernet MTU size less the UDP header,
 229                         // send all pending data and reset the buffer. Otherwise, continue
 230                         // accumulating entries into the current buffer.
 231                         if ( $length + $bufferLength > 1450 ) {
 232                                 socket_send( $sock, $buffer, $bufferLength, 0 );
 233                                 $buffer = '';
 234                                 $bufferLength = 0;
 235                         }
 236                         $buffer .= $encoded;
 237                         $bufferLength += $length;
 238                 }
 239                 if ( $bufferLength !== 0 ) {
 240                         socket_send( $sock, $buffer, $bufferLength, 0 );
 241                 }
 242         }
 243
 244         /**
 245          * Close opened profiling sections
 246          */
 247         public function close() {
 248                 while ( count( $this->mWorkStack ) ) {
 249                         $this->profileOut( 'close' );
 250                 }
 251         }
 252
 253         public function getOutput() {
 254                 return ''; // no report
 255         }
 256 }