From 671bcd8d27e7e4be6b1dcbdf9629946cdb46dd98 Mon Sep 17 00:00:00 2001 From: Aaron Schulz Date: Wed, 5 Nov 2014 15:05:22 -0800 Subject: [PATCH] Changed TransactionProfiler to only work via the DB classes * This makes it work with xhprof/xdebug, though it will only examine DB queries. Change-Id: I999b66e6c3af88dda408b2252c248e085af9eea4 --- includes/db/Database.php | 16 +++++++++---- includes/profiler/Profiler.php | 28 ++++------------------- includes/profiler/ProfilerStandard.php | 1 - includes/profiler/ProfilerStub.php | 6 ----- includes/profiler/TransactionProfiler.php | 10 ++++---- 5 files changed, 21 insertions(+), 40 deletions(-) diff --git a/includes/db/Database.php b/includes/db/Database.php index 4bb646e2b2..34132aa45e 100644 --- a/includes/db/Database.php +++ b/includes/db/Database.php @@ -1117,7 +1117,7 @@ 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; - Profiler::instance()->transactionWritingIn( + Profiler::instance()->getTransactionProfiler()->transactionWritingIn( $this->mServer, $this->mDBname, $this->mTrxShortId ); } @@ -1162,6 +1162,14 @@ abstract class DatabaseBase implements IDatabase, DatabaseType { throw new DBUnexpectedError( $this, "DB connection was already closed." ); } + # Log the query time and feed it into the DB trx profiler + $queryStartTime = microtime( true ); + $queryProfile = new ScopedCallback( function() use ( $queryStartTime, $queryProf ) { + $elapsed = microtime( true ) - $queryStartTime; + $trxProfiler = Profiler::instance()->getTransactionProfiler(); + $trxProfiler->recordFunctionCompletion( $queryProf, $elapsed ); + } ); + # Do the query and handle errors $ret = $this->doQuery( $commentedSql ); @@ -3524,7 +3532,7 @@ abstract class DatabaseBase implements IDatabase, DatabaseType { $this->runOnTransactionPreCommitCallbacks(); $this->doCommit( $fname ); if ( $this->mTrxDoneWrites ) { - Profiler::instance()->transactionWritingOut( + Profiler::instance()->getTransactionProfiler()->transactionWritingOut( $this->mServer, $this->mDBname, $this->mTrxShortId ); } $this->runOnTransactionIdleCallbacks(); @@ -3604,7 +3612,7 @@ abstract class DatabaseBase implements IDatabase, DatabaseType { $this->runOnTransactionPreCommitCallbacks(); $this->doCommit( $fname ); if ( $this->mTrxDoneWrites ) { - Profiler::instance()->transactionWritingOut( + Profiler::instance()->getTransactionProfiler()->transactionWritingOut( $this->mServer, $this->mDBname, $this->mTrxShortId ); } $this->runOnTransactionIdleCallbacks(); @@ -3662,7 +3670,7 @@ abstract class DatabaseBase implements IDatabase, DatabaseType { $this->mTrxPreCommitCallbacks = array(); // cancel $this->mTrxAtomicLevels = new SplStack; if ( $this->mTrxDoneWrites ) { - Profiler::instance()->transactionWritingOut( + Profiler::instance()->getTransactionProfiler()->transactionWritingOut( $this->mServer, $this->mDBname, $this->mTrxShortId ); } } diff --git a/includes/profiler/Profiler.php b/includes/profiler/Profiler.php index 8e5b98aefc..46296917cc 100644 --- a/includes/profiler/Profiler.php +++ b/includes/profiler/Profiler.php @@ -125,31 +125,11 @@ abstract class Profiler { abstract public function profileOut( $functionname ); /** - * Mark a DB as in a transaction with one or more writes pending - * - * Note that there can be multiple connections to a single DB. - * - * @param string $server DB server - * @param string $db DB name - * @param string $id Resource ID string of connection - */ - public function transactionWritingIn( $server, $db, $id = '' ) { - $this->trxProfiler->transactionWritingIn( $server, $db, $id ); - } - - /** - * Mark a DB as no longer in a transaction - * - * This will check if locks are possibly held for longer than - * needed and log any affected transactions to a special DB log. - * Note that there can be multiple connections to a single DB. - * - * @param string $server DB server - * @param string $db DB name - * @param string $id Resource ID string of connection + * @return TransactionProfiler + * @since 1.25 */ - public function transactionWritingOut( $server, $db, $id = '' ) { - $this->trxProfiler->transactionWritingOut( $server, $db, $id ); + public function getTransactionProfiler() { + return $this->trxProfiler; } /** diff --git a/includes/profiler/ProfilerStandard.php b/includes/profiler/ProfilerStandard.php index a65e53eb83..ea13bfb748 100644 --- a/includes/profiler/ProfilerStandard.php +++ b/includes/profiler/ProfilerStandard.php @@ -231,7 +231,6 @@ class ProfilerStandard extends Profiler { $this->mStack[] = array_merge( $item, array( $realTime, $cpuTime, memory_get_usage() ) ); } - $this->trxProfiler->recordFunctionCompletion( $functionname, $realTime - $ortime ); } } diff --git a/includes/profiler/ProfilerStub.php b/includes/profiler/ProfilerStub.php index 1d3b65d261..e81f579ad5 100644 --- a/includes/profiler/ProfilerStub.php +++ b/includes/profiler/ProfilerStub.php @@ -54,12 +54,6 @@ class ProfilerStub extends Profiler { return ''; } - public function transactionWritingIn( $server, $db, $id = '' ) { - } - - public function transactionWritingOut( $server, $db, $id = '' ) { - } - public function getRawData() { return array(); } diff --git a/includes/profiler/TransactionProfiler.php b/includes/profiler/TransactionProfiler.php index 5ee51e34b9..91b7bb7d5c 100644 --- a/includes/profiler/TransactionProfiler.php +++ b/includes/profiler/TransactionProfiler.php @@ -19,6 +19,7 @@ * * @file * @ingroup Profiler + * @author Aaron Schulz */ /** @@ -69,19 +70,18 @@ class TransactionProfiler { * This method is only to be called by the Profiler class as methods finish * * @param string $method Function name - * @param float $realtime Wal time ellapsed + * @param float $realtime Wall time ellapsed */ public function recordFunctionCompletion( $method, $realtime ) { if ( !$this->mDBTrxHoldingLocks ) { // Short-circuit return; - // @todo hardcoded check is a tad janky (what about FOR UPDATE?) - } elseif ( !preg_match( '/^query-m: (?!SELECT)/', $method ) - && $realtime < $this->mDBLockThreshold - ) { + // @todo hardcoded check is a tad janky + } elseif ( !preg_match( '/^query-m: /', $method ) && $realtime < 1.0 ) { // Not a DB master query nor slow enough return; } + $now = microtime( true ); foreach ( $this->mDBTrxHoldingLocks as $name => $info ) { // Hacky check to exclude entries from before the first TRX write -- 2.20.1