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.

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

Add EnrichDiagnosticContextAsync to allow async calls #346

Open
wants to merge 3 commits into
base: dev
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
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
7 changes: 7 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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);
};
});
```

Expand Down
43 changes: 36 additions & 7 deletions src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ class RequestLoggingMiddleware
readonly DiagnosticContext _diagnosticContext;
readonly MessageTemplate _messageTemplate;
readonly Action<IDiagnosticContext, HttpContext>? _enrichDiagnosticContext;
readonly Func<IDiagnosticContext, HttpContext, Task>? _enrichDiagnosticContextAsync;
readonly Func<HttpContext, double, Exception?, LogEventLevel> _getLevel;
readonly Func<HttpContext, string, double, int, IEnumerable<LogEventProperty>> _getMessageTemplateProperties;
readonly ILogger? _logger;
Expand All @@ -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<RequestLoggingMiddleware>();
_includeQueryInRequestPath = options.IncludeQueryInRequestPath;
Expand All @@ -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<RequestLoggingMiddleware>();
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);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I may be off track, but won't this be called after the LogCompletion calls in the try and catch/when blocks?

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<RequestLoggingMiddleware>();
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<RequestLoggingMiddleware>();
var level = _getLevel(httpContext, elapsedMs, ex);
logger ??= Log.ForContext<RequestLoggingMiddleware>();

if (!logger.IsEnabled(level)) return false;

Expand Down
8 changes: 8 additions & 0 deletions src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -69,6 +69,14 @@ public class RequestLoggingOptions
/// A callback that can be used to set additional properties on the request completion event.
/// </summary>
public Action<IDiagnosticContext, HttpContext>? EnrichDiagnosticContext { get; set; }

/// <summary>
/// An async callback that can be used to set additional properties on the request completion event.
/// Can be used in addition to <see cref="EnrichDiagnosticContext"/> if you need async calls (e.g. for getting the
/// request body) and will be called before the synchronous method.
/// </summary>
/// <remarks>Execution is not guaranteed if an exception occurs during finalizing the diagnostic entries.</remarks>
public Func<IDiagnosticContext, HttpContext, Task>? EnrichDiagnosticContextAsync { get; set; }

/// <summary>
/// The logger through which request completion events will be logged. The default is to use the
Expand Down