diff options
author | Pierre Schmitz <pierre@archlinux.de> | 2015-12-17 09:15:42 +0100 |
---|---|---|
committer | Pierre Schmitz <pierre@archlinux.de> | 2015-12-17 09:44:51 +0100 |
commit | a1789ddde42033f1b05cc4929491214ee6e79383 (patch) | |
tree | 63615735c4ddffaaabf2428946bb26f90899f7bf /includes/profiler/TransactionProfiler.php | |
parent | 9e06a62f265e3a2aaabecc598d4bc617e06fa32d (diff) |
Update to MediaWiki 1.26.0
Diffstat (limited to 'includes/profiler/TransactionProfiler.php')
-rw-r--r-- | includes/profiler/TransactionProfiler.php | 56 |
1 files changed, 46 insertions, 10 deletions
diff --git a/includes/profiler/TransactionProfiler.php b/includes/profiler/TransactionProfiler.php index f02d66f8..46d6119b 100644 --- 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 @@ -94,6 +97,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 * * @since 1.25 @@ -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 @@ -220,13 +246,23 @@ class TransactionProfiler implements LoggerAwareInterface { * @param string $server DB server * @param string $db DB name * @param string $id ID string of transaction + * @param float $writeTime Time spent in write queries */ - public function transactionWritingOut( $server, $db, $id ) { + public function transactionWritingOut( $server, $db, $id, $writeTime = 0.0 ) { $name = "{$server} ({$db}) (TRX#$id)"; if ( !isset( $this->dbTrxMethodTimes[$name] ) ) { $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})]" ); + $slow = true; + } // Fill in the last non-query period... $lastQuery = end( $this->dbTrxMethodTimes[$name] ); if ( $lastQuery ) { @@ -237,7 +273,6 @@ class TransactionProfiler implements LoggerAwareInterface { } } // 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 ) { @@ -268,7 +303,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 ) ); } } |