ASP.Net MVC5中Serilog LogContext.PushProperty在OWIN中间件失效问题

问题原因 #

OWIN中间件的Invoke方法里，LogContext.PushProperty返回的IDisposable作用域会在方法执行完毕后自动释放。而MVC控制器的请求处理是在OWIN管道执行完成后异步触发的，此时原有的LogContext上下文已经失效，导致控制器日志无法获取到RequestId。

解决方案 #

1. 确认Serilog配置启用LogContext增强 #

首先确保Serilog初始化时添加Enrich.FromLogContext()，否则LogContext中的属性不会被注入到日志中：

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

2. 跨OWIN与MVC上下文传递RequestId #

因为OWIN和MVC的执行上下文在异步场景下不共享，需要通过HttpContext.Items中转RequestId，再用MVC的ActionFilter在控制器执行前重建LogContext作用域。

2.1 修改SerilogMiddleware存储RequestId

public class SerilogMiddleware
{
    private readonly Func<IDictionary<string, object>, Task> _next;

    public SerilogMiddleware(Func<IDictionary<string, object>, Task> next)
    {
        _next = next;
    }

    public async Task Invoke(IDictionary<string, object> environment)
    {
        var requestId = "123";
        // 将RequestId存入HttpContext.Items，供后续MVC环节读取
        HttpContext.Current.Items["RequestId"] = requestId;

        using (LogContext.PushProperty("RequestId", requestId))
        {
            Log.Information("Middleware log: Request processed");
            await _next(environment);
        }
    }
}

2.2 编写MVC ActionFilter重建LogContext

public class SerilogRequestIdFilter : ActionFilterAttribute
{
    public override void OnActionExecuting(ActionExecutingContext filterContext)
    {
        if (filterContext.HttpContext.Items.TryGetValue("RequestId", out var requestId))
        {
            // 在控制器执行前推入RequestId到LogContext，作用域覆盖整个Action执行过程
            using (LogContext.PushProperty("RequestId", requestId))
            {
                base.OnActionExecuting(filterContext);
            }
        }
        else
        {
            base.OnActionExecuting(filterContext);
        }
    }
}

2.3 注册全局ActionFilter

打开App_Start\FilterConfig.cs，将过滤器添加到全局集合：

public class FilterConfig
{
    public static void RegisterGlobalFilters(GlobalFilterCollection filters)
    {
        filters.Add(new HandleErrorAttribute());
        filters.Add(new SerilogRequestIdFilter());
    }
}

3. 验证结果 #

修改HomeController的日志代码后运行项目：

public ActionResult Index()
{
    Log.Information("Controller log: Index action executed");
    return View();
}

此时控制器日志会正确携带RequestId: 123，与中间件日志保持一致。

如果不想自定义实现，也可以直接使用Serilog.Web.Classic NuGet包，它内置了RequestId自动增强功能，无需手动编写中间件和过滤器。

内容的提问来源于stack exchange，提问作者Jonas