Opt-in to TraceId and SpanId enrichment for ASP.NET Core 5.0 logs

[cloudnin9]

Hello, Serilog community. Firstly, thank you for the great library!

Description
I am trying out Asp.Net on Net 5 Preview 7 so I have created 2 web API projects one targeting [netcoreapp3.1] and another targeting [net5]

The problem is when I am looking at logs, I no longer see TraceId and SpanId for the API targeting [net5] with the DotNet 5 preview 7 SDK.

I also tested using the vanilla Logger and there was no issue there. Do I have to configure something, did I just miss something or is the DotNet 5 Preview SDK not fully supported yet?

Thanks for any info.

Reproduction
Below is my bootstrapping code, it is identical for both APIs,

using System.Diagnostics;
using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.Hosting;
using Serilog;
using Serilog.Formatting.Elasticsearch;

namespace WebApplication1
{
    public class Program
    {
        public static void Main(string[] args)
        {
            Activity.DefaultIdFormat = ActivityIdFormat.W3C;
            Log.Logger = new LoggerConfiguration()
                .MinimumLevel.Debug()
                .Enrich.FromLogContext()
                .WriteTo.Console(new ExceptionAsObjectJsonFormatter(renderMessage: true))
                .CreateLogger();
            CreateHostBuilder(args).Build().Run();
        }

        public static IHostBuilder CreateHostBuilder(string[] args) =>
            Host.CreateDefaultBuilder(args)
            .UseSerilog()
                .ConfigureWebHostDefaults(webBuilder =>
                {
                    webBuilder.UseStartup<Startup>();
                });
    }
}

Expected behavior
Be able to see TraceId and SpanId in my logs, regardless of the AspDotnet runtime version

Relevant package, tooling and runtime versions

<Project Sdk="Microsoft.NET.Sdk.Web">

  <PropertyGroup>
    <TargetFramework>net5.0</TargetFramework>
    <UserSecretsId>b7a811b1-eb5a-4655-b19c-5e97c4ae1370</UserSecretsId>
    <DockerDefaultTargetOS>Linux</DockerDefaultTargetOS>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.VisualStudio.Azure.Containers.Tools.Targets" Version="1.10.9" />
    <PackageReference Include="Serilog.AspNetCore" Version="3.4.0" />
	  <PackageReference Include="Serilog.Formatting.Elasticsearch" Version="8.2.0" />
  </ItemGroup>

</Project>

Additional context

[nblumhardt]

Hi! Thanks for the note.

It looks like these just became opt-in in .NET 5, and baked into the logger factory itself, to reduce fixed logging overheads.

Serilog's ASP.NET Core/hosting integration will need a similar opt-in enricher, enabled via UseSerilog() - would be great if anyone following along has time to explore what is required, and spike up an impl.

ASP.NET Core impl PR: dotnet/aspnetcore#11211

[cloudnin9]

Thanks for the very informative reply @nblumhardt.
Should I keep this bug active?
This looks more like a new feature, due to the changes in dotnet.

[nblumhardt]

@naingyelin we'll need to track this, so this ticket is useful, thanks 👍

[techgeek03]

Hi!
I wrote a very simple enricher just to get the values out for now until we have a native solution in Serilog.

public class ActivityEnricher : ILogEventEnricher
    {
        public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
        {
            var activity = Activity.Current;
            
            logEvent.AddPropertyIfAbsent(new LogEventProperty("SpanId", new ScalarValue(activity.GetSpanId())));
            logEvent.AddPropertyIfAbsent(new LogEventProperty("TraceId", new ScalarValue(activity.GetTraceId())));
            logEvent.AddPropertyIfAbsent(new LogEventProperty("ParentId", new ScalarValue(activity.GetParentId())));
        }
    }

    internal static class ActivityExtensions
    {
        public static string GetSpanId(this Activity activity)
        {
            return activity.IdFormat switch
            {
                ActivityIdFormat.Hierarchical => activity.Id,
                ActivityIdFormat.W3C => activity.SpanId.ToHexString(),
                _ => null,
            } ?? string.Empty;
        }

        public static string GetTraceId(this Activity activity)
        {
            return activity.IdFormat switch
            {
                ActivityIdFormat.Hierarchical => activity.RootId,
                ActivityIdFormat.W3C => activity.TraceId.ToHexString(),
                _ => null,
            } ?? string.Empty;
        }

        public static string GetParentId(this Activity activity)
        {
            return activity.IdFormat switch
            {
                ActivityIdFormat.Hierarchical => activity.ParentId,
                ActivityIdFormat.W3C => activity.ParentSpanId.ToHexString(),
                _ => null,
            } ?? string.Empty;
        }
    }

and then used it when configuring Serilog

public static IHostBuilder CreateHostBuilder(string[] args) =>
            Host.CreateDefaultBuilder(args)
                .ConfigureLogging(loggingBuilder =>
                {
                    loggingBuilder.Configure(options =>
                    {
                        options.ActivityTrackingOptions = ActivityTrackingOptions.TraceId | ActivityTrackingOptions.SpanId;
                    });
                })
                .UseSerilog((context, loggerConfiguration) =>
                    loggerConfiguration
                        .ReadFrom.Configuration(context.Configuration)
                        .Enrich.FromLogContext()
                        .Enrich.With<ActivityEnricher>()
                        .Enrich.WithExceptionDetails()
                        .WriteTo.Console(new RenderedCompactJsonFormatter()))
                .ConfigureWebHostDefaults(webBuilder =>
                {
                    webBuilder.UseStartup<Startup>();
                });

However I wonder why Serilog does not get the values from the logging scope automatically. Is it because it is not using LoggerExternalScopeProvider ?

[davidfowl]

However I wonder why Serilog does not get the values from the logging scope automatically. Is it because it is not using LoggerExternalScopeProvider ?

That's correct.

[RehanSaeed]

Is anyone starting this? Otherwise I'll dump @techgeek03's code in a NuGet package called Serilog.Enrichers.Span.

[RehanSaeed]

I rustled up a new NuGet package for this purpose: https://github.com/RehanSaeed/Serilog.Enrichers.Span

[kennethlong]

Just an FYI @techgeek03's code changes work with 3.1 as well. I added a null check when assigning activity in the Enrich method to catch cases where Activity.Current wasn't set. Thanks for this, saved me hours of fiddling! :-)

[RehanSaeed]

Added that check in the 1.0.1 release.

RehanSaeed/Serilog.Enrichers.Span#1