Merge pull request #349 from serilog/trace-span-dis

Collect trace and span ids in request completion events

Author: nblumhardt

samples/Sample/Program.cs

@@ -1,4 +1,5 @@
 using Serilog;
+using Serilog.Templates;
 
 namespace Sample;
 
@@ -39,6 +40,8 @@ public static IHostBuilder CreateHostBuilder(string[] args) =>
                 .ReadFrom.Configuration(context.Configuration)
                 .ReadFrom.Services(services)
                 .Enrich.FromLogContext()
-                .WriteTo.Console())
+                .WriteTo.Console(new ExpressionTemplate(
+                    // Include trace and span ids when present.
+                    "[{@t:HH:mm:ss} {@l:u3}{#if @tr is not null} ({@tr}:{@sp}){#end}] {@m}\n{@x}")))
             .ConfigureWebHostDefaults(webBuilder => webBuilder.UseStartup<Startup>());
-}
+}

samples/Sample/Sample.csproj

@@ -7,5 +7,9 @@
   <ItemGroup>
     <ProjectReference Include="..\..\src\Serilog.AspNetCore\Serilog.AspNetCore.csproj" />
   </ItemGroup>
+  
+  <ItemGroup>
+    <PackageReference Include="Serilog.Expressions" Version="4.0.0-*" />
+  </ItemGroup>
 
 </Project>

src/Serilog.AspNetCore/AspNetCore/RequestLoggingMiddleware.cs

@@ -32,7 +32,7 @@ class RequestLoggingMiddleware
     readonly Func<HttpContext, string, double, int, IEnumerable<LogEventProperty>> _getMessageTemplateProperties;
     readonly ILogger? _logger;
     readonly bool _includeQueryInRequestPath;
-    static readonly LogEventProperty[] NoProperties = new LogEventProperty[0];
+    static readonly LogEventProperty[] NoProperties = Array.Empty<LogEventProperty>();
 
     public RequestLoggingMiddleware(RequestDelegate next, DiagnosticContext diagnosticContext, RequestLoggingOptions options)
     {
@@ -82,7 +82,6 @@ bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector
 
         if (!logger.IsEnabled(level)) return false;
 
-        // Enrich diagnostic context
         _enrichDiagnosticContext?.Invoke(_diagnosticContext, httpContext);
 
         if (!collector.TryComplete(out var collectedProperties, out var collectedException))
@@ -91,7 +90,19 @@ bool LogCompletion(HttpContext httpContext, DiagnosticContextCollector collector
         // Last-in (correctly) wins...
         var properties = collectedProperties.Concat(_getMessageTemplateProperties(httpContext, GetPath(httpContext, _includeQueryInRequestPath), elapsedMs, statusCode));
 
-        var evt = new LogEvent(DateTimeOffset.Now, level, ex ?? collectedException, _messageTemplate, properties);
+        var (traceId, spanId) = Activity.Current is { } activity ?
+            (activity.TraceId, activity.SpanId) :
+            (default(ActivityTraceId), default(ActivitySpanId));
+
+        var evt = new LogEvent(
+            DateTimeOffset.Now,
+            level,
+            ex ?? collectedException,
+            _messageTemplate,
+            properties,
+            traceId,
+            spanId);
+        
         logger.Write(evt);
 
         return false;

src/Serilog.AspNetCore/Serilog.AspNetCore.csproj

@@ -3,7 +3,7 @@
   <PropertyGroup>
     <Description>Serilog support for ASP.NET Core logging</Description>
     <!-- This must match the major and minor components of the referenced *.Extensions.* packages (and highest supported .NET TFM). -->
-    <VersionPrefix>7.0.0</VersionPrefix>
+    <VersionPrefix>7.0.1</VersionPrefix>
     <Authors>Microsoft;Serilog Contributors</Authors>
     <TargetFrameworks>net462;netstandard2.0;netstandard2.1;net6.0;net7.0</TargetFrameworks>
     <GenerateDocumentationFile>true</GenerateDocumentationFile>
@@ -23,11 +23,11 @@
   </ItemGroup>
 
   <ItemGroup>
-    <PackageReference Include="Serilog" Version="2.12.0" />
+    <PackageReference Include="Serilog" Version="3.1.0-*" />
     <PackageReference Include="Serilog.Sinks.Console" Version="4.0.1" />
     <PackageReference Include="Serilog.Sinks.File" Version="5.0.0" />
     <PackageReference Include="Serilog.Sinks.Debug" Version="2.0.0" />
-    <PackageReference Include="Serilog.Formatting.Compact" Version="1.1.0" />
+    <PackageReference Include="Serilog.Formatting.Compact" Version="2.0.0-*" />
   </ItemGroup>
 
   <ItemGroup>
@@ -36,6 +36,8 @@
     <PackageReference Include="Serilog.Settings.Configuration" Version="7.0.0" />
     <PackageReference Include="Microsoft.Extensions.DependencyInjection" Version="7.0.0" />
     <PackageReference Include="Microsoft.Extensions.Logging" Version="7.0.0" />
+    <!-- Temporary addition to pull in trace/span support -->
+    <PackageReference Include="Serilog.Extensions.Logging" Version="7.0.1-*" />
   </ItemGroup>
 
   <ItemGroup Condition=" '$(TargetFramework)' != 'net462' and '$(TargetFramework)' != 'netstandard2.0' and '$(TargetFramework)' != 'netstandard2.1' ">

test/Serilog.AspNetCore.Tests/SerilogWebHostBuilderExtensionsTests.cs

@@ -164,6 +164,19 @@ WebApplicationFactory<TestStartup> Setup(
 
         return web;
     }
+    
+    [Fact]
+    public async Task RequestLoggingMiddlewareShouldAddTraceAndSpanIds()
+    {
+        var (sink, web) = Setup();
+
+        await web.CreateClient().GetAsync("/resource");
+
+        var completionEvent = sink.Writes.First(logEvent => Matching.FromSource<RequestLoggingMiddleware>()(logEvent));
+
+        Assert.NotNull(completionEvent.TraceId);
+        Assert.NotNull(completionEvent.SpanId);
+    }
 
     (SerilogSink, WebApplicationFactory<TestStartup>) Setup(
         Action<RequestLoggingOptions>? configureOptions = null,