diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/ErasingRedactorProvider.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/ErasingRedactorProvider.cs new file mode 100644 index 00000000000..33045d4cda6 --- /dev/null +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/ErasingRedactorProvider.cs @@ -0,0 +1,14 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using Microsoft.Extensions.Compliance.Classification; +using Microsoft.Extensions.Compliance.Redaction; + +namespace Microsoft.Extensions.Http.Diagnostics.Bench.Benchmarks; + +internal sealed class ErasingRedactorProvider : IRedactorProvider +{ + public static ErasingRedactorProvider Instance { get; } = new(); + + public Redactor GetRedactor(DataClassificationSet classifications) => ErasingRedactor.Instance; +} diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/HeadersReaderBenchmark.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/HeadersReaderBenchmark.cs new file mode 100644 index 00000000000..f13ec8500ce --- /dev/null +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/HeadersReaderBenchmark.cs @@ -0,0 +1,107 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; +using System.Net.Http; +using BenchmarkDotNet.Attributes; +using Microsoft.Extensions.Compliance.Testing; +using Microsoft.Extensions.Http.Logging; +using Microsoft.Extensions.Http.Logging.Internal; +using Microsoft.Extensions.Telemetry.Internal; + +namespace Microsoft.Extensions.Http.Diagnostics.Bench.Benchmarks; + +public class HeadersReaderBenchmark +{ + private List> _outputBuffer = null!; + private HttpHeadersReader _headersReader = null!; + + [Params(0, 5, 15)] + public int HeadersCount { get; set; } + + // This one can't be 0, because in that case HttpRequestReader simply doesn't call HttpHeadersReader + [Params(1, 3, 5, 10)] + public int HeadersToLogCount { get; set; } + + [Params(false, true)] + public bool LogContentHeaders { get; set; } + + public HttpRequestMessage? Request { get; set; } + + [GlobalSetup] + public void Setup() + { + _outputBuffer = new(capacity: 10240); + Request = new HttpRequestMessage(HttpMethod.Post, "https://www.microsoft.com"); + for (var i = 0; i < HeadersCount; i++) + { + Request.Headers.Add($"Header{i}", $"Value{i}"); + } + + var options = new LoggingOptions { LogContentHeaders = LogContentHeaders }; + for (var i = 0; i < HeadersToLogCount; i++) + { + options.RequestHeadersDataClasses.Add($"Header{i}", FakeTaxonomy.PublicData); + } + + var redactor = new HttpHeadersRedactor(ErasingRedactorProvider.Instance); + _headersReader = new HttpHeadersReader(new StaticOptionsMonitor(options), redactor); + } + + [GlobalCleanup] + public void Cleanup() + { + Request?.Dispose(); + _outputBuffer.Clear(); + _outputBuffer = null!; + } + + [Benchmark] + public void HeadersReader() + { + _headersReader.ReadRequestHeaders(Request!, _outputBuffer); + } +} + +/* + + These results show comparison between a plain logic (when we enumerate over "headersToLog" dictionary), + and an updated logic when we choose the strategy based on the number of headers to read and the number of headers to log. + +BenchmarkDotNet=v0.13.5, OS=Windows 11 (10.0.22631.2861), VM=Hyper-V +Intel Xeon Platinum 8370C CPU 2.80GHz, 1 CPU, 16 logical and 8 physical cores +.NET SDK=8.0.100 + [Host] : .NET 8.0.0 (8.0.23.53103), X64 RyuJIT AVX2 + +Job=MediumRun Jit=RyuJit Platform=X64 +Runtime=.NET 8.0 Server=True Toolchain=InProcessEmitToolchain +IterationCount=15 LaunchCount=2 WarmupCount=10 + +| Method | HeadersCount | HeadersToLogCount | Mean | Error | StdDev | Gen0 | Allocated | +|----------------- |------------- |------------------ |-------------:|-----------:|-----------:|-------:|----------:| +| HeadersReaderNew | 0 | 1 | 4.372 ns | 0.0120 ns | 0.0175 ns | - | - | +| HeadersReaderNew | 0 | 5 | 4.459 ns | 0.0639 ns | 0.0916 ns | - | - | +| HeadersReaderNew | 0 | 3 | 4.648 ns | 0.2073 ns | 0.2972 ns | - | - | +| HeadersReaderNew | 0 | 10 | 4.995 ns | 0.4255 ns | 0.6369 ns | - | - | +| HeadersReaderOld | 0 | 1 | 18.607 ns | 0.0492 ns | 0.0689 ns | - | - | +| HeadersReaderOld | 0 | 3 | 41.269 ns | 0.0759 ns | 0.1088 ns | - | - | +| HeadersReaderOld | 0 | 5 | 63.525 ns | 0.1879 ns | 0.2572 ns | - | - | +| HeadersReaderOld | 0 | 10 | 119.163 ns | 0.6748 ns | 0.9678 ns | - | - | +| HeadersReaderOld | 15 | 1 | 204.099 ns | 1.3834 ns | 1.8936 ns | 0.0100 | 256 B | +| HeadersReaderOld | 5 | 1 | 205.044 ns | 1.7938 ns | 2.4553 ns | 0.0095 | 256 B | +| HeadersReaderNew | 15 | 1 | 216.454 ns | 1.1861 ns | 1.6236 ns | 0.0100 | 256 B | +| HeadersReaderNew | 5 | 1 | 217.499 ns | 1.5149 ns | 2.0736 ns | 0.0100 | 256 B | +| HeadersReaderOld | 5 | 3 | 630.982 ns | 4.4363 ns | 5.9224 ns | 0.0305 | 768 B | +| HeadersReaderOld | 15 | 3 | 641.780 ns | 4.4820 ns | 6.1351 ns | 0.0305 | 768 B | +| HeadersReaderNew | 15 | 3 | 669.542 ns | 3.6006 ns | 4.9285 ns | 0.0305 | 768 B | +| HeadersReaderNew | 5 | 3 | 677.061 ns | 3.8858 ns | 5.3190 ns | 0.0305 | 768 B | +| HeadersReaderNew | 5 | 10 | 981.974 ns | 9.8502 ns | 13.4831 ns | 0.0515 | 1336 B | +| HeadersReaderOld | 5 | 5 | 1,126.471 ns | 7.1361 ns | 9.7680 ns | 0.0496 | 1280 B | +| HeadersReaderOld | 15 | 5 | 1,134.430 ns | 6.2873 ns | 8.3934 ns | 0.0496 | 1280 B | +| HeadersReaderNew | 15 | 5 | 1,153.805 ns | 3.0554 ns | 4.1823 ns | 0.0496 | 1280 B | +| HeadersReaderNew | 5 | 5 | 1,164.717 ns | 9.8121 ns | 13.4310 ns | 0.0496 | 1280 B | +| HeadersReaderOld | 5 | 10 | 1,413.431 ns | 7.9666 ns | 10.9048 ns | 0.0496 | 1280 B | +| HeadersReaderOld | 15 | 10 | 2,489.613 ns | 19.0100 ns | 26.0211 ns | 0.0992 | 2560 B | +| HeadersReaderNew | 15 | 10 | 2,507.523 ns | 10.2106 ns | 13.9763 ns | 0.0992 | 2560 B | + + */ diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/HugeHttpCLientLoggingBenchmark.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/HugeHttpCLientLoggingBenchmark.cs index b889a4e6e3b..edc19460f4b 100644 --- a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/HugeHttpCLientLoggingBenchmark.cs +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/HugeHttpCLientLoggingBenchmark.cs @@ -16,28 +16,28 @@ public class HugeHttpClientLoggingBenchmark private const int ReadSizeLimit = 53248; private static HttpRequestMessage Request => new(HttpMethod.Post, "https://www.microsoft.com"); - private static readonly System.Net.Http.HttpClient _hugeNoLog + private static readonly HttpClient _hugeNoLog = HttpClientFactory.CreateWithoutLogging(DataFileName); - private static readonly System.Net.Http.HttpClient _hugeLogAll + private static readonly HttpClient _hugeLogAll = HttpClientFactory.CreateWithLoggingLogAll(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _hugeLogRequest + private static readonly HttpClient _hugeLogRequest = HttpClientFactory.CreateWithLoggingLogRequest(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _hugeLogResponse + private static readonly HttpClient _hugeLogResponse = HttpClientFactory.CreateWithLoggingLogResponse(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _hugeNoLogChunked + private static readonly HttpClient _hugeNoLogChunked = HttpClientFactory.CreateWithoutLogging_ChunkedEncoding(DataFileName); - private static readonly System.Net.Http.HttpClient _hugeLogAllChunked + private static readonly HttpClient _hugeLogAllChunked = HttpClientFactory.CreateWithLoggingLogAll_ChunkedEncoding(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _hugeLogRequestChunked + private static readonly HttpClient _hugeLogRequestChunked = HttpClientFactory.CreateWithLoggingLogRequest_ChunkedEncoding(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _hugeLogResponseChunked + private static readonly HttpClient _hugeLogResponseChunked = HttpClientFactory.CreateWithLoggingLogResponse_ChunkedEncoding(DataFileName, ReadSizeLimit); [Benchmark(Baseline = true)] diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/MediumHttpClientLoggingBenchmark.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/MediumHttpClientLoggingBenchmark.cs index cd9b1604bf7..fea8ec17e53 100644 --- a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/MediumHttpClientLoggingBenchmark.cs +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/MediumHttpClientLoggingBenchmark.cs @@ -16,28 +16,28 @@ public class MediumHttpClientLoggingBenchmark private const int ReadSizeLimit = 16384; private static HttpRequestMessage Request => new(HttpMethod.Post, "https://www.microsoft.com"); - private static readonly System.Net.Http.HttpClient _mediumNoLog + private static readonly HttpClient _mediumNoLog = HttpClientFactory.CreateWithoutLogging(DataFileName); - private static readonly System.Net.Http.HttpClient _mediumLogAll + private static readonly HttpClient _mediumLogAll = HttpClientFactory.CreateWithLoggingLogAll(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _mediumLogRequest + private static readonly HttpClient _mediumLogRequest = HttpClientFactory.CreateWithLoggingLogRequest(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _mediumLogResponse + private static readonly HttpClient _mediumLogResponse = HttpClientFactory.CreateWithLoggingLogResponse(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _mediumNoLogChunked + private static readonly HttpClient _mediumNoLogChunked = HttpClientFactory.CreateWithoutLogging_ChunkedEncoding(DataFileName); - private static readonly System.Net.Http.HttpClient _mediumLogAllChunked + private static readonly HttpClient _mediumLogAllChunked = HttpClientFactory.CreateWithLoggingLogAll_ChunkedEncoding(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _mediumLogRequestChunked + private static readonly HttpClient _mediumLogRequestChunked = HttpClientFactory.CreateWithLoggingLogRequest_ChunkedEncoding(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _mediumLogResponseChunked + private static readonly HttpClient _mediumLogResponseChunked = HttpClientFactory.CreateWithLoggingLogResponse_ChunkedEncoding(DataFileName, ReadSizeLimit); [Benchmark(Baseline = true)] diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/SmallHttpClientLoggingBenchmark.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/SmallHttpClientLoggingBenchmark.cs index e21d0852e60..1689ceada92 100644 --- a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/SmallHttpClientLoggingBenchmark.cs +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Benchmarks/SmallHttpClientLoggingBenchmark.cs @@ -16,28 +16,28 @@ public class SmallHttpClientLoggingBenchmark private const int ReadSizeLimit = 8192; private static HttpRequestMessage Request => new(HttpMethod.Post, "https://www.microsoft.com"); - private static readonly System.Net.Http.HttpClient _smallNoLog + private static readonly HttpClient _smallNoLog = HttpClientFactory.CreateWithoutLogging(DataFileName); - private static readonly System.Net.Http.HttpClient _smallLogAll + private static readonly HttpClient _smallLogAll = HttpClientFactory.CreateWithLoggingLogAll(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _smallLogRequest + private static readonly HttpClient _smallLogRequest = HttpClientFactory.CreateWithLoggingLogRequest(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _smallLogResponse + private static readonly HttpClient _smallLogResponse = HttpClientFactory.CreateWithLoggingLogResponse(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _smallNoLogChunked + private static readonly HttpClient _smallNoLogChunked = HttpClientFactory.CreateWithoutLogging_ChunkedEncoding(DataFileName); - private static readonly System.Net.Http.HttpClient _smallLogAllChunked + private static readonly HttpClient _smallLogAllChunked = HttpClientFactory.CreateWithLoggingLogAll_ChunkedEncoding(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _smallLogRequestChunked + private static readonly HttpClient _smallLogRequestChunked = HttpClientFactory.CreateWithLoggingLogRequest_ChunkedEncoding(DataFileName, ReadSizeLimit); - private static readonly System.Net.Http.HttpClient _smallLogResponseChunked + private static readonly HttpClient _smallLogResponseChunked = HttpClientFactory.CreateWithLoggingLogResponse_ChunkedEncoding(DataFileName, ReadSizeLimit); [Benchmark(Baseline = true)] diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/HttpClientFactory.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/HttpClientFactory.cs index 8cef086ae76..4aac36f8ccd 100644 --- a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/HttpClientFactory.cs +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/HttpClientFactory.cs @@ -11,7 +11,7 @@ namespace Microsoft.Extensions.Http.Logging.Bench; internal static class HttpClientFactory { - public static System.Net.Http.HttpClient CreateWithLoggingLogRequest(string fileName, int readLimit) + public static HttpClient CreateWithLoggingLogRequest(string fileName, int readLimit) { var services = new ServiceCollection(); @@ -25,7 +25,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogRequest(string file .AddExtendedHttpClientLogging(options => { options.BodySizeLimit = readLimit; - options.RequestBodyContentTypes.Add(new("application/json")); + options.RequestBodyContentTypes.Add("application/json"); options.RequestHeadersDataClasses.Add("Content-Type", FakeTaxonomy.PrivateData); }) .AddHttpMessageHandler() @@ -35,7 +35,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogRequest(string file .CreateClient(nameof(fileName)); } - public static System.Net.Http.HttpClient CreateWithLoggingLogResponse(string fileName, int readLimit) + public static HttpClient CreateWithLoggingLogResponse(string fileName, int readLimit) { var services = new ServiceCollection(); @@ -48,7 +48,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogResponse(string fil .AddExtendedHttpClientLogging(options => { options.BodySizeLimit = readLimit; - options.ResponseBodyContentTypes.Add(new("application/json")); + options.ResponseBodyContentTypes.Add("application/json"); options.ResponseHeadersDataClasses.Add("Content-Type", FakeTaxonomy.PrivateData); }) .AddHttpMessageHandler() @@ -58,7 +58,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogResponse(string fil .CreateClient(nameof(fileName)); } - public static System.Net.Http.HttpClient CreateWithLoggingLogAll(string fileName, int readLimit) + public static HttpClient CreateWithLoggingLogAll(string fileName, int readLimit) { var services = new ServiceCollection(); @@ -72,10 +72,10 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogAll(string fileName { options.BodySizeLimit = readLimit; - options.RequestBodyContentTypes.Add(new("application/json")); + options.RequestBodyContentTypes.Add("application/json"); options.RequestHeadersDataClasses.Add("Content-Type", FakeTaxonomy.PrivateData); - options.ResponseBodyContentTypes.Add(new("application/json")); + options.ResponseBodyContentTypes.Add("application/json"); options.ResponseHeadersDataClasses.Add("Content-Type", FakeTaxonomy.PrivateData); }) .AddHttpMessageHandler() @@ -85,7 +85,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogAll(string fileName .CreateClient(nameof(fileName)); } - public static System.Net.Http.HttpClient CreateWithLoggingLogRequest_ChunkedEncoding(string fileName, int readLimit) + public static HttpClient CreateWithLoggingLogRequest_ChunkedEncoding(string fileName, int readLimit) { var services = new ServiceCollection(); @@ -108,7 +108,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogRequest_ChunkedEnco .CreateClient(nameof(fileName)); } - public static System.Net.Http.HttpClient CreateWithLoggingLogResponse_ChunkedEncoding(string fileName, int readLimit) + public static HttpClient CreateWithLoggingLogResponse_ChunkedEncoding(string fileName, int readLimit) { var services = new ServiceCollection(); @@ -131,7 +131,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogResponse_ChunkedEnc .CreateClient(nameof(fileName)); } - public static System.Net.Http.HttpClient CreateWithLoggingLogAll_ChunkedEncoding(string fileName, int readLimit) + public static HttpClient CreateWithLoggingLogAll_ChunkedEncoding(string fileName, int readLimit) { var services = new ServiceCollection(); @@ -158,7 +158,7 @@ public static System.Net.Http.HttpClient CreateWithLoggingLogAll_ChunkedEncoding .CreateClient(nameof(fileName)); } - public static System.Net.Http.HttpClient CreateWithoutLogging(string fileName) + public static HttpClient CreateWithoutLogging(string fileName) => new ServiceCollection() .AddSingleton(_ => NoRemoteCallHandler.Create(fileName)) .AddHttpClient(nameof(fileName)) @@ -168,7 +168,7 @@ public static System.Net.Http.HttpClient CreateWithoutLogging(string fileName) .GetRequiredService() .CreateClient(nameof(fileName)); - public static System.Net.Http.HttpClient CreateWithoutLogging_ChunkedEncoding(string fileName) + public static HttpClient CreateWithoutLogging_ChunkedEncoding(string fileName) => new ServiceCollection() .AddSingleton(_ => NoRemoteCallNotSeekableHandler.Create(fileName)) .AddHttpClient(nameof(fileName)) diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Microsoft.Extensions.Http.Diagnostics.PerformanceTests.csproj b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Microsoft.Extensions.Http.Diagnostics.PerformanceTests.csproj index 5348f6a365a..4c5e8386e9c 100644 --- a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Microsoft.Extensions.Http.Diagnostics.PerformanceTests.csproj +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Microsoft.Extensions.Http.Diagnostics.PerformanceTests.csproj @@ -1,4 +1,4 @@ - + Microsoft.Extensions.Http.Diagnostics.Bench Benchmarks for Microsoft.Extensions.Http.Diagnostics. @@ -12,6 +12,7 @@ + \ No newline at end of file diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/NoRemoteCallHandler.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/NoRemoteCallHandler.cs index 997b1b783da..78d12b285d5 100644 --- a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/NoRemoteCallHandler.cs +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/NoRemoteCallHandler.cs @@ -2,7 +2,6 @@ // The .NET Foundation licenses this file to you under the MIT license. using System; -using System.Diagnostics.CodeAnalysis; using System.IO; using System.Net.Http; using System.Threading; @@ -19,8 +18,6 @@ private NoRemoteCallHandler(byte[] data) _data = data; } - [SuppressMessage("Performance Analysis", "CPR120:File.ReadAllXXX should be replaced by using a StreamReader to avoid adding objects to the large object heap (LOH).", - Justification = "We can live with it here")] public static NoRemoteCallHandler Create(string fileName) { var assemblyFileLocation = Path.GetDirectoryName(typeof(NoRemoteCallHandler).Assembly.Location)!; @@ -41,7 +38,7 @@ protected override Task SendAsync(HttpRequestMessage reques { StatusCode = System.Net.HttpStatusCode.OK, RequestMessage = request, - Content = new StreamContent(new MemoryStream(_data)) + Content = new StreamContent(new MemoryStream(_data, writable: false)) }; response.Content.Headers.ContentType = new("application/json"); diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Program.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Program.cs index 9566c263011..72c9a47de43 100644 --- a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Program.cs +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/Program.cs @@ -18,7 +18,7 @@ private static void Main(string[] args) var dontRequireSlnToRunBenchmarks = ManualConfig .Create(DefaultConfig.Instance) .AddJob(Job.MediumRun - .WithRuntime(CoreRuntime.Core50) + .WithRuntime(CoreRuntime.Core80) .WithGcServer(true) .WithJit(Jit.RyuJit) .WithPlatform(Platform.X64) diff --git a/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/StaticOptionsMonitor.cs b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/StaticOptionsMonitor.cs new file mode 100644 index 00000000000..615fc33cb6c --- /dev/null +++ b/bench/Libraries/Microsoft.Extensions.Http.Diagnostics.PerformanceTests/StaticOptionsMonitor.cs @@ -0,0 +1,23 @@ +// 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 Microsoft.Extensions.Options; + +namespace Microsoft.Extensions.Http.Diagnostics.Bench; + +internal sealed class StaticOptionsMonitor : IOptionsMonitor +{ + public StaticOptionsMonitor(T options) + { + CurrentValue = options; + } + + public T CurrentValue { get; } + + public T Get(string? name) + => CurrentValue; + + public IDisposable OnChange(Action listener) + => throw new NotSupportedException(); +} diff --git a/eng/pipelines/templates/VerifyCoverageReport.yml b/eng/pipelines/templates/VerifyCoverageReport.yml index 5c55d4d42de..d956eac76d1 100644 --- a/eng/pipelines/templates/VerifyCoverageReport.yml +++ b/eng/pipelines/templates/VerifyCoverageReport.yml @@ -39,3 +39,4 @@ steps: repositoryName: '$(Build.Repository.Name)' id: $(System.PullRequest.PullRequestNumber) displayName: Report coverage to GitHub + continueOnError: 'true' # Temporary setting to avoid failing the build if the GitHub comment fails diff --git a/src/Libraries/Microsoft.Extensions.Compliance.Testing/FakeRedactorProvider.cs b/src/Libraries/Microsoft.Extensions.Compliance.Testing/FakeRedactorProvider.cs index 38b186688f4..c306d1d4c86 100644 --- a/src/Libraries/Microsoft.Extensions.Compliance.Testing/FakeRedactorProvider.cs +++ b/src/Libraries/Microsoft.Extensions.Compliance.Testing/FakeRedactorProvider.cs @@ -28,7 +28,7 @@ public class FakeRedactorProvider : IRedactorProvider public FakeRedactorProvider(FakeRedactorOptions? options = null, FakeRedactionCollector? eventCollector = null) { Collector = eventCollector ?? new FakeRedactionCollector(); - _redactor = new FakeRedactor(Microsoft.Extensions.Options.Options.Create(options ?? new FakeRedactorOptions()), Collector); + _redactor = new FakeRedactor(Options.Options.Create(options ?? new FakeRedactorOptions()), Collector); } /// diff --git a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/HttpHeadersReader.cs b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/HttpHeadersReader.cs index 9044ef4ab02..8e6bcedc4e7 100644 --- a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/HttpHeadersReader.cs +++ b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/HttpHeadersReader.cs @@ -15,9 +15,13 @@ namespace Microsoft.Extensions.Http.Logging.Internal; internal sealed class HttpHeadersReader : IHttpHeadersReader { - private readonly FrozenDictionary _requestHeaders; - private readonly FrozenDictionary _responseHeaders; + private readonly FrozenDictionary _requestHeadersToLog; + private readonly FrozenDictionary _responseHeadersToLog; private readonly IHttpHeadersRedactor _redactor; + private readonly bool _logContentHeaders; +#if NET6_0_OR_GREATER + private readonly int _headersCountThreshold; +#endif public HttpHeadersReader(IOptionsMonitor optionsMonitor, IHttpHeadersRedactor redactor, [ServiceKey] string? serviceKey = null) { @@ -25,8 +29,13 @@ public HttpHeadersReader(IOptionsMonitor optionsMonitor, IHttpHe _redactor = redactor; - _requestHeaders = options.RequestHeadersDataClasses.ToFrozenDictionary(StringComparer.OrdinalIgnoreCase); - _responseHeaders = options.ResponseHeadersDataClasses.ToFrozenDictionary(StringComparer.OrdinalIgnoreCase); + _requestHeadersToLog = options.RequestHeadersDataClasses.ToFrozenDictionary(StringComparer.OrdinalIgnoreCase); + _responseHeadersToLog = options.ResponseHeadersDataClasses.ToFrozenDictionary(StringComparer.OrdinalIgnoreCase); + _logContentHeaders = options.LogContentHeaders; + +#if NET6_0_OR_GREATER + _headersCountThreshold = _requestHeadersToLog.Count; +#endif } public void ReadRequestHeaders(HttpRequestMessage request, List>? destination) @@ -36,7 +45,11 @@ public void ReadRequestHeaders(HttpRequestMessage request, List>? destination) @@ -46,17 +59,47 @@ public void ReadResponseHeaders(HttpResponseMessage response, List headersToLog, List> destination) + private void ReadHeaders(HttpHeaders headers, FrozenDictionary headersToLog, List> destination) { +#if NET6_0_OR_GREATER + var headersCount = headers.NonValidated.Count; + if (headersCount == 0) + { + return; + } + + if (headersCount < _headersCountThreshold) + { + // We have less headers than registered for logging, iterating over the smaller collection + foreach (var header in headers) + { + if (headersToLog.TryGetValue(header.Key, out var classification)) + { + destination.Add(new(header.Key, _redactor.Redact(header.Value, classification))); + } + } + + return; + } +#endif + foreach (var kvp in headersToLog) { var classification = kvp.Value; var header = kvp.Key; - if (requestHeaders.TryGetValues(header, out var values)) + if (headers.TryGetValues(header, out var values)) { destination.Add(new(header, _redactor.Redact(values, classification))); } diff --git a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/Log.cs b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/Log.cs index 2b8a627b687..ea60895faf9 100644 --- a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/Log.cs +++ b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/Internal/Log.cs @@ -12,10 +12,9 @@ namespace Microsoft.Extensions.Http.Logging.Internal; /// Logs , and the exceptions due to errors of request/response. /// [SuppressMessage("Major Code Smell", "S109:Magic numbers should not be used", Justification = "Event ID's.")] -internal static class Log +internal static partial class Log { internal const string OriginalFormat = "{OriginalFormat}"; - private const string NullString = "(null)"; private const int MinimalPropertyCount = 4; @@ -34,7 +33,7 @@ internal static class Log "An error occurred in enricher '{Enricher}' while enriching the logger context for request: " + $"{{{HttpClientLoggingTagNames.Method}}} {{{HttpClientLoggingTagNames.Host}}}/{{{HttpClientLoggingTagNames.Path}}}"; - private static readonly Func _originalFormatValueFMTFunc = OriginalFormatValueFmt; + private static readonly Func _originalFormatValueFmtFunc = OriginalFormatValueFmt; public static void OutgoingRequest(ILogger logger, LogLevel level, LogRecord record) { @@ -46,114 +45,38 @@ public static void OutgoingRequestError(ILogger logger, LogRecord record, Except OutgoingRequest(logger, LogLevel.Error, 2, nameof(OutgoingRequestError), record, exception); } - public static void RequestReadError(ILogger logger, Exception exception, HttpMethod method, string? host, string? path) - { - var state = LoggerMessageHelper.ThreadLocalState; - - _ = state.ReserveTagSpace(4); - state.TagArray[3] = new(HttpClientLoggingTagNames.Method, method); - state.TagArray[2] = new(HttpClientLoggingTagNames.Host, host); - state.TagArray[1] = new(HttpClientLoggingTagNames.Path, path); - state.TagArray[0] = new(OriginalFormat, RequestReadErrorMessage); - - logger.Log( - LogLevel.Error, - new(0, nameof(RequestReadError)), - state, - exception, - static (s, _) => - { - var method = s.TagArray[3].Value ?? NullString; - var host = s.TagArray[2].Value ?? NullString; - var path = s.TagArray[1].Value ?? NullString; - return FormattableString.Invariant( - $"An error occurred while reading the request data to fill the logger context for request: {method} {host}/{path}"); - }); - - state.Clear(); - } - - public static void ResponseReadError(ILogger logger, Exception exception, HttpMethod method, string host, string path) - { - var state = LoggerMessageHelper.ThreadLocalState; - - _ = state.ReserveTagSpace(4); - state.TagArray[3] = new(HttpClientLoggingTagNames.Method, method); - state.TagArray[2] = new(HttpClientLoggingTagNames.Host, host); - state.TagArray[1] = new(HttpClientLoggingTagNames.Path, path); - state.TagArray[0] = new(OriginalFormat, ResponseReadErrorMessage); - - logger.Log( - LogLevel.Error, - new(0, nameof(ResponseReadError)), - state, - exception, - static (s, _) => - { - var method = s.TagArray[3].Value ?? NullString; - var host = s.TagArray[2].Value ?? NullString; - var path = s.TagArray[1].Value ?? NullString; - return FormattableString.Invariant( - $"An error occurred while reading the response data to fill the logger context for request: {method} {host}/{path}"); - }); - - state.Clear(); - } - - public static void LoggerContextMissing(ILogger logger, Exception? exception, string requestState, HttpMethod method, string? host) - { - var state = LoggerMessageHelper.ThreadLocalState; - - _ = state.ReserveTagSpace(4); - state.TagArray[3] = new("RequestState", requestState); - state.TagArray[2] = new(HttpClientLoggingTagNames.Method, method); - state.TagArray[1] = new(HttpClientLoggingTagNames.Host, host); - state.TagArray[0] = new(OriginalFormat, LoggerContextMissingMessage); - - logger.Log( - LogLevel.Error, - new(0, nameof(LoggerContextMissing)), - state, - exception, - static (s, _) => - { - var requestState = s.TagArray[3].Value ?? NullString; - var method = s.TagArray[2].Value ?? NullString; - var host = s.TagArray[1].Value ?? NullString; - return FormattableString.Invariant($"The logger couldn't read its context for {requestState} request: {method} {host}"); - }); - - state.Clear(); - } - - public static void EnrichmentError(ILogger logger, Exception exception, string? enricher, HttpMethod method, string host, string path) - { - var state = LoggerMessageHelper.ThreadLocalState; - - _ = state.ReserveTagSpace(5); - state.TagArray[4] = new("Enricher", enricher); - state.TagArray[3] = new(HttpClientLoggingTagNames.Method, method); - state.TagArray[2] = new(HttpClientLoggingTagNames.Host, host); - state.TagArray[1] = new(HttpClientLoggingTagNames.Path, path); - state.TagArray[0] = new(OriginalFormat, EnrichmentErrorMessage); - - logger.Log( - LogLevel.Error, - new(0, nameof(EnrichmentError)), - state, - exception, - static (s, _) => - { - var enricher = s.TagArray[4].Value ?? NullString; - var method = s.TagArray[3].Value ?? NullString; - var host = s.TagArray[2].Value ?? NullString; - var path = s.TagArray[1].Value ?? NullString; - return FormattableString.Invariant( - $"An error occurred in enricher '{enricher}' while enriching the logger context for request: {method} {host}/{path}"); - }); - - state.Clear(); - } + [LoggerMessage(LogLevel.Error, RequestReadErrorMessage)] + public static partial void RequestReadError( + ILogger logger, + Exception exception, + [TagName(HttpClientLoggingTagNames.Method)] HttpMethod method, + [TagName(HttpClientLoggingTagNames.Host)] string? host, + [TagName(HttpClientLoggingTagNames.Path)] string? path); + + [LoggerMessage(LogLevel.Error, ResponseReadErrorMessage)] + public static partial void ResponseReadError( + ILogger logger, + Exception exception, + [TagName(HttpClientLoggingTagNames.Method)] HttpMethod method, + [TagName(HttpClientLoggingTagNames.Host)] string host, + [TagName(HttpClientLoggingTagNames.Path)] string path); + + [LoggerMessage(LogLevel.Error, LoggerContextMissingMessage)] + public static partial void LoggerContextMissing( + ILogger logger, + Exception? exception, + string requestState, + [TagName(HttpClientLoggingTagNames.Method)] HttpMethod method, + [TagName(HttpClientLoggingTagNames.Host)] string? host); + + [LoggerMessage(LogLevel.Error, EnrichmentErrorMessage)] + public static partial void EnrichmentError( + ILogger logger, + Exception exception, + string? enricher, + [TagName(HttpClientLoggingTagNames.Method)] HttpMethod method, + [TagName(HttpClientLoggingTagNames.Host)] string host, + [TagName(HttpClientLoggingTagNames.Path)] string path); // Using the code below instead of generated logging method because we have a custom formatter and custom tag keys for headers. private static void OutgoingRequest( @@ -215,7 +138,7 @@ private static void OutgoingRequest( new(eventId, eventName), loggerMessageState, exception, - _originalFormatValueFMTFunc); + _originalFormatValueFmtFunc); if (record.EnrichmentTags is null) { diff --git a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/LoggingOptions.cs b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/LoggingOptions.cs index 184fca4a061..fe2d096f7bc 100644 --- a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/LoggingOptions.cs +++ b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Logging/LoggingOptions.cs @@ -8,6 +8,7 @@ using Microsoft.Extensions.Compliance.Classification; using Microsoft.Extensions.Http.Diagnostics; using Microsoft.Shared.Data.Validation; +using Microsoft.Shared.DiagnosticIds; namespace Microsoft.Extensions.Http.Logging; @@ -144,4 +145,18 @@ public class LoggingOptions [SuppressMessage("Usage", "CA2227:Collection properties should be read only", Justification = "Options pattern.")] public IDictionary RouteParameterDataClasses { get; set; } = new Dictionary(); + + /// + /// Gets or sets a value indicating whether the HTTP request and response content headers are logged. + /// + /// + /// The default value is . + /// + /// + /// This property controls whether the logging of HTTP request and response representation headers (e.g. Content-Type) is enabled. + /// Keep this option disabled if or + /// don't contain any representation headers, otherwise it will create unnecessary minor performance impact on the headers logging. + /// + [Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] + public bool LogContentHeaders { get; set; } } diff --git a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj index dc712fd3275..00cc5c466d6 100644 --- a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj +++ b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj @@ -1,4 +1,4 @@ - + Microsoft.Extensions.Http.Diagnostics Telemetry support for HTTP Client. @@ -13,7 +13,8 @@ true false true - false + true + true false true false diff --git a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/AcceptanceTests.cs b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/AcceptanceTests.cs index 8e2df28853b..36ad783c73b 100644 --- a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/AcceptanceTests.cs +++ b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/AcceptanceTests.cs @@ -360,7 +360,7 @@ public async Task AddHttpClientLogging_StructuredPathLogging_RedactsSensitivePar httpRequestMessage.SetRequestMetadata(new RequestMetadata(httpRequestMessage.Method.ToString(), RequestRoute)); - using var _ = await httpClient.SendAsync(httpRequestMessage).ConfigureAwait(false); + using var _ = await httpClient.SendAsync(httpRequestMessage); var collector = sp.GetFakeLogCollector(); var logRecord = collector.GetSnapshot().Single(logRecord => logRecord.Category == LoggingCategory); diff --git a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/HttpHeadersReaderTest.cs b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/HttpHeadersReaderTest.cs index a32a649b62e..625342d2468 100644 --- a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/HttpHeadersReaderTest.cs +++ b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Logging/HttpHeadersReaderTest.cs @@ -1,9 +1,9 @@ // 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.Collections.Generic; using System.Net.Http; +using System.Net.Mime; using FluentAssertions; using Microsoft.Extensions.Compliance.Classification; using Microsoft.Extensions.Compliance.Testing; @@ -58,8 +58,8 @@ public void HttpHeadersReader_WhenHeadersProvided_ReadsThem() { { "Header3", FakeTaxonomy.PublicData }, { "Header4", FakeTaxonomy.PublicData }, - { "hEaDeR7", FakeTaxonomy.PrivateData } - }, + { "hEaDeR7", FakeTaxonomy.PrivateData } // This one is to test case-insensitivity + } }; var headersReader = new HttpHeadersReader(options.ToOptionsMonitor(), mockHeadersRedactor.Object); @@ -86,11 +86,12 @@ public void HttpHeadersReader_WhenHeadersProvided_ReadsThem() new KeyValuePair("Header1", Redacted), new KeyValuePair("Header2", Redacted) }; + var expectedResponse = new[] { new KeyValuePair("Header3", "Value.3"), new KeyValuePair("Header4", "Value.4"), - new KeyValuePair("hEaDeR7", Redacted), + new KeyValuePair("hEaDeR7", Redacted) }; headersReader.ReadRequestHeaders(httpRequest, requestBuffer); @@ -100,6 +101,71 @@ public void HttpHeadersReader_WhenHeadersProvided_ReadsThem() responseBuffer.Should().BeEquivalentTo(expectedResponse); } + [Theory] + [CombinatorialData] + public void HttpHeadersReader_WhenProvided_ReadsContentHeaders(bool logContentHeaders) + { + var mockHeadersRedactor = new Mock(); + mockHeadersRedactor.Setup(r => r.Redact(It.IsAny>(), FakeTaxonomy.PublicData)) + .Returns, DataClassification>((x, _) => string.Join(",", x)); + + var options = new LoggingOptions + { + RequestHeadersDataClasses = new Dictionary + { + { "Header1", FakeTaxonomy.PublicData }, + { "Content-Header1", FakeTaxonomy.PublicData }, + { "Content-Type", FakeTaxonomy.PublicData } + }, + ResponseHeadersDataClasses = new Dictionary + { + { "Header3", FakeTaxonomy.PublicData }, + { "Content-Header2", FakeTaxonomy.PublicData }, + { "Content-Length", FakeTaxonomy.PublicData } + }, + LogContentHeaders = logContentHeaders + }; + + var headersReader = new HttpHeadersReader(options.ToOptionsMonitor(), mockHeadersRedactor.Object); + + using var requestContent = new StringContent(string.Empty); + requestContent.Headers.ContentType = new(MediaTypeNames.Application.Soap); + requestContent.Headers.ContentLength = 42; + requestContent.Headers.Add("Content-Header1", "Content.1"); + + using var httpRequest = new HttpRequestMessage { Content = requestContent }; + httpRequest.Headers.Add("Header1", "Value.1"); + httpRequest.Headers.Add("Header2", "Value.2"); + + using var responseContent = new StringContent(string.Empty); + responseContent.Headers.ContentType = new(MediaTypeNames.Text.Html); + responseContent.Headers.ContentLength = 24; + responseContent.Headers.Add("Content-Header2", "Content.2"); + + using var httpResponse = new HttpResponseMessage { Content = responseContent }; + httpResponse.Headers.Add("Header3", "Value.3"); + httpResponse.Headers.Add("Header4", "Value.4"); + + List> expectedRequest = [new KeyValuePair("Header1", "Value.1")]; + List> expectedResponse = [new KeyValuePair("Header3", "Value.3")]; + if (logContentHeaders) + { + expectedRequest.Add(new KeyValuePair("Content-Header1", "Content.1")); + expectedRequest.Add(new KeyValuePair("Content-Type", MediaTypeNames.Application.Soap)); + + expectedResponse.Add(new KeyValuePair("Content-Header2", "Content.2")); + expectedResponse.Add(new KeyValuePair("Content-Length", "24")); + } + + List> requestBuffer = []; + headersReader.ReadRequestHeaders(httpRequest, requestBuffer); + requestBuffer.Should().BeEquivalentTo(expectedRequest); + + List> responseBuffer = []; + headersReader.ReadResponseHeaders(httpResponse, responseBuffer); + responseBuffer.Should().BeEquivalentTo(expectedResponse); + } + [Fact] public void HttpHeadersReader_WhenBufferIsNull_DoesNothing() { diff --git a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/TelemetryCommonExtensions2Tests.cs b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/TelemetryCommonExtensionsTests.cs similarity index 98% rename from test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/TelemetryCommonExtensions2Tests.cs rename to test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/TelemetryCommonExtensionsTests.cs index 85f7791eeb2..a7a404079b6 100644 --- a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/TelemetryCommonExtensions2Tests.cs +++ b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/TelemetryCommonExtensionsTests.cs @@ -8,7 +8,7 @@ namespace Microsoft.Extensions.Telemetry.Internal.Test; -public class TelemetryCommonExtensions2Tests +public class TelemetryCommonExtensionsTests { [Fact] public void GetDependencyName_DependencyNameMissing_ReturnsUnknown()