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 5 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
25 changes: 21 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,25 @@ 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;
}

if (uri.IsAbsoluteUri)
{
return s_logQueryString
? uri.AbsoluteUri
: uri.GetComponents(UriComponents.AbsoluteUri & ~UriComponents.Query, UriFormat.UriEscaped);
}

string uriString = uri.ToString();
int queryOffset = s_logQueryString ? -1 : uriString.IndexOf('?');
return queryOffset < 0
? uriString
: uriString.Substring(0, queryOffset);
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();
}
}
}
}
253 changes: 124 additions & 129 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,151 @@ namespace Microsoft.Extensions.Http.Tests.Logging
{
public class LoggingUriOutputTests
{
[Fact]
public async Task LoggingHttpMessageHandler_LogsAbsoluteUri()
public static TheoryData<bool, bool, bool, bool> Handlers_LogAbsoluteUri_Data()
{
// 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 =>
TheoryData<bool, bool, bool, bool> result = new();
bool[] booleans = { true, false };
bool[] syncApiVals =
#if NET
booleans;
#else
{ false };
#endif
foreach (bool syncApi in syncApiVals)
{
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);
foreach (bool logQueryString in booleans)
{
foreach (bool absoluteUri in booleans)
{
foreach (bool scopeHandler in booleans)
{
result.Add(syncApi, logQueryString, absoluteUri, scopeHandler);
}
}
}
}
return result;
}

[Fact]
public async Task LoggingScopeHttpMessageHandler_LogsAbsoluteUri()
[ConditionalTheory(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))]
[MemberData(nameof(Handlers_LogAbsoluteUri_Data))]
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved
public async Task Handlers_LogExpectedUri(bool syncApi, bool logQueryString, bool absoluteUri, bool scopeHandler)
{
// 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");
await RemoteExecutor.Invoke(static async (syncApiStr, logQueryStringStr, absoluteUriStr, scopeHandlerStr) =>
{
bool syncApi = bool.Parse(syncApiStr);
bool logQueryString = bool.Parse(logQueryStringStr);
bool absoluteUri = bool.Parse(absoluteUriStr);
bool scopeHandler = bool.Parse(scopeHandlerStr);

string baseUri = absoluteUri ? "http://api.example.com/search" : "/search";
const string queryString = "term=Western%20Australia";
string destinationUri = $"{baseUri}?{queryString}";

// Act
var request = new HttpRequestMessage(HttpMethod.Get, "http://api.example.com/search?term=Western%20Australia");
if (logQueryString)
{
AppContext.SetSwitch("Microsoft.Extensions.Http.LogQueryString", true);
}

await client.SendAsync(request);
var sink = new TestSink();
var logger = new TestLogger("test", sink, enabled: true);

// Assert
var messages = sink.Writes.ToArray();
DelegatingHandler handler = scopeHandler ? new LoggingScopeHttpMessageHandler(logger) : new LoggingHttpMessageHandler(logger);
handler.InnerHandler = new TestMessageHandler();

var message = Assert.Single(messages.Where(m =>
{
return
m.EventId == LoggingScopeHttpMessageHandler.Log.EventIds.PipelineStart &&
m.LoggerName == "System.Net.Http.HttpClient.test.LogicalHandler";
}));
using HttpMessageInvoker invoker = new HttpMessageInvoker(handler);
using var request = new HttpRequestMessage(HttpMethod.Get, destinationUri);

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());
#if NET
if (syncApi)
{
_ = invoker.Send(request, default);
await Task.Yield();
}
else
#endif
{
_ = await invoker.SendAsync(request, default);
}

string expectedUri = logQueryString ? destinationUri : baseUri;

if (scopeHandler)
{
var pipelineStartMessage = Assert.Single(sink.Writes.Where(m => m.EventId == LoggingScopeHttpMessageHandler.Log.EventIds.PipelineStart));
Assert.Equal($"HTTP GET {expectedUri}", pipelineStartMessage.Scope.ToString());
Assert.Equal($"Start processing HTTP request GET {expectedUri}", pipelineStartMessage.Message);
}
else
{
var requestStartMessage = Assert.Single(sink.Writes.Where(m => m.EventId == LoggingHttpMessageHandler.Log.EventIds.RequestStart));
Assert.Equal($"Sending HTTP request GET {expectedUri}", requestStartMessage.Message);
}
}, syncApi.ToString(), logQueryString.ToString(), absoluteUri.ToString(), scopeHandler.ToString()).DisposeAsync();
}

[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()
[InlineData(true, false)]
[InlineData(true, true)]
#endif
public async Task Integration_LogsExpectedAbsoluteUri(bool syncApi, bool logQueryString)
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved
{
// Arrange
var sink = new TestSink();
const string baseUri = "http://api.example.com/search";
const string queryString = "term=Western%20Australia";
const string destinationUri = $"{baseUri}?{queryString}";

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 =>
await RemoteExecutor.Invoke(static async (syncApiStr, logQueryStringStr) =>
{
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()
{
// 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");
bool syncApi = bool.Parse(syncApiStr);
bool logQueryString = bool.Parse(logQueryStringStr);

if (logQueryString)
{
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, destinationUri);
#if NET
if (syncApi)
{
_ = client.Send(request);
await Task.Yield();
}
else
#endif
{
_ = await client.SendAsync(request);
}

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

// Act
var request = new HttpRequestMessage(HttpMethod.Get, "http://api.example.com/search?term=Western%20Australia");
var requestStartMessage = Assert.Single(sink.Writes.Where(m =>
m.EventId == LoggingHttpMessageHandler.Log.EventIds.RequestStart &&
m.LoggerName == "System.Net.Http.HttpClient.test.ClientHandler"));

client.Send(request);
string expectedUri = logQueryString ? destinationUri : baseUri;

// Assert
var messages = sink.Writes.ToArray();
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);

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());
}, syncApi.ToString(), logQueryString.ToString()).DisposeAsync();
}
#endif
}
}
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