RedisConnectionPool: convert to PSR3 logging

Convert from wfDebug* logging to Psr\Log\LoggerInterface. Use structured
logging data to tag log messages the associated redis server.

Bug: T88649
Change-Id: I5fc4c68e52b13a688bdcc93d9defc9f973323241

diff --git a/includes/clientpool/RedisConnectionPool.php b/includes/clientpool/RedisConnectionPool.php
index dc95727..0d00d11 100644 (file)
--- a/includes/clientpool/RedisConnectionPool.php
+++ b/includes/clientpool/RedisConnectionPool.php
@@ -22,6 +22,10 @@
  * @author Aaron Schulz
  */
 
+use MediaWiki\Logger\LoggerFactory;
+use Psr\Log\LoggerAwareInterface;
+use Psr\Log\LoggerInterface;
+
 /**
  * Helper class to manage Redis connections.
  *
@@ -68,6 +72,11 @@ class RedisConnectionPool {
        /** integer; seconds to cache servers as "down". */
        const SERVER_DOWN_TTL = 30;
 
+       /**
+        * @var LoggerInterface
+        */
+       protected $logger;
+
        /**
         * @param array $options
         * @throws MWException
@@ -77,6 +86,11 @@ class RedisConnectionPool {
                        throw new MWException( __CLASS__ . ' requires a Redis client library. ' .
                                'See https://www.mediawiki.org/wiki/Redis#Setup' );
                }
+               if ( isset( $options['logger'] ) ) {
+                       $this->setLogger( $options['logger'] );
+               } else {
+                       $this->setLogger( LoggerFactory::getInstance( 'redis' ) );
+               }
                $this->connectTimeout = $options['connectTimeout'];
                $this->readTimeout = $options['readTimeout'];
                $this->persistent = $options['persistent'];
@@ -92,6 +106,14 @@ class RedisConnectionPool {
                }
        }
 
+       /**
+        * @param LoggerInterface $logger
+        * @return null
+        */
+       public function setLogger( LoggerInterface $logger ) {
+               $this->logger = $logger;
+       }
+
        /**
         * @param array $options
         * @return array
@@ -136,7 +158,9 @@ class RedisConnectionPool {
                // Initialize the object at the hash as needed...
                if ( !isset( self::$instances[$id] ) ) {
                        self::$instances[$id] = new self( $options );
-                       wfDebug( "Creating a new " . __CLASS__ . " instance with id $id.\n" );
+                       LoggerFactory::getInstance( 'redis' )->debug(
+                               "Creating a new " . __CLASS__ . " instance with id $id."
+                       );
                }
 
                return self::$instances[$id];
@@ -161,8 +185,11 @@ class RedisConnectionPool {
                                unset( $this->downServers[$server] );
                        } else {
                                // Server is dead
-                               wfDebug( "server $server is marked down for another " .
-                                       ( $this->downServers[$server] - $now ) . " seconds, can't get connection\n" );
+                               $this->logger->debug(
+                                       'Server "{redis_server}" is marked down for another ' .
+                                       ( $this->downServers[$server] - $now ) . 'seconds',
+                                       array( 'redis_server' => $server )
+                               );
 
                                return false;
                        }
@@ -175,7 +202,9 @@ class RedisConnectionPool {
                                        $connection['free'] = false;
                                        --$this->idlePoolSize;
 
-                                       return new RedisConnRef( $this, $server, $connection['conn'] );
+                                       return new RedisConnRef(
+                                               $this, $server, $connection['conn'], $this->logger
+                                       );
                                }
                        }
                }
@@ -206,7 +235,10 @@ class RedisConnectionPool {
                                $result = $conn->connect( $host, $port, $this->connectTimeout );
                        }
                        if ( !$result ) {
-                               wfDebugLog( 'redis', "Could not connect to server $server" );
+                               $this->logger->error(
+                                       'Could not connect to server "{redis_server}"',
+                                       array( 'redis_server' => $server )
+                               );
                                // Mark server down for some time to avoid further timeouts
                                $this->downServers[$server] = time() + self::SERVER_DOWN_TTL;
 
@@ -214,12 +246,21 @@ class RedisConnectionPool {
                        }
                        if ( $this->password !== null ) {
                                if ( !$conn->auth( $this->password ) ) {
-                                       wfDebugLog( 'redis', "Authentication error connecting to $server" );
+                                       $this->logger->error(
+                                               'Authentication error connecting to "{redis_server}"',
+                                               array( 'redis_server' => $server )
+                                       );
                                }
                        }
                } catch ( RedisException $e ) {
                        $this->downServers[$server] = time() + self::SERVER_DOWN_TTL;
-                       wfDebugLog( 'redis', "Redis exception connecting to $server: " . $e->getMessage() );
+                       $this->logger->error(
+                               'Redis exception connecting to "{redis_server}"',
+                               array(
+                                       'redis_server' => $server,
+                                       'exception' => $e,
+                               )
+                       );
 
                        return false;
                }
@@ -229,7 +270,7 @@ class RedisConnectionPool {
                        $conn->setOption( Redis::OPT_SERIALIZER, $this->serializer );
                        $this->connections[$server][] = array( 'conn' => $conn, 'free' => false );
 
-                       return new RedisConnRef( $this, $server, $conn );
+                       return new RedisConnRef( $this, $server, $conn, $this->logger );
                } else {
                        return false;
                }
@@ -304,7 +345,13 @@ class RedisConnectionPool {
         */
        public function handleError( RedisConnRef $cref, RedisException $e ) {
                $server = $cref->getServer();
-               wfDebugLog( 'redis', "Redis exception on server $server: " . $e->getMessage() . "\n" );
+               $this->logger->error(
+                       'Redis exception on server "{redis_server}"',
+                       array(
+                               'redis_server' => $server,
+                               'exception' => $e,
+                       )
+               );
                foreach ( $this->connections[$server] as $key => $connection ) {
                        if ( $cref->isConnIdentical( $connection['conn'] ) ) {
                                $this->idlePoolSize -= $connection['free'] ? 1 : 0;
@@ -333,7 +380,10 @@ class RedisConnectionPool {
        public function reauthenticateConnection( $server, Redis $conn ) {
                if ( $this->password !== null ) {
                        if ( !$conn->auth( $this->password ) ) {
-                               wfDebugLog( 'redis', "Authentication error connecting to $server" );
+                               $this->logger->error(
+                                       'Authentication error connecting to "{redis_server}"',
+                                       array( 'redis_server' => $server )
+                               );
 
                                return false;
                        }
@@ -381,15 +431,22 @@ class RedisConnRef {
        protected $server; // string
        protected $lastError; // string
 
+       /**
+        * @var LoggerInterface
+        */
+       protected $logger;
+
        /**
         * @param RedisConnectionPool $pool
         * @param string $server
         * @param Redis $conn
+        * @param LoggerInterface $logger
         */
-       public function __construct( RedisConnectionPool $pool, $server, Redis $conn ) {
+       public function __construct( RedisConnectionPool $pool, $server, Redis $conn, LoggerInterface $logger ) {
                $this->pool = $pool;
                $this->server = $server;
                $this->conn = $conn;
+               $this->logger = $logger;
        }
 
        /**
@@ -428,7 +485,10 @@ class RedisConnRef {
                                $this->pool->reauthenticateConnection( $this->server, $conn );
                                $conn->clearLastError();
                                $res = call_user_func_array( array( $conn, $name ), $arguments );
-                               wfDebugLog( 'redis', "Used automatic re-authentication for method '$name'." );
+                               $this->logger->info(
+                                       "Used automatic re-authentication for method '$name'.",
+                                       array( 'redis_server' => $this->server )
+                               );
                        }
                } catch ( RedisException $e ) {
                        $this->pool->resetTimeout( $conn ); // restore
@@ -465,17 +525,29 @@ class RedisConnRef {
                        $this->pool->reauthenticateConnection( $server, $conn );
                        $conn->clearLastError();
                        $res = $conn->eval( $script, $params, $numKeys );
-                       wfDebugLog( 'redis', "Used automatic re-authentication for Lua script $sha1." );
+                       $this->logger->info(
+                               "Used automatic re-authentication for Lua script '$sha1'.",
+                               array( 'redis_server' => $server )
+                       );
                }
                // If the script is not in cache, use eval() to retry and cache it
                if ( preg_match( '/^NOSCRIPT/', $conn->getLastError() ) ) {
                        $conn->clearLastError();
                        $res = $conn->eval( $script, $params, $numKeys );
-                       wfDebugLog( 'redis', "Used eval() for Lua script $sha1." );
+                       $this->logger->info(
+                               "Used eval() for Lua script '$sha1'.",
+                               array( 'redis_server' => $server )
+                       );
                }
 
                if ( $conn->getLastError() ) { // script bug?
-                       wfDebugLog( 'redis', "Lua script error on server $server: " . $conn->getLastError() );
+                       $this->logger->error(
+                               'Lua script error on server "{redis_server}": {lua_error}',
+                               array(
+                                       'redis_server' => $server,
+                                       'lua_error' => $conn->getLastError()
+                               )
+                       );
                }
 
                $this->lastError = $conn->getLastError() ?: $this->lastError;