summaryrefslogtreecommitdiff
path: root/includes/profiler/TransactionProfiler.php
diff options
context:
space:
mode:
authorPierre Schmitz <pierre@archlinux.de>2015-12-17 09:15:42 +0100
committerPierre Schmitz <pierre@archlinux.de>2015-12-17 09:44:51 +0100
commita1789ddde42033f1b05cc4929491214ee6e79383 (patch)
tree63615735c4ddffaaabf2428946bb26f90899f7bf /includes/profiler/TransactionProfiler.php
parent9e06a62f265e3a2aaabecc598d4bc617e06fa32d (diff)
Update to MediaWiki 1.26.0
Diffstat (limited to 'includes/profiler/TransactionProfiler.php')
-rw-r--r--includes/profiler/TransactionProfiler.php56
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 )
);
}
}