Support ActivityTrackingOptions to enrich logs with Activity tags and baggage

[david-obee]

Hi, I'm raising this initially just as an issue, to check my thinking and see if there would be interest in this feature. If so, then I can potentially have a go at fully implementing this and raising a PR.

Is your feature request related to a problem? Please describe.

The Microsoft.Extensions.Logging library supports automatically enriching your logs with tags and/or baggage from the associated System.Diagnostics Activity at the time of logging. This is enabled by setting the ActivityTrackingOptions setting to either Tags or Baggage (or both). This is as introduced in this PR https://github.com/dotnet/runtime/pull/48722 which comes off the back of this issue https://github.com/dotnet/runtime/issues/46571.

I've found that setting this property doesn't seem to work when I'm using Serilog behind the Microsoft.Extensions.Logging API. Looking into it, I believe the reason is this line here in the Microsoft.Extensions.Logging library:

https://github.com/dotnet/runtime/blob/main/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs#L204

private void AddProviderRegistration(ILoggerProvider provider, bool dispose)
{
    _providerRegistrations.Add(new ProviderRegistration
    {
        Provider = provider,
        ShouldDispose = dispose
    });

    if (provider is ISupportExternalScope supportsExternalScope)
    {
        _scopeProvider ??= new LoggerFactoryScopeProvider(_factoryOptions.ActivityTrackingOptions);

        supportsExternalScope.SetScopeProvider(_scopeProvider);
    }
}

Here, the LoggerFactoryScopeProvider is what does the work of pulling out the tags and baggage defined on the Activity and making available for logging scopes. If the ILoggerProvider supports external scopes, by implementing ISupportExternalScope, then it can receive this LoggerFactoryScopeProvider to use later to enrich its logs.

Unfortunately, it seems that the SerilogLoggerProvider doesn't implement that ISupportExternalScope interface (https://github.com/serilog/serilog-extensions-logging/blob/main/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs), and hence misses out on this feature.

Describe the solution you'd like

Ideally, Serilog could support these Tags and Baggage switches on the ActivityTrackingOptions setting, so that logs can be enriched with tags and baggage from the ongoing Activity.

I don't have much deep experience with Serilog, so I might be a bit naïve here, but I think this might be a relatively straightforward addition to implement the ISupportExternalScope interface.

I think we can modify the Enrich method in SerilogLoggerProvider, with something like (this is a quick sketch of a solution):

public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
{
+    _externalScopeProvider?.ForEachScope((scope, state) =>
+    {
+        if (scope is IEnumerable<KeyValuePair<string, object?>> dict)
+        {
+            foreach (var kvp in dict)
+            {
+                state.AddPropertyIfAbsent(propertyFactory.CreateProperty(kvp.Key, kvp.Value));
+            }
+        }
+    }, logEvent);

    List<LogEventPropertyValue>? scopeItems = null;
    for (var scope = CurrentScope; scope != null; scope = scope.Parent)
    {
        scope.EnrichAndCreateScopeItem(logEvent, propertyFactory, out var scopeItem);

        if (scopeItem != null)
        {
            scopeItems ??= new List<LogEventPropertyValue>();
            scopeItems.Add(scopeItem);
        }
    }

    if (scopeItems != null)
    {
        scopeItems.Reverse();
        logEvent.AddPropertyIfAbsent(new LogEventProperty(ScopePropertyName, new SequenceValue(scopeItems)));
    }
}

where we implement the ISupportExternalScope.SetScopeProvider(IExternalScopeProvider scopeProvider) method by just storing the IExternalScopeProvider as the field _externalScopeProvider like:

public void SetScopeProvider(IExternalScopeProvider scopeProvider)
{
    _externalScopeProvider = scopeProvider;
}

Describe alternatives you've considered

An alternative is to manually define a Serilog enricher, to do the same thing, pulling out tags and baggage and enriching the logs. This is the approach taken by in this blog post: https://www.jimmybogard.com/increasing-trace-cardinality-with-tags-and-baggage/.

However, it would be great if Serilog could support all the available options on the ActivityTrackingOptions setting, and then allow us to rely on Microsoft's implementation for doing this.

[nblumhardt]

Hi @david-obee! I think this would be really interesting to explore.

Is there a chance you can whip up a proof-of-concept pull request we can dig into further?

[david-obee]

Hi @nblumhardt, thanks for the quick response!

I've created the PR #246 which demonstrates the original issue, then tests and implements this. As mentioned I've not contributed to Serilog before, so let me know if there's anything I'm missing and I can fix it up!

[nblumhardt]

Merged; currently in the 8.0.1-dev-* series.

[david-obee]

Hi @nblumhardt, a significant caveat I've only just realized (apologies!). This 'fix' only works if you use the Serilog ILoggerProvider, while sticking with M.E.L implementation of ILoggerFactory.

What I didn't realize sooner is that typically Serilog users are not using the M.E.L implementation of the ILoggerFactory, as Serilog provides it's own separate implementation of ILoggerFactory called SerilogLoggerFactory. I won't cover old ground because I've see that this has already been discussed and justified: https://github.com/serilog/serilog-extensions-logging/issues/183.

The issue is that in my experiment (the new sample service) where I tested this change, I was testing it using the M.E.L ILoggerFactory implementation, just setting up Serilog as a M.E.L provider, not realising that this wasn't really representative of how most people configure Serilog. The SerilogLoggerFactory doesn't provide that same ActivityTracking feature as the M.E.L implementation, so ActivityTrackingOptions are still getting ignored, and this PR doesn't 'fix' that.

So, this change could still be useful for people just using Serilog as a M.E.L provider, but otherwise it's not actually having any effect. Not sure if that changes you're opinion on whether to still include it or not?

[nblumhardt]

Hi David, thanks for looping back. Yes, sorry, I should have mentioned this caveat, too.

It would be great if, at some stage, we can figure out how to get external scope providers into SerilogLoggerFactory, but, I suspect it's something we might just have to live with. Not a major worry, since UseSerilog() provides opportunities to set up enrichers for these kinds of things if desired.