Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[HttpClientFactory] Do not log query string by default #103769

Merged
merged 21 commits into from
Jul 4, 2024
Merged

[HttpClientFactory] Do not log query string by default #103769

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
21 commits
Select commit Hold shift + click to select a range
d3b0e77
Do not log query strings in HttpClientFactory
antonfirsov Jun 20, 2024
af01fc6
shuffle tests
antonfirsov Jun 20, 2024
e3fb184
Update GetUriString
antonfirsov Jun 20, 2024
ea4b8ad
add tests for relative Uri logging
antonfirsov Jun 20, 2024
7a7bf09
remove unnecessary using
antonfirsov Jun 20, 2024
098279a
move log message implementation into LogHelper, introduce an environm…
antonfirsov Jun 21, 2024
9ebabcc
redact query string with '*'
antonfirsov Jun 21, 2024
0d49a23
suggestion
antonfirsov Jun 24, 2024
f6c3095
rename switch
antonfirsov Jun 24, 2024
8361df7
suggestions
antonfirsov Jun 28, 2024
4d7a777
Merge branch 'main' into querystring-01
antonfirsov Jun 28, 2024
236fc8d
Merge branch 'querystring-01' of https://github.com/antonfirsov/runti…
antonfirsov Jun 28, 2024
b9daee4
adjustments
antonfirsov Jun 28, 2024
a894f8b
handle fragment
antonfirsov Jun 28, 2024
fed974b
remove userinfo from absolute Uri-s
antonfirsov Jun 28, 2024
ca88ab0
Redact relative Uri unconditionally
antonfirsov Jul 1, 2024
e711ec9
Merge branch 'main' into querystring-01
antonfirsov Jul 2, 2024
e557330
Harmonize redaction:
antonfirsov Jul 2, 2024
902f459
AggressiveInlining
antonfirsov Jul 2, 2024
74b1d04
save 1 allocation in LoggingScopeHttpMessageHandler
antonfirsov Jul 3, 2024
956de73
Update src/libraries/Microsoft.Extensions.Http/src/Logging/LogHelper.cs
antonfirsov Jul 3, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 11 additions & 4 deletions src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingHttpMessageHandler.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -88,6 +89,8 @@ protected override HttpResponseMessage Send(HttpRequestMessage request, Cancella
// Used in tests.
internal static class Log
{
private static readonly bool s_logQueryString = AppContext.TryGetSwitch("Microsoft.Extensions.Http.LogQueryString", out bool value) && value;
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved

public static class EventIds
{
public static readonly EventId RequestStart = new EventId(100, "RequestStart");
Expand Down Expand Up @@ -144,11 +147,15 @@ public static void RequestEnd(ILogger logger, HttpResponseMessage response, Time
}
}

private static string? GetUriString(Uri? requestUri)
internal static string? GetUriString(Uri? uri)
{
return requestUri?.IsAbsoluteUri == true
? requestUri.AbsoluteUri
: requestUri?.ToString();
if (uri is null)
{
return null;
}

Debug.Assert(uri.IsAbsoluteUri, "HttpClient should not forward relative Uri to its handlers.");
return s_logQueryString ? uri.AbsoluteUri : $"{uri.Scheme}://{uri.Host}{uri.AbsolutePath}";
MihaZupan marked this conversation as resolved.
Show resolved Hide resolved
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved
}
}
}
Expand Down
11 changes: 2 additions & 9 deletions src/libraries/Microsoft.Extensions.Http/src/Logging/LoggingScopeHttpMessageHandler.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -113,12 +113,12 @@ public static class EventIds

public static IDisposable? BeginRequestPipelineScope(ILogger logger, HttpRequestMessage request)
{
return _beginRequestPipelineScope(logger, request.Method, GetUriString(request.RequestUri));
return _beginRequestPipelineScope(logger, request.Method, LoggingHttpMessageHandler.Log.GetUriString(request.RequestUri));
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved
}

public static void RequestPipelineStart(ILogger logger, HttpRequestMessage request, Func<string, bool> shouldRedactHeaderValue)
{
_requestPipelineStart(logger, request.Method, GetUriString(request.RequestUri), null);
_requestPipelineStart(logger, request.Method, LoggingHttpMessageHandler.Log.GetUriString(request.RequestUri), null);

if (logger.IsEnabled(LogLevel.Trace))
{
Expand All @@ -145,13 +145,6 @@ 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();
}
}
}
}
1 change: 1 addition & 0 deletions ...oft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/Logging/HttpClientLoggerTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
using System.Net.Http;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.DotNet.RemoteExecutor;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Testing;
Expand Down
212 changes: 65 additions & 147 deletions ...ft.Extensions.Http/tests/Microsoft.Extensions.Http.Tests/Logging/LoggingUriOutputTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,8 +4,8 @@
using System;
using System.Linq;
using System.Net.Http;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.DotNet.RemoteExecutor;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Http.Logging;
using Microsoft.Extensions.Logging;
Expand All @@ -16,156 +16,74 @@ 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());
}

