From: Erik Bernhardson <ebernhardson@wikimedia.org>
Date: Wed, 5 Oct 2016 19:30:18 +0000 (-0700)
Subject: Use a parameterized log for sub-optimal transaction logging
X-Git-Tag: 1.31.0-rc.0~5200^2
X-Git-Url: http://git.cyclocoop.org/%28%5B%5E/404?a=commitdiff_plain;h=44da55fffb7142a27b010e9eae42b55783410495;p=lhc%2Fweb%2Fwiklou.git

Use a parameterized log for sub-optimal transaction logging

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
---

diff --git a/includes/libs/rdbms/TransactionProfiler.php b/includes/libs/rdbms/TransactionProfiler.php
index 4d2b28fdd5..12f6df5d4a 100644
--- a/includes/libs/rdbms/TransactionProfiler.php
+++ b/includes/libs/rdbms/TransactionProfiler.php
@@ -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] );