SeriLog LogContext.PushProperty not working with OWIN middleware in ASP.Net MVC 5

When using LogContext.PushProperty in an OWIN middleware to add a correlation ID to all log events, it is only added in the middleware, but not added when logging in a controller which I would expect.

Here is the code with the issue reproduced https://github.com/mk0sojo/SerilogOwinBug. It is the Asp.Net MVC on .Net framework template changing the following:

Add Microsoft.Owin.Host.SystemWeb Nuget package to run OWIN middleware in IIS
Add Serlog and Serilog.Sinks.Trace from Nuget
Add a Startup.cs file at the root of the project with the following content:

using Microsoft.Owin;
using Owin;
using Serilog;

[assembly: OwinStartup(typeof(SerilogOwinBug.Startup))]

namespace SerilogOwinBug
{
    public class Startup
    {
        // Running the app produces the following log:
        // 2023-11-28 14:25:35Z [RequestId: 123] Starting middleware. URL: "/"
        // 2023-11-28 14:25:35Z [RequestId: ] Hello from Home Controller
        // 2023-11-28 14:25:37Z [RequestId: 123] Ending middleware. URL: "/"
        //
        // Expecting
        // 2023-11-28 14:25:35Z [RequestId: 123] Starting middleware. URL: "/"
        // 2023-11-28 14:25:35Z [RequestId: 123] Hello from Home Controller
        // 2023-11-28 14:25:37Z [RequestId: 123] Ending middleware. URL: "/"
        public Startup()
        {

            Log.Logger = new LoggerConfiguration()
                .Enrich.FromLogContext()
                .WriteTo.Trace(
                    outputTemplate: "{Timestamp:u} [RequestId: {RequestId}] {Message}"
                 )
                .CreateLogger();
        }
        public void Configuration(IAppBuilder app)
        {
            app.Use<SerilogMiddleware>();
        }
    }
}

Add SerilogMiddleware.cs at the root of the project:

using Microsoft.Owin;
using Serilog.Context;
using Serilog;
using System.Threading.Tasks;

namespace SerilogOwinBug
{
    public class SerilogMiddleware : OwinMiddleware
    {
        public SerilogMiddleware(OwinMiddleware next) : base(next)
        {

        }

        public override async Task Invoke(IOwinContext context)
        {
            using (LogContext.PushProperty("RequestId", "123"))
            {
                Log.Information("Starting middleware. URL: {URL}", context.Request.Path);
                await Next.Invoke(context);
                Log.Information("Ending middleware. URL: {URL}", context.Request.Path);
            }
        }
    }
}

Add a log statement to the HomeController.cs file so it looks like this:

using Serilog;
using System.Web.Mvc;

namespace SerilogOwinBug.Controllers
{
    public class HomeController : Controller
    {
        public ActionResult Index()
        {
            Log.Information("Hello from Home Controller");
            return View();
        }

        public ActionResult About()
        {
            ViewBag.Message = "Your application description page.";

            return View();
        }

        public ActionResult Contact()
        {
            ViewBag.Message = "Your contact page.";

            return View();
        }
    }
}

Run the application and open it in a web browser. Check the logs in the Output window. It would look like this:

iisexpress.exe Information: 0 : 2023-11-28 14:25:35Z [RequestId: 123] Starting middleware. URL: "/"
iisexpress.exe Information: 0 : 2023-11-28 14:25:35Z [RequestId: ] Hello from Home Controller
...
iisexpress.exe Information: 0 : 2023-11-28 14:25:37Z [RequestId: 123] Ending middleware. URL: "/"

Expected behavior Would expect the output to be:

iisexpress.exe Information: 0 : 2023-11-28 14:25:35Z [RequestId: 123] Starting middleware. URL: "/"
iisexpress.exe Information: 0 : 2023-11-28 14:25:35Z [RequestId: 123] Hello from Home Controller
...
iisexpress.exe Information: 0 : 2023-11-28 14:25:37Z [RequestId: 123] Ending middleware. URL: "/"

Solution

May be a duplicate of How to add a request identifier to OWIN requests using Serilog?

Have you tried adding

Enrich.FromLogContext()

to you serilog configuration?

UPDATE: Another option is to implement a custom LogEnricher class:

in SerilogMiddleware.Invoke(IOwinContext context) set request id into the Request:
```
HttpContext.Current.Items["RequestId"] = Guid.NewGuid().ToString();
```

Create a LogEnricher class as:

public class LogEnricher : ILogEventEnricher

Implement the ILogEventEnricher.Enrich method:

 public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
 {
   // get the request id
   string requestid = HttpContext.Current.Items[Constants.RequestId]?.ToString();

   // create the property
   var property = propertyFactory.CreateProperty("RequestId", requestid);

   // add property to event
   logEvent.AddOrUpdateProperty(property);
 }