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

Dav*_*eer 3 c# serilog asp.net-core razor-pages

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

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

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

密码-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>();
        });
}
Run Code Online (Sandbox Code Playgroud)

进而

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();
        });
    }
}

Run Code Online (Sandbox Code Playgroud)

进而

// 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;
    }
}


Run Code Online (Sandbox Code Playgroud)

在此输入图像描述

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

更新

感谢下面艾伦的回答,我将 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..
}

Run Code Online (Sandbox Code Playgroud)

ERR在日志中给出了 2 条消息:

在此输入图像描述

我对此很满意。

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

可以为每个日志条目指定一个,RequestId如样板 Error.cshtml.cs 给出的那样。

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

Run Code Online (Sandbox Code Playgroud)

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

Ala*_*rda 6

简短回答:

为了防止在这种情况下重复记录,您可以在方法中放置UseSerilogRequestLogging() beforeUseStatusCodePagesWithReExecute()Configure

    app.UseSerilogRequestLogging();
    app.UseStatusCodePagesWithReExecute("/CustomError", "?statusCode={0}");
Run Code Online (Sandbox Code Playgroud)

长答案:

根据ASP.NET 文档,用于构建中间件的顺序很重要:

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

现在,根据Serilog 文档,将仅处理中间件管道中出现UseSerilogRequestLogging的组件。

考虑到这一点,我注意到在课堂上,StartupUseSerilogRequestLogging. UseStatusCodePagesWithReExecute

UseStatusCodePagesWithReExecute 文档说它做了两件事:

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

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