Serilog ASP.NET Core 出现重复的错误消息

Question

使用 Serilog 的 ASP.NET Core 5 Razor 页面

UseStatusCodePagesWithReExecute 按预期工作，并在进入我的 /CustomError 页面后重新执行页面。

如何抑制对重新执行页面的第二次调用的 Serilog 日志记录？

password-postgres 完整样本

// program.cs
public static void Main(string[] args)
{
    Log.Logger = new LoggerConfiguration()
        // if only do warning, then will get duplicate error messages when an exception is thrown, then again when re-executed
        // we do get 2 error message per single error, but only 1 stack trace
        .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Fatal)
        .Enrich.FromLogContext()
        .WriteTo.Console()
        .CreateLogger();

    try
    {
        Log.Information("Starting up");
        CreateHostBuilder(args).Build().Run();
    }
    catch (Exception ex)
    {
        Log.Fatal(ex, "Application start-up failed");
    }
    finally
    {
        Log.CloseAndFlush();
    }
}

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

然后

public class Startup
{
    public void ConfigureServices(IServiceCollection services)
    {
        // snip
    }

    public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
    {
        if (env.IsDevelopment())
        {
            app.UseDeveloperExceptionPage();
        }
        else
        {
            app.UseExceptionHandler("/CustomError");
        }

        app.UseStaticFiles(); 

        // https://khalidabuhakmeh.com/handle-http-status-codes-with-razor-pages
        // https://andrewlock.net/retrieving-the-path-that-generated-an-error-with-the-statuscodepages-middleware/
        app.UseStatusCodePagesWithReExecute("/CustomError", "?statusCode={0}");

        app.UseRouting();

        // don't want request logging for static files so put this serilog middleware here in the pipeline
        app.UseSerilogRequestLogging(); // <- add this

        app.UseAuthentication();
        app.UseAuthorization();

        app.UseCookiePolicy(new CookiePolicyOptions { MinimumSameSitePolicy = SameSiteMode.Strict });

        app.UseEndpoints(endpoints =>
        {
            endpoints.MapRazorPages();
        });
    }
}

然后

// CustomError.cshtml.cs
[ResponseCache(Duration = 0, Location = ResponseCacheLocation.None, NoStore = true)]
[IgnoreAntiforgeryToken]
public class CustomErrorModel : PageModel
{
    public int? CustomStatusCode { get; set; }

    public void OnGet(int? statusCode = null)
    {
        var feature = HttpContext.Features.Get<IStatusCodeReExecuteFeature>();

        // a non 500 eg 404
        // this can be non page requests eg /js/site-chart.js
        // feature can be null when a 500 is thrown
        if (feature != null)
        {

            //Log.Warning($"Http Status code {statusCode} on {feature.OriginalPath}");
            CustomStatusCode = statusCode;
            return;
        }

        // a 500
        // relying on serilog to output the error
        //var exceptionHandlerPathFeature = HttpContext.Features.Get<IExceptionHandlerPathFeature>();

        // integration tests can call a page where the exceptionHandlerPathFeature can be null
        CustomStatusCode = 500;

        // somewhere else is emitting the Log.Error stacktracke
        //Log.Error($"Exception is {exceptionHandlerPathFeature.Error}");

        //OriginalPath = exceptionHandlerPathFeature.Path;
        //Exception exception = exceptionHandlerPathFeature.Error;
    }

    public void OnPost()
    {
        Log.Warning( "ASP.NET failure - maybe antiforgery. Caught by OnPost Custom Error. Sending a 400 to the user which is probable");
        Log.Warning("Need to take off minimumlevel override in Program.cs for more information");
        CustomStatusCode = 400;
    }
}

错误的重复日志条目，例如 404 - 理想情况下只需要 1 个

更新

感谢 Alan 在下面的回答，我已将 SerilogRequestLogging 放在配置的开头。

 public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
 {

      app.UseSerilogRequestLogging(); 

      if (env.IsDevelopment())
      {
           app.UseDeveloperExceptionPage();
      }
      else
      {
           app.UseExceptionHandler("/CustomError");
      }

      app.UseStaticFiles(); 

      app.UseStatusCodePagesWithReExecute("/CustomError", "?statusCode={0}");

      // snip..
}

这会在日志中提供 2 条 ERR 消息：

我觉得很好。

可能有一种方法可以合并 2 个ERR 条目，但这很简单。这两个条目也适用于不同的概念。请求和例外。

可以像样板文件 Error.cshtml.cs 给出的那样，为每个日志条目提供 RequestId。

RequestId = Activity.Current?.Id ?? HttpContext.TraceIdentifier;

但是，嘿，这个解决方案对我来说已经足够好了。谢谢艾伦！

Answer 1

简答：

为了防止在这种情况下重复记录，您可以将UseSerilogRequestLogging() 之前 UseStatusCodePagesWithReExecute() 放在您的Configure 方法中：

    app.UseSerilogRequestLogging();
    app.UseStatusCodePagesWithReExecute("/CustomError", "?statusCode={0}");

---

长答案：

根据ASP.NET documentation，用于构建中间件的顺序很重要：

在Startup.Configure 方法中添加中间件组件的顺序定义了请求时调用中间件组件的顺序和响应的相反顺序。顺序对于安全性、性能和功能至关重要。

现在，根据Serilog documentation，UseSerilogRequestLogging 将只处理中间件管道中之后出现的组件。

考虑到这一点，我注意到在 Startup 类中，您在 UseStatusCodePagesWithReExecute 之后添加了 UseSerilogRequestLogging 中间件。

UseStatusCodePagesWithReExecute documentation 说它做了两件事：

• 将原始状态码返回给客户端。
• 通过使用备用路径重新执行请求管道来生成响应正文。

换句话说，当您收到错误时，Serilog 似乎不知道第二个请求是由先前的中间件在内部生成的，因此它会记录两者：

• 原始请求
• 第二个，由执行备用路径 (/CustomError) 创建

---

一步一步，当GET 请求到达StatusCode400 端点时，请求管道中会发生以下情况：

1. 请求流程： UseStatusCodePagesWithReExecute -> Serilog -> StatusCode400 endpoint (error happens here)

2. 响应流程： UseStatusCodePagesWithReExecute (error status code, so re-execution kicks in) <- Serilog (logs request) <- StatusCode400 endpoint

3. 重新执行请求流程： UseStatusCodePagesWithReExecute -> Serilog -> CustomError endpoint (no error now, but re-execution preserves the HTTP status code)

4. 重新执行响应流程： UseStatusCodePagesWithReExecute <- Serilog (logs request) <- CustomError endpoint

因此，如果您不想有重复的日志消息，您可以将 Serilog 中间件放在 重新执行之前，这样它只会处理来自它的一个请求（第二个一）：

1. 请求流程： Serilog -> UseStatusCodePagesWithReExecute -> StatusCode400 endpoint (error happens here)

2. 响应流程： Serilog <- UseStatusCodePagesWithReExecute (error status code, so re-execution kicks in) <- StatusCode400 endpoint

3. 重新执行请求流程： Serilog -> UseStatusCodePagesWithReExecute -> CustomError endpoint (no error now, but re-execution preserves the HTTP status code)

4. 重新执行响应流程： Serilog (logs request) <- UseStatusCodePagesWithReExecute <- CustomError endpoint