Skip to content

Commit 756cde2

Browse files
committed
Add option to exception handler middleware to not log error
1 parent c5d6996 commit 756cde2

File tree

6 files changed

+170
-30
lines changed

6 files changed

+170
-30
lines changed

src/Middleware/Diagnostics/src/DeveloperExceptionPage/DeveloperExceptionPageMiddlewareImpl.cs

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -115,6 +115,8 @@ public async Task Invoke(HttpContext context)
115115
}
116116
catch (Exception ex)
117117
{
118+
DiagnosticsTelemetry.AddMetricsTags(context, ex);
119+
118120
var exceptionName = ex.GetType().FullName!;
119121

120122
if ((ex is OperationCanceledException || ex is IOException) && context.RequestAborted.IsCancellationRequested)
@@ -135,7 +137,7 @@ public async Task Invoke(HttpContext context)
135137
return;
136138
}
137139

138-
DiagnosticsTelemetry.ReportUnhandledException(_logger, context, ex);
140+
_logger.UnhandledException(ex);
139141

140142
if (context.Response.HasStarted)
141143
{

src/Middleware/Diagnostics/src/DiagnosticsTelemetry.cs

Lines changed: 1 addition & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3,16 +3,13 @@
33

44
using Microsoft.AspNetCore.Http.Features;
55
using Microsoft.AspNetCore.Http;
6-
using Microsoft.Extensions.Logging;
76

87
namespace Microsoft.AspNetCore.Diagnostics;
98

109
internal static class DiagnosticsTelemetry
1110
{
12-
public static void ReportUnhandledException(ILogger logger, HttpContext context, Exception ex)
11+
public static void AddMetricsTags(HttpContext context, Exception ex)
1312
{
14-
logger.UnhandledException(ex);
15-
1613
if (context.Features.Get<IHttpMetricsTagsFeature>() is { } tagsFeature)
1714
{
1815
// Multiple exception middleware could be registered that have already added the tag.

src/Middleware/Diagnostics/src/ExceptionHandler/ExceptionHandlerMiddlewareImpl.cs

Lines changed: 52 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -112,10 +112,13 @@ static async Task Awaited(ExceptionHandlerMiddlewareImpl middleware, HttpContext
112112

113113
private async Task HandleException(HttpContext context, ExceptionDispatchInfo edi)
114114
{
115+
DiagnosticsTelemetry.AddMetricsTags(context, edi.SourceException);
116+
115117
var exceptionName = edi.SourceException.GetType().FullName!;
116118

117119
if ((edi.SourceException is OperationCanceledException || edi.SourceException is IOException) && context.RequestAborted.IsCancellationRequested)
118120
{
121+
// Don't log unhandled exception for aborted request.
119122
_logger.RequestAbortedException();
120123

121124
if (!context.Response.HasStarted)
@@ -127,11 +130,10 @@ private async Task HandleException(HttpContext context, ExceptionDispatchInfo ed
127130
return;
128131
}
129132

130-
DiagnosticsTelemetry.ReportUnhandledException(_logger, context, edi.SourceException);
131-
132133
// We can't do anything if the response has already started, just abort.
133134
if (context.Response.HasStarted)
134135
{
136+
_logger.UnhandledException(edi.SourceException);
135137
_logger.ResponseStartedErrorHandler();
136138

137139
_metrics.RequestException(exceptionName, ExceptionResult.Skipped, handler: null);
@@ -168,52 +170,73 @@ private async Task HandleException(HttpContext context, ExceptionDispatchInfo ed
168170
context.Response.StatusCode = _options.StatusCodeSelector?.Invoke(edi.SourceException) ?? DefaultStatusCode;
169171
context.Response.OnStarting(_clearCacheHeadersDelegate, context.Response);
170172

171-
string? handler = null;
172-
var handled = false;
173+
string? handlerTag = null;
174+
var handler = Handler.None;
173175
foreach (var exceptionHandler in _exceptionHandlers)
174176
{
175-
handled = await exceptionHandler.TryHandleAsync(context, edi.SourceException, context.RequestAborted);
176-
if (handled)
177+
if (await exceptionHandler.TryHandleAsync(context, edi.SourceException, context.RequestAborted))
177178
{
178-
handler = exceptionHandler.GetType().FullName;
179+
handler = Handler.IExceptionHandler;
180+
handlerTag = exceptionHandler.GetType().FullName;
179181
break;
180182
}
181183
}
182184

183-
if (!handled)
185+
if (handler == Handler.None)
184186
{
185187
if (_options.ExceptionHandler is not null)
186188
{
187189
await _options.ExceptionHandler!(context);
190+
191+
// If the response has started, assume exception handler was successful.
192+
if (context.Response.HasStarted)
193+
{
194+
handler = Handler.ExceptionHandler;
195+
if (_options.ExceptionHandlingPath.HasValue)
196+
{
197+
handlerTag = _options.ExceptionHandlingPath.Value;
198+
}
199+
}
188200
}
189201
else
190202
{
191-
handled = await _problemDetailsService!.TryWriteAsync(new()
203+
if (await _problemDetailsService!.TryWriteAsync(new()
192204
{
193205
HttpContext = context,
194206
AdditionalMetadata = exceptionHandlerFeature.Endpoint?.Metadata,
195207
ProblemDetails = { Status = context.Response.StatusCode },
196208
Exception = edi.SourceException,
197-
});
198-
if (handled)
209+
}))
199210
{
200-
handler = _problemDetailsService.GetType().FullName;
211+
handler = Handler.IProblemDetailsService;
212+
handlerTag = _problemDetailsService.GetType().FullName;
201213
}
202214
}
203215
}
204-
// If the response has already started, assume exception handler was successful.
205-
if (context.Response.HasStarted || handled || _options.StatusCodeSelector != null || context.Response.StatusCode != StatusCodes.Status404NotFound || _options.AllowStatusCode404Response)
216+
217+
if (handler != Handler.None || _options.StatusCodeSelector != null || context.Response.StatusCode != StatusCodes.Status404NotFound || _options.AllowStatusCode404Response)
206218
{
207-
const string eventName = "Microsoft.AspNetCore.Diagnostics.HandledException";
208-
if (_diagnosticListener.IsEnabled() && _diagnosticListener.IsEnabled(eventName))
219+
// Customers with an IExceptionHandler that reports it handled the exception could do their own logging.
220+
// Don't log IExceptionHandler handled exceptions if SuppressLoggingIExceptionHandler is set to true.
221+
// Note: Microsoft.AspNetCore.Diagnostics.HandledException is used by AppInsights to log errors so it's also skipped.
222+
if (handler != Handler.IExceptionHandler || !_options.SuppressLoggingIExceptionHandler)
209223
{
210-
WriteDiagnosticEvent(_diagnosticListener, eventName, new { httpContext = context, exception = edi.SourceException });
224+
const string eventName = "Microsoft.AspNetCore.Diagnostics.HandledException";
225+
if (_diagnosticListener.IsEnabled() && _diagnosticListener.IsEnabled(eventName))
226+
{
227+
WriteDiagnosticEvent(_diagnosticListener, eventName, new { httpContext = context, exception = edi.SourceException });
228+
}
229+
230+
_logger.UnhandledException(edi.SourceException);
211231
}
212232

213-
_metrics.RequestException(exceptionName, ExceptionResult.Handled, handler);
233+
_metrics.RequestException(exceptionName, ExceptionResult.Handled, handlerTag);
214234
return;
215235
}
216236

237+
// Log original unhandled exception before it is wrapped.
238+
_logger.UnhandledException(edi.SourceException);
239+
217240
edi = ExceptionDispatchInfo.Capture(new InvalidOperationException($"The exception handler configured on {nameof(ExceptionHandlerOptions)} produced a 404 status response. " +
218241
$"This {nameof(InvalidOperationException)} containing the original exception was thrown since this is often due to a misconfigured {nameof(ExceptionHandlerOptions.ExceptionHandlingPath)}. " +
219242
$"If the exception handler is expected to return 404 status responses then set {nameof(ExceptionHandlerOptions.AllowStatusCode404Response)} to true.", edi.SourceException));
@@ -222,6 +245,9 @@ private async Task HandleException(HttpContext context, ExceptionDispatchInfo ed
222245
{
223246
// Suppress secondary exceptions, re-throw the original.
224247
_logger.ErrorHandlerException(ex2);
248+
249+
// There was an error handling the exception. Log original unhandled exception.
250+
_logger.UnhandledException(edi.SourceException);
225251
}
226252
finally
227253
{
@@ -259,4 +285,12 @@ private static Task ClearCacheHeaders(object state)
259285
headers.ETag = default;
260286
return Task.CompletedTask;
261287
}
288+
289+
private enum Handler
290+
{
291+
None,
292+
IExceptionHandler,
293+
IProblemDetailsService,
294+
ExceptionHandler
295+
}
262296
}

src/Middleware/Diagnostics/src/ExceptionHandler/ExceptionHandlerOptions.cs

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,10 +40,16 @@ public class ExceptionHandlerOptions
4040
public bool AllowStatusCode404Response { get; set; }
4141

4242
/// <summary>
43-
/// Gets or sets a delegate used to map an exception to a http status code.
43+
/// Gets or sets a delegate used to map an exception to an HTTP status code.
4444
/// </summary>
4545
/// <remarks>
4646
/// If <see cref="StatusCodeSelector"/> is <c>null</c>, the default exception status code 500 is used.
4747
/// </remarks>
4848
public Func<Exception, int>? StatusCodeSelector { get; set; }
49+
50+
/// <summary>
51+
/// Gets or sets a value that determines if the exception handler middleware should suppress logging
52+
/// if the exception was handled by a <see cref="IExceptionHandler"/> registered in the DI container.
53+
/// </summary>
54+
public bool SuppressLoggingIExceptionHandler { get; set; }
4955
}
Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,6 @@
11
#nullable enable
22
Microsoft.AspNetCore.Builder.StatusCodePagesOptions.CreateScopeForErrors.get -> bool
33
Microsoft.AspNetCore.Builder.StatusCodePagesOptions.CreateScopeForErrors.set -> void
4-
static Microsoft.AspNetCore.Builder.StatusCodePagesExtensions.UseStatusCodePagesWithReExecute(this Microsoft.AspNetCore.Builder.IApplicationBuilder! app, string! pathFormat, bool createScopeForErrors, string? queryFormat = null) -> Microsoft.AspNetCore.Builder.IApplicationBuilder!
4+
static Microsoft.AspNetCore.Builder.StatusCodePagesExtensions.UseStatusCodePagesWithReExecute(this Microsoft.AspNetCore.Builder.IApplicationBuilder! app, string! pathFormat, bool createScopeForErrors, string? queryFormat = null) -> Microsoft.AspNetCore.Builder.IApplicationBuilder!
5+
Microsoft.AspNetCore.Builder.ExceptionHandlerOptions.SuppressLoggingIExceptionHandler.get -> bool
6+
Microsoft.AspNetCore.Builder.ExceptionHandlerOptions.SuppressLoggingIExceptionHandler.set -> void

src/Middleware/Diagnostics/test/UnitTests/ExceptionHandlerMiddlewareTest.cs

Lines changed: 104 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@
2222
using Microsoft.Extensions.Hosting;
2323
using Microsoft.Extensions.Logging;
2424
using Microsoft.Extensions.Logging.Abstractions;
25+
using Microsoft.Extensions.Logging.Testing;
2526
using Microsoft.Extensions.Options;
2627
using Moq;
2728

@@ -81,6 +82,7 @@ public async Task ExceptionIsSetOnProblemDetailsContext()
8182
public async Task Invoke_ExceptionThrownResultsInClearedRouteValuesAndEndpoint()
8283
{
8384
// Arrange
85+
var sink = new TestSink();
8486
var httpContext = CreateHttpContext();
8587
httpContext.SetEndpoint(new Endpoint((_) => Task.CompletedTask, new EndpointMetadataCollection(), "Test"));
8688
httpContext.Request.RouteValues["John"] = "Doe";
@@ -92,10 +94,39 @@ public async Task Invoke_ExceptionThrownResultsInClearedRouteValuesAndEndpoint()
9294
Assert.Null(context.GetEndpoint());
9395
return Task.CompletedTask;
9496
});
95-
var middleware = CreateMiddleware(_ => throw new InvalidOperationException(), optionsAccessor);
97+
var middleware = CreateMiddleware(_ => throw new InvalidOperationException(), optionsAccessor, loggerFactory: new TestLoggerFactory(sink, true));
9698

9799
// Act & Assert
98100
await middleware.Invoke(httpContext);
101+
102+
Assert.Collection(sink.Writes, w => Assert.Equal("UnhandledException", w.EventId.Name));
103+
}
104+
105+
[Fact]
106+
public async Task Invoke_HasExceptionHandler_SuppressIExceptionHandlerLogging_HasLogs()
107+
{
108+
// Arrange
109+
var sink = new TestSink();
110+
var httpContext = CreateHttpContext();
111+
112+
var optionsAccessor = CreateOptionsAccessor(
113+
exceptionHandler: context =>
114+
{
115+
context.Features.Set<IHttpResponseFeature>(new TestHttpResponseFeature());
116+
return Task.CompletedTask;
117+
},
118+
suppressLoggingHandlingException: true);
119+
var middleware = CreateMiddleware(_ => throw new InvalidOperationException(), optionsAccessor, loggerFactory: new TestLoggerFactory(sink, true));
120+
121+
// Act & Assert
122+
await middleware.Invoke(httpContext);
123+
124+
Assert.Collection(sink.Writes, w => Assert.Equal("UnhandledException", w.EventId.Name));
125+
}
126+
127+
private sealed class TestHttpResponseFeature : HttpResponseFeature
128+
{
129+
public override bool HasStarted => true;
99130
}
100131

101132
[Fact]
@@ -126,6 +157,7 @@ public async Task Invoke_ExceptionHandlerCaptureRouteValuesAndEndpoint()
126157
public async Task IExceptionHandlers_CallNextIfNotHandled()
127158
{
128159
// Arrange
160+
var sink = new TestSink();
129161
var httpContext = CreateHttpContext();
130162

131163
var optionsAccessor = CreateOptionsAccessor();
@@ -137,14 +169,49 @@ public async Task IExceptionHandlers_CallNextIfNotHandled()
137169
new TestExceptionHandler(true, "3"),
138170
};
139171

140-
var middleware = CreateMiddleware(_ => throw new InvalidOperationException(), optionsAccessor, exceptionHandlers);
172+
var middleware = CreateMiddleware(_ => throw new InvalidOperationException(), optionsAccessor, exceptionHandlers, loggerFactory: new TestLoggerFactory(sink, true));
141173

142174
// Act & Assert
143175
await middleware.Invoke(httpContext);
144176

145177
Assert.True(httpContext.Items.ContainsKey("1"));
146178
Assert.True(httpContext.Items.ContainsKey("2"));
147179
Assert.True(httpContext.Items.ContainsKey("3"));
180+
181+
Assert.Collection(sink.Writes, w => Assert.Equal("UnhandledException", w.EventId.Name));
182+
}
183+
184+
[Theory]
185+
[InlineData(true)]
186+
[InlineData(false)]
187+
public async Task IExceptionHandlers_SuppressLogging_TestLogs(bool suppressedLogs)
188+
{
189+
// Arrange
190+
var sink = new TestSink();
191+
var httpContext = CreateHttpContext();
192+
193+
var optionsAccessor = CreateOptionsAccessor(suppressLoggingHandlingException: suppressedLogs);
194+
195+
var exceptionHandlers = new List<IExceptionHandler>
196+
{
197+
new TestExceptionHandler(true, "1")
198+
};
199+
200+
var middleware = CreateMiddleware(_ => throw new InvalidOperationException(), optionsAccessor, exceptionHandlers, loggerFactory: new TestLoggerFactory(sink, true));
201+
202+
// Act & Assert
203+
await middleware.Invoke(httpContext);
204+
205+
Assert.True(httpContext.Items.ContainsKey("1"));
206+
207+
if (suppressedLogs)
208+
{
209+
Assert.Empty(sink.Writes);
210+
}
211+
else
212+
{
213+
Assert.Collection(sink.Writes, w => Assert.Equal("UnhandledException", w.EventId.Name));
214+
}
148215
}
149216

150217
[Fact]
@@ -445,6 +512,32 @@ public async Task Metrics_ExceptionThrown_Unhandled_Reported()
445512
m => AssertRequestException(m, "System.InvalidOperationException", "unhandled"));
446513
}
447514

515+
[Fact]
516+
public async Task Metrics_ExceptionThrown_ErrorPathHandled_Reported()
517+
{
518+
// Arrange
519+
var httpContext = CreateHttpContext();
520+
var optionsAccessor = CreateOptionsAccessor(
521+
exceptionHandler: context =>
522+
{
523+
context.Features.Set<IHttpResponseFeature>(new TestHttpResponseFeature());
524+
return Task.CompletedTask;
525+
},
526+
exceptionHandlingPath: "/error");
527+
var meterFactory = new TestMeterFactory();
528+
var middleware = CreateMiddleware(_ => throw new InvalidOperationException(), optionsAccessor, meterFactory: meterFactory);
529+
var meter = meterFactory.Meters.Single();
530+
531+
using var diagnosticsRequestExceptionCollector = new MetricCollector<long>(meterFactory, DiagnosticsMetrics.MeterName, "aspnetcore.diagnostics.exceptions");
532+
533+
// Act
534+
await middleware.Invoke(httpContext);
535+
536+
// Assert
537+
Assert.Collection(diagnosticsRequestExceptionCollector.GetMeasurementSnapshot(),
538+
m => AssertRequestException(m, "System.InvalidOperationException", "handled", "/error"));
539+
}
540+
448541
private static void AssertRequestException(CollectedMeasurement<long> measurement, string exceptionName, string result, string handler = null)
449542
{
450543
Assert.Equal(1, measurement.Value);
@@ -490,14 +583,19 @@ private HttpContext CreateHttpContext()
490583

491584
private IOptions<ExceptionHandlerOptions> CreateOptionsAccessor(
492585
RequestDelegate exceptionHandler = null,
493-
string exceptionHandlingPath = null)
586+
string exceptionHandlingPath = null,
587+
bool? suppressLoggingHandlingException = null)
494588
{
495589
exceptionHandler ??= c => Task.CompletedTask;
496590
var options = new ExceptionHandlerOptions()
497591
{
498592
ExceptionHandler = exceptionHandler,
499593
ExceptionHandlingPath = exceptionHandlingPath,
500594
};
595+
if (suppressLoggingHandlingException != null)
596+
{
597+
options.SuppressLoggingIExceptionHandler = suppressLoggingHandlingException.Value;
598+
}
501599
var optionsAccessor = Mock.Of<IOptions<ExceptionHandlerOptions>>(o => o.Value == options);
502600
return optionsAccessor;
503601
}
@@ -506,14 +604,15 @@ private ExceptionHandlerMiddlewareImpl CreateMiddleware(
506604
RequestDelegate next,
507605
IOptions<ExceptionHandlerOptions> options,
508606
IEnumerable<IExceptionHandler> exceptionHandlers = null,
509-
IMeterFactory meterFactory = null)
607+
IMeterFactory meterFactory = null,
608+
ILoggerFactory loggerFactory = null)
510609
{
511610
next ??= c => Task.CompletedTask;
512611
var listener = new DiagnosticListener("Microsoft.AspNetCore");
513612

514613
var middleware = new ExceptionHandlerMiddlewareImpl(
515614
next,
516-
NullLoggerFactory.Instance,
615+
loggerFactory ?? NullLoggerFactory.Instance,
517616
options,
518617
listener,
519618
exceptionHandlers ?? Enumerable.Empty<IExceptionHandler>(),

0 commit comments

Comments
 (0)