From 08f56f6aa186cff67fe91f5a445e2c237b0fc4ab Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Fri, 19 Apr 2024 10:56:12 +0800 Subject: [PATCH 1/3] Fix duplicate error.type tags --- .../Hosting/src/Internal/HostingMetrics.cs | 16 ++- .../src/Microsoft.AspNetCore.Hosting.csproj | 1 + .../Diagnostics/src/DiagnosticsTelemetry.cs | 4 +- .../Microsoft.AspNetCore.Diagnostics.csproj | 1 + .../Diagnostics.FunctionalTests.csproj | 3 + .../ExceptionHandlerSampleTest.cs | 2 +- .../test/FunctionalTests/TestFixture.cs | 12 +- .../test/UnitTests/ExceptionHandlerTest.cs | 133 ++++++++++++++++++ .../ExceptionHandlerSample.csproj | 1 + .../StartupWithWebSocket.cs | 49 +++++++ src/Shared/Metrics/MetricsExtensions.cs | 55 ++++++++ 11 files changed, 263 insertions(+), 14 deletions(-) create mode 100644 src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/StartupWithWebSocket.cs create mode 100644 src/Shared/Metrics/MetricsExtensions.cs diff --git a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs index b680d2f76ab0..19661792dd42 100644 --- a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs +++ b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs @@ -69,12 +69,7 @@ public void RequestEnd(string protocol, bool isHttps, string scheme, string meth { tags.Add("http.route", route); } - // This exception is only present if there is an unhandled exception. - // An exception caught by ExceptionHandlerMiddleware and DeveloperExceptionMiddleware isn't thrown to here. Instead, those middleware add error.type to custom tags. - if (exception != null) - { - tags.Add("error.type", exception.GetType().FullName); - } + if (customTags != null) { for (var i = 0; i < customTags.Count; i++) @@ -83,6 +78,15 @@ public void RequestEnd(string protocol, bool isHttps, string scheme, string meth } } + // This exception is only present if there is an unhandled exception. + // An exception caught by ExceptionHandlerMiddleware and DeveloperExceptionMiddleware isn't thrown to here. Instead, those middleware add error.type to custom tags. + if (exception != null) + { + // Exception tag could have been added by middleware. If an exception is later thrown in request pipeline + // then we don't want to add a duplicate tag here because that breaks some metrics systems. + tags.TryAddTag("error.type", exception.GetType().FullName); + } + var duration = Stopwatch.GetElapsedTime(startTimestamp, currentTimestamp); _requestDuration.Record(duration.TotalSeconds, tags); } diff --git a/src/Hosting/Hosting/src/Microsoft.AspNetCore.Hosting.csproj b/src/Hosting/Hosting/src/Microsoft.AspNetCore.Hosting.csproj index c898aed6af58..3caa14c4beb3 100644 --- a/src/Hosting/Hosting/src/Microsoft.AspNetCore.Hosting.csproj +++ b/src/Hosting/Hosting/src/Microsoft.AspNetCore.Hosting.csproj @@ -16,6 +16,7 @@ + diff --git a/src/Middleware/Diagnostics/src/DiagnosticsTelemetry.cs b/src/Middleware/Diagnostics/src/DiagnosticsTelemetry.cs index aace88526805..36ab75c70ad2 100644 --- a/src/Middleware/Diagnostics/src/DiagnosticsTelemetry.cs +++ b/src/Middleware/Diagnostics/src/DiagnosticsTelemetry.cs @@ -15,7 +15,9 @@ public static void ReportUnhandledException(ILogger logger, HttpContext context, if (context.Features.Get() is { } tagsFeature) { - tagsFeature.Tags.Add(new KeyValuePair("error.type", ex.GetType().FullName)); + // Multiple exception middleware could be registered that have already added the tag. + // We don't want to add a duplicate tag here because that breaks some metrics systems. + tagsFeature.TryAddTag("error.type", ex.GetType().FullName); } } } diff --git a/src/Middleware/Diagnostics/src/Microsoft.AspNetCore.Diagnostics.csproj b/src/Middleware/Diagnostics/src/Microsoft.AspNetCore.Diagnostics.csproj index 4657b64cbf7b..8671a3b03fb4 100644 --- a/src/Middleware/Diagnostics/src/Microsoft.AspNetCore.Diagnostics.csproj +++ b/src/Middleware/Diagnostics/src/Microsoft.AspNetCore.Diagnostics.csproj @@ -17,6 +17,7 @@ + diff --git a/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj b/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj index 7ad4c58c860d..945f6468d94a 100644 --- a/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj +++ b/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj @@ -19,6 +19,9 @@ + + + diff --git a/src/Middleware/Diagnostics/test/FunctionalTests/ExceptionHandlerSampleTest.cs b/src/Middleware/Diagnostics/test/FunctionalTests/ExceptionHandlerSampleTest.cs index aea061e0c4c7..20a21449f879 100644 --- a/src/Middleware/Diagnostics/test/FunctionalTests/ExceptionHandlerSampleTest.cs +++ b/src/Middleware/Diagnostics/test/FunctionalTests/ExceptionHandlerSampleTest.cs @@ -1,4 +1,4 @@ -// Licensed to the .NET Foundation under one or more agreements. +// Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. using System.Net; diff --git a/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs b/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs index d5822a0237b0..54c96a0b07d0 100644 --- a/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs +++ b/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs @@ -22,12 +22,12 @@ public TestFixture() using (new CultureReplacer()) { _host = new HostBuilder() - .ConfigureWebHost(webHostBuilder => - { - webHostBuilder - .UseTestServer() - .UseStartup(typeof(TStartup)); - }).Build(); + .ConfigureWebHost(webHostBuilder => + { + webHostBuilder + .UseTestServer() + .UseStartup(typeof(TStartup)); + }).Build(); _host.Start(); _server = _host.GetTestServer(); diff --git a/src/Middleware/Diagnostics/test/UnitTests/ExceptionHandlerTest.cs b/src/Middleware/Diagnostics/test/UnitTests/ExceptionHandlerTest.cs index fe721073c218..94b89686ef22 100644 --- a/src/Middleware/Diagnostics/test/UnitTests/ExceptionHandlerTest.cs +++ b/src/Middleware/Diagnostics/test/UnitTests/ExceptionHandlerTest.cs @@ -15,6 +15,7 @@ using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Testing; +using System.Net.Http; namespace Microsoft.AspNetCore.Diagnostics; @@ -965,4 +966,136 @@ public async Task UnhandledError_ExceptionNameTagAdded() Assert.Equal("System.Exception", (string)m.Tags["error.type"]); }); } + + [Fact] + public async Task UnhandledError_MultipleHandlers_ExceptionNameTagAddedOnce() + { + // Arrange + var meterFactory = new TestMeterFactory(); + using var instrumentCollector = new MetricCollector(meterFactory, "Microsoft.AspNetCore.Hosting", "http.server.request.duration"); + + using var host = new HostBuilder() + .ConfigureServices(s => + { + s.AddSingleton(meterFactory); + }) + .ConfigureWebHost(webHostBuilder => + { + webHostBuilder + .UseTestServer() + .Configure(app => + { + // Second error and handler + app.UseExceptionHandler(new ExceptionHandlerOptions() + { + ExceptionHandler = httpContext => + { + httpContext.Response.StatusCode = StatusCodes.Status500InternalServerError; + return Task.CompletedTask; + } + }); + app.Use(async (context, next) => + { + await next(); + throw new InvalidOperationException("Test exception2"); + }); + + // First error and handler + app.UseExceptionHandler(new ExceptionHandlerOptions() + { + ExceptionHandler = httpContext => + { + httpContext.Response.StatusCode = StatusCodes.Status404NotFound; + return Task.CompletedTask; + } + }); + app.Run(context => + { + throw new Exception("Test exception1"); + }); + }); + }).Build(); + + await host.StartAsync(); + + var server = host.GetTestServer(); + + // Act + var response = await server.CreateClient().GetAsync("/path"); + Assert.Equal(HttpStatusCode.InternalServerError, response.StatusCode); + + await instrumentCollector.WaitForMeasurementsAsync(minCount: 1).DefaultTimeout(); + + // Assert + Assert.Collection( + instrumentCollector.GetMeasurementSnapshot(), + m => + { + Assert.True(m.Value > 0); + Assert.Equal(500, (int)m.Tags["http.response.status_code"]); + Assert.Equal("System.Exception", (string)m.Tags["error.type"]); + }); + } + + [Fact] + public async Task UnhandledError_ErrorAfterHandler_ExceptionNameTagAddedOnce() + { + // Arrange + var meterFactory = new TestMeterFactory(); + using var instrumentCollector = new MetricCollector(meterFactory, "Microsoft.AspNetCore.Hosting", "http.server.request.duration"); + + using var host = new HostBuilder() + .ConfigureServices(s => + { + s.AddSingleton(meterFactory); + }) + .ConfigureWebHost(webHostBuilder => + { + webHostBuilder + .UseTestServer() + .Configure(app => + { + // Second error + app.Use(async (context, next) => + { + await next(); + + throw new InvalidOperationException("Test exception2"); + }); + + // First error and handler + app.UseExceptionHandler(new ExceptionHandlerOptions() + { + ExceptionHandler = httpContext => + { + httpContext.Response.StatusCode = StatusCodes.Status404NotFound; + return httpContext.Response.WriteAsync("Custom handler"); + } + }); + app.Run(context => + { + throw new Exception("Test exception1"); + }); + }); + }).Build(); + + await host.StartAsync(); + + var server = host.GetTestServer(); + + // Act + await Assert.ThrowsAsync(async () => await server.CreateClient().GetAsync("/path")); + + await instrumentCollector.WaitForMeasurementsAsync(minCount: 1).DefaultTimeout(); + + // Assert + Assert.Collection( + instrumentCollector.GetMeasurementSnapshot(), + m => + { + Assert.True(m.Value > 0); + Assert.Equal(404, (int)m.Tags["http.response.status_code"]); + Assert.Equal("System.Exception", (string)m.Tags["error.type"]); + }); + } } diff --git a/src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/ExceptionHandlerSample.csproj b/src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/ExceptionHandlerSample.csproj index 2faf636c4914..e2eaca2faeda 100644 --- a/src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/ExceptionHandlerSample.csproj +++ b/src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/ExceptionHandlerSample.csproj @@ -10,5 +10,6 @@ + diff --git a/src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/StartupWithWebSocket.cs b/src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/StartupWithWebSocket.cs new file mode 100644 index 000000000000..eb2fc7b4a956 --- /dev/null +++ b/src/Middleware/Diagnostics/test/testassets/ExceptionHandlerSample/StartupWithWebSocket.cs @@ -0,0 +1,49 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics; +using System.Text; +using System.Text.Encodings.Web; +using Microsoft.AspNetCore.Diagnostics; +using Microsoft.AspNetCore.Http.Metadata; + +namespace ExceptionHandlerSample; + +// Note that this class isn't used in tests as TestServer doesn't have the right behavior to test web sockets +// in the way we need. But leaving here so it can be used in Program.cs when starting the app manually. +public class StartupWithWebSocket +{ + public void ConfigureServices(IServiceCollection services) + { + } + + public void Configure(IApplicationBuilder app) + { + app.UseExceptionHandler(options => { }); // Exception handling middleware introduces duplicate tag + app.UseWebSockets(); + + app.Use(async (HttpContext context, Func next) => + { + try + { + if (context.WebSockets.IsWebSocketRequest) + { + using var ws = await context.WebSockets.AcceptWebSocketAsync(); + await ws.SendAsync(new ArraySegment(Encoding.UTF8.GetBytes("Hello")), System.Net.WebSockets.WebSocketMessageType.Text, true, context.RequestAborted); + await ws.CloseAsync(System.Net.WebSockets.WebSocketCloseStatus.NormalClosure, "done", context.RequestAborted); + throw new InvalidOperationException("Throw after websocket request completion to produce the bug"); + } + else + { + await context.Response.WriteAsync($"Not a web socket request. PID: {Process.GetCurrentProcess().Id}"); + } + } + catch (Exception ex) + { + _ = ex; + throw; + } + }); + } +} + diff --git a/src/Shared/Metrics/MetricsExtensions.cs b/src/Shared/Metrics/MetricsExtensions.cs new file mode 100644 index 000000000000..307bb9517601 --- /dev/null +++ b/src/Shared/Metrics/MetricsExtensions.cs @@ -0,0 +1,55 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics; +using Microsoft.AspNetCore.Http.Features; + +namespace Microsoft.AspNetCore.Http; + +internal static class MetricsExtensions +{ + public static bool TryAddTag(this IHttpMetricsTagsFeature feature, string name, object? value) + { + var tags = feature.Tags; + + // Tags is internally represented as a List. + // Prefer looping through the list to avoid allocating an enumerator. + if (tags is List> list) + { + foreach (var tag in list) + { + if (tag.Key == name) + { + return false; + } + } + } + else + { + foreach (var tag in tags) + { + if (tag.Key == name) + { + return false; + } + } + } + + tags.Add(new KeyValuePair(name, value)); + return true; + } + + public static bool TryAddTag(this ref TagList tags, string name, object? value) + { + for (var i = 0; i < tags.Count; i++) + { + if (tags[i].Key == name) + { + return false; + } + } + + tags.Add(new KeyValuePair(name, value)); + return true; + } +} From c58cd60a9187bbf9dbe5f3aa150b62053a040ae8 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Fri, 19 Apr 2024 10:57:14 +0800 Subject: [PATCH 2/3] Clean up --- .../Diagnostics.FunctionalTests.csproj | 3 --- .../Diagnostics/test/FunctionalTests/TestFixture.cs | 12 ++++++------ 2 files changed, 6 insertions(+), 9 deletions(-) diff --git a/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj b/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj index 945f6468d94a..7ad4c58c860d 100644 --- a/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj +++ b/src/Middleware/Diagnostics/test/FunctionalTests/Diagnostics.FunctionalTests.csproj @@ -19,9 +19,6 @@ - - - diff --git a/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs b/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs index 54c96a0b07d0..d5822a0237b0 100644 --- a/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs +++ b/src/Middleware/Diagnostics/test/FunctionalTests/TestFixture.cs @@ -22,12 +22,12 @@ public TestFixture() using (new CultureReplacer()) { _host = new HostBuilder() - .ConfigureWebHost(webHostBuilder => - { - webHostBuilder - .UseTestServer() - .UseStartup(typeof(TStartup)); - }).Build(); + .ConfigureWebHost(webHostBuilder => + { + webHostBuilder + .UseTestServer() + .UseStartup(typeof(TStartup)); + }).Build(); _host.Start(); _server = _host.GetTestServer(); From 3483ad8fc13e42eb10866a50d7a9ae8e9da19062 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Fri, 19 Apr 2024 10:58:26 +0800 Subject: [PATCH 3/3] Clean up --- src/Hosting/Hosting/src/Internal/HostingMetrics.cs | 1 + 1 file changed, 1 insertion(+) diff --git a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs index 19661792dd42..3b313cddf89e 100644 --- a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs +++ b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs @@ -70,6 +70,7 @@ public void RequestEnd(string protocol, bool isHttps, string scheme, string meth tags.Add("http.route", route); } + // Add before some built in tags so custom tags are prioritized when dealing with duplicates. if (customTags != null) { for (var i = 0; i < customTags.Count; i++)