Logging provider greedily caches NoOpTracer if app startup consumes logging

[tillig]

Summary

The OpenTracingLoggerProvider greedily caches the global tracer, causing a race condition when setting up Jaeger.

Details

When setting up the Jaeger C# client using environment-based configuration, the Jaeger system wants an ILoggerFactory so it can log information about startup.

This looks like this in your ASP.NET Core Startup class:

public void ConfigureServices(IServiceCollection services)
{
    services.AddSingleton<ITracer>(serviceProvider =>
            {
                var logFactory = serviceProvider.GetRequiredService<ILoggerFactory>();
                var config = Jaeger.Configuration.FromEnv(logFactory);
                var tracer = config.GetTracerBuilder().Build();
                GlobalTracer.Register(tracer);
                return tracer;
            });
}

When the ILoggerFactory gets resolved, it also resolves all of the logger providers that are registered - this includes the OpenTracingLoggerProvider.

When the OpenTracingLoggerProvder is resolved, it greedily caches the global tracer instance which, as you can see, hasn't actually been set up yet.

The net result of this is that no log messages ever get piped to the OT logger because the cached trace instance is always the NoOpTracer.

Proposal

One of two solutions would address this:

1. Get the tracer when the logger is created, not the log provider. Instead of resolving the global tracer in the constructor of the OpenTracingLoggerProvider resolve the tracer in the OpenTracingLoggerProvider.GetLogger method just before the logger itself is created.
2. Pass the accessor to the logger and resolve as needed. Instead of the OpenTracingLoggerProvider doing any resolution of the global tracer, have the provider pass the accessor to each logger. Have the logger resolve the tracer as needed rather than caching it at all.

I think option 2 may be slightly safer since it'd avoid race conditions where other ASP.NET Core components may also need to log information at startup and then later also log more information that we may want caught by tracing.

I think option 1 appears that it may be more performant but since accessing the global trace is really just a static property access, it's likely negligible.

[tillig]

I also noticed there's a TODO in the TracerExtensions to update to use the public NoOpTracer types if that was ever released; it's released in v0.12.0 of OpenTracing which is already a dependency.

This is relevant because the logger uses this information to determine if logging is enabled.

[austinlparker]

A fix for this was released in v0.6.1, available now. Thanks!