Added $wgTrxProfilerLimits and slow query limits

* Limits are now configurable instead of being hard-coded

Change-Id: I99133586eb82e8e9e84061548c8d1a99695fde5c

diff --git a/includes/DefaultSettings.php b/includes/DefaultSettings.php
index a16a1f0..d35683e 100644 (file)
--- a/includes/DefaultSettings.php
+++ b/includes/DefaultSettings.php
@@ -5295,6 +5295,21 @@ $wgDebugDumpSql = false;
  */
 $wgDebugDumpSqlLength = 500;
 
+/**
+ * Performance expectations for DB usage
+ *
+ * @since 1.26
+ */
+$wgTrxProfilerLimits = array(
+       // Basic GET and POST requests
+       'GET'  => array( 'masterConns' => 0, 'writes' => 0, 'readQueryTime' => 5 ),
+       'POST' => array( 'maxAffected' => 500, 'readQueryTime' => 5, 'writeQueryTime' => 1 ),
+       // Background job runner
+       'JobRunner' => array( 'maxAffected' => 500, 'readQueryTime' => 30, 'writeQueryTime' => 5 ),
+       // Command-line scripts
+       'Maintenance' => array( 'maxAffected' => 1000, 'writeQueryTime' => 5 )
+);
+
 /**
  * Map of string log group names to log destinations.
  *

diff --git a/includes/MediaWiki.php b/includes/MediaWiki.php
index ec2f40f..d0e81cf 100644 (file)
--- a/includes/MediaWiki.php
+++ b/includes/MediaWiki.php
@@ -457,7 +457,7 @@ class MediaWiki {
        }
 
        private function main() {
-               global $wgTitle;
+               global $wgTitle, $wgTrxProfilerLimits;
 
                $request = $this->context->getRequest();
 
@@ -489,10 +489,9 @@ class MediaWiki {
                if ( !$request->wasPosted()
                        && in_array( $action, array( 'view', 'edit', 'history' ) )
                ) {
-                       $trxProfiler->setExpectation( 'masterConns', 0, __METHOD__ );
-                       $trxProfiler->setExpectation( 'writes', 0, __METHOD__ );
+                       $trxProfiler->setExpectations( $wgTrxProfilerLimits['GET'], __METHOD__ );
                } else {
-                       $trxProfiler->setExpectation( 'maxAffected', 500, __METHOD__ );
+                       $trxProfiler->setExpectations( $wgTrxProfilerLimits['POST'], __METHOD__ );
                }
 
                // If the user has forceHTTPS set to true, or if the user

diff --git a/includes/jobqueue/JobRunner.php b/includes/jobqueue/JobRunner.php
index 9425423..e9ae30e 100644 (file)
--- a/includes/jobqueue/JobRunner.php
+++ b/includes/jobqueue/JobRunner.php
@@ -88,7 +88,7 @@ class JobRunner implements LoggerAwareInterface {
         * @return array Summary response that can easily be JSON serialized
         */
        public function run( array $options ) {
-               global $wgJobClasses;
+               global $wgJobClasses, $wgTrxProfilerLimits;
 
                $response = array( 'jobs' => array(), 'reached' => 'none-ready' );
 
@@ -120,7 +120,7 @@ class JobRunner implements LoggerAwareInterface {
                // Catch huge single updates that lead to slave lag
                $trxProfiler = Profiler::instance()->getTransactionProfiler();
                $trxProfiler->setLogger( LoggerFactory::getInstance( 'DBPerformance' ) );
-               $trxProfiler->setExpectation( 'maxAffected', 500, __METHOD__ );
+               $trxProfiler->setExpectations( $wgTrxProfilerLimits['JobRunner'], __METHOD__ );
 
                // Bail out if there is too much DB lag.
                // This check should not block as we want to try other wiki queues.

diff --git a/includes/profiler/TransactionProfiler.php b/includes/profiler/TransactionProfiler.php
index f02d66f..5f2a57a 100644 (file)
--- a/includes/profiler/TransactionProfiler.php
+++ b/includes/profiler/TransactionProfiler.php
@@ -25,6 +25,7 @@
 use Psr\Log\LoggerInterface;
 use Psr\Log\LoggerAwareInterface;
 use Psr\Log\NullLogger;
+
 /**
  * Helper class that detects high-contention DB queries via profiling calls
  *
@@ -52,11 +53,13 @@ class TransactionProfiler implements LoggerAwareInterface {
        );
        /** @var array */
        protected $expect = array(
-               'writes'      => INF,
-               'queries'     => INF,
-               'conns'       => INF,
-               'masterConns' => INF,
-               'maxAffected' => INF
+               'writes'         => INF,
+               'queries'        => INF,
+               'conns'          => INF,
+               'masterConns'    => INF,
+               'maxAffected'    => INF,
+               'readQueryTime'  => INF,
+               'writeQueryTime' => INF,
        );
        /** @var array */
        protected $expectBy = array();
@@ -77,7 +80,7 @@ class TransactionProfiler implements LoggerAwareInterface {
        /**
         * Set performance expectations
         *
-        * With conflicting expect, the most specific ones will be used
+        * With conflicting expectations, the most narrow ones will be used
         *
         * @param string $event (writes,queries,conns,mConns)
         * @param integer $value Maximum count of the event
@@ -93,6 +96,21 @@ class TransactionProfiler implements LoggerAwareInterface {
                }
        }
 
+       /**
+        * Set multiple performance expectations
+        *
+        * With conflicting expectations, the most narrow ones will be used
+        *
+        * @param array $expects Map of (event => limit)
+        * @param $fname
+        * @since 1.26
+        */
+       public function setExpectations( array $expects, $fname ) {
+               foreach ( $expects as $event => $value ) {
+                       $this->setExpectation( $event, $value, $fname );
+               }
+       }
+
        /**
         * Reset performance expectations and hit counters
         *
@@ -170,7 +188,8 @@ class TransactionProfiler implements LoggerAwareInterface {
                $elapsed = ( $eTime - $sTime );
 
                if ( $isWrite && $n > $this->expect['maxAffected'] ) {
-                       $this->logger->info( "Query affected $n row(s):\n" . $query . "\n" . wfBacktrace( true ) );
+                       $this->logger->info( "Query affected $n row(s):\n" . $query . "\n" .
+                               wfBacktrace( true ) );
                }
 
                // Report when too many writes/queries happen...
@@ -180,6 +199,13 @@ class TransactionProfiler implements LoggerAwareInterface {
                if ( $isWrite && $this->hits['writes']++ == $this->expect['writes'] ) {
                        $this->reportExpectationViolated( 'writes', $query );
                }
+               // Report slow queries...
+               if ( !$isWrite && $elapsed > $this->expect['readQueryTime'] ) {
+                       $this->reportExpectationViolated( 'readQueryTime', $query );
+               }
+               if ( $isWrite && $elapsed > $this->expect['writeQueryTime'] ) {
+                       $this->reportExpectationViolated( 'writeQueryTime', $query );
+               }
 
                if ( !$this->dbTrxHoldingLocks ) {
                        // Short-circuit
@@ -268,7 +294,8 @@ class TransactionProfiler implements LoggerAwareInterface {
                $n = $this->expect[$expect];
                $by = $this->expectBy[$expect];
                $this->logger->info(
-                       "[{$wgRequest->getMethod()}] Expectation ($expect <= $n) by $by not met:\n$query\n" . wfBacktrace( true )
+                       "[{$wgRequest->getMethod()}] Expectation ($expect <= $n) by $by not met:\n$query\n" .
+                       wfBacktrace( true )
                );
        }
 }

diff --git a/maintenance/Maintenance.php b/maintenance/Maintenance.php
index f97f6dc..50b8a01 100644 (file)
--- a/maintenance/Maintenance.php
+++ b/maintenance/Maintenance.php
@@ -603,7 +603,7 @@ abstract class Maintenance {
         * Activate the profiler (assuming $wgProfiler is set)
         */
        protected function activateProfiler() {
-               global $wgProfiler;
+               global $wgProfiler, $wgTrxProfilerLimits;
 
                $output = $this->getOption( 'profiler' );
                if ( $output && is_array( $wgProfiler ) && isset( $wgProfiler['class'] ) ) {
@@ -617,8 +617,7 @@ abstract class Maintenance {
 
                $trxProfiler = Profiler::instance()->getTransactionProfiler();
                $trxProfiler->setLogger( LoggerFactory::getInstance( 'DBPerformance' ) );
-               # Catch huge single updates that lead to slave lag
-               $trxProfiler->setExpectation( 'maxAffected', 1000, __METHOD__ );
+               $trxProfiler->setExpectations( $wgTrxProfilerLimits['Maintenance'], __METHOD__ );
        }
 
        /**