Database debug log cleanup (remove wgDebugDumpSqlLength/wgDebugDBTransactions)

* Simplify the debug log call and use queries group
* Remove $wgDebugDumpSqlLength, as profiler output
  already has shortened query strings (one can use
  profiling without DBO_DEBUG)
* Removed $wgDebugDBTransactions as BEGIN/COMMIT already show
* Removed PostgresTransactionState as it was only used for
  $wgDebugDBTransactions handling
* This cuts down on lots of global variable usage

Change-Id: I185adb1694441d074dea965960429b4910727620

RELEASE-NOTES-1.27

@@ -14,6 +14,8 @@ production.
   $wgResourceLoaderMinifierMaxLineLength, because there was little value in
   making the behavior configurable. The default values (`false` for the former,
   1000 for the latter) are now hard-coded.
+* $wgDebugDumpSqlLength was removed (deprecated in 1.24).
+* $wgDebugDBTransactions was removed (deprecated in 1.20).
 
 === New features in 1.27 ===
 * $wgDataCenterId and $wgDataCenterRoles where added, which will serve as

autoload.php

@@ -933,7 +933,6 @@ $wgAutoloadLocalClasses = array(
 	'PostgresBlob' => __DIR__ . '/includes/db/DatabasePostgres.php',
 	'PostgresField' => __DIR__ . '/includes/db/DatabasePostgres.php',
 	'PostgresInstaller' => __DIR__ . '/includes/installer/PostgresInstaller.php',
-	'PostgresTransactionState' => __DIR__ . '/includes/db/DatabasePostgres.php',
 	'PostgresUpdater' => __DIR__ . '/includes/installer/PostgresUpdater.php',
 	'Preferences' => __DIR__ . '/includes/Preferences.php',
 	'PreferencesForm' => __DIR__ . '/includes/Preferences.php',

includes/DefaultSettings.php

@@ -5453,13 +5453,6 @@ $wgDebugRawPage = false;
  */
 $wgDebugComments = false;
 
-/**
- * Extensive database transaction state debugging
- *
- * @since 1.20
- */
-$wgDebugDBTransactions = false;
-
 /**
  * Write SQL queries to the debug log.
  *
@@ -5470,13 +5463,6 @@ $wgDebugDBTransactions = false;
  */
 $wgDebugDumpSql = false;
 
-/**
- * Trim logged SQL queries to this many bytes. Set 0/false/null to do no
- * trimming.
- * @since 1.24
- */
-$wgDebugDumpSqlLength = 500;
-
 /**
  * Performance expectations for DB usage
  *

includes/db/Database.php

@@ -479,11 +479,7 @@ abstract class DatabaseBase implements IDatabase {
 	 *   - DBO_PERSISTENT: use persistant database connection
 	 */
 	public function setFlag( $flag ) {
-		global $wgDebugDBTransactions;
 		$this->mFlags |= $flag;
-		if ( ( $flag & DBO_TRX ) && $wgDebugDBTransactions ) {
-			wfDebug( "Implicit transactions are now enabled.\n" );
-		}
 	}
 
 	/**
@@ -498,11 +494,7 @@ abstract class DatabaseBase implements IDatabase {
 	 *   - DBO_PERSISTENT: use persistant database connection
 	 */
 	public function clearFlag( $flag ) {
-		global $wgDebugDBTransactions;
 		$this->mFlags &= ~$flag;
-		if ( ( $flag & DBO_TRX ) && $wgDebugDBTransactions ) {
-			wfDebug( "Implicit transactions are now disabled.\n" );
-		}
 	}
 
 	/**
@@ -607,7 +599,7 @@ abstract class DatabaseBase implements IDatabase {
 	 * @param array $params Parameters passed from DatabaseBase::factory()
 	 */
 	function __construct( array $params ) {
-		global $wgDBprefix, $wgDBmwschema, $wgCommandLineMode, $wgDebugDBTransactions;
+		global $wgDBprefix, $wgDBmwschema, $wgCommandLineMode;
 
 		$server = $params['host'];
 		$user = $params['user'];
@@ -622,14 +614,8 @@ abstract class DatabaseBase implements IDatabase {
 		if ( $this->mFlags & DBO_DEFAULT ) {
 			if ( $wgCommandLineMode ) {
 				$this->mFlags &= ~DBO_TRX;
-				if ( $wgDebugDBTransactions ) {
-					wfDebug( "Implicit transaction open disabled.\n" );
-				}
 			} else {
 				$this->mFlags |= DBO_TRX;
-				if ( $wgDebugDBTransactions ) {
-					wfDebug( "Implicit transaction open enabled.\n" );
-				}
 			}
 		}
 
@@ -926,7 +912,7 @@ abstract class DatabaseBase implements IDatabase {
 	 *     for a successful read query, or false on failure if $tempIgnore set
 	 */
 	public function query( $sql, $fname = __METHOD__, $tempIgnore = false ) {
-		global $wgUser, $wgDebugDBTransactions, $wgDebugDumpSqlLength;
+		global $wgUser;
 
 		$this->mLastQuery = $sql;
 
@@ -956,9 +942,6 @@ abstract class DatabaseBase implements IDatabase {
 		$commentedSql = preg_replace( '/\s|$/', " /* $fname $userName */ ", $sql, 1 );
 
 		if ( !$this->mTrxLevel && $this->getFlag( DBO_TRX ) && $this->isTransactableQuery( $sql ) ) {
-			if ( $wgDebugDBTransactions ) {
-				wfDebug( "Implicit transaction start.\n" );
-			}
 			$this->begin( __METHOD__ . " ($fname)" );
 			$this->mTrxAutomatic = true;
 		}
@@ -990,15 +973,7 @@ abstract class DatabaseBase implements IDatabase {
 		}
 
 		if ( $this->debug() ) {
-			static $cnt = 0;
+			wfDebugLog( 'queries', sprintf( "%s: %s", $this->mDBname, $sql ) );
-
-			$cnt++;
-			$sqlx = $wgDebugDumpSqlLength ? substr( $commentedSql, 0, $wgDebugDumpSqlLength )
-				: $commentedSql;
-			$sqlx = strtr( $sqlx, "\t\n", '  ' );
-
-			$master = $isMaster ? 'master' : 'slave';
-			wfDebug( "Query {$this->mDBname} ($cnt) ($master): $sqlx\n" );
 		}
 
 		$queryId = MWDebug::query( $sql, $fname, $isMaster );
@@ -3438,8 +3413,6 @@ abstract class DatabaseBase implements IDatabase {
 	 * @throws DBError
 	 */
 	final public function begin( $fname = __METHOD__ ) {
-		global $wgDebugDBTransactions;
-
 		if ( $this->mTrxLevel ) { // implicit commit
 			if ( $this->mTrxAtomicLevels ) {
 				// If the current transaction was an automatic atomic one, then we definitely have
@@ -3460,9 +3433,8 @@ abstract class DatabaseBase implements IDatabase {
 					) )
 				);
 			} else {
-				// if the transaction was automatic and has done write operations,
+				// if the transaction was automatic and has done write operations
-				// log it if $wgDebugDBTransactions is enabled.
+				if ( $this->mTrxDoneWrites ) {
-				if ( $this->mTrxDoneWrites && $wgDebugDBTransactions ) {
 					wfDebug( "$fname: Automatic transaction with writes in progress" .
 						" (from {$this->mTrxFname}), performing implicit commit!\n"
 					);

includes/db/DatabasePostgres.php

@@ -128,89 +128,6 @@ SQL;
 	}
 }
 
-/**
- * Used to debug transaction processing
- * Only used if $wgDebugDBTransactions is true
- *
- * @since 1.19
- * @ingroup Database
- */
-class PostgresTransactionState {
-	private static $WATCHED = array(
-		array(
-			"desc" => "%s: Connection state changed from %s -> %s\n",
-			"states" => array(
-				PGSQL_CONNECTION_OK => "OK",
-				PGSQL_CONNECTION_BAD => "BAD"
-			)
-		),
-		array(
-			"desc" => "%s: Transaction state changed from %s -> %s\n",
-			"states" => array(
-				PGSQL_TRANSACTION_IDLE => "IDLE",
-				PGSQL_TRANSACTION_ACTIVE => "ACTIVE",
-				PGSQL_TRANSACTION_INTRANS => "TRANS",
-				PGSQL_TRANSACTION_INERROR => "ERROR",
-				PGSQL_TRANSACTION_UNKNOWN => "UNKNOWN"
-			)
-		)
-	);
-
-	/** @var array */
-	private $mNewState;
-
-	/** @var array */
-	private $mCurrentState;
-
-	public function __construct( $conn ) {
-		$this->mConn = $conn;
-		$this->update();
-		$this->mCurrentState = $this->mNewState;
-	}
-
-	public function update() {
-		$this->mNewState = array(
-			pg_connection_status( $this->mConn ),
-			pg_transaction_status( $this->mConn )
-		);
-	}
-
-	public function check() {
-		global $wgDebugDBTransactions;
-		$this->update();
-		if ( $wgDebugDBTransactions ) {
-			if ( $this->mCurrentState !== $this->mNewState ) {
-				$old = reset( $this->mCurrentState );
-				$new = reset( $this->mNewState );
-				foreach ( self::$WATCHED as $watched ) {
-					if ( $old !== $new ) {
-						$this->log_changed( $old, $new, $watched );
-					}
-					$old = next( $this->mCurrentState );
-					$new = next( $this->mNewState );
-				}
-			}
-		}
-		$this->mCurrentState = $this->mNewState;
-	}
-
-	protected function describe_changed( $status, $desc_table ) {
-		if ( isset( $desc_table[$status] ) ) {
-			return $desc_table[$status];
-		} else {
-			return "STATUS " . $status;
-		}
-	}
-
-	protected function log_changed( $old, $new, $watched ) {
-		wfDebug( sprintf( $watched["desc"],
-			$this->mConn,
-			$this->describe_changed( $old, $watched["states"] ),
-			$this->describe_changed( $new, $watched["states"] )
-		) );
-	}
-}
-
 /**
  * Manage savepoints within a transaction
  * @ingroup Database
@@ -252,11 +169,7 @@ class SavepointPostgres {
 	}
 
 	protected function query( $keyword, $msg_ok, $msg_failed ) {
-		global $wgDebugDBTransactions;
 		if ( $this->dbw->doQuery( $keyword . " " . $this->id ) !== false ) {
-			if ( $wgDebugDBTransactions ) {
-				wfDebug( sprintf( $msg_ok, $this->id ) );
-			}
 		} else {
 			wfDebug( sprintf( $msg_failed, $this->id ) );
 		}
@@ -307,9 +220,6 @@ class DatabasePostgres extends DatabaseBase {
 	/** @var string Connect string to open a PostgreSQL connection */
 	private $connectString;
 
-	/** @var PostgresTransactionState */
-	private $mTransactionState;
-
 	/** @var string */
 	private $mCoreSchema;
 
@@ -428,7 +338,6 @@ class DatabasePostgres extends DatabaseBase {
 		}
 
 		$this->mOpened = true;
-		$this->mTransactionState = new PostgresTransactionState( $this->mConn );
 
 		global $wgCommandLineMode;
 		# If called from the command-line (e.g. importDump), only show errors
@@ -486,12 +395,10 @@ class DatabasePostgres extends DatabaseBase {
 		if ( function_exists( 'mb_convert_encoding' ) ) {
 			$sql = mb_convert_encoding( $sql, 'UTF-8' );
 		}
-		$this->mTransactionState->check();
 		if ( pg_send_query( $this->mConn, $sql ) === false ) {
 			throw new DBUnexpectedError( $this, "Unable to post new query to PostgreSQL\n" );
 		}
 		$this->mLastResult = pg_get_result( $this->mConn );
-		$this->mTransactionState->check();
 		$this->mAffectedRows = null;
 		if ( pg_result_error( $this->mLastResult ) ) {
 			return false;

includes/objectcache/SqlBagOStuff.php

@@ -131,8 +131,6 @@ class SqlBagOStuff extends BagOStuff {
 	 * @throws MWException
 	 */
 	protected function getDB( $serverIndex ) {
-		global $wgDebugDBTransactions;
-
 		if ( !isset( $this->conns[$serverIndex] ) ) {
 			if ( $serverIndex >= $this->numServers ) {
 				throw new MWException( __METHOD__ . ": Invalid server index \"$serverIndex\"" );
@@ -147,9 +145,6 @@ class SqlBagOStuff extends BagOStuff {
 
 			# If server connection info was given, use that
 			if ( $this->serverInfos ) {
-				if ( $wgDebugDBTransactions ) {
-					$this->logger->debug( "Using provided serverInfo for SqlBagOStuff" );
-				}
 				$info = $this->serverInfos[$serverIndex];
 				$type = isset( $info['type'] ) ? $info['type'] : 'mysql';
 				$host = isset( $info['host'] ) ? $info['host'] : '[unknown]';
@@ -173,9 +168,7 @@ class SqlBagOStuff extends BagOStuff {
 					$db = wfGetDB( $index );
 				}
 			}
-			if ( $wgDebugDBTransactions ) {
+			$this->logger->debug( sprintf( "Connection %s will be used for SqlBagOStuff", $db ) );
-				$this->logger->debug( sprintf( "Connection %s will be used for SqlBagOStuff", $db ) );
-			}
 			$this->conns[$serverIndex] = $db;
 		}