Merge commit 'fa89acd'

# Conflicts:
#	.gitignore
#	extensions/ArchInterWiki.sql

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 )
 		);
 	}
 }