From 52a59540689520f15c54cbb779cfc7a6d59670cd Mon Sep 17 00:00:00 2001
From: Aaron Schulz <aschulz@wikimedia.org>
Date: Thu, 15 Jan 2015 12:53:27 -0800
Subject: [PATCH] Moved "large write query" code to TransactionProfiler

Change-Id: Ic05e832eb21545a4e639b52aca7b3a5811a890ce
---
 includes/db/Database.php                  | 18 +++++-------------
 includes/profiler/TransactionProfiler.php | 12 ++++++++++--
 2 files changed, 15 insertions(+), 15 deletions(-)

diff --git a/includes/db/Database.php b/includes/db/Database.php
index 054f27a909..92d998c60b 100644
--- a/includes/db/Database.php
+++ b/includes/db/Database.php
@@ -46,9 +46,6 @@ abstract class DatabaseBase implements IDatabase {
 	/** Maximum time to wait before retry */
 	const DEADLOCK_DELAY_MAX = 1500000;
 
-	/** How many row changes in a write query trigger a log entry */
-	const LOG_WRITE_THRESHOLD = 300;
-
 	protected $mLastQuery = '';
 	protected $mDoneWrites = false;
 	protected $mPHPError = false;
@@ -1160,11 +1157,13 @@ abstract class DatabaseBase implements IDatabase {
 
 		# Log the query time and feed it into the DB trx profiler
 		if ( $queryProf != '' ) {
+			$that = $this;
 			$queryStartTime = microtime( true );
 			$queryProfile = new ScopedCallback(
-				function () use ( $queryStartTime, $queryProf, $isMaster ) {
-					$trxProfiler = Profiler::instance()->getTransactionProfiler();
-					$trxProfiler->recordQueryCompletion( $queryProf, $queryStartTime, $isMaster );
+				function () use ( $that, $queryStartTime, $queryProf, $isMaster ) {
+					$n = $that->affectedRows();
+					$trxProf = Profiler::instance()->getTransactionProfiler();
+					$trxProf->recordQueryCompletion( $queryProf, $queryStartTime, $isMaster, $n );
 				}
 			);
 		}
@@ -1206,13 +1205,6 @@ abstract class DatabaseBase implements IDatabase {
 
 		if ( false === $ret ) {
 			$this->reportQueryError( $this->lastError(), $this->lastErrno(), $sql, $fname, $tempIgnore );
-		} else {
-			$n = $this->affectedRows();
-			if ( $isWriteQuery && $n > self::LOG_WRITE_THRESHOLD && PHP_SAPI !== 'cli' ) {
-				wfDebugLog( 'DBPerformance',
-					"Query affected $n rows:\n" .
-					DatabaseBase::generalizeSQL( $sql ) . "\n" . wfBacktrace( true ) );
-			}
 		}
 
 		$res = $this->resultObject( $ret );
diff --git a/includes/profiler/TransactionProfiler.php b/includes/profiler/TransactionProfiler.php
index 886bc5a0b4..3637781050 100644
--- a/includes/profiler/TransactionProfiler.php
+++ b/includes/profiler/TransactionProfiler.php
@@ -34,6 +34,8 @@ class TransactionProfiler {
 	protected $dbLockThreshold = 3.0;
 	/** @var float Seconds */
 	protected $eventThreshold = .25;
+	/** @var integer */
+	protected $affectedThreshold = 500;
 
 	/** @var array transaction ID => (write start time, list of DBs involved) */
 	protected $dbTrxHoldingLocks = array();
@@ -71,14 +73,20 @@ class TransactionProfiler {
 	 *
 	 * This assumes that all queries are synchronous (non-overlapping)
 	 *
-	 * @param string $query Function name
+	 * @param string $query Function name or generalized SQL
 	 * @param float $sTime Starting UNIX wall time
 	 * @param bool $isWrite Whether this is a write query
+	 * @param integer $n Number of affected rows
 	 */
-	public function recordQueryCompletion( $query, $sTime, $isWrite = false ) {
+	public function recordQueryCompletion( $query, $sTime, $isWrite = false, $n = 0 ) {
 		$eTime = microtime( true );
 		$elapsed = ( $eTime - $sTime );
 
+		if ( $isWrite && $n > $this->affectedThreshold && PHP_SAPI !== 'cli' ) {
+			wfDebugLog( 'DBPerformance',
+				"Query affected $n rows:\n" . $query . "\n" . wfBacktrace( true ) );
+		}
+
 		if ( !$this->dbTrxHoldingLocks ) {
 			// Short-circuit
 			return;
-- 
2.20.1