Log when transactions affect many rows in TransactionProfiler

This augments the logging which detect single large write queries

Bug: T95501
Change-Id: I4eac35c56a472e5ba64270ea10c48bf33138417b

diff --git a/includes/libs/rdbms/TransactionProfiler.php b/includes/libs/rdbms/TransactionProfiler.php
index 5d3534f..823e0dc 100644 (file)
--- a/includes/libs/rdbms/TransactionProfiler.php
+++ b/includes/libs/rdbms/TransactionProfiler.php
@@ -265,8 +265,9 @@ class TransactionProfiler implements LoggerAwareInterface {
         * @param string $db DB name
         * @param string $id ID string of transaction
         * @param float $writeTime Time spent in write queries
+        * @param integer $affected Number of rows affected by writes
         */
-       public function transactionWritingOut( $server, $db, $id, $writeTime = 0.0 ) {
+       public function transactionWritingOut( $server, $db, $id, $writeTime = 0.0, $affected = 0 ) {
                $name = "{$server} ({$db}) (TRX#$id)";
                if ( !isset( $this->dbTrxMethodTimes[$name] ) ) {
                        $this->logger->info( "Detected no transaction for '$name' - out of sync." );
@@ -284,6 +285,14 @@ class TransactionProfiler implements LoggerAwareInterface {
                        );
                        $slow = true;
                }
+               // Warn if too many rows were changed...
+               if ( $affected > $this->expect['maxAffected'] ) {
+                       $this->reportExpectationViolated(
+                               'maxAffected',
+                               "[transaction $id writes to {$server} ({$db})]",
+                               $affected
+                       );
+               }
                // Fill in the last non-query period...
                $lastQuery = end( $this->dbTrxMethodTimes[$name] );
                if ( $lastQuery ) {

diff --git a/includes/libs/rdbms/database/DBConnRef.php b/includes/libs/rdbms/database/DBConnRef.php
index b6167aa..5b59d2a 100644 (file)
--- a/includes/libs/rdbms/database/DBConnRef.php
+++ b/includes/libs/rdbms/database/DBConnRef.php
@@ -124,6 +124,10 @@ class DBConnRef implements IDatabase {
                return $this->__call( __FUNCTION__, func_get_args() );
        }
 
+       public function pendingWriteRowsAffected() {
+               return $this->__call( __FUNCTION__, func_get_args() );
+       }
+
        public function isOpen() {
                return $this->__call( __FUNCTION__, func_get_args() );
        }

diff --git a/includes/libs/rdbms/database/Database.php b/includes/libs/rdbms/database/Database.php
index ee7644f..8bea8cc 100644 (file)
--- a/includes/libs/rdbms/database/Database.php
+++ b/includes/libs/rdbms/database/Database.php
@@ -200,6 +200,10 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         * @var integer Number of write queries for the current transaction
         */
        private $mTrxWriteQueryCount = 0;
+       /**
+        * @var integer Number of rows affected by write queries for the current transaction
+        */
+       private $mTrxWriteAffectedRows = 0;
        /**
         * @var float Like mTrxWriteQueryCount but excludes lock-bound, easy to replicate, queries
         */
@@ -583,6 +587,10 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                return $this->mTrxLevel ? $this->mTrxWriteCallers : [];
        }
 
+       public function pendingWriteRowsAffected() {
+               return $this->mTrxWriteAffectedRows;
+       }
+
        /**
         * Get the list of method names that have pending write queries or callbacks
         * for this transaction
@@ -1011,7 +1019,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                if ( $ret !== false ) {
                        $this->lastPing = $startTime;
                        if ( $isWrite && $this->mTrxLevel ) {
-                               $this->updateTrxWriteQueryTime( $sql, $queryRuntime );
+                               $this->updateTrxWriteQueryTime( $sql, $queryRuntime, $this->affectedRows() );
                                $this->mTrxWriteCallers[] = $fname;
                        }
                }
@@ -1042,8 +1050,9 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
         *
         * @param string $sql A SQL write query
         * @param float $runtime Total runtime, including RTT
+        * @param integer $affected Affected row count
         */
-       private function updateTrxWriteQueryTime( $sql, $runtime ) {
+       private function updateTrxWriteQueryTime( $sql, $runtime, $affected ) {
                // Whether this is indicative of replica DB runtime (except for RBR or ws_repl)
                $indicativeOfReplicaRuntime = true;
                if ( $runtime > self::SLOW_WRITE_SEC ) {
@@ -1058,6 +1067,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
 
                $this->mTrxWriteDuration += $runtime;
                $this->mTrxWriteQueryCount += 1;
+               $this->mTrxWriteAffectedRows += $affected;
                if ( $indicativeOfReplicaRuntime ) {
                        $this->mTrxWriteAdjDuration += $runtime;
                        $this->mTrxWriteAdjQueryCount += 1;
@@ -2805,6 +2815,7 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                $this->mTrxShortId = sprintf( '%06x', mt_rand( 0, 0xffffff ) );
                $this->mTrxWriteDuration = 0.0;
                $this->mTrxWriteQueryCount = 0;
+               $this->mTrxWriteAffectedRows = 0;
                $this->mTrxWriteAdjDuration = 0.0;
                $this->mTrxWriteAdjQueryCount = 0;
                $this->mTrxWriteCallers = [];
@@ -2871,7 +2882,12 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                if ( $this->mTrxDoneWrites ) {
                        $this->mLastWriteTime = microtime( true );
                        $this->trxProfiler->transactionWritingOut(
-                               $this->mServer, $this->mDBname, $this->mTrxShortId, $writeTime );
+                               $this->mServer,
+                               $this->mDBname,
+                               $this->mTrxShortId,
+                               $writeTime,
+                               $this->mTrxWriteAffectedRows
+                       );
                }
 
                $this->runOnTransactionIdleCallbacks( self::TRIGGER_COMMIT );
@@ -2916,7 +2932,10 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware
                $this->mTrxAtomicLevels = [];
                if ( $this->mTrxDoneWrites ) {
                        $this->trxProfiler->transactionWritingOut(
-                               $this->mServer, $this->mDBname, $this->mTrxShortId );
+                               $this->mServer,
+                               $this->mDBname,
+                               $this->mTrxShortId
+                       );
                }
 
                $this->mTrxIdleCallbacks = []; // clear

diff --git a/includes/libs/rdbms/database/IDatabase.php b/includes/libs/rdbms/database/IDatabase.php
index bec26a6..617982c 100644 (file)
--- a/includes/libs/rdbms/database/IDatabase.php
+++ b/includes/libs/rdbms/database/IDatabase.php
@@ -274,6 +274,14 @@ interface IDatabase {
         */
        public function pendingWriteCallers();
 
+       /**
+        * Get the number of affected rows from pending write queries
+        *
+        * @return integer
+        * @since 1.30
+        */
+       public function pendingWriteRowsAffected();
+
        /**
         * Is a connection to the database open?
         * @return bool