From a1bc02ec8bae79bb7b471e4f4195dc0764f76f7c Mon Sep 17 00:00:00 2001
From: Aaron Schulz <aschulz@wikimedia.org>
Date: Wed, 25 Jun 2014 11:33:20 -0700
Subject: [PATCH] Include trx state in query profiling (and DBPerformance log)

* Replaced use of spl hash with random transaction IDs.
  These can be correlated better and make the DBPerformance
  log easier to make sense of. They are also shorter.

Change-Id: I5f49c0d0c26e37807341bbc83b1b41b124164419
---
 includes/db/Database.php       | 28 ++++++++++++++++++++--------
 includes/profiler/Profiler.php |  8 ++++----
 2 files changed, 24 insertions(+), 12 deletions(-)

diff --git a/includes/db/Database.php b/includes/db/Database.php
index 7bbcc2ffe4..6b6c62e350 100644
--- a/includes/db/Database.php
+++ b/includes/db/Database.php
@@ -268,6 +268,13 @@ abstract class DatabaseBase implements IDatabase, DatabaseType {
 	 */
 	protected $mTrxLevel = 0;
 
+	/**
+	 * Either a short hexidecimal string if a transaction is active or ""
+	 *
+	 * @var string
+	 */
+	protected $mTrxShortId = '';
+
 	/**
 	 * Remembers the function name given for starting the most recent transaction via begin().
 	 * Used to provide additional context for error reporting.
@@ -1054,8 +1061,8 @@ abstract class DatabaseBase implements IDatabase, DatabaseType {
 		# Keep track of whether the transaction has write queries pending
 		if ( $this->mTrxLevel && !$this->mTrxDoneWrites && $this->isWriteQuery( $sql ) ) {
 			$this->mTrxDoneWrites = true;
-			$id = spl_object_hash( $this );
-			Profiler::instance()->transactionWritingIn( $this->mServer, $this->mDBname, $id );
+			Profiler::instance()->transactionWritingIn(
+				$this->mServer, $this->mDBname, $this->mTrxShortId );
 		}
 
 		$queryProf = '';
@@ -1072,6 +1079,10 @@ abstract class DatabaseBase implements IDatabase, DatabaseType {
 				$queryProf = 'query: ' . substr( DatabaseBase::generalizeSQL( $sql ), 0, 255 );
 				$totalProf = 'DatabaseBase::query';
 			}
+			# Include query transaction state
+			$queryProf .= $this->mTrxShortId ? " [TRX#{$this->mTrxShortId}]" : "";
+
+			$trx = $this->mTrxLevel ? 'TRX=yes' : 'TRX=no';
 			wfProfileIn( $totalProf );
 			wfProfileIn( $queryProf );
 		}
@@ -3412,8 +3423,8 @@ abstract class DatabaseBase implements IDatabase, DatabaseType {
 			$this->runOnTransactionPreCommitCallbacks();
 			$this->doCommit( $fname );
 			if ( $this->mTrxDoneWrites ) {
-				$id = spl_object_hash( $this );
-				Profiler::instance()->transactionWritingOut( $this->mServer, $this->mDBname, $id );
+				Profiler::instance()->transactionWritingOut(
+					$this->mServer, $this->mDBname, $this->mTrxShortId );
 			}
 			$this->runOnTransactionIdleCallbacks();
 		}
@@ -3431,6 +3442,7 @@ abstract class DatabaseBase implements IDatabase, DatabaseType {
 		$this->mTrxAtomicLevels = new SplStack;
 		$this->mTrxIdleCallbacks = array();
 		$this->mTrxPreCommitCallbacks = array();
+		$this->mTrxShortId = wfRandomString( 12 );
 	}
 
 	/**
@@ -3489,8 +3501,8 @@ abstract class DatabaseBase implements IDatabase, DatabaseType {
 		$this->runOnTransactionPreCommitCallbacks();
 		$this->doCommit( $fname );
 		if ( $this->mTrxDoneWrites ) {
-			$id = spl_object_hash( $this );
-			Profiler::instance()->transactionWritingOut( $this->mServer, $this->mDBname, $id );
+			Profiler::instance()->transactionWritingOut(
+				$this->mServer, $this->mDBname, $this->mTrxShortId );
 		}
 		$this->runOnTransactionIdleCallbacks();
 	}
@@ -3546,8 +3558,8 @@ abstract class DatabaseBase implements IDatabase, DatabaseType {
 		$this->mTrxPreCommitCallbacks = array(); // cancel
 		$this->mTrxAtomicLevels = new SplStack;
 		if ( $this->mTrxDoneWrites ) {
-			$id = spl_object_hash( $this );
-			Profiler::instance()->transactionWritingOut( $this->mServer, $this->mDBname, $id );
+			Profiler::instance()->transactionWritingOut(
+				$this->mServer, $this->mDBname, $this->mTrxShortId );
 		}
 	}
 
diff --git a/includes/profiler/Profiler.php b/includes/profiler/Profiler.php
index 9633d0d273..d5cdf28866 100644
--- a/includes/profiler/Profiler.php
+++ b/includes/profiler/Profiler.php
@@ -370,10 +370,10 @@ class TransactionProfiler {
 	 *
 	 * @param string $server DB server
 	 * @param string $db DB name
-	 * @param string $id Resource ID string of connection
+	 * @param string $id ID string of transaction
 	 */
 	public function transactionWritingIn( $server, $db, $id ) {
-		$name = "{$server} ({$db}) ($id)";
+		$name = "{$server} ({$db}) (TRX#$id)";
 		if ( isset( $this->mDBTrxHoldingLocks[$name] ) ) {
 			++$this->mDBTrxHoldingLocks[$name]['refs'];
 		} else {
@@ -421,10 +421,10 @@ class TransactionProfiler {
 	 *
 	 * @param string $server DB server
 	 * @param string $db DB name
-	 * @param string $id Resource ID string of connection
+	 * @param string $id ID string of transaction
 	 */
 	public function transactionWritingOut( $server, $db, $id ) {
-		$name = "{$server} ({$db}) ($id)";
+		$name = "{$server} ({$db}) (TRX#$id)";
 		if ( --$this->mDBTrxHoldingLocks[$name]['refs'] <= 0 ) {
 			$slow = false;
 			foreach ( $this->mDBTrxMethodTimes[$name] as $info ) {
-- 
2.20.1