c# - 使用 Microsoft 的 ILogger 时如何将范围包含在 Serilog 的控制台接收器中？

Question

基于 this blog post 中的详细信息来自 Nicholas Blumhardt(我知道，它已经有几年历史了，但我似乎找不到更新的东西)，我希望能够使用以下(最小)配置并将范围自动添加到我的日志事件中，但是，我没有从默认控制台提供程序那里得到任何东西。理想情况下，这只是日志行上的 key=value，但 json blob {"key":"value"} 也可以。

ASP.NET 核心版本:3.1
Serilog 版本:2.10.0
Serilog.AspNetCore 版本:3.4.0

程序.cs

public class Program
{
    public static int Main(string[] args)
    {
        Log.Logger = new LoggerConfiguration()
            .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
            .WriteTo.Console()
            .CreateLogger();

        try
        {
            Log.Information("Starting web host");
            CreateHostBuilder(args).Build().Run();
            return 0;
        }
        catch (Exception ex)
        {
            Log.Fatal(ex, "Host terminated unexpectedly");
            return 1;
        }
        finally
        {
            Log.CloseAndFlush();
        }
    }

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

启动.cs

public class Startup
{
    public Startup(IConfiguration configuration)
    {
        Configuration = configuration;
    }

    public IConfiguration Configuration { get; }

    // This method gets called by the runtime. Use this method to add services to the container.
    public void ConfigureServices(IServiceCollection services)
    {
        services.AddControllers();
    }

