Pass-through of `M.E.L.ILogger.BeginScope()` when using custom MEL `ILoggingProvider` as Serilog sink?

[DavidHopkinsFbr]

trafficstars

Hi,

I'm trying to wire up "legacy" custom implementations of Microsoft.Extensions.Logging.ILoggerProvider and Microsoft.Extensions.Logging.ILogger as a Serilog sink.

My Serilog configuration looks like this:

var customProviders = new LoggerProviderCollection();
customProviders.AddProvider(new CustomLoggerProvider());

// Configure Serilog
Log.Logger = new LoggerConfiguration()
      .MinimumLevel.Debug()
      .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
      .Enrich.WithThreadId()
      .Enrich.FromLogContext()
      // Hook up custom providers as Serilog sink
      .WriteTo.Providers(customProviders)
      // More log sinks here
      // [...]
      .CreateLogger();

IHostBuilder builder = Host.CreateDefaultBuilder(args)
      // Configure a stack of other app services
      // [...]
      // Replace default logging providers from Host.CreateDefaultBuilder() with Serilog
      .ConfigureLogging(logBuilder =>
      {
	      logBuilder.SetMinimumLevel(LogLevel.Trace);
	      logBuilder.ClearProviders();
      })
      .UseSerilog(providers: customProviders)

IHost host = builder.Build();

At runtime, my custom logger provider gets called and returns my custom ILogger implementations. So far so good.

This particular logging provider needs some context provided via ILogger.BeginScope() to complete its logging.

But, when I set breakpoints in my custom logger's implementations of ILogger.Log(...) and ILogger.BeginScope(...) methods, the breakpoint inside Log(...) gets hit, but the BeginScope<TState>(...) breakpoint never gets hit. The code being logged definitely calls _logger.BeginScope<TState>(foo) with the state information that the custom logger needs. It looks like Serilog isn't passing the BeginScope<TState>() information on to the CustomLogger instances, so they never get a chance to capture the information they need to complete the logging.

Am I using the APIs incorrectly or is this a bug?

[DavidHopkinsFbr]

I'm running Microsoft.Extensions.Hosting 8.0.0, Microsoft.Extensions.Logging 8.0.0, Serilog.Extensions.Hosting 8.0.0, Serilog.Extensions.Logging 8.0.0, and Serilog 3.1.1, on .NET 8. The host configuration APIs are using the .NET 6 style because I only recently upgraded to .NET 8.

[DavidHopkinsFbr]

I've also tried adding the custom provider via conventional DI injection and then instructing Serilog to write to existing providers, using code like below:

Host.CreateDefaultBuilder(args)
  .ConfigureLogging(logBuilder =>
  {
	  logBuilder.SetMinimumLevel(LogLevel.Trace);
	  logBuilder.ClearProviders();
	  logBuilder.AddProvider(new MessageDatabaseLoggerProvider());
  })
  .UseSerilog(
	  (hostingContext, loggerConfiguration) => ConfigureSerilog(loggerConfiguration), writeToProviders: true);

Serilog doesn't let the custom logger see the ILogger.BeginScope() calls when configured that way, either. If I completely remove the call to .UseSerilog(), then my custom provider does receive the BeginScope() invocations.

[bartelink]

If you're looking to solve this quickly, SO has way more people and is better suited to troubleshooting than GH issues - anyone that watches this repo watches the serilog tag there too

[DavidHopkinsFbr]

Ok thanks. Sorry for any notification spam. Looks like I can get the desired behavior by never calling UseSerilog() and instead adding Serilog as a parallel provider alongside my custom provider, like so:

host.ConfigureLogging(logBuilder =>
		{
			logBuilder.SetMinimumLevel(LogLevel.Trace);
			logBuilder.ClearProviders();
			logBuilder.AddProvider(new MessageDatabaseLoggerProvider());
			logBuilder.AddSerilog();
		});

I'm not sure if the lack of pass-through of BeginScope() with UseSerilog() and provider registration is a bug or by design, but this is a configuration that's working for my use case. I will leave it to project authors to decide if a bug exists; if not, please feel free to close the issue.

[bartelink]

Don't worry about the notification spam; my main concern is stopping the frustration of logging stuff in the official Issues of a high traffic project to be met with crickets. I know SO can quite often feel like it just has a few more crickets for anything that's nontrivial.

Main point is that issues in the Serilog repo necessarily are handled on a very async and intermittent basis, but it's a fact that anyone that's going to be useful in this will probably see it on SO first; whether or not they have time to answer it in the moment is a different matter.

In other words, extending the problem discussion or logging research notes isn't a problem, and I'm not trying to chase you away; just set realistic expectations.