Properties added to LogContext disappear when throwing exceptions

[ThomasArdal]

I have a problem with disappearing properties, added to the LogContext in ASP.NET Core. I have an ASP.NET Core 3.1 application with Serilog added in the Program.cs file:

Log.Logger = new LoggerConfiguration()
    .WriteTo.File(...)
    .Enrich.FromLogContext()
    .CreateLogger();

And configuring the Serilog.AspNetCore package:

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
            webBuilder.UseSerilog();
        });

In a piece of middleware, I want to add a simple property for all web requests to the LogContext:

public class MyMiddleware
{
    private readonly RequestDelegate _next;

    public MyMiddleware(RequestDelegate next)
    {
        _next = next;
    }

    public async Task Invoke(HttpContext context)
    {
        using (LogContext.PushProperty("hello", "world"))
            await _next.Invoke(context);
    }
}

Then, installing the middleware in the Startup.cs file:

app.UseMiddleware<MyMiddleware>();

When logging using:

public IHttpActionResult Index()
{
    logger.LogError("Uh oh");
    return View();
}

Then inspect the output to the configured Serilog sink(s), shows the hello property as part of the log message as expected. But if I throw an exception inside an MVC controller (rather than calling one of the Log* methods manually:

public IHttpActionResult Index()
{
    throw new Exception("Uh oh");
}

And then inspect the output to the sinks, the hello property is not there.

I have put a breakpoint inside the custom middleware and see that it is called in both cases and adding the property to LogContext. Can someone maybe help track down why this is happening?

I'm not 100% sure if this issue is related to the Serilog.AspNetCore package. But since it is happening when this package is added to an ASP.NET Core project, I believe it might be the case.

BTW: I thought this issue sounded like something similar. I did try to replace the LogContext with a Microsoft.Extensions.Logging scope. Same behavior. The property is there when logging manually but not when throwing an exception.

[nblumhardt]

Serilog's RequestLoggingMiddleware uses a trick to achieve what you want; it sounds like you might be relying on the default request logging from ASP.NET Core, which (IIRC) doesn't do this.

The core problem is that without the when trick, the stack has already been unwound (and LogContext popped) before the outermost exception handler is invoked. HTH~!

[ThomasArdal]

Thank you so much, @nblumhardt. I wasn't aware of the LogContext being popped but I was suspecting something like that to happen. Very nice with an explanation and even an example of how to fix it.

Thanks again and closing the issue 👍