LoggingHttpMessageHandler should log unescaped URL in log message (#62894)

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<ILogger, HttpMethod, Uri, Exception> _requestStart = LoggerMessage.Define<HttpMethod, Uri>(
+            private static readonly LogDefineOptions _skipEnabledCheckLogDefineOptions = new LogDefineOptions() { SkipEnabledCheck = true };
+
+            private static readonly Action<ILogger, HttpMethod, string, Exception> _requestStart = LoggerMessage.Define<HttpMethod, string>(
                 LogLevel.Information,
                 EventIds.RequestStart,
-                "Sending HTTP request {HttpMethod} {Uri}");
+                "Sending HTTP request {HttpMethod} {Uri}",
+                _skipEnabledCheckLogDefineOptions);
 
             private static readonly Action<ILogger, double, int, Exception> _requestEnd = LoggerMessage.Define<double, int>(
                 LogLevel.Information,
@@ -102,7 +105,11 @@ public static class EventIds
 
             public static void RequestStart(ILogger logger, HttpRequestMessage request, Func<string, bool> 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();
+            }
         }
     }
 }

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<ILogger, HttpMethod, Uri, IDisposable> _beginRequestPipelineScope = LoggerMessage.DefineScope<HttpMethod, Uri>("HTTP {HttpMethod} {Uri}");
+            private static readonly Func<ILogger, HttpMethod, string, IDisposable> _beginRequestPipelineScope = LoggerMessage.DefineScope<HttpMethod, string>("HTTP {HttpMethod} {Uri}");
 
-            private static readonly Action<ILogger, HttpMethod, Uri, Exception> _requestPipelineStart = LoggerMessage.Define<HttpMethod, Uri>(
+            private static readonly Action<ILogger, HttpMethod, string, Exception> _requestPipelineStart = LoggerMessage.Define<HttpMethod, string>(
                 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<string, bool> 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();
+            }
         }
     }
 }

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<ILoggerFactory>(new TestLoggerFactory(sink, enabled: true));
+
+            serviceCollection
+            .AddHttpClient("test")
+            .ConfigurePrimaryHttpMessageHandler(() => new TestMessageHandler());
+
+            var services = serviceCollection.BuildServiceProvider();
+
+            var client = services.GetRequiredService<IHttpClientFactory>().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<ILoggerFactory>(new TestLoggerFactory(sink, enabled: true));
+
+            serviceCollection
+            .AddHttpClient("test")
+            .ConfigurePrimaryHttpMessageHandler(() => new TestMessageHandler());
+
+            var services = serviceCollection.BuildServiceProvider();
+
+            var client = services.GetRequiredService<IHttpClientFactory>().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<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
+            {
+                var response = new HttpResponseMessage();
+
+                return Task.FromResult(response);
+            }
+        }
+    }
+}