[HttpClientFactory] Do not log query string by default

src/libraries/Microsoft.Extensions.Http/src/Logging/LogHelper.cs

@@ -0,0 +1,193 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+using System;
+using System.Diagnostics;
+using System.Net.Http;
+using System.Runtime.CompilerServices;
+using System.Threading;
+using System.Threading.Tasks;
+using Microsoft.Extensions.Internal;
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.Extensions.Http.Logging
+{
+    internal static class LogHelper
+    {
+        private static readonly LogDefineOptions s_skipEnabledCheckLogDefineOptions = new LogDefineOptions() { SkipEnabledCheck = true };
+        private static readonly bool s_disableUriRedaction = GetDisableUriRedactionSettingValue();
+
+        private static class EventIds
+        {
+            public static readonly EventId RequestStart = new EventId(100, "RequestStart");
+            public static readonly EventId RequestEnd = new EventId(101, "RequestEnd");
+
+            public static readonly EventId RequestHeader = new EventId(102, "RequestHeader");
+            public static readonly EventId ResponseHeader = new EventId(103, "ResponseHeader");
+
+            public static readonly EventId PipelineStart = new EventId(100, "RequestPipelineStart");
+            public static readonly EventId PipelineEnd = new EventId(101, "RequestPipelineEnd");
+
+            public static readonly EventId RequestPipelineRequestHeader = new EventId(102, "RequestPipelineRequestHeader");
+            public static readonly EventId RequestPipelineResponseHeader = new EventId(103, "RequestPipelineResponseHeader");
+        }
+
+        private static readonly Action<ILogger, HttpMethod, string?, Exception?> _requestStart = LoggerMessage.Define<HttpMethod, string?>(
+            LogLevel.Information,
+            EventIds.RequestStart,
+            "Sending HTTP request {HttpMethod} {Uri}",
+            s_skipEnabledCheckLogDefineOptions);
+
+        private static readonly Action<ILogger, double, int, Exception?> _requestEnd = LoggerMessage.Define<double, int>(
+            LogLevel.Information,
+            EventIds.RequestEnd,
+            "Received HTTP response headers after {ElapsedMilliseconds}ms - {StatusCode}");
+
+        private static readonly Func<ILogger, HttpMethod, string?, IDisposable?> _beginRequestPipelineScope = LoggerMessage.DefineScope<HttpMethod, string?>("HTTP {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}");
+
+        private static readonly Action<ILogger, double, int, Exception?> _requestPipelineEnd = LoggerMessage.Define<double, int>(
+            LogLevel.Information,
+            EventIds.PipelineEnd,
+            "End processing HTTP request after {ElapsedMilliseconds}ms - {StatusCode}");
+
+        private static bool GetDisableUriRedactionSettingValue()
+        {
+            if (AppContext.TryGetSwitch("System.Net.Http.DisableUriRedaction", out bool value))
+            {
+                return value;
+            }
+
+            string? envVar = Environment.GetEnvironmentVariable("DOTNET_SYSTEM_NET_HTTP_DISABLEURIREDACTION");
+
+            if (bool.TryParse(envVar, out value))
+            {
+                return value;
+            }
+            else if (uint.TryParse(envVar, out uint intVal))
+            {
+                return intVal != 0;
+            }
+
+            return false;
+        }
+
+        public static void LogRequestStart(this ILogger logger, HttpRequestMessage request, Func<string, bool> shouldRedactHeaderValue)
+        {
+            // We check here to avoid allocating in the GetRedactedUriString call unnecessarily
+            if (logger.IsEnabled(LogLevel.Information))
+            {
+                _requestStart(logger, request.Method, GetRedactedUriString(request.RequestUri), null);
+            }
+
+            if (logger.IsEnabled(LogLevel.Trace))
+            {
+                logger.Log(
+                    LogLevel.Trace,
+                    EventIds.RequestHeader,
+                    new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Request, request.Headers, request.Content?.Headers, shouldRedactHeaderValue),
+                    null,
+                    (state, ex) => state.ToString());
+            }
+        }
+
+        public static void LogRequestEnd(this ILogger logger, HttpResponseMessage response, TimeSpan duration, Func<string, bool> shouldRedactHeaderValue)
+        {
+            _requestEnd(logger, duration.TotalMilliseconds, (int)response.StatusCode, null);
+
+            if (logger.IsEnabled(LogLevel.Trace))
+            {
+                logger.Log(
+                    LogLevel.Trace,
+                    EventIds.ResponseHeader,
+                    new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Response, response.Headers, response.Content?.Headers, shouldRedactHeaderValue),
+                    null,
+                    (state, ex) => state.ToString());
+            }
+        }
+
+        public static IDisposable? BeginRequestPipelineScope(this ILogger logger, HttpRequestMessage request, out string? formattedUri)
+        {
+            formattedUri = GetRedactedUriString(request.RequestUri);
+            return _beginRequestPipelineScope(logger, request.Method, formattedUri);
+        }
+
+        public static void LogRequestPipelineStart(this ILogger logger, HttpRequestMessage request, string? formattedUri, Func<string, bool> shouldRedactHeaderValue)
+        {
+            _requestPipelineStart(logger, request.Method, formattedUri, null);
+
+            if (logger.IsEnabled(LogLevel.Trace))
+            {
+                logger.Log(
+                    LogLevel.Trace,
+                    EventIds.RequestPipelineRequestHeader,
+                    new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Request, request.Headers, request.Content?.Headers, shouldRedactHeaderValue),
+                    null,
+                    (state, ex) => state.ToString());
+            }
+        }
+
+        public static void LogRequestPipelineEnd(this ILogger logger, HttpResponseMessage response, TimeSpan duration, Func<string, bool> shouldRedactHeaderValue)
+        {
+            _requestPipelineEnd(logger, duration.TotalMilliseconds, (int)response.StatusCode, null);
+
+            if (logger.IsEnabled(LogLevel.Trace))
+            {
+                logger.Log(
+                    LogLevel.Trace,
+                    EventIds.RequestPipelineResponseHeader,
+                    new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Response, response.Headers, response.Content?.Headers, shouldRedactHeaderValue),
+                    null,
+                    (state, ex) => state.ToString());
+            }
+        }
+
+        internal static string? GetRedactedUriString(Uri? uri)
+        {
+            if (uri is null)
+            {
+                return null;
+            }
+
+            if (s_disableUriRedaction)
+            {
+                return uri.IsAbsoluteUri ? uri.AbsoluteUri : uri.ToString();
+            }
+
+            if (!uri.IsAbsoluteUri)
+            {
+                // We cannot guarantee the redaction of UserInfo for relative Uris without implementing some subset of Uri parsing in this package.
+                // To avoid this, we redact the whole Uri. Seeing a relative Uri in LoggingHttpMessageHandler or LoggingScopeHttpMessageHandler
+                // requires a custom handler chain with custom expansion logic implemented by the user's HttpMessageHandler.
+                // In such advanced scenarios we recommend users to log the Uri in their handler.
+                return "*";
+            }
+
+            string pathAndQuery = uri.PathAndQuery;
+            int queryIndex = pathAndQuery.IndexOf('?');
+
+            bool redactQuery = queryIndex >= 0 && // Query is present.
+                queryIndex < pathAndQuery.Length - 1; // Query is not empty.
+
+            return (redactQuery, uri.IsDefaultPort) switch
+            {
+                (true, true) => $"{uri.Scheme}://{uri.Host}{GetPath(pathAndQuery, queryIndex)}*",
+                (true, false) => $"{uri.Scheme}://{uri.Host}:{uri.Port}{GetPath(pathAndQuery, queryIndex)}*",
+                (false, true) => $"{uri.Scheme}://{uri.Host}{pathAndQuery}",
+                (false, false) => $"{uri.Scheme}://{uri.Host}:{uri.Port}{pathAndQuery}"
+            };
+
+#if NET
+            [MethodImpl(MethodImplOptions.AggressiveInlining)]
+            static ReadOnlySpan<char> GetPath(string pathAndQuery, int queryIndex) => pathAndQuery.AsSpan(0, queryIndex + 1);
+#else
+            [MethodImpl(MethodImplOptions.AggressiveInlining)]
+            static string GetPath(string pathAndQuery, int queryIndex) => pathAndQuery.Substring(0, queryIndex + 1);
+#endif
+        }
+    }
+}