    // This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
    public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
    {
        if (env.IsDevelopment())
        {
            app.UseDeveloperExceptionPage();
        }

        app.UseHttpsRedirection();

        app.UseRouting();

        app.UseAuthorization();

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

WeatherForecastController.cs

[ApiController]
[Route("[controller]")]
public class WeatherForecastController : ControllerBase
{
    private static readonly string[] _summaries = { "Freezing", "Bracing", "Chilly", "Cool", "Mild", "Warm", "Balmy", "Hot", "Sweltering", "Scorching" };

    private readonly ILogger<WeatherForecastController> _logger;

    public WeatherForecastController(ILogger<WeatherForecastController> logger)
    {
        _logger = logger;
    }

    [HttpGet]
    public IEnumerable<WeatherForecast> Get()
    {
        var scopeProps = new Dictionary<string, string> { ["dude"] = "123" };
        using (_logger.BeginScope(scopeProps))
        {
            _logger.LogInformation("Hello world!");
        }

        var rng = new Random();
        return Enumerable.Range(1, 5).Select(index => new WeatherForecast
        {
            Date = DateTime.Now.AddDays(index),
            TemperatureC = rng.Next(-20, 55),
            Summary = _summaries[rng.Next(_summaries.Length)]
        })
        .ToArray();
    }
}

日志(请注意“Hello World”行中的任何地方都没有“dude”或“123”)

[15:47:09 INF] Starting web host
[15:47:11 INF] Now listening on: https://localhost:5001
[15:47:11 INF] Now listening on: http://localhost:5000
[15:47:11 INF] Application started. Press Ctrl+C to shut down.
[15:47:11 INF] Hosting environment: Development
[15:47:11 INF] Content root path: C:\Users\a806228\source\repos\WebApplication10\WebApplication10
[15:47:13 INF] Request starting HTTP/2 GET https://localhost:5001/weatherforecast
[15:47:13 INF] Executing endpoint 'WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)'
[15:47:13 INF] Route matched with {action = "Get", controller = "WeatherForecast"}. Executing controller action with signature System.Collections.Generic.IEnumerable`1[WebApplication10.WeatherForecast] Get() on controller WebApplication10.Controllers.WeatherForecastController (WebApplication10).
[15:47:13 INF] Hello world!
[15:47:13 INF] Executing ObjectResult, writing value of type 'WebApplication10.WeatherForecast[]'.
[15:47:13 INF] Executed action WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10) in 197.2872ms
[15:47:13 INF] Executed endpoint 'WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)'
[15:47:13 INF] Request finished in 533.989ms 200 application/json; charset=utf-8

我也尝试过添加 RenderedCompactJsonFormatter，但这也没有产生我所期望的结果(基于上述博客文章)。

RenderedCompactJsonFormatter 日志(请注意，范围属性嵌套在“范围”属性中，而不是在 json 对象的顶层)。

{"@t":"2021-02-24T23:56:08.5102552Z","@m":"Content root path: \"C:\\Users\\a806228\\source\\repos\\WebApplication10\\WebApplication10\"","@i":"b5d60022","contentRoot":"C:\\Users\\a806228\\source\\repos\\WebApplication10\\WebApplication10","SourceContext":"Microsoft.Hosting.Lifetime"}
{"@t":"2021-02-24T23:56:10.2879619Z","@m":"Request starting HTTP/2 GET https://localhost:5001/weatherforecast  ","@i":"ca22a1cb","Protocol":"HTTP/2","Method":"GET","ContentType":null,"ContentLength":null,"Scheme":"https","Host":"localhost:5001","PathBase":"","Path":"/weatherforecast","QueryString":"","HostingRequestStartingLog":"Request starting HTTP/2 GET https://localhost:5001/weatherforecast  ","EventId":{"Id":1},"SourceContext":"Microsoft.AspNetCore.Hosting.Diagnostics","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":""}
{"@t":"2021-02-24T23:56:10.3924937Z","@m":"Executing endpoint '\"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)\"'","@i":"500cc934","EndpointName":"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)","EventId":{"Name":"ExecutingEndpoint"},"SourceContext":"Microsoft.AspNetCore.Routing.EndpointMiddleware","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":""}
{"@t":"2021-02-24T23:56:10.5410912Z","@m":"Route matched with \"{action = \\\"Get\\\", controller = \\\"WeatherForecast\\\"}\". Executing controller action with signature \"System.Collections.Generic.IEnumerable`1[WebApplication10.WeatherForecast] Get()\" on controller \"WebApplication10.Controllers.WeatherForecastController\" (\"WebApplication10\").","@i":"122b2fdf","RouteData":"{action = \"Get\", controller = \"WeatherForecast\"}","MethodInfo":"System.Collections.Generic.IEnumerable`1[WebApplication10.WeatherForecast] Get()","Controller":"WebApplication10.Controllers.WeatherForecastController","AssemblyName":"WebApplication10","EventId":{"Id":3,"Name":"ControllerActionExecuting"},"SourceContext":"Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker","ActionId":"e2ddfe67-f10f-4720-b5f3-d7219eac02de","ActionName":"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":""}
{"@t":"2021-02-24T23:56:10.5548872Z","@m":"Hello world!","@i":"cc6ac8ad","SourceContext":"WebApplication10.Controllers.WeatherForecastController","ActionId":"e2ddfe67-f10f-4720-b5f3-d7219eac02de","ActionName":"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":"","Scope":[{"dude":"123"}]}
{"@t":"2021-02-24T23:56:10.6437907Z","@m":"Executing ObjectResult, writing value of type '\"WebApplication10.WeatherForecast[]\"'.","@i":"8a1b66c8","Type":"WebApplication10.WeatherForecast[]","EventId":{"Id":1,"Name":"ObjectResultExecuting"},"SourceContext":"Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor","ActionId":"e2ddfe67-f10f-4720-b5f3-d7219eac02de","ActionName":"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":""}
{"@t":"2021-02-24T23:56:10.7730179Z","@m":"Executed action \"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)\" in 181.1047ms","@i":"afa2e885","ActionName":"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)","ElapsedMilliseconds":181.1047,"EventId":{"Id":2,"Name":"ActionExecuted"},"SourceContext":"Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker","ActionId":"e2ddfe67-f10f-4720-b5f3-d7219eac02de","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":""}
{"@t":"2021-02-24T23:56:10.8005134Z","@m":"Executed endpoint '\"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)\"'","@i":"99874f2b","EndpointName":"WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)","EventId":{"Id":1,"Name":"ExecutedEndpoint"},"SourceContext":"Microsoft.AspNetCore.Routing.EndpointMiddleware","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":""}
{"@t":"2021-02-24T23:56:10.8202960Z","@m":"Request finished in 538.2013ms 200 application/json; charset=utf-8","@i":"791a596a","ElapsedMilliseconds":538.2013,"StatusCode":200,"ContentType":"application/json; charset=utf-8","HostingRequestFinishedLog":"Request finished in 538.2013ms 200 application/json; charset=utf-8","EventId":{"Id":2},"SourceContext":"Microsoft.AspNetCore.Hosting.Diagnostics","RequestId":"0HM6P3V0MULJ3:00000001","RequestPath":"/weatherforecast","SpanId":"|705afff2-40607f543d36f77d.","TraceId":"705afff2-40607f543d36f77d","ParentId":""}

此外，我知道我可以在 Serilog 中专门使用 LogContext.PushProperty 方法，但作为库维护者，我真的很想避免这种情况，让我的调用者使用 Microsoft 的 ILogger 接口(interface)(和范围)与 ASP.NET Core 中的日志记录交互，因为从长远来看，它为我提供了更大的灵 active 。

编辑:我特别关注 Microsoft 的 ILogger 接口(interface)，与 Serilog 无关。我实际上并不关心“上下文”，因为我想围绕“范围”进行标准化——.NET 概念(不是 Serilog 概念)。我不关心这里的所有其他“属性”，因为那是“Serilog”概念，而不是“Microsoft”概念。

将“属性”添加到“outputTemplate”并不是我想要的。通过以下代码这样做:

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .UseSerilog(
            (context, configuration) =>
            {
                configuration.WriteTo.Console(outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj} Properties={Properties:j}{NewLine}{Exception}");
            })
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
        });

