diff --git a/README.md b/README.md index f4c2578..e9f5c8b 100644 --- a/README.md +++ b/README.md @@ -163,6 +163,13 @@ app.UseSerilogRequestLogging(options => diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value); diagnosticContext.Set("RequestScheme", httpContext.Request.Scheme); }; + + // Use an async method to add additional properties that can only be retrieved + // asynchronously like request body + options.EnrichDiagnosticContextAsync = async (diagnosticContext, httpContext) => + { + await AddRequestBodyAsync(diagnosticContext, httpContext); + }; }); ``` diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs index 0b0b3eb..13b2e68 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs @@ -28,6 +28,7 @@ class RequestLoggingMiddleware readonly DiagnosticContext _diagnosticContext; readonly MessageTemplate _messageTemplate; readonly Action? _enrichDiagnosticContext; + readonly Func? _enrichDiagnosticContextAsync; readonly Func _getLevel; readonly Func> _getMessageTemplateProperties; readonly ILogger? _logger; @@ -42,6 +43,7 @@ public RequestLoggingMiddleware(RequestDelegate next, DiagnosticContext diagnost _getLevel = options.GetLevel; _enrichDiagnosticContext = options.EnrichDiagnosticContext; + _enrichDiagnosticContextAsync = options.EnrichDiagnosticContextAsync; _messageTemplate = new MessageTemplateParser().Parse(options.MessageTemplate); _logger = options.Logger?.ForContext(); _includeQueryInRequestPath = options.IncludeQueryInRequestPath; @@ -54,31 +56,58 @@ public async Task Invoke(HttpContext httpContext) if (httpContext == null) throw new ArgumentNullException(nameof(httpContext)); var start = Stopwatch.GetTimestamp(); - var collector = _diagnosticContext.BeginCollection(); + var logger = _logger; + var level = LogEventLevel.Information; // only used if _getLevel throws an exception + double elapsedMs; + try { await _next(httpContext); - var elapsedMs = GetElapsedMilliseconds(start, Stopwatch.GetTimestamp()); + elapsedMs = GetElapsedMilliseconds(start, Stopwatch.GetTimestamp()); var statusCode = httpContext.Response.StatusCode; - LogCompletion(httpContext, collector, statusCode, elapsedMs, null); + logger = _logger ?? Log.ForContext(); + level = _getLevel(httpContext, elapsedMs, null); + LogCompletion(httpContext, collector, statusCode, elapsedMs, logger, level, null); } catch (Exception ex) // Never caught, because `LogCompletion()` returns false. This ensures e.g. the developer exception page is still // shown, although it does also mean we see a duplicate "unhandled exception" event from ASP.NET Core. - when (LogCompletion(httpContext, collector, 500, GetElapsedMilliseconds(start, Stopwatch.GetTimestamp()), ex)) + // The elapsedMs is required for calculating the level and for LogCompletion. + // The level is required in the finally block. + when ((elapsedMs = GetElapsedMilliseconds(start, Stopwatch.GetTimestamp())) >= 0 + && (level = _getLevel(httpContext, elapsedMs, ex)) >= 0 + && LogCompletion(httpContext, collector, 500, elapsedMs, logger, level, ex)) { } finally { + await CallEnrichDiagnosticContextAsync(httpContext, logger, level); collector.Dispose(); } } - bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector, int statusCode, double elapsedMs, Exception? ex) + async Task CallEnrichDiagnosticContextAsync(HttpContext httpContext, ILogger? logger, LogEventLevel level) + { + try + { + logger ??= Log.ForContext(); + if (!logger.IsEnabled(level)) return; + + if (_enrichDiagnosticContextAsync != null) + { + await _enrichDiagnosticContextAsync.Invoke(_diagnosticContext, httpContext); + } + } + catch + { + // we want to avoid throwing exceptions in the logging pipeline, so we just swallow them here + } + } + + bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector, int statusCode, double elapsedMs, ILogger? logger, LogEventLevel level, Exception? ex) { - var logger = _logger ?? Log.ForContext(); - var level = _getLevel(httpContext, elapsedMs, ex); + logger ??= Log.ForContext(); if (!logger.IsEnabled(level)) return false; diff --git a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs index d782e6d..e901346 100644 --- a/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs +++ b/src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs @@ -69,6 +69,14 @@ static IEnumerable DefaultGetMessageTemplateProperties(HttpCon /// A callback that can be used to set additional properties on the request completion event. /// public Action? EnrichDiagnosticContext { get; set; } + + /// + /// An async callback that can be used to set additional properties on the request completion event. + /// Can be used in addition to if you need async calls (e.g. for getting the + /// request body) and will be called before the synchronous method. + /// + /// Execution is not guaranteed if an exception occurs during finalizing the diagnostic entries. + public Func? EnrichDiagnosticContextAsync { get; set; } /// /// The logger through which request completion events will be logged. The default is to use the