Introduce ProfilerOutputStats
authorOri Livneh <ori@wikimedia.org>
Wed, 1 Apr 2015 23:30:16 +0000 (16:30 -0700)
committerKrinkle <krinklemail@gmail.com>
Thu, 2 Apr 2015 01:32:46 +0000 (01:32 +0000)
* Associate Profiler objects with a request context by adding a $context
  property with a getter and a setter.
* Introduce ProfilerOutputStats, which writes profiling data to the stats
  buffer associated with the current request context.
* Make it the Profiler class's responsibility to enforce $wgProfilerLimit.
* Deprecate $wgProfilerLimit in favor of the (more aptly named, IMO)
  $wgProfiler['threshold'] config setting.
* Tidy up Profiler instance creation code in Profiler::instance().
* Add Profiler::getOutputs, which returns an array of ProfilerOutput instances
  which are configured for the current profiler and whose canUse() method
  returns true.
* Make ProfilerStub not log by creating a stub ProfilerStub::logData() method
  which does not call the parent. Previously the parent class checked if $this
  was an instance of ProfilerStub and returned early if so.

Task: T90623
Task: T85641
Change-Id: Icf644ad3435c1f30d0a49957a97b481808a3153d

autoload.php
includes/DefaultSettings.php
includes/GlobalFunctions.php
includes/profiler/Profiler.php
includes/profiler/ProfilerStub.php
includes/profiler/output/ProfilerOutputStats.php [new file with mode: 0644]

