Result of LogContext.Clone() is not usable outside of BeginScope()

[Tolyandre]

Hi, I'm trying to capture Serilog's context on exception throw to log it later in an exception handler. I use LogContext.Clone() to save context. I've managed to do this when properties are pushed with pure Serilog, e.g. LogContext.Push(new PropertyEnricher("Name", "Pizza")). Unfortunately, that didn't work for framework's logger.BeginScope(..)

I ended up with this example (peeked SerilogLoggerTests.cs):

[Fact]
public void LogContextCloneShouldSaveScope()
{
    var sink = new SerilogSink();

    Microsoft.Extensions.Logging.ILogger logger =
        new SerilogLoggerProvider(
            new LoggerConfiguration()
            .Enrich.FromLogContext()
            .WriteTo.Sink(sink)
            .CreateLogger())
        .CreateLogger(Name);

    ILogEventEnricher context;

    //using (Serilog.Context.LogContext.Push(new PropertyEnricher("Name", "pizza")))  <--- works
    using (logger.BeginScope(new FoodScope("pizza")))  // doesn't work
    {
        logger.Log(LogLevel.Information, 0, TestMessage, null, null);

        context = Serilog.Context.LogContext.Clone();
    }

    using (Serilog.Context.LogContext.Push(context))
    {
        logger.Log(LogLevel.Information, 0, TestMessage, null, null);
    }

    Assert.Equal(2, sink.Writes.Count);
    Assert.Equal("\"pizza\"", sink.Writes[0].Properties["Name"].ToString());
    Assert.Equal("\"pizza\"", sink.Writes[1].Properties["Name"].ToString());  // <--- No property here
}

It seems because BeginScope() stores state in AsyncLocal<> and is not just a proxy to LogContext.Push().

[nblumhardt]

Hi - yes, this is the expected behavior - SerilogLoggerProvider doesn't map BeginScope() 1:1 onto Serilog LogContext.Push() calls because it needs to work in the absence of LogContext.

We could introduce a new implementation when SerilogLoggerFactory is used, since it enables the "thin wrapper" you're possibly envisaging - would be a worthwhile concept to spike out.

[Tolyandre]

New implementation should be enabled explicitly, right? So if my test asp.netcore configuration looks like:

public void ConfigureServices(IServiceCollection services)
{
    services.AddControllers();
    services.AddLogging(loggingBuilder =>
        loggingBuilder.AddSerilog(
            new LoggerConfiguration()
                .Enrich.FromLogContext()
                .Enrich.With<ThrowContextEnricher>()
                .WriteTo.File(new CompactJsonFormatter(), "log.txt")
                .CreateLogger(),
            dispose: true));
}

how it would be changed?

I probably can try to make a pull request with the new implementation (during the next two weeks). Let me know if I supposed to do this. I have so far only doubt what the signature should be to enable it

[skomis-mm]

A more generilized approach for capturing/restoring ambient context also can be used:

context = ExecutionContext.Capture(); // captures all AsyncLocal-s as well
...
// using (Serilog.Context.LogContext.Push(context))
ExecutionContext.Run(context, delegate { 
    logger.Log(LogLevel.Information, 0, TestMessage, null, null); // restores AsyncLocal-s 
}, null);

Might be worth to check if it fits your needs.

[Tolyandre]

Actually, ExecutionContext.Capture() approach works for me. Thank you for the suggestion. It seems my issue is resolved for now.

Btw, I put my code here https://github.com/Tolyandre/serilog-throw-context-enricher, thou not tested yet for performance or memory leaks.