diff --git a/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingHttpMessageHandler.cs b/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingHttpMessageHandler.cs index b2bee46b3a3d60..cca20cbca1a1ed 100644 --- a/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingHttpMessageHandler.cs +++ b/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingHttpMessageHandler.cs @@ -90,10 +90,13 @@ public static class EventIds public static readonly EventId ResponseHeader = new EventId(103, "ResponseHeader"); } - private static readonly Action _requestStart = LoggerMessage.Define( + private static readonly LogDefineOptions _skipEnabledCheckLogDefineOptions = new LogDefineOptions() { SkipEnabledCheck = true }; + + private static readonly Action _requestStart = LoggerMessage.Define( LogLevel.Information, EventIds.RequestStart, - "Sending HTTP request {HttpMethod} {Uri}"); + "Sending HTTP request {HttpMethod} {Uri}", + _skipEnabledCheckLogDefineOptions); private static readonly Action _requestEnd = LoggerMessage.Define( LogLevel.Information, @@ -102,7 +105,11 @@ public static class EventIds public static void RequestStart(ILogger logger, HttpRequestMessage request, Func shouldRedactHeaderValue) { - _requestStart(logger, request.Method, request.RequestUri, null); + // We check here to avoid allocating in the GetUriString call unnecessarily + if (logger.IsEnabled(LogLevel.Information)) + { + _requestStart(logger, request.Method, GetUriString(request.RequestUri), null); + } if (logger.IsEnabled(LogLevel.Trace)) { @@ -129,6 +136,13 @@ public static void RequestEnd(ILogger logger, HttpResponseMessage response, Time (state, ex) => state.ToString()); } } + + private static string? GetUriString(Uri? requestUri) + { + return requestUri?.IsAbsoluteUri == true + ? requestUri.AbsoluteUri + : requestUri?.ToString(); + } } } } diff --git a/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingScopeHttpMessageHandler.cs b/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingScopeHttpMessageHandler.cs index 8ac16482c5e1ad..92fab8b7d06f34 100644 --- a/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingScopeHttpMessageHandler.cs +++ b/src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingScopeHttpMessageHandler.cs @@ -92,9 +92,9 @@ public static class EventIds public static readonly EventId ResponseHeader = new EventId(103, "RequestPipelineResponseHeader"); } - private static readonly Func _beginRequestPipelineScope = LoggerMessage.DefineScope("HTTP {HttpMethod} {Uri}"); + private static readonly Func _beginRequestPipelineScope = LoggerMessage.DefineScope("HTTP {HttpMethod} {Uri}"); - private static readonly Action _requestPipelineStart = LoggerMessage.Define( + private static readonly Action _requestPipelineStart = LoggerMessage.Define( LogLevel.Information, EventIds.PipelineStart, "Start processing HTTP request {HttpMethod} {Uri}"); @@ -106,12 +106,12 @@ public static class EventIds public static IDisposable BeginRequestPipelineScope(ILogger logger, HttpRequestMessage request) { - return _beginRequestPipelineScope(logger, request.Method, request.RequestUri); + return _beginRequestPipelineScope(logger, request.Method, GetUriString(request.RequestUri)); } public static void RequestPipelineStart(ILogger logger, HttpRequestMessage request, Func shouldRedactHeaderValue) { - _requestPipelineStart(logger, request.Method, request.RequestUri, null); + _requestPipelineStart(logger, request.Method, GetUriString(request.RequestUri), null); if (logger.IsEnabled(LogLevel.Trace)) { @@ -138,6 +138,13 @@ public static void RequestPipelineEnd(ILogger logger, HttpResponseMessage respon (state, ex) => state.ToString()); } } + + private static string? GetUriString(Uri? requestUri) + { + return requestUri?.IsAbsoluteUri == true + ? requestUri.AbsoluteUri + : requestUri?.ToString(); + } } } } diff --git a/src/libraries/Microsoft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/Logging/LoggingUriOutputTests.cs b/src/libraries/Microsoft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/Logging/LoggingUriOutputTests.cs new file mode 100644 index 00000000000000..9f5588a3f61051 --- /dev/null +++ b/src/libraries/Microsoft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/Logging/LoggingUriOutputTests.cs @@ -0,0 +1,103 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Linq; +using System.Net.Http; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Http.Logging; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Testing; +using Xunit; + +namespace Microsoft.Extensions.Http.Tests.Logging +{ + public class LoggingUriOutputTests + { + [Fact] + public async Task LoggingHttpMessageHandler_LogsAbsoluteUri() + { + // Arrange + var sink = new TestSink(); + + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(); + serviceCollection.AddSingleton(new TestLoggerFactory(sink, enabled: true)); + + serviceCollection + .AddHttpClient("test") + .ConfigurePrimaryHttpMessageHandler(() => new TestMessageHandler()); + + var services = serviceCollection.BuildServiceProvider(); + + var client = services.GetRequiredService().CreateClient("test"); + + + // Act + var request = new HttpRequestMessage(HttpMethod.Get, "http://api.example.com/search?term=Western%20Australia"); + + await client.SendAsync(request); + + // Assert + var messages = sink.Writes.ToArray(); + + var message = Assert.Single(messages.Where(m => + { + return + m.EventId == LoggingHttpMessageHandler.Log.EventIds.RequestStart && + m.LoggerName == "System.Net.Http.HttpClient.test.ClientHandler"; + })); + + Assert.Equal("Sending HTTP request GET http://api.example.com/search?term=Western%20Australia", message.Message); + } + + [Fact] + public async Task LoggingScopeHttpMessageHandler_LogsAbsoluteUri() + { + // Arrange + var sink = new TestSink(); + + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(); + serviceCollection.AddSingleton(new TestLoggerFactory(sink, enabled: true)); + + serviceCollection + .AddHttpClient("test") + .ConfigurePrimaryHttpMessageHandler(() => new TestMessageHandler()); + + var services = serviceCollection.BuildServiceProvider(); + + var client = services.GetRequiredService().CreateClient("test"); + + + // Act + var request = new HttpRequestMessage(HttpMethod.Get, "http://api.example.com/search?term=Western%20Australia"); + + await client.SendAsync(request); + + // Assert + var messages = sink.Writes.ToArray(); + + var message = Assert.Single(messages.Where(m => + { + return + m.EventId == LoggingScopeHttpMessageHandler.Log.EventIds.PipelineStart && + m.LoggerName == "System.Net.Http.HttpClient.test.LogicalHandler"; + })); + + Assert.Equal("Start processing HTTP request GET http://api.example.com/search?term=Western%20Australia", message.Message); + Assert.Equal("HTTP GET http://api.example.com/search?term=Western%20Australia", message.Scope.ToString()); + } + + private class TestMessageHandler : HttpClientHandler + { + protected override Task SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) + { + var response = new HttpResponseMessage(); + + return Task.FromResult(response); + } + } + } +}