HttpClientFactory Prevent throwing if ILogger couldn't be created (#90503)

* HttpClientFactory stop cleanup timer on dispose

* Remove finalizer

* Tweak ThrowIfDisposed

* Revert some changes

* Fix

diff --git a/src/libraries/Microsoft.Extensions.Http/src/DefaultHttpClientFactory.cs b/src/libraries/Microsoft.Extensions.Http/src/DefaultHttpClientFactory.cs
index e4a8496..15d5b6d 100644 (file)
--- a/src/libraries/Microsoft.Extensions.Http/src/DefaultHttpClientFactory.cs
+++ b/src/libraries/Microsoft.Extensions.Http/src/DefaultHttpClientFactory.cs
@@ -5,6 +5,7 @@ using System;
 using System.Collections.Concurrent;
 using System.Collections.Generic;
 using System.Diagnostics;
+using System.Diagnostics.CodeAnalysis;
 using System.Linq;
 using System.Net.Http;
 using System.Threading;
@@ -208,7 +209,7 @@ namespace Microsoft.Extensions.Http
             var expired = new ExpiredHandlerTrackingEntry(active);
             _expiredHandlers.Enqueue(expired);
 
-            Log.HandlerExpired(_logger.Value, active.Name, active.Lifetime);
+            Log.HandlerExpired(_logger, active.Name, active.Lifetime);
 
             StartCleanupTimer();
         }
@@ -266,7 +267,7 @@ namespace Microsoft.Extensions.Http
             try
             {
                 int initialCount = _expiredHandlers.Count;
-                Log.CleanupCycleStart(_logger.Value, initialCount);
+                Log.CleanupCycleStart(_logger, initialCount);
 
                 var stopwatch = ValueStopwatch.StartNew();
 
@@ -287,7 +288,7 @@ namespace Microsoft.Extensions.Http
                         }
                         catch (Exception ex)
                         {
-                            Log.CleanupItemFailed(_logger.Value, entry.Name, ex);
+                            Log.CleanupItemFailed(_logger, entry.Name, ex);
                         }
                     }
                     else
@@ -298,7 +299,7 @@ namespace Microsoft.Extensions.Http
                     }
                 }
 
-                Log.CleanupCycleEnd(_logger.Value, stopwatch.GetElapsedTime(), disposedCount, _expiredHandlers.Count);
+                Log.CleanupCycleEnd(_logger, stopwatch.GetElapsedTime(), disposedCount, _expiredHandlers.Count);
             }
             finally
             {
@@ -343,24 +344,48 @@ namespace Microsoft.Extensions.Http
                 "HttpMessageHandler expired after {HandlerLifetime}ms for client '{ClientName}'");
 
 
-            public static void CleanupCycleStart(ILogger logger, int initialCount)
+            public static void CleanupCycleStart(Lazy<ILogger> loggerLazy, int initialCount)
             {
-                _cleanupCycleStart(logger, initialCount, null);
+                if (TryGetLogger(loggerLazy, out ILogger? logger))
+                {
+                    _cleanupCycleStart(logger, initialCount, null);
+                }
+            }
+
+            public static void CleanupCycleEnd(Lazy<ILogger> loggerLazy, TimeSpan duration, int disposedCount, int finalCount)
+            {
+                if (TryGetLogger(loggerLazy, out ILogger? logger))
+                {
+                    _cleanupCycleEnd(logger, duration.TotalMilliseconds, disposedCount, finalCount, null);
+                }
             }
 
-            public static void CleanupCycleEnd(ILogger logger, TimeSpan duration, int disposedCount, int finalCount)
+            public static void CleanupItemFailed(Lazy<ILogger> loggerLazy, string clientName, Exception exception)
             {
-                _cleanupCycleEnd(logger, duration.TotalMilliseconds, disposedCount, finalCount, null);
+                if (TryGetLogger(loggerLazy, out ILogger? logger))
+                {
+                    _cleanupItemFailed(logger, clientName, exception);
+                }
             }
 
-            public static void CleanupItemFailed(ILogger logger, string clientName, Exception exception)
+            public static void HandlerExpired(Lazy<ILogger> loggerLazy, string clientName, TimeSpan lifetime)
             {
-                _cleanupItemFailed(logger, clientName, exception);
+                if (TryGetLogger(loggerLazy, out ILogger? logger))
+                {
+                    _handlerExpired(logger, lifetime.TotalMilliseconds, clientName, null);
+                }
             }
 
-            public static void HandlerExpired(ILogger logger, string clientName, TimeSpan lifetime)
+            private static bool TryGetLogger(Lazy<ILogger> loggerLazy, [NotNullWhen(true)] out ILogger? logger)
             {
-                _handlerExpired(logger, lifetime.TotalMilliseconds, clientName, null);
+                logger = null;
+                try
+                {
+                    logger = loggerLazy.Value;
+                }
+                catch { } // not throwing in logs
+
+                return logger is not null;
             }
         }
     }

diff --git a/src/libraries/Microsoft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/DefaultHttpClientFactoryTest.cs b/src/libraries/Microsoft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/DefaultHttpClientFactoryTest.cs
index 4ebd568..63cc940 100644 (file)
--- a/src/libraries/Microsoft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/DefaultHttpClientFactoryTest.cs
+++ b/src/libraries/Microsoft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/DefaultHttpClientFactoryTest.cs
@@ -3,6 +3,7 @@
 
 using System;
 using System.Collections.Generic;
+using System.Linq;
 using System.Net.Http;
 using System.Runtime.CompilerServices;
 using System.Threading;
@@ -10,6 +11,7 @@ using System.Threading.Tasks;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Logging.Abstractions;
+using Microsoft.Extensions.Logging.Testing;
 using Microsoft.Extensions.Options;
 using Moq;
 using Moq.Protected;
@@ -508,6 +510,29 @@ namespace Microsoft.Extensions.Http
             return cleanupEntry;
         }
 
+        [Fact]
+        public void ServiceProviderDispose_DebugLoggingDoesNotThrow()
+        {
+            var sink = new TestSink();
+
+            var serviceCollection = new ServiceCollection();
+            serviceCollection.AddLogging();
+            serviceCollection.AddSingleton<ILoggerFactory>(new TestLoggerFactory(sink, enabled: true));
+            serviceCollection.AddHttpClient("test");
+
+            var serviceProvider = serviceCollection.BuildServiceProvider();
+
+            var httpClientFactory = (DefaultHttpClientFactory)serviceProvider.GetRequiredService<IHttpClientFactory>();
+            _ =  httpClientFactory.CreateClient("test");
+
+            serviceProvider.Dispose();
+
+            httpClientFactory.StartCleanupTimer(); // we need to create a timer instance before triggering cleanup; normally it happens after the first expiry
+            httpClientFactory.CleanupTimer_Tick(); // trigger cleanup to (try to) write debug logs
+            // but no log is added, because ILogger couldn't be created
+            Assert.Equal(0, sink.Writes.Count(w => w.LoggerName == typeof(DefaultHttpClientFactory).FullName));
+        }
+
         private class TestHttpClientFactory : DefaultHttpClientFactory
         {
             public TestHttpClientFactory(