[API Proposal] HttpClientFactory logging configuration #77312
Description
Original issue by @CarnaViire
Tracking all the community asks regarding HttpClientFactory logging in one place.
-
Make logging opt-in. Opt-out currently is possible only using a workaround to remove all IHttpMessageHandlerBuilderFilter registrations from the DI container. Related: Make it possible to disable the built-in HTTP client logging #81540, Microsoft.Extensions.Http is too heavy-weight for mobile usages #66863, Ability to disable default http request logging #85840
-
Make logging configurable. Related: Modify HttpClientFactory based HttpClient request logging #44411 -- 7 upvotes
- Ability to substitute by Networking Telemetry (incl. ActivityId). Related: [API Proposal]: Add http request/response correlation id to LoggingHttpMessageHandler (Microsoft.Extensions.Http.Logging) #76998
- Ability to redact URIs used for logging. Related: IHttpClientBuilder should have extension to redact query parameter from logging #68675, Modify HttpClientFactory based HttpClient request logging #44411
- Ability to write response body by analogy with ASP.NET's Http logging. Related: [API Proposal]: Add body content to HttpRequestException #86095
Background and motivation
There is a growing number of asks to make HttpClientFactory's logging opt out and/or configurable (see original issue description). Given the enrichable logging designed in dotnet/extensions, we want to have a flexible and extensible logging infrastructure and give users an API experience that feels consistent even if it spans more than one package.
API Proposal
// new
interface IHttpClientLogger
{
// returns context object (e.g. LogRecord)
ValueTask<object?> LogRequestStartAsync(
HttpRequestMessage request,
CancellationToken cancellationToken = default);
ValueTask LogRequestStopAsync(
object? context,
HttpRequestMessage request,
HttpResponseMessage response,
TimeSpan elapsed,
CancellationToken cancellationToken = default);
ValueTask LogRequestFailedAsync(
object? context,
HttpRequestMessage request,
HttpResponseMessage? response,
Exception exception,
TimeSpan elapsed,
CancellationToken cancellationToken = default);
}
// new
interface IHttpClientLoggingBuilder
{
string Name { get; }
IServiceCollection Services { get; }
// adds custom implementation
// wrapHandlersPipeline -- whether a logging handler should be added to the top or to the bottom
// of the handlers chain
IHttpClientLoggingBuilder AddLogger(
Func<IServiceProvider, IHttpClientLogger> httpClientLoggerFactory,
bool wrapHandlersPipeline = false);
// removes all loggers incl. default ones
IHttpClientLoggingBuilder RemoveAllLoggers();
}
// new
static class HttpClientLoggingBuilderExtensions
{
// adds (back) the default logging (LoggingHttpMessageHandler + LoggingScopeHttpMessageHandler)
// useful if the logging was removed by RemoveAll before e.g. by ConfigureHttpClientDefaults
public static IHttpClientLoggingBuilder AddDefaultLogger(this IHttpClientLoggingBuilder builder);
// convenience method -- adds custom implementation from container
public static IHttpClientLoggingBuilder AddLogger<TLogger>(
this IHttpClientLoggingBuilder builder, bool wrapHandlersPipeline = false)
where TLogger : IHttpClientLogger;
}
// existing
static class HttpClientBuilderExtensions
{
// new
public static IHttpClientBuilder ConfigureLogging(
this IHttpClientBuilder builder, Action<IHttpClientLoggingBuilder> configure) {}
}API Usage
1. Removing the logging
services.AddHttpClient("foo").ConfigureLogging(b => b.RemoveAllLoggers());
// -OR-
// remove for all clients
services.ConfigureHttpCientDefaults(defaults =>
defaults.ConfigureLogging(b => b.RemoveAllLoggers());2. Implementing custom one-line console logging
Related: #44411, #76998, #68675, #86095
// registration
services.AddSingleton<MyConsoleLogger>();
services.AddHttpClient("bar").ConfigureLogging(b =>
b.RemoveAllLoggers()
.AddLogger<MyConsoleLogger>());
// ...
// logger implementation
public class MyConsoleLogger : IHttpClientLogger
{
public ValueTask<object?> LogRequestStartAsync(HttpRequestMessage request, CancellationToken cancellationToken = default) => ValueTask.FromResult((object?)null);
public ValueTask LogRequestStopAsync(object? context, HttpRequestMessage request, HttpResponseMessage response, TimeSpan elapsed, CancellationToken cancellationToken = default)
{
Console.WriteLine($"{request.Method} {request.RequestUri?.AbsoluteUri} - {(int)response.StatusCode} {response.StatusCode} in {elapsed.TotalMilliseconds}ms");
return ValueTask.CompletedTask;
}
public ValueTask LogRequestFailedAsync(object? context, HttpRequestMessage request, HttpResponseMessage? response, Exception exception, TimeSpan elapsed, CancellationToken cancellationToken = default)
{
Console.WriteLine($"{request.Method} {request.RequestUri?.AbsoluteUri} - FAILED {exception.GetType().FullName}: {exception.Message}");
return ValueTask.CompletedTask;
}
}example output
client code:
await client.GetAsync("https://httpbin.dmuth.org/get");
await client.PostAsync("https://httpbin.dmuth.org/post", new ByteArrayContent(new byte[] { 42 }));
await client.GetAsync("http://httpbin.dmuth.org/status/500");
await client.GetAsync("http://localhost:1234");console output:
GET https://httpbin.dmuth.org/get - 200 OK in 393.2039ms
POST https://httpbin.dmuth.org/post - 200 OK in 95.524ms
GET https://httpbin.dmuth.org/status/500 - 500 InternalServerError in 99.5025ms
GET http://localhost:1234/ - FAILED System.Net.Http.HttpRequestException: No connection could be made because the target machine actively refused it. (localhost:1234)
3. Same but for ILogger
Bonus: add client name to ILogger category name
Bonus 2: custom extension method
// registration
services.AddHttpClient("baz").ConfigureLogging(b => b.UseMyMinimalLogging());
// ...
// custom extension method
IHttpClientLoggingBuilder UseMyMinimalLogging(this IHttpClientLoggingBuilder builder)
{
var name = builder.Name;
return builder.RemoveAllLoggers()
.AddLogger(sp =>
{
var loggerFactory = sp.GetRequiredService<ILoggerFactory>();
var log = loggerFactory.CreateLogger($"{nameof(MyMinimalLogger)}.{name}");
return new MyMinimalLogger(log);
});
}
// ...
// logger implementation
public class MyMinimalLogger : IHttpClientLogger
{
private ILogger _log;
public MyMinimalLogger(ILogger log)
{
_log = log;
}
public ValueTask<object?> LogRequestStartAsync(HttpRequestMessage request, CancellationToken cancellationToken = default) => ValueTask.FromResult((object?)null);
public ValueTask LogRequestStopAsync(object? context, HttpRequestMessage request, HttpResponseMessage response, TimeSpan elapsed, CancellationToken cancellationToken = default)
{
_log.LogInformation($"{request.Method} {request.RequestUri?.AbsoluteUri} - {(int)response.StatusCode} {response.StatusCode} in {elapsed.TotalMilliseconds}ms");
return ValueTask.CompletedTask;
}
public ValueTask LogRequestFailedAsync(object? context, HttpRequestMessage request, HttpResponseMessage? response, Exception exception, TimeSpan elapsed, CancellationToken cancellationToken = default)
{
_log.LogWarning($"{request.Method} {request.RequestUri?.AbsoluteUri} - FAILED {exception.GetType().FullName}: {exception.Message}");
return ValueTask.CompletedTask;
}
}example output
client code:
await client.GetAsync("https://httpbin.dmuth.org/get");
await client.PostAsync("https://httpbin.dmuth.org/post", new ByteArrayContent(new byte[] { 42 }));
await client.GetAsync("http://httpbin.dmuth.org/status/500");
await client.GetAsync("http://localhost:1234");console output:
info: MyMinimalLogger.baz[0]
GET https://httpbin.dmuth.org/get - 200 OK in 393.2039ms
info: MyMinimalLogger.baz[0]
POST https://httpbin.dmuth.org/post - 200 OK in 95.524ms
info: MyMinimalLogger.baz[0]
GET https://httpbin.dmuth.org/status/500 - 500 InternalServerError in 99.5025ms
warn: MyMinimalLogger.baz[0]
GET http://localhost:1234/ - FAILED System.Net.Http.HttpRequestException: No connection could be made because the target machine actively refused it. (localhost:1234)
4. Adding (back) the default HttpClientFactory logging
After removal, or after the logging would be potentially turned off by default in a future release
// remove for all clients
services.ConfigureHttpCientDefaults(defaults =>
defaults.ConfigureLogging(b => b.RemoveAllLoggers());
// add back for a single client
services.AddHttpClient("qux").ConfigureLogging(b => b.AddDefaultLogger());5. Implementing Microsoft.Extensions.Http.Telemetry logging
Related: #87247
Based on HttpLoggingHandler functionality from Extensions.
The logger itself in the gist https://gist.github.com/CarnaViire/08346da1634d357f6bcb8adefa01da67#file-httpclientlogger-cs
// registration
services.AddHttpClient("quux").ConfigureLogging(b => b.UseEnrichedLogging());
// ...
// custom extension method
IHttpClientLoggingBuilder UseEnrichedLogging(this IHttpClientLoggingBuilder builder) =>
builder.RemoveAllLoggers()
.AddLogger(services =>
{
var log = services.GetRequiredService<ILogger<HttpClientLogger>>();
var httpRequestReader = services.GetRequiredService<IHttpRequestReader>();
var enrichers = services.GetServices<IHttpClientLogEnricher>();
var loggingOptions = services.GetRequiredService<IOptions<LoggingOptions>>();
return new HttpClientLogger(log, httpRequestReader, enrichers, loggingOptions);
});6. Going forward
We can consider adding convenience methods for a configurable minimal logging in the future (with implementation based on the Example 3):
// existing (to be)
static class HttpClientLoggingBuilderExtensions
{
// new
IHttpClientLoggingBuilder AddMinimalLogger(
this IHttpClientLoggingBuilder builder,
Func<HttpRequestMessage, HttpResponseMessage?, Exception?, TimeSpan, string> formatter);
}Logger implementation
internal class MinimalHttpClientLogger : IHttpClientLogger
{
private ILogger _log;
private Func<HttpRequestMessage, HttpResponseMessage?, Exception?, TimeSpan, string> _formatter;
public MinimalHttpClientLogger(ILogger log, Func<HttpRequestMessage, HttpResponseMessage?, Exception?, TimeSpan, string> formatter)
{
_log = log;
_formatter = formatter;
}
public ValueTask<object?> LogRequestStartAsync(HttpRequestMessage request, CancellationToken cancellationToken = default) => ValueTask.FromResult((object?)null);
public ValueTask LogRequestStopAsync(object? context, HttpRequestMessage request, HttpResponseMessage response, TimeSpan elapsed, CancellationToken cancellationToken = default)
{
_log.LogInformation(_formatter(request, response, null, elapsed));
return ValueTask.CompletedTask;
}
public ValueTask LogRequestFailedAsync(object? context, HttpRequestMessage request, HttpResponseMessage? response, Exception exception, TimeSpan elapsed, CancellationToken cancellationToken = default)
{
_log.LogWarning(_formatter(request, response, exception, elapsed));
return ValueTask.CompletedTask;
}
}Alternative Design
I believe we can expect most of the custom user logging to be sync rather than async. Having async-only interface would force the users to always do return ValueTask.CompletedTask; in the end of an inherently sync implementation, which might be a bit inconvenient. We might consider having sync methods on the interface as well, and default-implement async ones. We cannot drop async, as there's already a precedent for async logging in dotnet/extensions.
interface IHttpClientLogger
{
object? LogRequestStart(HttpRequestMessage request, CancellationToken cancellationToken = default);
void LogRequestStop(object? context, HttpRequestMessage request, HttpResponseMessage response, TimeSpan elapsed, CancellationToken cancellationToken = default);
void LogRequestFailed(object? context, HttpRequestMessage request, HttpResponseMessage? response, Exception exception,TimeSpan elapsed, CancellationToken cancellationToken = default);
ValueTask<object?> LogRequestStartAsync(HttpRequestMessage request, CancellationToken cancellationToken = default)
{
object? context = LogRequestStart(request, cancellationToken);
return ValueTask.FromResult(context);
}
ValueTask LogRequestStopAsync(object? context, HttpRequestMessage request, HttpResponseMessage response, TimeSpan elapsed, CancellationToken cancellationToken = default)
{
LogRequestStop(context, request, response, elapsed, cancellationToken);
return ValueTask.CompletedTask;
}
ValueTask LogRequestFailedAsync(object? context, HttpRequestMessage request, HttpResponseMessage? response, Exception exception,TimeSpan elapsed, CancellationToken cancellationToken = default)
{
LogRequestFailed(context, request, response, exception, elapsed, cancellationToken);
return ValueTask.CompletedTask;
}
}