像这样创建一个日志行(请注意，范围仍作为特定属性嵌套在属性中)。

[17:39:39 INF] Hello world! Properties={"SourceContext": "WebApplication10.Controllers.WeatherForecastController", "ActionId": "09a79aaf-7b21-46d2-b142-70d17fa41213", "ActionName": "WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)", "RequestId": "0HM6P5OR3IC2K:00000001", "RequestPath": "/weatherforecast", "SpanId": "|1c7f1f94-446bb6d3ebf05f96.", "TraceId": "1c7f1f94-446bb6d3ebf05f96", "ParentId": "", "Scope": [{"dude": "123"}]}

我想要的是以匹配上下文呈现方式的方式呈现日志记录范围。

这是 Serilog 的方法。

// Program.cs
public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .UseSerilog(
            (context, configuration) =>
            {
                // add properties
                configuration
                    .Enrich.FromLogContext()
                    .WriteTo.Console(outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj} {Properties:j}{NewLine}{Exception}");
            })
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
        });

// WeatherForecastController.cs
[HttpGet]
public IEnumerable<WeatherForecast> Get()
{
    // use Serilog's LogContext instead of _logger.BeginScope()
    using (LogContext.PushProperty("dude", 123))
    {
        _logger.LogInformation("Hello world!");
    }

    var rng = new Random();
    return Enumerable.Range(1, 5).Select(index => new WeatherForecast
    {
        Date = DateTime.Now.AddDays(index),
        TemperatureC = rng.Next(-20, 55),
        Summary = _summaries[rng.Next(_summaries.Length)]
    })
    .ToArray();
}

它应该产生与我直接添加到范围时完全相同的日志行(但是，范围嵌套在属性中而不是像我添加的上下文属性那样是顶级属性元素)

[17:51:35 INF] Hello world! {"SourceContext": "WebApplication10.Controllers.WeatherForecastController", "ActionId": "e0997db9-b301-495d-9cfc-7f2d2113f6f2", "ActionName": "WebApplication10.Controllers.WeatherForecastController.Get (WebApplication10)", "RequestId": "0HM6P5VGQ0U9J:00000001", "RequestPath": "/weatherforecast", "SpanId": "|1134d47e-49ed237c257f2857.", "TraceId": "1134d47e-49ed237c257f2857", "ParentId": "", "dude": 123}

Answer 1

我认为您可能会混淆添加属性到上下文/范围与呈现它们。

当您使用 BeginScope 时，您正在添加 日志上下文/范围的属性，它们将被发送到所有 接收器 - 和 < strong>接收器决定如何呈现属性。

从BeginScope 更改为LogContext.PushProperty 不会对接收器呈现 属性的方式产生任何影响。这两种方法同样将属性添加到日志上下文/范围，即接收器不知道(或关心)如何将属性添加到日志事件。

这意味着控制台接收器正确地接收了您正在编写的属性，但它选择不呈现它们，这是因为 default outputTemplate 是:

"[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}"

其中不包含任何上下文信息。您需要在模板中的某处添加 {Properties:j}，以使接收器呈现属性。

例如

const string outputTemplate =
    "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj} {Properties:j}{NewLine}{Exception}";

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
    .WriteTo.Console(outputTemplate: outputTemplate)
    .CreateLogger();

---

关于输出模板的文档:https://github.com/serilog/serilog/wiki/Configuration-Basics#output-templates