index dcd7879..da661a2 100644 (file)
@@ -910,6 +910,7 @@ $wgAutoloadLocalClasses = array(
        'ProfilerOutput' => __DIR__ . '/includes/profiler/output/ProfilerOutput.php',
        'ProfilerOutputDb' => __DIR__ . '/includes/profiler/output/ProfilerOutputDb.php',
        'ProfilerOutputDump' => __DIR__ . '/includes/profiler/output/ProfilerOutputDump.php',
+       'ProfilerOutputStats' => __DIR__ . '/includes/profiler/output/ProfilerOutputStats.php',
        'ProfilerOutputText' => __DIR__ . '/includes/profiler/output/ProfilerOutputText.php',
        'ProfilerOutputUdp' => __DIR__ . '/includes/profiler/output/ProfilerOutputUdp.php',
        'ProfilerSectionOnly' => __DIR__ . '/includes/profiler/ProfilerSectionOnly.php',
index 84dc3aa..5e81d0f 100644 (file)
@@ -5423,6 +5423,7 @@ $wgDeprecationReleaseLimit = false;
 
 /**
  * Only record profiling info for pages that took longer than this
+ * @deprecated since 1.25: set $wgProfiler['threshold'] instead.
  */
 $wgProfileLimit = 0.0;
 
index 70473ca..24a3c33 100644 (file)
@@ -1237,10 +1237,15 @@ function wfErrorLog( $text, $file, array $context = array() ) {
  * @todo document
  */
 function wfLogProfilingData() {
-       global $wgDebugLogGroups, $wgDebugRawPage, $wgProfileLimit;
+       global $wgDebugLogGroups, $wgDebugRawPage;
 
        $context = RequestContext::getMain();
        $request = $context->getRequest();
+
+       $profiler = Profiler::instance();
+       $profiler->setContext( $context );
+       $profiler->logData();
+
        $config = $context->getConfig();
        if ( $config->has( 'StatsdServer' ) ) {
                $statsdServer = explode( ':', $config->get( 'StatsdServer' ) );
@@ -1251,22 +1256,11 @@ function wfLogProfilingData() {
                $statsdClient->send( $context->getStats()->getBuffer() );
        }
 
-       $profiler = Profiler::instance();
-
        # Profiling must actually be enabled...
        if ( $profiler instanceof ProfilerStub ) {
                return;
        }
 
-       // Get total page request time and only show pages that longer than
-       // $wgProfileLimit time (default is 0)
-       $elapsed = $request->getElapsedTime();
-       if ( $elapsed <= $wgProfileLimit ) {
-               return;
-       }
-
-       $profiler->logData();
-
        if ( isset( $wgDebugLogGroups['profileoutput'] )
                && $wgDebugLogGroups['profileoutput'] === false
        ) {
@@ -1277,7 +1271,7 @@ function wfLogProfilingData() {
                return;
        }
 
-       $ctx = array( 'elapsed' => $elapsed );
+       $ctx = array( 'elapsed' => $request->getElapsedTime() );
        if ( !empty( $_SERVER['HTTP_X_FORWARDED_FOR'] ) ) {
                $ctx['forwarded_for'] = $_SERVER['HTTP_X_FORWARDED_FOR'];
        }
index 1c9824a..0718875 100644 (file)
@@ -35,6 +35,8 @@ abstract class Profiler {
        protected $templated = false;
        /** @var array All of the params passed from $wgProfiler */
        protected $params = array();
+       /** @var IContextSource Current request context */
+       protected $context = null;
 
        /** @var TransactionProfiler */
        protected $trxProfiler;
@@ -47,6 +49,7 @@ abstract class Profiler {
                'text' => 'ProfilerOutputText',
                'udp' => 'ProfilerOutputUdp',
                'dump' => 'ProfilerOutputDump',
+               'context' => 'ProfilerOutputStats',
        );
 
        /** @var Profiler */
@@ -69,17 +72,28 @@ abstract class Profiler {
         */
        final public static function instance() {
                if ( self::$instance === null ) {
-                       global $wgProfiler;
+                       global $wgProfiler, $wgProfileLimit;
+
+                       $params = array(
+                               'class'     => 'ProfilerStub',
+                               'sampling'  => 1,
+                               'threshold' => $wgProfileLimit,
+                               'output'    => array(),
+                       );
                        if ( is_array( $wgProfiler ) ) {
-                               $class = isset( $wgProfiler['class'] ) ? $wgProfiler['class'] : 'ProfilerStub';
-                               $factor = isset( $wgProfiler['sampling'] ) ? $wgProfiler['sampling'] : 1;
-                               if ( PHP_SAPI === 'cli' || mt_rand( 0, $factor - 1 ) != 0 ) {
-                                       $class = 'ProfilerStub';
-                               }
-                               self::$instance = new $class( $wgProfiler );
-                       } else {
-                               self::$instance = new ProfilerStub( array() );
+                               $params = array_merge( $params, $wgProfiler );
+                       }
+
+                       $inSample = mt_rand( 0, $params['sampling'] - 1 ) === 0;
+                       if ( PHP_SAPI === 'cli' || !$inSample ) {
+                               $params['class'] = 'ProfilerStub';
+                       }
+
+                       if ( !is_array( $params['output'] ) ) {
+                               $params['output'] = array( $params['output'] );
                        }
+
+                       self::$instance = new $params['class']( $params );
                }
                return self::$instance;
        }
@@ -117,6 +131,32 @@ abstract class Profiler {
                }
        }
 
+       /**
+        * Sets the context for this Profiler
+        *
+        * @param IContextSource $context
+        * @since 1.25
+        */
+       public function setContext( $context ) {
+               $this->context = $context;
+       }
+
+       /**
+        * Gets the context for this Profiler
+        *
+        * @return IContextSource
+        * @since 1.25
+        */
+       public function getContext() {
+               if ( $this->context ) {
+                       return $this->context;
+               } else {
+                       wfDebug( __METHOD__ . " called and \$context is null. " .
+                               "Return RequestContext::getMain(); for sanity\n" );
+                       return RequestContext::getMain();
+               }
+       }
+
        // Kept BC for now, remove when possible
        public function profileIn( $functionname ) {}
        public function profileOut( $functionname ) {}
@@ -152,37 +192,49 @@ abstract class Profiler {
        abstract public function close();
 
        /**
-        * Log the data to some store or even the page output
+        * Get all usable outputs.
         *
         * @throws MWException
+        * @return array Array of ProfilerOutput instances.
+        * @since 1.25
+        */
+       private function getOutputs() {
+               $outputs = array();
+               foreach ( $this->params['output'] as $outputType ) {
+                       if ( !isset( self::$outputTypes[$outputType] ) ) {
+                               throw new MWException( "'$outputType' is an invalid output type" );
+                       }
+                       $outputClass = self::$outputTypes[$outputType];
+                       $outputInstance = new $outputClass( $this, $this->params );
+                       if ( $outputInstance->canUse() ) {
+                               $outputs[] = $outputInstance;
+                       }
+               }
+               return $outputs;
+       }
+
+       /**
+        * Log the data to some store or even the page output
+        *
         * @since 1.25
         */
        public function logData() {
-               $output = isset( $this->params['output'] ) ? $this->params['output'] : null;
+               $request = $this->getContext()->getRequest();
 
-               if ( !$output || $this instanceof ProfilerStub ) {
-                       // return early when no output classes defined or we're a stub
+               $timeElapsed = $request->getElapsedTime();
+               $timeElapsedThreshold = $this->params['threshold'];
+               if ( $timeElapsed <= $timeElapsedThreshold ) {
                        return;
                }
 
-               if ( !is_array( $output ) ) {
-                       $output = array( $output );
+               $outputs = $this->getOutputs();
+               if ( !$outputs ) {
+                       return;
                }
-               $stats = null;
-               foreach ( $output as $outType ) {
-                       if ( !isset( self::$outputTypes[$outType] ) ) {
-                               throw new MWException( "'$outType' is an invalid output type" );
-                       }
-                       $class = self::$outputTypes[$outType];
 
-                       /** @var ProfilerOutput $profileOut */
-                       $profileOut = new $class( $this, $this->params );
-                       if ( $profileOut->canUse() ) {
-                               if ( is_null( $stats ) ) {
-                                       $stats = $this->getFunctionStats();
-                               }
-                               $profileOut->log( $stats );
-                       }
+               $stats = $this->getFunctionStats();
+               foreach ( $outputs as $output ) {
+                       $output->log( $stats );
                }
        }
 
index 1d04536..244b4e4 100644 (file)
@@ -43,4 +43,7 @@ class ProfilerStub extends Profiler {
        public function getCurrentSection() {
                return '';
        }
+
+       public function logData() {
+       }
 }
diff --git a/includes/profiler/output/ProfilerOutputStats.php b/includes/profiler/output/ProfilerOutputStats.php
new file mode 100644 (file)
index 0000000..ef6ef7c
--- /dev/null
@@ -0,0 +1,57 @@
+<?php
+/**
+ * ProfilerOutput class that flushes profiling data to the profiling
+ * context's stats buffer.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ * @ingroup Profiler
+ */
+
+/**
+ * ProfilerOutput class that flushes profiling data to the profiling
+ * context's stats buffer.
+ *
+ * @ingroup Profiler
+ * @since 1.25
+ */
+class ProfilerOutputStats extends ProfilerOutput {
+
+       /**
+        * Flush profiling data to the current profiling context's stats buffer.
+        *
+        * @param array $stats
+        */
+       public function log( array $stats ) {
+               $contextStats = $this->collector->getContext()->getStats();
+
+               foreach ( $stats as $stat ) {
+                       // Sanitize the key
+                       $key = str_replace( '::', '.', $stat['name'] );
+                       $key = preg_replace( '/[^a-z.]+/i', '_', $key );
+                       $key = trim( $key, '_.' );
+
+                       // Convert fractional seconds to whole milliseconds
+                       $cpu = round( $stat['cpu'] * 1000 );
+                       $real = round( $stat['real'] * 1000 );
+
+                       $contextStats->increment( "{$key}.calls" );
+                       $contextStats->timing( "{$key}.cpu", $cpu );
+                       $contextStats->timing( "{$key}.real", $real );
+               }
+       }
+}