MVC 日志记录范围

Question

我读到在 MVC 中间件框架内部使用带有控制器操作的日志记录范围：

谨慎使用作用域，并且只用于有界的开始和结束的动作。例如，该框架提供了围绕 MVC 操作的范围。避免在另一个范围内嵌套多个范围。

和

作用域是调用 ILogger.BeginScope 方法返回的 IDisposable 类型，从创建的那一刻一直持续到释放。任何日志状态，例如事务 ID，都会在创建时附加到范围。

我正在尝试使用此功能来编写一些日志信息。我执行了以下步骤：

1) 创建 Asp.net 核心 MVC 应用程序
2) 在 appsetting.json
中将属性“IncludeScopes”设置为“true” 3) 像这样创建控制器和操作：

  [Route("api/[controller]")]
public class TodoController : Controller
{
    private readonly ILogger<TodoController> _logger;
    public TodoController(ILogger<TodoController> logger)
    {
        _logger = logger;
    }

    // GET: api/values
    [HttpGet]
    public IEnumerable<string> Get()
    {
        _logger.LogInformation(1000, "Listing all items started");
        Thread.Sleep(2000);
        _logger.LogInformation(1000, "Listing all items finished");
        return new string[] { "value1", "value2" };
    }
}

我希望我的日志消息流始终只包含“列出所有已开始的项目”和“列出所有已完成的项目”部分，它们没有相互分隔。 但是当我同时启动两个请求时，得到的日志流为：

RequestId: xxx 列出所有已开始的项目
RequestId: yyy 列出所有已开始的项目
RequestId: xxx 列出所有已完成的项目
RequestId: yyy 列出所有已完成的项目

这是什么原因？这是正确的行为吗？我在日志记录的上下文中误解了“范围”一词？

Answer 1

日志记录范围有助于创建任何日志语句创建的范围在中，它将有可用的信息。

从ConsoleLogger 开始，IncludeScopes 设置为true：

info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      => RequestId:0HKT6JC0EVFNA RequestPath:/api/values
      Request starting HTTP/1.1 GET http://localhost:5000/api/values
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      => RequestId:0HKT6JC0EVFNA RequestPath:/api/values => WebApplication8.Controllers.ValuesController.Get (WebApplication8)
      Executing action method WebApplication8.Controllers.ValuesController.Get (WebApplication8) with arguments () - ModelState is Valid
info: Microsoft.AspNetCore.Mvc.Internal.ObjectResultExecutor[1]
      => RequestId:0HKT6JC0EVFNA RequestPath:/api/values => WebApplication8.Controllers.ValuesController.Get (WebApplication8)
      Executing ObjectResult, writing value Microsoft.AspNetCore.Mvc.ControllerContext.
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      => RequestId:0HKT6JC0EVFNA RequestPath:/api/values => WebApplication8.Controllers.ValuesController.Get (WebApplication8)
      Executed action WebApplication8.Controllers.ValuesController.Get (WebApplication8) in 322.8533ms
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      => RequestId:0HKT6JC0EVFNA RequestPath:/api/values
      Request finished in 428.477ms 200 application/json; charset=utf-8

如果您注意到上面的日志，这里会为每个日志语句打印RequestId:0HKT6JC0EVFNA（如前所述，作用域或嵌套作用域内的所有日志语句都会从所有这些作用域获取信息）

在 ASP.NET 中默认创建的一些日志范围是如上所示的 RequestId 范围，以及从日志中看到的围绕 MVC 的控制器操作调用的范围（例如这一行：=> WebApplication8.Controllers.ValuesController.Get (WebApplication8)）

如果需要，您也可以自己创建范围：

using (logger.BeginScope("OrderOrchestrationId:{OrderOrchestrationId}", orderOrchestrationId))
{
   // any log statements from here on would have `OrderOrchestrationId` available
}

注意： 默认情况下，所有记录器都不支持范围。在ConsoleLogger 的情况下，它会以文本格式打印出范围，但在接下来讨论的结构化日志记录的情况下，范围确实很出色。

作用域有什么用处？ ASP.NET 日志框架允许你做structured logging。例如，在上面的代码中，{OrderOrchestrationId} 用于此目的。 Serilog 有一个用于 ASP.NET 5 的记录器，它实现了结构化日志记录，使用它，您可以将数据作为 json 数据写入 Azure 的 DocumentDB。 因此，在这种情况下，如果 OrderOrchestrationId 被写入 Azure 的 DocumentDB，您可以使用此 id 搜索日志，这在纯文本文件搜索中很难做到。