Add CollationFa
[lhc/web/wiklou.git] / includes / profiler / TransactionProfiler.php
index 3f4d58b..bf26573 100644 (file)
@@ -38,21 +38,23 @@ class TransactionProfiler implements LoggerAwareInterface {
        protected $dbLockThreshold = 3.0;
        /** @var float Seconds */
        protected $eventThreshold = .25;
+       /** @var bool */
+       protected $silenced = false;
 
        /** @var array transaction ID => (write start time, list of DBs involved) */
-       protected $dbTrxHoldingLocks = array();
+       protected $dbTrxHoldingLocks = [];
        /** @var array transaction ID => list of (query name, start time, end time) */
-       protected $dbTrxMethodTimes = array();
+       protected $dbTrxMethodTimes = [];
 
        /** @var array */
-       protected $hits = array(
+       protected $hits = [
                'writes'      => 0,
                'queries'     => 0,
                'conns'       => 0,
                'masterConns' => 0
-       );
+       ];
        /** @var array */
-       protected $expect = array(
+       protected $expect = [
                'writes'         => INF,
                'queries'        => INF,
                'conns'          => INF,
@@ -60,9 +62,9 @@ class TransactionProfiler implements LoggerAwareInterface {
                'maxAffected'    => INF,
                'readQueryTime'  => INF,
                'writeQueryTime' => INF
-       );
+       ];
        /** @var array */
-       protected $expectBy = array();
+       protected $expectBy = [];
 
        /**
         * @var LoggerInterface
@@ -77,6 +79,14 @@ class TransactionProfiler implements LoggerAwareInterface {
                $this->logger = $logger;
        }
 
+       /**
+        * @param bool $value
+        * @since 1.28
+        */
+       public function setSilenced( $value ) {
+               $this->silenced = $value;
+       }
+
        /**
         * Set performance expectations
         *
@@ -125,7 +135,7 @@ class TransactionProfiler implements LoggerAwareInterface {
                        $val = INF;
                }
                unset( $val );
-               $this->expectBy = array();
+               $this->expectBy = [];
        }
 
        /**
@@ -161,11 +171,11 @@ class TransactionProfiler implements LoggerAwareInterface {
                if ( isset( $this->dbTrxHoldingLocks[$name] ) ) {
                        $this->logger->info( "Nested transaction for '$name' - out of sync." );
                }
-               $this->dbTrxHoldingLocks[$name] = array(
+               $this->dbTrxHoldingLocks[$name] = [
                        'start' => microtime( true ),
-                       'conns' => array(), // all connections involved
-               );
-               $this->dbTrxMethodTimes[$name] = array();
+                       'conns' => [], // all connections involved
+               ];
+               $this->dbTrxMethodTimes[$name] = [];
 
                foreach ( $this->dbTrxHoldingLocks as $name => &$info ) {
                        // Track all DBs in transactions for this transaction
@@ -201,10 +211,10 @@ class TransactionProfiler implements LoggerAwareInterface {
                }
                // Report slow queries...
                if ( !$isWrite && $elapsed > $this->expect['readQueryTime'] ) {
-                       $this->reportExpectationViolated( 'readQueryTime', $query );
+                       $this->reportExpectationViolated( 'readQueryTime', $query, $elapsed );
                }
                if ( $isWrite && $elapsed > $this->expect['writeQueryTime'] ) {
-                       $this->reportExpectationViolated( 'writeQueryTime', $query );
+                       $this->reportExpectationViolated( 'writeQueryTime', $query, $elapsed );
                }
 
                if ( !$this->dbTrxHoldingLocks ) {
@@ -223,14 +233,14 @@ class TransactionProfiler implements LoggerAwareInterface {
                                if ( $sTime >= $lastEnd ) { // sanity check
                                        if ( ( $sTime - $lastEnd ) > $this->eventThreshold ) {
                                                // Add an entry representing the time spent doing non-queries
-                                               $this->dbTrxMethodTimes[$name][] = array( '...delay...', $lastEnd, $sTime );
+                                               $this->dbTrxMethodTimes[$name][] = [ '...delay...', $lastEnd, $sTime ];
                                        }
-                                       $this->dbTrxMethodTimes[$name][] = array( $query, $sTime, $eTime );
+                                       $this->dbTrxMethodTimes[$name][] = [ $query, $sTime, $eTime ];
                                }
                        } else {
                                // First query in the trx...
                                if ( $sTime >= $info['start'] ) { // sanity check
-                                       $this->dbTrxMethodTimes[$name][] = array( $query, $sTime, $eTime );
+                                       $this->dbTrxMethodTimes[$name][] = [ $query, $sTime, $eTime ];
                                }
                        }
                }
@@ -254,10 +264,17 @@ class TransactionProfiler implements LoggerAwareInterface {
                        $this->logger->info( "Detected no transaction for '$name' - out of sync." );
                        return;
                }
+
+               $slow = false;
+
                // Warn if too much time was spend writing...
                if ( $writeTime > $this->expect['writeQueryTime'] ) {
-                       $this->reportExpectationViolated( 'writeQueryTime',
-                               "[transaction $id writes to {$server} ({$db})]" );
+                       $this->reportExpectationViolated(
+                               'writeQueryTime',
+                               "[transaction $id writes to {$server} ({$db})]",
+                               $writeTime
+                       );
+                       $slow = true;
                }
                // Fill in the last non-query period...
                $lastQuery = end( $this->dbTrxMethodTimes[$name] );
@@ -265,11 +282,10 @@ class TransactionProfiler implements LoggerAwareInterface {
                        $now = microtime( true );
                        $lastEnd = $lastQuery[2];
                        if ( ( $now - $lastEnd ) > $this->eventThreshold ) {
-                               $this->dbTrxMethodTimes[$name][] = array( '...delay...', $lastEnd, $now );
+                               $this->dbTrxMethodTimes[$name][] = [ '...delay...', $lastEnd, $now ];
                        }
                }
                // Check for any slow queries or non-query periods...
-               $slow = false;
                foreach ( $this->dbTrxMethodTimes[$name] as $info ) {
                        $elapsed = ( $info[2] - $info[1] );
                        if ( $elapsed >= $this->dbLockThreshold ) {
@@ -293,14 +309,19 @@ class TransactionProfiler implements LoggerAwareInterface {
        /**
         * @param string $expect
         * @param string $query
+        * @param string|float|int $actual [optional]
         */
-       protected function reportExpectationViolated( $expect, $query ) {
-               global $wgRequest;
+       protected function reportExpectationViolated( $expect, $query, $actual = null ) {
+               if ( $this->silenced ) {
+                       return;
+               }
 
                $n = $this->expect[$expect];
                $by = $this->expectBy[$expect];
+               $actual = ( $actual !== null ) ? " (actual: $actual)" : "";
+
                $this->logger->info(
-                       "[{$wgRequest->getMethod()}] Expectation ($expect <= $n) by $by not met:\n$query\n" .
+                       "Expectation ($expect <= $n) by $by not met$actual:\n$query\n" .
                        wfBacktrace( true )
                );
        }