ILogger for ConnectionMultiplexer (#2051)

ILogger support - since we support `Action<ConfigurationOptions>` this can be added today e.g. with `o => o.LoggerFactory = myLoggerFactory`: ```cs var muxer = ConnectionMultiplexer.Connect("localhost", o => o.LoggerFactory = myLoggerFactory); ``` ...or we could add sibling overloads to the existing `TextWriter`. I'd love to not create a ^2 matrix every time we do this, though. Starting simpler for that reason. Note: this is on top of #2050 for simplicity, will roll against `main` when merged.
StackExchange · Aug 19, 2023 · 830d2c6 · 830d2c6
1 parent 4cf2013
commit 830d2c6
Show file tree

Hide file tree

Showing 43 changed files with 607 additions and 475 deletions.
diff --git a/.github/workflows/CI.yml b/.github/workflows/CI.yml
@@ -20,7 +20,7 @@ jobs:
     - name: Checkout code
       uses: actions/checkout@v1
     - name: Install .NET SDK
-      uses: actions/setup-dotnet@v1
+      uses: actions/setup-dotnet@v3
       with:
         dotnet-version: | 
           6.0.x
@@ -53,7 +53,7 @@ jobs:
     - name: Checkout code
       uses: actions/checkout@v1
     # - name: Install .NET SDK
-    #   uses: actions/setup-dotnet@v1
+    #   uses: actions/setup-dotnet@v3
     #   with:
     #     dotnet-version: | 
     #       6.0.x

diff --git a/Directory.Packages.props b/Directory.Packages.props
@@ -12,6 +12,7 @@
     <PackageVersion Include="BenchmarkDotNet" Version="0.13.1" />
     <PackageVersion Include="GitHubActionsTestLogger" Version="2.0.0-alpha" />
     <PackageVersion Include="Microsoft.CodeAnalysis.PublicApiAnalyzers" Version="3.3.4-beta1.22362.3" />
+    <PackageVersion Include="Microsoft.Extensions.Logging.Abstractions" Version="6.0.0" />
     <PackageVersion Include="Microsoft.NETFramework.ReferenceAssemblies" Version="1.0.2" />
     <PackageVersion Include="Microsoft.NET.Test.Sdk" Version="17.1.0" />
     <PackageVersion Include="Microsoft.SourceLink.GitHub" Version="1.1.1" />

diff --git a/appveyor.yml b/appveyor.yml
@@ -74,6 +74,7 @@ build_script:
 test: off
 artifacts:
 - path: .\.nupkgs\*.nupkg
+- path: '**\*.trx'
 
 deploy:
 - provider: NuGet

diff --git a/docs/Configuration.md b/docs/Configuration.md
@@ -100,6 +100,8 @@ The `ConfigurationOptions` object has a wide range of properties, all of which a
 | setlib={bool}          | `SetClientLibrary`     | `true`                       | Whether to attempt to use `CLIENT SETINFO` to set the library name/version on the connection              |
 
 Additional code-only options:
+- LoggerFactory (`ILoggerFactory`) - Default: `null`
+  - The logger to use for connection events (not per command), e.g. connection log, disconnects, reconnects, server errors.
 - ReconnectRetryPolicy (`IReconnectRetryPolicy`) - Default: `ReconnectRetryPolicy = ExponentialRetry(ConnectTimeout / 2);`
   - Determines how often a multiplexer will try to reconnect after a failure
 - BacklogPolicy - Default: `BacklogPolicy = BacklogPolicy.Default;`

diff --git a/docs/ReleaseNotes.md b/docs/ReleaseNotes.md
@@ -10,6 +10,7 @@ Current package versions:
 
 - Fix [#2507](https://github.com/StackExchange/StackExchange.Redis/issues/2507): Pub/sub with multi-item payloads should be usable ([#2508 by mgravell](https://github.com/StackExchange/StackExchange.Redis/pull/2508))
 - Add: connection-id tracking (internal only, no public API) ([#2508 by mgravell](https://github.com/StackExchange/StackExchange.Redis/pull/2508))
+- Add: `ConfigurationOptions.LoggerFactory` for logging to an `ILoggerFactory` (e.g. `ILogger`) all connection and error events ([#2051 by NickCraver](https://github.com/StackExchange/StackExchange.Redis/pull/2051))
 - Fix [#2467](https://github.com/StackExchange/StackExchange.Redis/issues/2467): Add StreamGroupInfo EntriesRead and Lag ([#2510 by tvdias](https://github.com/StackExchange/StackExchange.Redis/pull/2510))
 
 ## 2.6.122

diff --git a/src/StackExchange.Redis/Configuration/DefaultOptionsProvider.cs b/src/StackExchange.Redis/Configuration/DefaultOptionsProvider.cs
@@ -3,6 +3,7 @@
 using System.Net;
 using System.Reflection;
 using System.Threading.Tasks;
+using Microsoft.Extensions.Logging;
 
 namespace StackExchange.Redis.Configuration
 {
@@ -156,6 +157,12 @@ public static DefaultOptionsProvider GetProvider(EndPoint endpoint)
         /// </summary>
         public virtual TimeSpan KeepAliveInterval => TimeSpan.FromSeconds(60);
 
+        /// <summary>
+        /// The <see cref="ILoggerFactory"/> to get loggers for connection events.
+        /// Note: changes here only affect <see cref="ConnectionMultiplexer"/>s created after.
+        /// </summary>
+        public virtual ILoggerFactory? LoggerFactory => null;
+
         /// <summary>
         /// Type of proxy to use (if any); for example <see cref="Proxy.Twemproxy"/>.
         /// </summary>

diff --git a/src/StackExchange.Redis/ConfigurationOptions.cs b/src/StackExchange.Redis/ConfigurationOptions.cs
@@ -10,6 +10,7 @@
 using System.Text;
 using System.Threading;
 using System.Threading.Tasks;
+using Microsoft.Extensions.Logging;
 using StackExchange.Redis.Configuration;
 
 namespace StackExchange.Redis
@@ -161,6 +162,8 @@ public static string TryNormalize(string value)
 
         private BacklogPolicy? backlogPolicy;
 
+        private ILoggerFactory? loggerFactory;
+
         /// <summary>
         /// A LocalCertificateSelectionCallback delegate responsible for selecting the certificate used for authentication; note
         /// that this cannot be specified in the configuration-string.
@@ -448,6 +451,16 @@ public int KeepAlive
             set => keepAlive = value;
         }
 
+        /// <summary>
+        /// The <see cref="ILoggerFactory"/> to get loggers for connection events.
+        /// Note: changes here only affect <see cref="ConnectionMultiplexer"/>s created after.
+        /// </summary>
+        public ILoggerFactory? LoggerFactory
+        {
+            get => loggerFactory ?? Defaults.LoggerFactory;
+            set => loggerFactory = value;
+        }
+
         /// <summary>
         /// The username to use to authenticate with the server.
         /// </summary>
@@ -675,6 +688,7 @@ public static ConfigurationOptions Parse(string configuration, bool ignoreUnknow
             checkCertificateRevocation = checkCertificateRevocation,
             BeforeSocketConnect = BeforeSocketConnect,
             EndPoints = EndPoints.Clone(),
+            LoggerFactory = LoggerFactory,
 #if NETCOREAPP3_1_OR_GREATER
             SslClientAuthenticationOptions = SslClientAuthenticationOptions,
 #endif

diff --git a/src/StackExchange.Redis/ConnectionMultiplexer.Sentinel.cs b/src/StackExchange.Redis/ConnectionMultiplexer.Sentinel.cs
@@ -1,4 +1,5 @@
-using Pipelines.Sockets.Unofficial;
+using Microsoft.Extensions.Logging;
+using Pipelines.Sockets.Unofficial;
 using System;
 using System.Collections.Generic;
 using System.IO;
@@ -19,8 +20,8 @@ public partial class ConnectionMultiplexer
     /// <summary>
     /// Initializes the connection as a Sentinel connection and adds the necessary event handlers to track changes to the managed primaries.
     /// </summary>
-    /// <param name="logProxy">The writer to log to, if any.</param>
-    internal void InitializeSentinel(LogProxy? logProxy)
+    /// <param name="log">The <see cref="ILogger"/> to log to, if any.</param>
+    internal void InitializeSentinel(ILogger? log)
     {
         if (ServerSelectionStrategy.ServerType != ServerType.Sentinel)
         {
@@ -65,7 +66,7 @@ internal void InitializeSentinel(LogProxy? logProxy)
         // we need to reconfigure to make sure we still have a subscription to the +switch-master channel
         ConnectionFailed += (sender, e) =>
             // Reconfigure to get subscriptions back online
-            ReconfigureAsync(first: false, reconfigureAll: true, logProxy, e.EndPoint, "Lost sentinel connection", false).Wait();
+            ReconfigureAsync(first: false, reconfigureAll: true, log, e.EndPoint, "Lost sentinel connection", false).Wait();
 
         // Subscribe to new sentinels being added
         if (sub.SubscribedEndpoint(RedisChannel.Literal("+sentinel")) == null)
@@ -142,12 +143,12 @@ private static ConnectionMultiplexer SentinelPrimaryConnect(ConfigurationOptions
     /// for the specified <see cref="ConfigurationOptions.ServiceName"/> in the config and returns a managed connection to the current primary server.
     /// </summary>
     /// <param name="configuration">The configuration options to use for this multiplexer.</param>
-    /// <param name="log">The <see cref="TextWriter"/> to log to.</param>
-    private static async Task<ConnectionMultiplexer> SentinelPrimaryConnectAsync(ConfigurationOptions configuration, TextWriter? log = null)
+    /// <param name="writer">The <see cref="TextWriter"/> to log to.</param>
+    private static async Task<ConnectionMultiplexer> SentinelPrimaryConnectAsync(ConfigurationOptions configuration, TextWriter? writer = null)
     {
-        var sentinelConnection = await SentinelConnectAsync(configuration, log).ForAwait();
+        var sentinelConnection = await SentinelConnectAsync(configuration, writer).ForAwait();
 
-        var muxer = sentinelConnection.GetSentinelMasterConnection(configuration, log);
+        var muxer = sentinelConnection.GetSentinelMasterConnection(configuration, writer);
         // Set reference to sentinel connection so that we can dispose it
         muxer.sentinelConnection = sentinelConnection;
 
@@ -375,49 +376,45 @@ internal void OnManagedConnectionFailed(object? sender, ConnectionFailedEventArg
     /// </summary>
     /// <param name="switchBlame">The endpoint responsible for the switch.</param>
     /// <param name="connection">The connection that should be switched over to a new primary endpoint.</param>
-    /// <param name="log">The writer to log to, if any.</param>
-    internal void SwitchPrimary(EndPoint? switchBlame, ConnectionMultiplexer connection, TextWriter? log = null)
+    /// <param name="writer">The writer to log to, if any.</param>
+    internal void SwitchPrimary(EndPoint? switchBlame, ConnectionMultiplexer connection, TextWriter? writer = null)
     {
-        if (log == null) log = TextWriter.Null;
-
-        using (var logProxy = LogProxy.TryCreate(log))
+        var logger = Logger.With(writer);
+        if (connection.RawConfig.ServiceName is not string serviceName)
         {
-            if (connection.RawConfig.ServiceName is not string serviceName)
-            {
-                logProxy?.WriteLine("Service name not defined.");
-                return;
-            }
+            logger?.LogInformation("Service name not defined.");
+            return;
+        }
 
-            // Get new primary - try twice
-            EndPoint newPrimaryEndPoint = GetConfiguredPrimaryForService(serviceName)
-                                        ?? GetConfiguredPrimaryForService(serviceName)
-                                        ?? throw new RedisConnectionException(ConnectionFailureType.UnableToConnect,
-                                            $"Sentinel: Failed connecting to switch primary for service: {serviceName}");
+        // Get new primary - try twice
+        EndPoint newPrimaryEndPoint = GetConfiguredPrimaryForService(serviceName)
+                                    ?? GetConfiguredPrimaryForService(serviceName)
+                                    ?? throw new RedisConnectionException(ConnectionFailureType.UnableToConnect,
+                                        $"Sentinel: Failed connecting to switch primary for service: {serviceName}");
 
-            connection.currentSentinelPrimaryEndPoint = newPrimaryEndPoint;
+        connection.currentSentinelPrimaryEndPoint = newPrimaryEndPoint;
 
-            if (!connection.servers.Contains(newPrimaryEndPoint))
-            {
-                EndPoint[]? replicaEndPoints = GetReplicasForService(serviceName)
-                                            ?? GetReplicasForService(serviceName);
+        if (!connection.servers.Contains(newPrimaryEndPoint))
+        {
+            EndPoint[]? replicaEndPoints = GetReplicasForService(serviceName)
+                                        ?? GetReplicasForService(serviceName);
 
-                connection.servers.Clear();
-                connection.EndPoints.Clear();
-                connection.EndPoints.TryAdd(newPrimaryEndPoint);
-                if (replicaEndPoints is not null)
+            connection.servers.Clear();
+            connection.EndPoints.Clear();
+            connection.EndPoints.TryAdd(newPrimaryEndPoint);
+            if (replicaEndPoints is not null)
+            {
+                foreach (var replicaEndPoint in replicaEndPoints)
                 {
-                    foreach (var replicaEndPoint in replicaEndPoints)
-                    {
-                        connection.EndPoints.TryAdd(replicaEndPoint);
-                    }
+                    connection.EndPoints.TryAdd(replicaEndPoint);
                 }
-                Trace($"Switching primary to {newPrimaryEndPoint}");
-                // Trigger a reconfigure
-                connection.ReconfigureAsync(first: false, reconfigureAll: false, logProxy, switchBlame,
-                    $"Primary switch {serviceName}", false, CommandFlags.PreferMaster).Wait();
-
-                UpdateSentinelAddressList(serviceName);
             }
+            Trace($"Switching primary to {newPrimaryEndPoint}");
+            // Trigger a reconfigure
+            connection.ReconfigureAsync(first: false, reconfigureAll: false, logger, switchBlame,
+                $"Primary switch {serviceName}", false, CommandFlags.PreferMaster).Wait();
+
+            UpdateSentinelAddressList(serviceName);
         }
     }