Phobos trace and span are not properly propagated to Serilog contexts

[Aaronontheweb]

From a customer:

Datadog can connect the logs for a trace if the logging context is enriched with dd.trace_id and dd.span_id, so I wrote an extension function for that

 public class OpenTracingContextLogEventEnricher : ILogEventEnricher
    {
        public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
        {
            var tracer = GlobalTracer.Instance;
            if (tracer?.ActiveSpan == null)
                return;

            logEvent.AddPropertyIfAbsent(
                propertyFactory.CreateProperty("dd.trace_id", tracer.ActiveSpan.Context.TraceId));
            logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty("dd.span_id", tracer.ActiveSpan.Context.SpanId));
        }
    }

Unfortunately it did not work as I expected. Akka.net does not add those context properties to the Serilog logs, hence the logs from akka level don’t connect for any trace, though it works nicely in MVC API level.

An example of how this got gets used in concert with the Akka.Logger.Serilog package inside a running Akka.NET actor (pseudo-code):

public sealed class MyTestActor : UntypedActor{
    public override void Receive(object msg){

        using (var span = Context.GetInstrumentation().Tracer.BuildSpan("SomeSubSpan").StartActive())
        {
            // do some handling

            // call the `EnrichLogging` extension method from earlier
            Context.EnrichLogging().Info($"We did a thing");
        }

    }
}

Expected Results

We'd expect to see the Serilog structured logs contain the dd.trace_id and dd.span_id properties populated with the values of the current ITracer.ActiveSpan.Context.TraceId and ITracer.ActiveSpan.Context.SpanId properties respectively.

Actual Results

Those properties are never added to the Serilog context.

Possible Issues

Some thoughts on what could cause this issue:

• the GlobalTracer.Instance in this case is not set, thus all of the properties return null;
• for whatever reason, there is no ActiveSpan in this context;
• the formatting of the LogEvent by the Serilog logger tries to access the ActiveSpan outside of its scope, thus there is non available.

Work-arounds

When setting up the ITracer you're going to pass into Phobos, explicitly set that tracer as the GlobalTracer.Instance:

var tracer = new MockTracer(new ActorScopeManager());
GlobalTracer.Register(tracer);

var phobosConfigBuilder = new PhobosConfigBuilder()
    .WithTracing(t => t.SetTracer(tracer));

var bootstrap = BootstrapSetup.Create()
    .WithActorRefProvider(PhobosProviderSelection.Cluster) // configures Phobos for Akka.Cluster
    .WithConfig(HoconConfig);

// need this to launch our ActorSystem
ActorSystemSetup phobosSetup = PhobosSetup.Create(phobosConfigBuilder).And(bootstrap);
ActorSystem actorSystem = ActorSystem.Create("MySys", phobosSetup);

If the issue is that the Serilog logger is trying to access contextual properties that aren't available when the Serilog logger runs asynchronously, we can work around that issue by closing over the properties from inside the Akka.NET actor, rather than having the Serilog ILogEventEnricher handle it. That way the appropriate span data can be captured during actor execution.

[IgorFedchenko]

Reproduced this issue. The problem is that Serilog is accessing ActiveSpan outside of the scope, and it is null in spite of the fact that it is set on global tracer.

The solution to this is using the following EnrichLogging implementation:

public static ILoggingAdapter EnrichLogging(IUntypedActorContext context)
{
    var tracer = context.GetInstrumentation().Tracer;

    var logger = context.GetLogger<SerilogLoggingAdapter>()
        .ForContext("dd.trace_id", tracer.ScopeManager.Active.Span.Context.TraceId)
        .ForContext("dd.span_id", tracer.ScopeManager.Active.Span.Context.SpanId);

    return logger;
}

Note that you need to get SerilogLoggingAdapter adapter, not just context.GetLogger(), to have ForContext helper working - as stated in the documentation: https://getakka.net/articles/utilities/serilog.html#extensions .