[serilog#389]

Add option to add ElapsedMs to the HttpContext before enrishing diagnostic contect.

Author: jmenziessmith-vemi

src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs

@@ -32,6 +32,7 @@ class RequestLoggingMiddleware
     readonly Func<HttpContext, string, double, int, IEnumerable<LogEventProperty>> _getMessageTemplateProperties;
     readonly ILogger? _logger;
     readonly bool _includeQueryInRequestPath;
+    readonly bool _addElapsedToHttpContext;
     static readonly LogEventProperty[] NoProperties = [];
 
     public RequestLoggingMiddleware(RequestDelegate next, DiagnosticContext diagnosticContext, RequestLoggingOptions options)
@@ -45,6 +46,7 @@ public RequestLoggingMiddleware(RequestDelegate next, DiagnosticContext diagnost
         _messageTemplate = new MessageTemplateParser().Parse(options.MessageTemplate);
         _logger = options.Logger?.ForContext<RequestLoggingMiddleware>();
         _includeQueryInRequestPath = options.IncludeQueryInRequestPath;
+        _addElapsedToHttpContext = options.AddElapsedToHttpContext;
         _getMessageTemplateProperties = options.GetMessageTemplateProperties;
     }
 
@@ -82,6 +84,11 @@ bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector
 
         if (!logger.IsEnabled(level)) return false;
 
+        if (_addElapsedToHttpContext)
+        {
+            httpContext.Items.Add(RequestLoggingOptions.HttpContextItemsElapsedKey, elapsedMs);
+        }
+        
         _enrichDiagnosticContext?.Invoke(_diagnosticContext, httpContext);
 
         if (!collector.TryComplete(out var collectedProperties, out var collectedException))

src/Serilog.AspNetCore/AspNetCore/RequestLoggingOptions.cs

@@ -26,7 +26,7 @@ public class RequestLoggingOptions
 {
     const string DefaultRequestCompletionMessageTemplate =
         "HTTP {RequestMethod} {RequestPath} responded {StatusCode} in {Elapsed:0.0000} ms";
-
+    
     static LogEventLevel DefaultGetLevel(HttpContext ctx, double _, Exception? ex) =>
         ex != null
             ? LogEventLevel.Error
@@ -41,6 +41,11 @@ static IEnumerable<LogEventProperty> DefaultGetMessageTemplateProperties(HttpCon
             new LogEventProperty("StatusCode", new ScalarValue(statusCode)),
             new LogEventProperty("Elapsed", new ScalarValue(elapsedMs))
         ];
+    
+    /// <summary>
+    /// The key used to add the ElapsedMs value to <see cref="HttpContext"/> <c>Items</c> collection
+    /// </summary>
+    public const string HttpContextItemsElapsedKey = "Serilog.AspNetCore.ElapsedMs";
 
     /// <summary>
     /// Gets or sets the message template. The default value is
@@ -80,6 +85,12 @@ static IEnumerable<LogEventProperty> DefaultGetMessageTemplateProperties(HttpCon
     /// that is attached to request log events. The default is <c>false</c>.
     /// </summary>
     public bool IncludeQueryInRequestPath { get; set; }
+    
+    
+    /// <summary>
+    /// Add the elapsed millisecond value to the <see cref="HttpContext"/> <c>Items</c> collection before invoking <c>EnrichDiagnosticContext</c>
+    /// </summary>
+    public bool AddElapsedToHttpContext { get; set; }
 
     /// <summary>
     /// A function to specify the values of the MessageTemplateProperties.

test/Serilog.AspNetCore.Tests/SerilogWebHostBuilderExtensionsTests.cs

@@ -64,6 +64,29 @@ public async Task RequestLoggingMiddlewareShouldEnrich()
         Assert.True(completionEvent.Properties.ContainsKey("Elapsed"));
     }
 
+    
+    [Fact]
+    public async Task RequestLoggingMiddlewareShouldEnrichWithElapsed()
+    {
+        var (sink, web) = Setup(options =>
+        {
+            options.AddElapsedToHttpContext = true;
+            options.EnrichDiagnosticContext += (diagnosticContext, httpContext) =>
+            {
+                var elapsedValue = (double)(httpContext.Items[RequestLoggingOptions.HttpContextItemsElapsedKey] ?? -0.1);
+                diagnosticContext.Set("ElapsedValue", elapsedValue);
+            };
+        });
+
+        await web.CreateClient().GetAsync("/resource");
+
+        Assert.NotEmpty(sink.Writes);
+
+        var completionEvent = sink.Writes.First(logEvent => Matching.FromSource<RequestLoggingMiddleware>()(logEvent));
+
+        Assert.True((double)completionEvent.Properties["ElapsedValue"].LiteralValue()! > 0);
+    }
+    
     [Fact]
     public async Task RequestLoggingMiddlewareShouldEnrichWithCustomisedProperties()
     {