Convert LoadBalancer/Database class logging to PSR
authorAaron Schulz <aschulz@wikimedia.org>
Mon, 12 Sep 2016 22:10:16 +0000 (15:10 -0700)
committerAaron Schulz <aschulz@wikimedia.org>
Wed, 14 Sep 2016 02:22:50 +0000 (02:22 +0000)
Reorder DatabaseBase constructor/factory to the top.

Change-Id: I2ffff950b9170d6ff15dcd46b64dd366f1e441a8

includes/db/ChronologyProtector.php
includes/db/Database.php
includes/db/loadbalancer/LBFactory.php
includes/db/loadbalancer/LoadBalancer.php
includes/db/loadbalancer/LoadMonitor.php
includes/db/loadbalancer/LoadMonitorMySQL.php

index 1cdb49f..9b01adc 100644 (file)
  * @file
  * @ingroup Database
  */
+use Psr\Log\LoggerAwareInterface;
+use Psr\Log\LoggerInterface;
+use MediaWiki\Logger\LoggerFactory;
 
 /**
  * Class for ensuring a consistent ordering of events as seen by the user, despite replication.
  * Kind of like Hawking's [[Chronology Protection Agency]].
  */
-class ChronologyProtector {
+class ChronologyProtector implements LoggerAwareInterface{
        /** @var BagOStuff */
        protected $store;
+       /** @var LoggerInterface */
+       protected $logger;
 
        /** @var string Storage key name */
        protected $key;
@@ -67,6 +72,11 @@ class ChronologyProtector {
                $this->clientId = md5( $client['ip'] . "\n" . $client['agent'] );
                $this->key = $store->makeGlobalKey( __CLASS__, $this->clientId );
                $this->waitForPosTime = $posTime;
+               $this->logger = LoggerFactory::getInstance( 'DBReplication' );
+       }
+
+       public function setLogger( LoggerInterface $logger ) {
+               $this->logger = $logger;
        }
 
        /**
@@ -106,7 +116,7 @@ class ChronologyProtector {
                $masterName = $lb->getServerName( $lb->getWriterIndex() );
                if ( !empty( $this->startupPositions[$masterName] ) ) {
                        $pos = $this->startupPositions[$masterName];
-                       wfDebugLog( 'replication', __METHOD__ . ": LB for '$masterName' set to pos $pos\n" );
+                       $this->logger->info( __METHOD__ . ": LB for '$masterName' set to pos $pos\n" );
                        $lb->waitFor( $pos );
                }
        }
@@ -129,10 +139,10 @@ class ChronologyProtector {
                $masterName = $lb->getServerName( $lb->getWriterIndex() );
                if ( $lb->getServerCount() > 1 ) {
                        $pos = $lb->getMasterPos();
-                       wfDebugLog( 'replication', __METHOD__ . ": LB for '$masterName' has pos $pos\n" );
+                       $this->logger->info( __METHOD__ . ": LB for '$masterName' has pos $pos\n" );
                        $this->shutdownPositions[$masterName] = $pos;
                } else {
-                       wfDebugLog( 'replication', __METHOD__ . ": DB '$masterName' touched\n" );
+                       $this->logger->info( __METHOD__ . ": DB '$masterName' touched\n" );
                }
                $this->shutdownTouchDBs[$masterName] = 1;
        }
@@ -165,8 +175,7 @@ class ChronologyProtector {
                        return []; // nothing to save
                }
 
-               wfDebugLog( 'replication',
-                       __METHOD__ . ": saving master pos for " .
+               $this->logger->info( __METHOD__ . ": saving master pos for " .
                        implode( ', ', array_keys( $this->shutdownPositions ) ) . "\n"
                );
 
@@ -193,16 +202,14 @@ class ChronologyProtector {
                if ( !$ok ) {
                        $bouncedPositions = $this->shutdownPositions;
                        // Raced out too many times or stash is down
-                       wfDebugLog( 'replication',
-                               __METHOD__ . ": failed to save master pos for " .
+                       $this->logger->warning( __METHOD__ . ": failed to save master pos for " .
                                implode( ', ', array_keys( $this->shutdownPositions ) ) . "\n"
                        );
                } elseif ( $mode === 'sync' &&
                        $store->getQoS( $store::ATTR_SYNCWRITES ) < $store::QOS_SYNCWRITES_BE
                ) {
                        // Positions may not be in all datacenters, force LBFactory to play it safe
-                       wfDebugLog( 'replication',
-                               __METHOD__ . ": store does not report ability to sync replicas. " );
+                       $this->logger->info( __METHOD__ . ": store may not support synchronous writes." );
                        $bouncedPositions = $this->shutdownPositions;
                } else {
                        $bouncedPositions = [];
@@ -267,10 +274,10 @@ class ChronologyProtector {
                        }
 
                        $this->startupPositions = $data ? $data['positions'] : [];
-                       wfDebugLog( 'replication', __METHOD__ . ": key is {$this->key} (read)\n" );
+                       $this->logger->info( __METHOD__ . ": key is {$this->key} (read)\n" );
                } else {
                        $this->startupPositions = [];
-                       wfDebugLog( 'replication', __METHOD__ . ": key is {$this->key} (unread)\n" );
+                       $this->logger->info( __METHOD__ . ": key is {$this->key} (unread)\n" );
                }
        }
 
index c41e7c7..b044e23 100644 (file)
@@ -1,5 +1,4 @@
 <?php
-
 /**
  * @defgroup Database Database
  *
  * @file
  * @ingroup Database
  */
+use Psr\Log\LoggerAwareInterface;
+use Psr\Log\LoggerInterface;
 
 /**
  * Database abstraction object
  * @ingroup Database
  */
-abstract class DatabaseBase implements IDatabase {
+abstract class DatabaseBase implements IDatabase, LoggerAwareInterface {
        /** Number of times to re-try an operation in case of deadlock */
        const DEADLOCK_TRIES = 4;
        /** Minimum time to wait before retry, in microseconds */
@@ -64,6 +65,10 @@ abstract class DatabaseBase implements IDatabase {
 
        /** @var BagOStuff APC cache */
        protected $srvCache;
+       /** @var LoggerInterface */
+       protected $connLogger;
+       /** @var LoggerInterface */
+       protected $queryLogger;
 
        /** @var resource Database connection */
        protected $mConn = null;
@@ -219,6 +224,183 @@ abstract class DatabaseBase implements IDatabase {
        /** @var TransactionProfiler */
        protected $trxProfiler;
 
+       /**
+        * Constructor.
+        *
+        * FIXME: It is possible to construct a Database object with no associated
+        * connection object, by specifying no parameters to __construct(). This
+        * feature is deprecated and should be removed.
+        *
+        * DatabaseBase subclasses should not be constructed directly in external
+        * code. DatabaseBase::factory() should be used instead.
+        *
+        * @param array $params Parameters passed from DatabaseBase::factory()
+        */
+       function __construct( array $params ) {
+               global $wgDBprefix, $wgDBmwschema;
+
+               $this->srvCache = ObjectCache::getLocalServerInstance( 'hash' );
+
+               $server = $params['host'];
+               $user = $params['user'];
+               $password = $params['password'];
+               $dbName = $params['dbname'];
+               $flags = $params['flags'];
+               $tablePrefix = $params['tablePrefix'];
+               $schema = $params['schema'];
+               $foreign = $params['foreign'];
+
+               $this->cliMode = isset( $params['cliMode'] )
+                       ? $params['cliMode']
+                       : ( PHP_SAPI === 'cli' );
+
+               $this->mFlags = $flags;
+               if ( $this->mFlags & DBO_DEFAULT ) {
+                       if ( $this->cliMode ) {
+                               $this->mFlags &= ~DBO_TRX;
+                       } else {
+                               $this->mFlags |= DBO_TRX;
+                       }
+               }
+
+               $this->mSessionVars = $params['variables'];
+
+               /** Get the default table prefix*/
+               if ( $tablePrefix === 'get from global' ) {
+                       $this->mTablePrefix = $wgDBprefix;
+               } else {
+                       $this->mTablePrefix = $tablePrefix;
+               }
+
+               /** Get the database schema*/
+               if ( $schema === 'get from global' ) {
+                       $this->mSchema = $wgDBmwschema;
+               } else {
+                       $this->mSchema = $schema;
+               }
+
+               $this->mForeign = $foreign;
+
+               $this->profiler = isset( $params['profiler'] )
+                       ? $params['profiler']
+                       : Profiler::instance(); // @TODO: remove global state
+               $this->trxProfiler = isset( $params['trxProfiler'] )
+                       ? $params['trxProfiler']
+                       : new TransactionProfiler();
+               $this->connLogger = isset( $params['connLogger'] )
+                       ? $params['connLogger']
+                       : new \Psr\Log\NullLogger();
+               $this->queryLogger = isset( $params['queryLogger'] )
+                       ? $params['queryLogger']
+                       : new \Psr\Log\NullLogger();
+
+               if ( $user ) {
+                       $this->open( $server, $user, $password, $dbName );
+               }
+       }
+
+       /**
+        * Given a DB type, construct the name of the appropriate child class of
+        * DatabaseBase. This is designed to replace all of the manual stuff like:
+        *    $class = 'Database' . ucfirst( strtolower( $dbType ) );
+        * as well as validate against the canonical list of DB types we have
+        *
+        * This factory function is mostly useful for when you need to connect to a
+        * database other than the MediaWiki default (such as for external auth,
+        * an extension, et cetera). Do not use this to connect to the MediaWiki
+        * database. Example uses in core:
+        * @see LoadBalancer::reallyOpenConnection()
+        * @see ForeignDBRepo::getMasterDB()
+        * @see WebInstallerDBConnect::execute()
+        *
+        * @since 1.18
+        *
+        * @param string $dbType A possible DB type
+        * @param array $p An array of options to pass to the constructor.
+        *    Valid options are: host, user, password, dbname, flags, tablePrefix, schema, driver
+        * @throws MWException If the database driver or extension cannot be found
+        * @return DatabaseBase|null DatabaseBase subclass or null
+        */
+       final public static function factory( $dbType, $p = [] ) {
+               global $wgCommandLineMode;
+
+               $canonicalDBTypes = [
+                       'mysql' => [ 'mysqli', 'mysql' ],
+                       'postgres' => [],
+                       'sqlite' => [],
+                       'oracle' => [],
+                       'mssql' => [],
+               ];
+
+               $driver = false;
+               $dbType = strtolower( $dbType );
+               if ( isset( $canonicalDBTypes[$dbType] ) && $canonicalDBTypes[$dbType] ) {
+                       $possibleDrivers = $canonicalDBTypes[$dbType];
+                       if ( !empty( $p['driver'] ) ) {
+                               if ( in_array( $p['driver'], $possibleDrivers ) ) {
+                                       $driver = $p['driver'];
+                               } else {
+                                       throw new MWException( __METHOD__ .
+                                               " cannot construct Database with type '$dbType' and driver '{$p['driver']}'" );
+                               }
+                       } else {
+                               foreach ( $possibleDrivers as $posDriver ) {
+                                       if ( extension_loaded( $posDriver ) ) {
+                                               $driver = $posDriver;
+                                               break;
+                                       }
+                               }
+                       }
+               } else {
+                       $driver = $dbType;
+               }
+               if ( $driver === false ) {
+                       throw new MWException( __METHOD__ .
+                               " no viable database extension found for type '$dbType'" );
+               }
+
+               // Determine schema defaults. Currently Microsoft SQL Server uses $wgDBmwschema,
+               // and everything else doesn't use a schema (e.g. null)
+               // Although postgres and oracle support schemas, we don't use them (yet)
+               // to maintain backwards compatibility
+               $defaultSchemas = [
+                       'mssql' => 'get from global',
+               ];
+
+               $class = 'Database' . ucfirst( $driver );
+               if ( class_exists( $class ) && is_subclass_of( $class, 'DatabaseBase' ) ) {
+                       // Resolve some defaults for b/c
+                       $p['host'] = isset( $p['host'] ) ? $p['host'] : false;
+                       $p['user'] = isset( $p['user'] ) ? $p['user'] : false;
+                       $p['password'] = isset( $p['password'] ) ? $p['password'] : false;
+                       $p['dbname'] = isset( $p['dbname'] ) ? $p['dbname'] : false;
+                       $p['flags'] = isset( $p['flags'] ) ? $p['flags'] : 0;
+                       $p['variables'] = isset( $p['variables'] ) ? $p['variables'] : [];
+                       $p['tablePrefix'] = isset( $p['tablePrefix'] ) ? $p['tablePrefix'] : 'get from global';
+                       if ( !isset( $p['schema'] ) ) {
+                               $p['schema'] = isset( $defaultSchemas[$dbType] ) ? $defaultSchemas[$dbType] : null;
+                       }
+                       $p['foreign'] = isset( $p['foreign'] ) ? $p['foreign'] : false;
+                       $p['cliMode'] = $wgCommandLineMode;
+
+                       $conn = new $class( $p );
+                       if ( isset( $p['connLogger'] ) ) {
+                               $conn->connLogger = $p['connLogger'];
+                       }
+                       if ( isset( $p['queryLogger'] ) ) {
+                               $conn->queryLogger = $p['queryLogger'];
+                       }
+               } else {
+                       $conn = null;
+               }
+
+               return $conn;
+       }
+
+       public function setLogger( LoggerInterface $logger ) {
+               $this->quertLogger = $logger;
+       }
+
        public function getServerInfo() {
                return $this->getServerVersion();
        }
@@ -552,76 +734,6 @@ abstract class DatabaseBase implements IDatabase {
         */
        abstract function strencode( $s );
 
-       /**
-        * Constructor.
-        *
-        * FIXME: It is possible to construct a Database object with no associated
-        * connection object, by specifying no parameters to __construct(). This
-        * feature is deprecated and should be removed.
-        *
-        * DatabaseBase subclasses should not be constructed directly in external
-        * code. DatabaseBase::factory() should be used instead.
-        *
-        * @param array $params Parameters passed from DatabaseBase::factory()
-        */
-       function __construct( array $params ) {
-               global $wgDBprefix, $wgDBmwschema;
-
-               $this->srvCache = ObjectCache::getLocalServerInstance( 'hash' );
-
-               $server = $params['host'];
-               $user = $params['user'];
-               $password = $params['password'];
-               $dbName = $params['dbname'];
-               $flags = $params['flags'];
-               $tablePrefix = $params['tablePrefix'];
-               $schema = $params['schema'];
-               $foreign = $params['foreign'];
-
-               $this->cliMode = isset( $params['cliMode'] )
-                       ? $params['cliMode']
-                       : ( PHP_SAPI === 'cli' );
-
-               $this->mFlags = $flags;
-               if ( $this->mFlags & DBO_DEFAULT ) {
-                       if ( $this->cliMode ) {
-                               $this->mFlags &= ~DBO_TRX;
-                       } else {
-                               $this->mFlags |= DBO_TRX;
-                       }
-               }
-
-               $this->mSessionVars = $params['variables'];
-
-               /** Get the default table prefix*/
-               if ( $tablePrefix === 'get from global' ) {
-                       $this->mTablePrefix = $wgDBprefix;
-               } else {
-                       $this->mTablePrefix = $tablePrefix;
-               }
-
-               /** Get the database schema*/
-               if ( $schema === 'get from global' ) {
-                       $this->mSchema = $wgDBmwschema;
-               } else {
-                       $this->mSchema = $schema;
-               }
-
-               $this->mForeign = $foreign;
-
-               $this->profiler = isset( $params['profiler'] )
-                       ? $params['profiler']
-                       : Profiler::instance(); // @TODO: remove global state
-               $this->trxProfiler = isset( $params['trxProfiler'] )
-                       ? $params['trxProfiler']
-                       : new TransactionProfiler();
-
-               if ( $user ) {
-                       $this->open( $server, $user, $password, $dbName );
-               }
-
-       }
-
        /**
         * Called by serialize. Throw an exception when DB connection is serialized.
         * This causes problems on some database engines because the connection is
@@ -632,96 +744,6 @@ abstract class DatabaseBase implements IDatabase {
                        'the connection is not restored on wakeup.' );
        }
 
-       /**
-        * Given a DB type, construct the name of the appropriate child class of
-        * DatabaseBase. This is designed to replace all of the manual stuff like:
-        *    $class = 'Database' . ucfirst( strtolower( $dbType ) );
-        * as well as validate against the canonical list of DB types we have
-        *
-        * This factory function is mostly useful for when you need to connect to a
-        * database other than the MediaWiki default (such as for external auth,
-        * an extension, et cetera). Do not use this to connect to the MediaWiki
-        * database. Example uses in core:
-        * @see LoadBalancer::reallyOpenConnection()
-        * @see ForeignDBRepo::getMasterDB()
-        * @see WebInstallerDBConnect::execute()
-        *
-        * @since 1.18
-        *
-        * @param string $dbType A possible DB type
-        * @param array $p An array of options to pass to the constructor.
-        *    Valid options are: host, user, password, dbname, flags, tablePrefix, schema, driver
-        * @throws MWException If the database driver or extension cannot be found
-        * @return DatabaseBase|null DatabaseBase subclass or null
-        */
-       final public static function factory( $dbType, $p = [] ) {
-               global $wgCommandLineMode;
-
-               $canonicalDBTypes = [
-                       'mysql' => [ 'mysqli', 'mysql' ],
-                       'postgres' => [],
-                       'sqlite' => [],
-                       'oracle' => [],
-                       'mssql' => [],
-               ];
-
-               $driver = false;
-               $dbType = strtolower( $dbType );
-               if ( isset( $canonicalDBTypes[$dbType] ) && $canonicalDBTypes[$dbType] ) {
-                       $possibleDrivers = $canonicalDBTypes[$dbType];
-                       if ( !empty( $p['driver'] ) ) {
-                               if ( in_array( $p['driver'], $possibleDrivers ) ) {
-                                       $driver = $p['driver'];
-                               } else {
-                                       throw new MWException( __METHOD__ .
-                                               " cannot construct Database with type '$dbType' and driver '{$p['driver']}'" );
-                               }
-                       } else {
-                               foreach ( $possibleDrivers as $posDriver ) {
-                                       if ( extension_loaded( $posDriver ) ) {
-                                               $driver = $posDriver;
-                                               break;
-                                       }
-                               }
-                       }
-               } else {
-                       $driver = $dbType;
-               }
-               if ( $driver === false ) {
-                       throw new MWException( __METHOD__ .
-                               " no viable database extension found for type '$dbType'" );
-               }
-
-               // Determine schema defaults. Currently Microsoft SQL Server uses $wgDBmwschema,
-               // and everything else doesn't use a schema (e.g. null)
-               // Although postgres and oracle support schemas, we don't use them (yet)
-               // to maintain backwards compatibility
-               $defaultSchemas = [
-                       'mssql' => 'get from global',
-               ];
-
-               $class = 'Database' . ucfirst( $driver );
-               if ( class_exists( $class ) && is_subclass_of( $class, 'DatabaseBase' ) ) {
-                       // Resolve some defaults for b/c
-                       $p['host'] = isset( $p['host'] ) ? $p['host'] : false;
-                       $p['user'] = isset( $p['user'] ) ? $p['user'] : false;
-                       $p['password'] = isset( $p['password'] ) ? $p['password'] : false;
-                       $p['dbname'] = isset( $p['dbname'] ) ? $p['dbname'] : false;
-                       $p['flags'] = isset( $p['flags'] ) ? $p['flags'] : 0;
-                       $p['variables'] = isset( $p['variables'] ) ? $p['variables'] : [];
-                       $p['tablePrefix'] = isset( $p['tablePrefix'] ) ? $p['tablePrefix'] : 'get from global';
-                       if ( !isset( $p['schema'] ) ) {
-                               $p['schema'] = isset( $defaultSchemas[$dbType] ) ? $defaultSchemas[$dbType] : null;
-                       }
-                       $p['foreign'] = isset( $p['foreign'] ) ? $p['foreign'] : false;
-                       $p['cliMode'] = $wgCommandLineMode;
-
-                       return new $class( $p );
-               } else {
-                       return null;
-               }
-       }
-
        protected function installErrorHandler() {
                $this->mPHPError = false;
                $this->htmlErrors = ini_set( 'html_errors', '0' );
@@ -912,7 +934,7 @@ abstract class DatabaseBase implements IDatabase {
                }
 
                if ( $this->debug() ) {
-                       wfDebugLog( 'queries', sprintf( "%s: %s", $this->mDBname, $commentedSql ) );
+                       $this->queryLogger->debug( "{$this->mDBname} {$commentedSql}" );
                }
 
                # Avoid fatals if close() was called
@@ -929,11 +951,10 @@ abstract class DatabaseBase implements IDatabase {
                        $lastErrno = $this->lastErrno();
                        # Update state tracking to reflect transaction loss due to disconnection
                        $this->handleTransactionLoss();
-                       wfDebug( "Connection lost, reconnecting...\n" );
                        if ( $this->reconnect() ) {
-                               wfDebug( "Reconnected\n" );
                                $msg = __METHOD__ . ": lost connection to {$this->getServer()}; reconnected";
-                               wfDebugLog( 'DBPerformance', "$msg:\n" . wfBacktrace( true ) );
+                               $this->connLogger->warning( $msg );
+                               $this->queryLogger->warning( "$msg:\n" . wfBacktrace( true ) );
 
                                if ( !$recoverable ) {
                                        # Callers may catch the exception and continue to use the DB
@@ -943,7 +964,8 @@ abstract class DatabaseBase implements IDatabase {
                                        $ret = $this->doProfiledQuery( $sql, $commentedSql, $isWrite, $fname );
                                }
                        } else {
-                               wfDebug( "Failed\n" );
+                               $msg = __METHOD__ . ": lost connection to {$this->getServer()} permanently";
+                               $this->connLogger->error( $msg );
                        }
                }
 
@@ -1078,7 +1100,7 @@ abstract class DatabaseBase implements IDatabase {
 
        public function reportQueryError( $error, $errno, $sql, $fname, $tempIgnore = false ) {
                if ( $this->ignoreErrors() || $tempIgnore ) {
-                       wfDebug( "SQL ERROR (ignored): $error\n" );
+                       $this->queryLogger->debug( "SQL ERROR (ignored): $error\n" );
                } else {
                        $sql1line = mb_substr( str_replace( "\n", "\\n", $sql ), 0, 5 * 1024 );
                        wfLogDBError(
@@ -1091,7 +1113,7 @@ abstract class DatabaseBase implements IDatabase {
                                        'fname' => $fname,
                                ] )
                        );
-                       wfDebug( "SQL ERROR: " . $error . "\n" );
+                       $this->queryLogger->debug( "SQL ERROR: " . $error . "\n" );
                        throw new DBQueryError( $this, $error, $errno, $sql, $fname );
                }
        }
index 440954f..27bef0a 100644 (file)
@@ -21,9 +21,9 @@
  * @ingroup Database
  */
 
+use Psr\Log\LoggerInterface;
 use MediaWiki\MediaWikiServices;
 use MediaWiki\Services\DestructibleService;
-use Psr\Log\LoggerInterface;
 use MediaWiki\Logger\LoggerFactory;
 
 /**
@@ -37,6 +37,8 @@ abstract class LBFactory implements DestructibleService {
        protected $trxProfiler;
        /** @var LoggerInterface */
        protected $trxLogger;
+       /** @var LoggerInterface */
+       protected $replLogger;
        /** @var BagOStuff */
        protected $srvCache;
        /** @var WANObjectCache */
@@ -80,6 +82,7 @@ abstract class LBFactory implements DestructibleService {
                        $this->wanCache = WANObjectCache::newEmpty();
                }
                $this->trxLogger = LoggerFactory::getInstance( 'DBTransaction' );
+               $this->replLogger = LoggerFactory::getInstance( 'DBReplication' );
                $this->ticket = mt_rand();
        }
 
@@ -645,14 +648,18 @@ abstract class LBFactory implements DestructibleService {
 
        /**
         * Base parameters to LoadBalancer::__construct()
+        * @return array
         */
        final protected function baseLoadBalancerParams() {
                return [
+                       'localDomain' => wfWikiID(),
                        'readOnlyReason' => $this->readOnlyReason,
-                       'trxProfiler' => $this->trxProfiler,
                        'srvCache' => $this->srvCache,
                        'wanCache' => $this->wanCache,
-                       'localDomain' => wfWikiID(),
+                       'trxProfiler' => $this->trxProfiler,
+                       'queryLogger' => LoggerFactory::getInstance( 'DBQuery' ),
+                       'connLogger' => LoggerFactory::getInstance( 'DBConnection' ),
+                       'replLogger' => LoggerFactory::getInstance( 'DBReplication' ),
                        'errorLogger' => [ MWExceptionHandler::class, 'logException' ]
                ];
        }
index a02c759..b4898d5 100644 (file)
@@ -1,6 +1,6 @@
 <?php
 /**
- * Database load balancing.
+ * Database load balancing manager
  *
  * This program is free software; you can redistribute it and/or modify
  * it under the terms of the GNU General Public License as published by
  * @file
  * @ingroup Database
  */
+use Psr\Log\LoggerInterface;
 
 /**
- * Database load balancing object
+ * Database load balancing, tracking, and transaction management object
  *
- * @todo document
  * @ingroup Database
  */
 class LoadBalancer {
@@ -40,11 +40,9 @@ class LoadBalancer {
        private $mAllowLagged;
        /** @var integer Seconds to spend waiting on replica DB lag to resolve */
        private $mWaitTimeout;
-       /** @var array LBFactory information */
-       private $mParentInfo;
-
        /** @var string The LoadMonitor subclass name */
        private $mLoadMonitorClass;
+
        /** @var LoadMonitor */
        private $mLoadMonitor;
        /** @var BagOStuff */
@@ -53,6 +51,14 @@ class LoadBalancer {
        private $wanCache;
        /** @var TransactionProfiler */
        protected $trxProfiler;
+       /** @var LoggerInterface */
+       protected $replLogger;
+       /** @var LoggerInterface */
+       protected $connLogger;
+       /** @var LoggerInterface */
+       protected $queryLogger;
+       /** @var LoggerInterface */
+       protected $perfLogger;
 
        /** @var bool|DatabaseBase Database connection that caused a problem */
        private $mErrorConnection;
@@ -79,6 +85,9 @@ class LoadBalancer {
        /** @var callable Exception logger */
        private $errorLogger;
 
+       /** @var boolean */
+       private $disabled = false;
+
        /** @var integer Warn when this many connection are held */
        const CONN_HELD_WARN_THRESHOLD = 10;
        /** @var integer Default 'max lag' when unspecified */
@@ -88,11 +97,6 @@ class LoadBalancer {
        /** @var integer Seconds to cache master server read-only status */
        const TTL_CACHE_READONLY = 5;
 
-       /**
-        * @var boolean
-        */
-       private $disabled = false;
-
        /**
         * @param array $params Array with keys:
         *  - servers : Required. Array of server info structures.
@@ -103,11 +107,15 @@ class LoadBalancer {
         *  - wanCache : WANObjectCache object [optional]
         *  - localDomain: The wiki ID of the "local"/"current" wiki [optional]
         *  - errorLogger: Callback that takes an Exception and logs it [optional]
-        * @throws MWException
+        *  - connLogger : LoggerInterface object [optional]
+        *  - queryLogger : LoggerInterface object [optional]
+        *  - replLogger : LoggerInterface object [optional]
+        *  - perfLogger : LoggerInterface object [optional]
+        * @throws InvalidArgumentException
         */
        public function __construct( array $params ) {
                if ( !isset( $params['servers'] ) ) {
-                       throw new MWException( __CLASS__ . ': missing servers parameter' );
+                       throw new InvalidArgumentException( __CLASS__ . ': missing servers parameter' );
                }
                $this->mServers = $params['servers'];
                $this->mWaitTimeout = isset( $params['waitTimeout'] )
@@ -116,7 +124,6 @@ class LoadBalancer {
                $this->localDomain = isset( $params['localDomain'] ) ? $params['localDomain'] : '';
 
                $this->mReadIndex = -1;
-               $this->mWriteIndex = -1;
                $this->mConns = [
                        'local' => [],
                        'foreignUsed' => [],
@@ -174,6 +181,10 @@ class LoadBalancer {
                        : function ( Exception $e ) {
                                trigger_error( E_WARNING, $e->getMessage() );
                        };
+
+               foreach ( [ 'replLogger', 'connLogger', 'queryLogger', 'perfLogger' ] as $key ) {
+                       $this->$key = isset( $params[$key] ) ? $params[$key] : new \Psr\Log\NullLogger();
+               }
        }
 
        /**
@@ -185,6 +196,7 @@ class LoadBalancer {
                if ( !isset( $this->mLoadMonitor ) ) {
                        $class = $this->mLoadMonitorClass;
                        $this->mLoadMonitor = new $class( $this );
+                       $this->mLoadMonitor->setLogger( $this->replLogger );
                }
 
                return $this->mLoadMonitor;
@@ -211,10 +223,10 @@ class LoadBalancer {
 
                                $host = $this->getServerName( $i );
                                if ( $lag === false && !is_infinite( $maxServerLag ) ) {
-                                       wfDebugLog( 'replication', "Server $host (#$i) is not replicating?" );
+                                       $this->replLogger->error( "Server $host (#$i) is not replicating?" );
                                        unset( $loads[$i] );
                                } elseif ( $lag > $maxServerLag ) {
-                                       wfDebugLog( 'replication', "Server $host (#$i) has >= $lag seconds of lag" );
+                                       $this->replLogger->warning( "Server $host (#$i) has >= $lag seconds of lag" );
                                        unset( $loads[$i] );
                                }
                        }
@@ -267,7 +279,7 @@ class LoadBalancer {
                                $nonErrorLoads = $this->mGroupLoads[$group];
                        } else {
                                # No loads for this group, return false and the caller can use some other group
-                               wfDebugLog( 'connect', __METHOD__ . ": no loads for group $group\n" );
+                               $this->connLogger->info( __METHOD__ . ": no loads for group $group" );
 
                                return false;
                        }
@@ -308,7 +320,7 @@ class LoadBalancer {
                                }
                                if ( $i === false && count( $currentLoads ) != 0 ) {
                                        # All replica DBs lagged. Switch to read-only mode
-                                       wfDebugLog( 'replication', "All replica DBs lagged. Switch to read-only mode" );
+                                       $this->replLogger->error( "All replica DBs lagged. Switch to read-only mode" );
                                        $i = ArrayUtils::pickRandom( $currentLoads );
                                        $laggedReplicaMode = true;
                                }
@@ -318,17 +330,17 @@ class LoadBalancer {
                                # pickRandom() returned false
                                # This is permanent and means the configuration or the load monitor
                                # wants us to return false.
-                               wfDebugLog( 'connect', __METHOD__ . ": pickRandom() returned false" );
+                               $this->connLogger->debug( __METHOD__ . ": pickRandom() returned false" );
 
                                return false;
                        }
 
                        $serverName = $this->getServerName( $i );
-                       wfDebugLog( 'connect', __METHOD__ . ": Using reader #$i: $serverName..." );
+                       $this->connLogger->debug( __METHOD__ . ": Using reader #$i: $serverName..." );
 
                        $conn = $this->openConnection( $i, $wiki );
                        if ( !$conn ) {
-                               wfDebugLog( 'connect', __METHOD__ . ": Failed connecting to $i/$wiki" );
+                               $this->connLogger->warning( __METHOD__ . ": Failed connecting to $i/$wiki" );
                                unset( $nonErrorLoads[$i] );
                                unset( $currentLoads[$i] );
                                $i = false;
@@ -347,7 +359,7 @@ class LoadBalancer {
 
                # If all servers were down, quit now
                if ( !count( $nonErrorLoads ) ) {
-                       wfDebugLog( 'connect', "All servers down" );
+                       $this->connLogger->error( "All servers down" );
                }
 
                if ( $i !== false ) {
@@ -364,8 +376,8 @@ class LoadBalancer {
                                }
                        }
                        $serverName = $this->getServerName( $i );
-                       wfDebugLog( 'connect', __METHOD__ .
-                               ": using server $serverName for group '$group'\n" );
+                       $this->connLogger->debug(
+                               __METHOD__ . ": using server $serverName for group '$group'\n" );
                }
 
                return $i;
@@ -472,7 +484,7 @@ class LoadBalancer {
                /** @var DBMasterPos $knownReachedPos */
                $knownReachedPos = $this->srvCache->get( $key );
                if ( $knownReachedPos && $knownReachedPos->hasReached( $this->mWaitForPos ) ) {
-                       wfDebugLog( 'replication', __METHOD__ .
+                       $this->replLogger->debug( __METHOD__ .
                                ": replica DB $server known to be caught up (pos >= $knownReachedPos).\n" );
                        return true;
                }
@@ -481,13 +493,13 @@ class LoadBalancer {
                $conn = $this->getAnyOpenConnection( $index );
                if ( !$conn ) {
                        if ( !$open ) {
-                               wfDebugLog( 'replication', __METHOD__ . ": no connection open for $server\n" );
+                               $this->replLogger->debug( __METHOD__ . ": no connection open for $server\n" );
 
                                return false;
                        } else {
                                $conn = $this->openConnection( $index, '' );
                                if ( !$conn ) {
-                                       wfDebugLog( 'replication', __METHOD__ . ": failed to connect to $server\n" );
+                                       $this->replLogger->warning( __METHOD__ . ": failed to connect to $server\n" );
 
                                        return false;
                                }
@@ -497,18 +509,18 @@ class LoadBalancer {
                        }
                }
 
-               wfDebugLog( 'replication', __METHOD__ . ": Waiting for replica DB $server to catch up...\n" );
+               $this->replLogger->info( __METHOD__ . ": Waiting for replica DB $server to catch up...\n" );
                $timeout = $timeout ?: $this->mWaitTimeout;
                $result = $conn->masterPosWait( $this->mWaitForPos, $timeout );
 
                if ( $result == -1 || is_null( $result ) ) {
                        // Timed out waiting for replica DB, use master instead
                        $msg = __METHOD__ . ": Timed out waiting on $server pos {$this->mWaitForPos}";
-                       wfDebugLog( 'replication', "$msg\n" );
-                       wfDebugLog( 'DBPerformance', "$msg:\n" . wfBacktrace( true ) );
+                       $this->replLogger->warning( "$msg\n" );
+                       $this->perfLogger->warning( "$msg:\n" . wfBacktrace( true ) );
                        $ok = false;
                } else {
-                       wfDebugLog( 'replication', __METHOD__ . ": Done\n" );
+                       $this->replLogger->info( __METHOD__ . ": Done\n" );
                        $ok = true;
                        // Remember that the DB reached this point
                        $this->srvCache->set( $key, $this->mWaitForPos, BagOStuff::TTL_DAY );
@@ -703,10 +715,10 @@ class LoadBalancer {
                        $conn = $this->reallyOpenConnection( $server, false );
                        $serverName = $this->getServerName( $i );
                        if ( $conn->isOpen() ) {
-                               wfDebugLog( 'connect', "Connected to database $i at $serverName\n" );
+                               $this->connLogger->debug( "Connected to database $i at '$serverName'." );
                                $this->mConns['local'][$i][0] = $conn;
                        } else {
-                               wfDebugLog( 'connect', "Failed to connect to database $i at $serverName\n" );
+                               $this->connLogger->warning( "Failed to connect to database $i at '$serverName'." );
                                $this->mErrorConnection = $conn;
                                $conn = false;
                        }
@@ -847,12 +859,16 @@ class LoadBalancer {
 
                // Log when many connection are made on requests
                if ( ++$this->connsOpened >= self::CONN_HELD_WARN_THRESHOLD ) {
-                       wfDebugLog( 'DBPerformance', __METHOD__ . ": " .
+                       $this->perfLogger->warning( __METHOD__ . ": " .
                                "{$this->connsOpened}+ connections made (master=$masterName)\n" .
                                wfBacktrace( true ) );
                }
 
-               # Create object
+               // Set loggers
+               $server['connLogger'] = $this->connLogger;
+               $server['queryLogger'] = $this->queryLogger;
+
+               // Create a live connection object
                try {
                        $db = DatabaseBase::factory( $server['type'], $server );
                } catch ( DBConnectionError $e ) {
@@ -1670,11 +1686,11 @@ class LoadBalancer {
         *
         * @param IDatabase $conn Replica DB
         * @param DBMasterPos|bool $pos Master position; default: current position
-        * @param integer|null $timeout Timeout in seconds [optional]
+        * @param integer $timeout Timeout in seconds
         * @return bool Success
         * @since 1.27
         */
-       public function safeWaitForMasterPos( IDatabase $conn, $pos = false, $timeout = null ) {
+       public function safeWaitForMasterPos( IDatabase $conn, $pos = false, $timeout = 10 ) {
                if ( $this->getServerCount() == 1 || !$conn->getLBInfo( 'replica' ) ) {
                        return true; // server is not a replica DB
                }
@@ -1684,15 +1700,14 @@ class LoadBalancer {
                        return false; // something is misconfigured
                }
 
-               $timeout = $timeout ?: $this->mWaitTimeout;
                $result = $conn->masterPosWait( $pos, $timeout );
                if ( $result == -1 || is_null( $result ) ) {
                        $msg = __METHOD__ . ": Timed out waiting on {$conn->getServer()} pos {$pos}";
-                       wfDebugLog( 'replication', "$msg\n" );
-                       wfDebugLog( 'DBPerformance', "$msg:\n" . wfBacktrace( true ) );
+                       $this->replLogger->warning( "$msg\n" );
+                       $this->perfLogger->warning( "$msg:\n" . wfBacktrace( true ) );
                        $ok = false;
                } else {
-                       wfDebugLog( 'replication', __METHOD__ . ": Done\n" );
+                       $this->replLogger->info( __METHOD__ . ": Done\n" );
                        $ok = true;
                }
 
index e68cf1a..247955a 100644 (file)
  * @file
  * @ingroup Database
  */
+use Psr\Log\LoggerAwareInterface;
+use Psr\Log\LoggerInterface;
 
 /**
  * An interface for database load monitoring
  *
  * @ingroup Database
  */
-interface LoadMonitor {
+interface LoadMonitor extends LoggerAwareInterface {
        /**
         * Construct a new LoadMonitor with a given LoadBalancer parent
         *
         * @param LoadBalancer $parent
         */
-       public function __construct( $parent );
+       public function __construct( LoadBalancer $parent );
 
        /**
         * Perform pre-connection load ratio adjustment.
@@ -62,7 +64,10 @@ interface LoadMonitor {
 }
 
 class LoadMonitorNull implements LoadMonitor {
-       public function __construct( $parent ) {
+       public function __construct( LoadBalancer $parent ) {
+       }
+
+       public function setLogger( LoggerInterface $logger ) {
        }
 
        public function scaleLoads( &$loads, $group = false, $wiki = false ) {
index 444c4b4..7238388 100644 (file)
@@ -19,6 +19,8 @@
  * @ingroup Database
  */
 
+use Psr\Log\LoggerInterface;
+
 /**
  * Basic MySQL load monitor with no external dependencies
  * Uses memcached to cache the replication lag for a short time
@@ -32,12 +34,18 @@ class LoadMonitorMySQL implements LoadMonitor {
        protected $srvCache;
        /** @var BagOStuff */
        protected $mainCache;
+       /** @var LoggerInterface */
+       protected $replLogger;
 
-       public function __construct( $parent ) {
+       public function __construct( LoadBalancer $parent ) {
                $this->parent = $parent;
-
                $this->srvCache = ObjectCache::getLocalServerInstance( 'hash' );
                $this->mainCache = ObjectCache::getLocalClusterInstance();
+               $this->replLogger = new \Psr\Log\NullLogger();
+       }
+
+       public function setLogger( LoggerInterface $logger ) {
+               $this->replLogger = $logger;
        }
 
        public function scaleLoads( &$loads, $group = false, $wiki = false ) {
@@ -58,7 +66,7 @@ class LoadMonitorMySQL implements LoadMonitor {
                # (a) Check the local APC cache
                $value = $this->srvCache->get( $key );
                if ( $value && $value['timestamp'] > ( microtime( true ) - $ttl ) ) {
-                       wfDebugLog( 'replication', __METHOD__ . ": got lag times ($key) from local cache" );
+                       $this->replLogger->debug( __METHOD__ . ": got lag times ($key) from local cache" );
                        return $value['lagTimes']; // cache hit
                }
                $staleValue = $value ?: false;
@@ -67,7 +75,7 @@ class LoadMonitorMySQL implements LoadMonitor {
                $value = $this->mainCache->get( $key );
                if ( $value && $value['timestamp'] > ( microtime( true ) - $ttl ) ) {
                        $this->srvCache->set( $key, $value, $staleTTL );
-                       wfDebugLog( 'replication', __METHOD__ . ": got lag times ($key) from main cache" );
+                       $this->replLogger->debug( __METHOD__ . ": got lag times ($key) from main cache" );
 
                        return $value['lagTimes']; // cache hit
                }
@@ -104,14 +112,14 @@ class LoadMonitorMySQL implements LoadMonitor {
                        if ( !$conn ) {
                                $lagTimes[$i] = false;
                                $host = $this->parent->getServerName( $i );
-                               wfDebugLog( 'replication', __METHOD__ . ": host $host (#$i) is unreachable" );
+                               $this->replLogger->error( __METHOD__ . ": host $host (#$i) is unreachable" );
                                continue;
                        }
 
                        $lagTimes[$i] = $conn->getLag();
                        if ( $lagTimes[$i] === false ) {
                                $host = $this->parent->getServerName( $i );
-                               wfDebugLog( 'replication', __METHOD__ . ": host $host (#$i) is not replicating?" );
+                               $this->replLogger->error( __METHOD__ . ": host $host (#$i) is not replicating?" );
                        }
 
                        if ( $close ) {
@@ -127,7 +135,7 @@ class LoadMonitorMySQL implements LoadMonitor {
                $value = [ 'lagTimes' => $lagTimes, 'timestamp' => microtime( true ) ];
                $this->mainCache->set( $key, $value, $staleTTL );
                $this->srvCache->set( $key, $value, $staleTTL );
-               wfDebugLog( 'replication', __METHOD__ . ": re-calculated lag times ($key)" );
+               $this->replLogger->info( __METHOD__ . ": re-calculated lag times ($key)" );
 
                return $value['lagTimes'];
        }