src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingHttpMessageHandler.cs

@@ -2,6 +2,7 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 using System;
+using System.Diagnostics;
 using System.Net.Http;
 using System.Threading;
 using System.Threading.Tasks;
@@ -58,7 +59,7 @@ async Task<HttpResponseMessage> Core(HttpRequestMessage request, bool useAsync,
 
                 // Not using a scope here because we always expect this to be at the end of the pipeline, thus there's
                 // not really anything to surround.
-                Log.RequestStart(_logger, request, shouldRedactHeaderValue);
+                _logger.LogRequestStart(request, shouldRedactHeaderValue);
                 var stopwatch = ValueStopwatch.StartNew();
                 HttpResponseMessage response = useAsync
                     ? await base.SendAsync(request, cancellationToken).ConfigureAwait(false)
@@ -67,7 +68,7 @@ async Task<HttpResponseMessage> Core(HttpRequestMessage request, bool useAsync,
 #else
                     : throw new NotImplementedException("Unreachable code");
 #endif
-                Log.RequestEnd(_logger, response, stopwatch.GetElapsedTime(), shouldRedactHeaderValue);
+                _logger.LogRequestEnd(response, stopwatch.GetElapsedTime(), shouldRedactHeaderValue);
 
                 return response;
             }
@@ -84,72 +85,5 @@ protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage reques
         protected override HttpResponseMessage Send(HttpRequestMessage request, CancellationToken cancellationToken)
             => SendCoreAsync(request, useAsync: false, cancellationToken).GetAwaiter().GetResult();
 #endif
-
-        // Used in tests.
-        internal static class Log
-        {
-            public static class EventIds
-            {
-                public static readonly EventId RequestStart = new EventId(100, "RequestStart");
-                public static readonly EventId RequestEnd = new EventId(101, "RequestEnd");
-
-                public static readonly EventId RequestHeader = new EventId(102, "RequestHeader");
-                public static readonly EventId ResponseHeader = new EventId(103, "ResponseHeader");
-            }
-
-            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}",
-                _skipEnabledCheckLogDefineOptions);
-
-            private static readonly Action<ILogger, double, int, Exception?> _requestEnd = LoggerMessage.Define<double, int>(
-                LogLevel.Information,
-                EventIds.RequestEnd,
-                "Received HTTP response headers after {ElapsedMilliseconds}ms - {StatusCode}");
-
-            public static void RequestStart(ILogger logger, HttpRequestMessage request, Func<string, bool> shouldRedactHeaderValue)
-            {
-                // 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))
-                {
-                    logger.Log(
-                        LogLevel.Trace,
-                        EventIds.RequestHeader,
-                        new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Request, request.Headers, request.Content?.Headers, shouldRedactHeaderValue),
-                        null,
-                        (state, ex) => state.ToString());
-                }
-            }
-
-            public static void RequestEnd(ILogger logger, HttpResponseMessage response, TimeSpan duration, Func<string, bool> shouldRedactHeaderValue)
-            {
-                _requestEnd(logger, duration.TotalMilliseconds, (int)response.StatusCode, null);
-
-                if (logger.IsEnabled(LogLevel.Trace))
-                {
-                    logger.Log(
-                        LogLevel.Trace,
-                        EventIds.ResponseHeader,
-                        new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Response, response.Headers, response.Content?.Headers, shouldRedactHeaderValue),
-                        null,
-                        (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

@@ -58,17 +58,17 @@ async Task<HttpResponseMessage> Core(HttpRequestMessage request, bool useAsync,
 
                 Func<string, bool> shouldRedactHeaderValue = _options?.ShouldRedactHeaderValue ?? _shouldNotRedactHeaderValue;
 
-                using (Log.BeginRequestPipelineScope(_logger, request))
+                using (_logger.BeginRequestPipelineScope(request, out string? formattedUri))
                 {
-                    Log.RequestPipelineStart(_logger, request, shouldRedactHeaderValue);
+                    _logger.LogRequestPipelineStart(request, formattedUri, shouldRedactHeaderValue);
                     HttpResponseMessage response = useAsync
                         ? await base.SendAsync(request, cancellationToken).ConfigureAwait(false)
 #if NET
                         : base.Send(request, cancellationToken);
 #else
                         : throw new NotImplementedException("Unreachable code");
 #endif
-                    Log.RequestPipelineEnd(_logger, response, stopwatch.GetElapsedTime(), shouldRedactHeaderValue);
+                    _logger.LogRequestPipelineEnd(response, stopwatch.GetElapsedTime(), shouldRedactHeaderValue);
 
                     return response;
                 }
@@ -86,72 +86,5 @@ protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage reques
         protected override HttpResponseMessage Send(HttpRequestMessage request, CancellationToken cancellationToken)
             => SendCoreAsync(request, useAsync: false, cancellationToken).GetAwaiter().GetResult();
 #endif
-
-        // Used in tests
-        internal static class Log
-        {
-            public static class EventIds
-            {
-                public static readonly EventId PipelineStart = new EventId(100, "RequestPipelineStart");
-                public static readonly EventId PipelineEnd = new EventId(101, "RequestPipelineEnd");
-
-                public static readonly EventId RequestHeader = new EventId(102, "RequestPipelineRequestHeader");
-                public static readonly EventId ResponseHeader = new EventId(103, "RequestPipelineResponseHeader");
-            }
-
-            private static readonly Func<ILogger, HttpMethod, string?, IDisposable?> _beginRequestPipelineScope = LoggerMessage.DefineScope<HttpMethod, string?>("HTTP {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}");
-
-            private static readonly Action<ILogger, double, int, Exception?> _requestPipelineEnd = LoggerMessage.Define<double, int>(
-                LogLevel.Information,
-                EventIds.PipelineEnd,
-                "End processing HTTP request after {ElapsedMilliseconds}ms - {StatusCode}");
-
-            public static IDisposable? BeginRequestPipelineScope(ILogger logger, HttpRequestMessage request)
-            {
-                return _beginRequestPipelineScope(logger, request.Method, GetUriString(request.RequestUri));
-            }
-
-            public static void RequestPipelineStart(ILogger logger, HttpRequestMessage request, Func<string, bool> shouldRedactHeaderValue)
-            {
-                _requestPipelineStart(logger, request.Method, GetUriString(request.RequestUri), null);
-
-                if (logger.IsEnabled(LogLevel.Trace))
-                {
-                    logger.Log(
-                        LogLevel.Trace,
-                        EventIds.RequestHeader,
-                        new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Request, request.Headers, request.Content?.Headers, shouldRedactHeaderValue),
-                        null,
-                        (state, ex) => state.ToString());
-                }
-            }
-
-            public static void RequestPipelineEnd(ILogger logger, HttpResponseMessage response, TimeSpan duration, Func<string, bool> shouldRedactHeaderValue)
-            {
-                _requestPipelineEnd(logger, duration.TotalMilliseconds, (int)response.StatusCode, null);
-
-                if (logger.IsEnabled(LogLevel.Trace))
-                {
-                    logger.Log(
-                        LogLevel.Trace,
-                        EventIds.ResponseHeader,
-                        new HttpHeadersLogValue(HttpHeadersLogValue.Kind.Response, response.Headers, response.Content?.Headers, shouldRedactHeaderValue),
-                        null,
-                        (state, ex) => state.ToString());
-                }
-            }
-
-            private static string? GetUriString(Uri? requestUri)
-            {
-                return requestUri?.IsAbsoluteUri == true
-                    ? requestUri.AbsoluteUri
-                    : requestUri?.ToString();
-            }
-        }
     }
 }