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