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

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->logger->debug(
-					( $this->downServers[$server] - $now ) . " seconds, can't get connection\n" );
+					'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;