From f6c9b7a7b74dfe3582a1b39777b85b68b9a9ab8d Mon Sep 17 00:00:00 2001 From: Aaron Schulz Date: Wed, 31 Jan 2018 14:33:28 -0800 Subject: [PATCH] rdbms: Bump TransactionProfiler log entries to WARNING Change-Id: I4816cfb8c8cd3b8e3dd2fe10c028c4654cc82854 --- includes/libs/rdbms/TransactionProfiler.php | 10 +++++----- .../libs/rdbms/TransactionProfilerTest.php | 18 +++++++++--------- 2 files changed, 14 insertions(+), 14 deletions(-) diff --git a/includes/libs/rdbms/TransactionProfiler.php b/includes/libs/rdbms/TransactionProfiler.php index a828cd3f1c..c353a224c6 100644 --- a/includes/libs/rdbms/TransactionProfiler.php +++ b/includes/libs/rdbms/TransactionProfiler.php @@ -177,7 +177,7 @@ class TransactionProfiler implements LoggerAwareInterface { public function transactionWritingIn( $server, $db, $id ) { $name = "{$server} ({$db}) (TRX#$id)"; if ( isset( $this->dbTrxHoldingLocks[$name] ) ) { - $this->logger->info( "Nested transaction for '$name' - out of sync." ); + $this->logger->warning( "Nested transaction for '$name' - out of sync." ); } $this->dbTrxHoldingLocks[$name] = [ 'start' => microtime( true ), @@ -206,7 +206,7 @@ class TransactionProfiler implements LoggerAwareInterface { $elapsed = ( $eTime - $sTime ); if ( $isWrite && $n > $this->expect['maxAffected'] ) { - $this->logger->info( + $this->logger->warning( "Query affected $n row(s):\n" . $query . "\n" . ( new RuntimeException() )->getTraceAsString() ); } @@ -271,7 +271,7 @@ class TransactionProfiler implements LoggerAwareInterface { 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." ); + $this->logger->warning( "Detected no transaction for '$name' - out of sync." ); return; } @@ -317,7 +317,7 @@ class TransactionProfiler implements LoggerAwareInterface { list( $query, $sTime, $end ) = $info; $trace .= sprintf( "%d\t%.6f\t%s\n", $i, ( $end - $sTime ), $query ); } - $this->logger->info( "Sub-optimal transaction on DB(s) [{dbs}]: \n{trace}", [ + $this->logger->warning( "Sub-optimal transaction on DB(s) [{dbs}]: \n{trace}", [ 'dbs' => implode( ', ', array_keys( $this->dbTrxHoldingLocks[$name]['conns'] ) ), 'trace' => $trace ] ); @@ -336,7 +336,7 @@ class TransactionProfiler implements LoggerAwareInterface { return; } - $this->logger->info( + $this->logger->warning( "Expectation ({measure} <= {max}) by {by} not met (actual: {actual}):\n{query}\n" . ( new RuntimeException() )->getTraceAsString(), [ diff --git a/tests/phpunit/includes/libs/rdbms/TransactionProfilerTest.php b/tests/phpunit/includes/libs/rdbms/TransactionProfilerTest.php index 54706d55c4..25613fed6b 100644 --- a/tests/phpunit/includes/libs/rdbms/TransactionProfilerTest.php +++ b/tests/phpunit/includes/libs/rdbms/TransactionProfilerTest.php @@ -12,7 +12,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testAffected() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); - $logger->expects( $this->exactly( 3 ) )->method( 'info' ); + $logger->expects( $this->exactly( 3 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -27,7 +27,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testReadTime() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); // 1 per query - $logger->expects( $this->exactly( 2 ) )->method( 'info' ); + $logger->expects( $this->exactly( 2 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -42,7 +42,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testWriteTime() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); // 1 per query, 1 per trx, and one "sub-optimal trx" entry - $logger->expects( $this->exactly( 4 ) )->method( 'info' ); + $logger->expects( $this->exactly( 4 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -56,7 +56,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testAffectedTrx() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); - $logger->expects( $this->exactly( 1 ) )->method( 'info' ); + $logger->expects( $this->exactly( 1 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -69,7 +69,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testWriteTimeTrx() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); // 1 per trx, and one "sub-optimal trx" entry - $logger->expects( $this->exactly( 2 ) )->method( 'info' ); + $logger->expects( $this->exactly( 2 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -81,7 +81,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testConns() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); - $logger->expects( $this->exactly( 2 ) )->method( 'info' ); + $logger->expects( $this->exactly( 2 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -95,7 +95,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testMasterConns() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); - $logger->expects( $this->exactly( 2 ) )->method( 'info' ); + $logger->expects( $this->exactly( 2 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -112,7 +112,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testReadQueryCount() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); - $logger->expects( $this->exactly( 2 ) )->method( 'info' ); + $logger->expects( $this->exactly( 2 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); @@ -126,7 +126,7 @@ class TransactionProfilerTest extends PHPUnit_Framework_TestCase { public function testWriteQueryCount() { $logger = $this->getMockBuilder( LoggerInterface::class )->getMock(); - $logger->expects( $this->exactly( 2 ) )->method( 'info' ); + $logger->expects( $this->exactly( 2 ) )->method( 'warning' ); $tp = new TransactionProfiler(); $tp->setLogger( $logger ); -- 2.20.1