Use a parameterized log for sub-optimal transaction logging
authorErik Bernhardson <ebernhardson@wikimedia.org>
Wed, 5 Oct 2016 19:30:18 +0000 (12:30 -0700)
committerErik Bernhardson <ebernhardson@wikimedia.org>
Wed, 5 Oct 2016 19:30:18 +0000 (12:30 -0700)
In logstash these messages can't be grouped in any way, because they are
all slightly different. By using a parameterized log message these can
be grouped to give a better overview about the size of a problem.

Change-Id: Icfa957bd1775b49bccd6e9920586c94eb4597f9b

includes/libs/rdbms/TransactionProfiler.php

index 4d2b28f..12f6df5 100644 (file)
@@ -295,13 +295,15 @@ class TransactionProfiler implements LoggerAwareInterface {
                        }
                }
                if ( $slow ) {
-                       $dbs = implode( ', ', array_keys( $this->dbTrxHoldingLocks[$name]['conns'] ) );
-                       $msg = "Sub-optimal transaction on DB(s) [{$dbs}]:\n";
+                       $trace = '';
                        foreach ( $this->dbTrxMethodTimes[$name] as $i => $info ) {
                                list( $query, $sTime, $end ) = $info;
-                               $msg .= sprintf( "%d\t%.6f\t%s\n", $i, ( $end - $sTime ), $query );
+                               $trace .= sprintf( "%d\t%.6f\t%s\n", $i, ( $end - $sTime ), $query );
                        }
-                       $this->logger->info( $msg );
+                       $this->logger->info( "Sub-optimal transaction on DB(s) [{dbs}]: \n{trace}", [
+                               'dbs' => implode( ', ', array_keys( $this->dbTrxHoldingLocks[$name]['conns'] ) ),
+                               'trace' => $trace
+                       ] );
                }
                unset( $this->dbTrxHoldingLocks[$name] );
                unset( $this->dbTrxMethodTimes[$name] );