c# - 使用 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 条目，但这很简单。这 2 个条目也适用于不同的概念。请求和异常(exception)。

可以像样板 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 ，用于构建中间件的顺序很重要:

The order that middleware components are added in the Startup.Configure method defines the order in which the middleware components are invoked on requests and the reverse order for the response. The order is critical for security, performance, and functionality.

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

考虑到这一点，我注意到 Startup类，你添加了你的UseSerilogRequestLogging中间件之后 UseStatusCodePagesWithReExecute .

UseStatusCodePagesWithReExecute documentation说它做了两件事:

• Returns the original status code to the client.
• Generates the response body by re-executing the request pipeline using an alternate path.

换句话说，当您遇到错误时，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