[ConditionalTheory(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))]
[InlineData(false, false)]
[InlineData(false, true)]
#if NET
[ConditionalFact(typeof(PlatformDetection), nameof(PlatformDetection.IsNetCore))]
public void LoggingHttpMessageHandler_LogsAbsoluteUri_Sync()
{
// 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");

client.Send(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);
}

[ConditionalFact(typeof(PlatformDetection), nameof(PlatformDetection.IsNetCore))]
public void LoggingScopeHttpMessageHandler_LogsAbsoluteUri_Sync()
[InlineData(true, false)]
[InlineData(true, true)]
#endif
public async Task LogsAbsoluteUrl(bool syncApi, bool logQueryString)
{
// 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");
const string BaseUri = "http://api.example.com/search";
const string QueryString = "term=Western%20Australia";
const string FullUri = $"{BaseUri}?{QueryString}";

client.Send(request);

// Assert
var messages = sink.Writes.ToArray();

var message = Assert.Single(messages.Where(m =>
await RemoteExecutor.Invoke(static async (syncApiStr, enableQueryStringLoggingStr) =>
{
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());
}
bool syncApi = bool.Parse(syncApiStr);
bool enableQueryStringLogging = bool.Parse(enableQueryStringLoggingStr);

if (enableQueryStringLogging)
{
AppContext.SetSwitch("Microsoft.Extensions.Http.LogQueryString", true);
}

var sink = new TestSink();
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging();
serviceCollection.AddSingleton<ILoggerFactory>(new TestLoggerFactory(sink, enabled: true));
serviceCollection.AddTransient<TestMessageHandler>();
serviceCollection.AddHttpClient("test").ConfigurePrimaryHttpMessageHandler<TestMessageHandler>();

var services = serviceCollection.BuildServiceProvider();
var factory = services.GetRequiredService<IHttpClientFactory>();
var client = factory.CreateClient("test");

using var request = new HttpRequestMessage(HttpMethod.Get, FullUri);
#if NET
if (syncApi)
{
client.Send(request);
await Task.Yield();
}
else
#endif
{
_ = await client.SendAsync(request);
}

var pipelineStartMessage = Assert.Single(sink.Writes.Where(m =>
{
return
m.EventId == LoggingScopeHttpMessageHandler.Log.EventIds.PipelineStart &&
m.LoggerName == "System.Net.Http.HttpClient.test.LogicalHandler";
}));

var requestStartMessage = Assert.Single(sink.Writes.Where(m =>
{
return
m.EventId == LoggingHttpMessageHandler.Log.EventIds.RequestStart &&
m.LoggerName == "System.Net.Http.HttpClient.test.ClientHandler";
}));

string expectedUri = enableQueryStringLogging ? FullUri : BaseUri;

Assert.Equal($"HTTP GET {expectedUri}", pipelineStartMessage.Scope.ToString());
Assert.Equal($"Start processing HTTP request GET {expectedUri}", pipelineStartMessage.Message);
Assert.Equal($"Sending HTTP request GET {expectedUri}", requestStartMessage.Message);

}, syncApi.ToString(), logQueryString.ToString()).DisposeAsync();
}
}
}
3 changes: 3 additions & 0 deletions ...ensions.Http/tests/Microsoft.Extensions.Http.Tests/Microsoft.Extensions.Http.Tests.csproj
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
<PropertyGroup>
<TargetFrameworks>$(NetCoreAppCurrent);$(NetFrameworkMinimum)</TargetFrameworks>
<EnableDefaultItems>true</EnableDefaultItems>
<IncludeRemoteExecutor>true</IncludeRemoteExecutor>
</PropertyGroup>

<ItemGroup>
Expand All @@ -20,6 +21,8 @@
Link="tests\DI.Common\Common\src\TestLoggerFactory.cs" />
<Compile Include="$(CommonPath)..\tests\Extensions\SingleThreadedSynchronizationContext.cs"
Link="Shared\SingleThreadedSynchronizationContext.cs" />
<Compile Include="$(CommonTestPath)System\Net\RemoteExecutorExtensions.cs"
Link="tests\System\Net\RemoteExecutorExtensions.cs" />
</ItemGroup>

<ItemGroup>
Expand Down
Loading