[HttpClientFactory] Remove dependency on ILoggerFactory

[CarnaViire]

1. Internal diagnostics logging in DefaultHttpClientFactory now uses a new EventSource ("Private.InternalDiagnostics.Microsoft.Extensions.Http") instead of ILogger

2. LoggingHttpMessageHandlerBuilderFilter only resolves ILoggerFactory if default logging is on

cc @CodeBlanch

Fixes #89032

[ghost]

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

Issue Details

---

1. Internal diagnostics logging in DefaultHttpClientFactory now uses a new EventSource ("Private.InternalDiagnostics.Microsoft.Extensions.Http") instead of ILogger

2. LoggingHttpMessageHandlerBuilderFilter only resolves ILoggerFactory if default logging is on

cc @CodeBlanch

Fixes #89032

Author:	CarnaViire
Assignees:	-
Labels:	area-Extensions-HttpClientFactory
Milestone:	-

[CarnaViire]

Test failures are unrelated.

[ManickaP]

LGTM, just one question.

[CodeBlanch]

@CarnaViire

Would you mind verifying that this test passes with the change? This will verify #89032. It seems like it should, but just want to make sure.

        [Fact]
        public void LoggerFactoryWithHttpClientFactoryTest()
        {
            var services = new ServiceCollection();

            services.AddHttpClient();

            services.AddLogging(builder => builder.Services.AddSingleton<ILoggerProvider, TestLoggerProvider>());

            using var serviceProvider = services.BuildServiceProvider();

            var loggerFactory = serviceProvider.GetService<ILoggerFactory>();
        }

        private sealed class TestLoggerProvider : ILoggerProvider
        {
            private readonly HttpClient _httpClient;

            public TestLoggerProvider(IHttpClientFactory httpClientFactory)
            {
                _httpClient = httpClientFactory.CreateClient("TestLoggerProvider");
            }

            public ILogger CreateLogger(string categoryName)
            {
                return NullLogger.Instance;
            }

            public void Dispose()
            {
                _httpClient.Dispose();
            }
        }

[CarnaViire]

@CodeBlanch you need to remove the default HttpClient logging (that uses ILoggerFactory, and I cannot change that without breaking the end users) -- so in your suggestion I've changed services.AddHttpClient(); to

services.AddHttpClient("TestLoggerProvider").RemoveAllLoggers();

Default logging can also be removed for all HttpClients by

services.ConfigureHttpClientDefaults(b => b.RemoveAllLoggers());

(it is still possible to add the default logging back per-name with AddDefaultLogger())

[JamesNK]

Wait, this is a breaking change for anyone who is using these logs. Also, EventSource is not as easy to use or as powerful as ILogger.

Could this be fixed by not resolving ILoggerFactory in the DefaultHttpClientFactory constructor? DefaultHttpClientFactory has IServiceProvider. It could be used to lazily get an ILogger instance the first time it is used. e.g.

private ILogger Logger
{
    get { return _logger ??= _serviceProvider.GetRequiredService<ILoggerFactory>().CreateLogger<DefaultHttpClientFactory>(); }
}

[JamesNK]

#89531 (comment)

[CarnaViire]

Wait, this is a breaking change for anyone who is using these logs.

You mean debugging DefaultHttpClientFactory logs that say that the cleanup cycle has started? This really looked like an internal diagnostics stuff, not a thing anyone could depend on?

Because the "default" per-client logs stay the same as they were (using ILogger).

I've thought on an ability to bring the debugging back to ILogger via an app-context switch, if it's reeeally needed.... And the user setting this would guarantee that they haven't registered any logging provider that internally uses HttpClientFactory.

Could this be fixed by not resolving ILoggerFactory in the DefaultHttpClientFactory constructor?

I don't think there's any other way to fix the bug. Even if the factory would be created by making the resolution to be lazy, the whole thing would still enter an endless cycle trying to log that it logs that it logs etc

[JamesNK]

I don't think there's any other way to fix the bug. Even if the factory would be created by making the resolution to be lazy, the whole thing would still enter an endless cycle trying to log that it logs that it logs etc

Are you sure?

Logging isn't async. _logger.LogInformation("Hello world") won't pause until the log message is sent with HttpClient. What I guess OTel folks do is put the log message into a queue and send it via HttpClient in a background thread. That's how most complex log providers do async IO.

Some more log messages will get written when, for example, HttpClientFactory's CleanupCycleStart message is logged, but that shouldn't put the ILoggerProvider that uses the client factory into a stack overflow because HttpClientFactory logged something.

Btw I don't have an objection to requiring people to remove default HTTP client logging. That's just a configuration change required by someone who wants to do this.

Alternatively, you could suggest to them that they disable that logging with Microsoft.Extensions.Logging filters. They could do the same thing to filter out logging from HttpClientFactory if it is problematic.

[CarnaViire]

@JamesNK @ManickaP PTAL

[ManickaP]

I assume the added tests simulate the reported problem and with the lazy initialization it's solved. If so, still LGTM.

[JamesNK]

Add a comment explaining why.

[JamesNK]

Why PublicationOnly in this lazy and ExecutionAndPublication in DefaultHttpClientFactory lazy?

[CarnaViire]

I guess we don't need to guard this one at all, given that DI should already guard creation of a singleton.

DefaultHttpClientFactory lazy is creating ILogger, which is most possibly a new instance every time CreateLogger is invoked, so I want to avoid unnecessary allocations.

[CarnaViire]

@JamesNK PTAL