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

diff --git a/includes/db/Database.php b/includes/db/Database.php
index 7bbcc2f..6b6c62e 100644 (file)
--- 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 9633d0d..d5cdf28 100644 (file)
--- 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 ) {