ASP.NET Core日志

原文:Logging
作者:Steve Smith
翻译:刘怡(AlexLEWIS)
校对:何镇汐许登洋(Seay)

ASP.NET Core 内建支持日志,也允许开发人员轻松切换为他们想用的其他日志框架。尽量用最少的代码来实现应用程序日志,只要做到这点,就能想在哪里加就能在那里加日志记录。

章节:

访问或下载样例代码

在应用程序中实现日志

通过 dependency-injection 请求 ILoggerFactoryILogger<T> 可为应用程序增加日志功能。如果请求了 ILoggerFactory,日志记录器就必须使用它的 CreateLogger 方法,在下例中将展示如何做到这一点:

var logger = loggerFactory.CreateLogger("Catchall Endpoint");
logger.LogInformation("No endpoint found for request {path}", context.Request.Path);

当日志记录器创建时,需要提供类别名称。类别名称指定了日志记录事件的根源。根据约定,这一字符串通过点符号(.)来分割以体现其层次性。一些日志记录提供程序还提供了过滤功能,这使得输出的日志更易被检索。在本文的示例应用程序中,日志被配置为使用内建的 ConsoleLogger (查阅下文的 在应用程序中配置日志_ 一节)。使用 dotnet run 命令运行应用程序,并请求已配置的 URL(localhost:5000),查看运行中的控制台记录器。你将看到如下输出:

你可能会发现每次通过浏览器发出一个 Web 请求都会产生超过一条日志记录,这是因为大多数浏览器尝试加载一个页面的时候会发出多个请求(既请求网站的图标文件)。注意一点,在控制台记录器显示的日志级别(比如上图中的 info),然后是类别([Catchall Endpoint]),最后是日志消息。

日志方法被调用时,可以利用命名占位符(如 {path} )来实现格式化。按照方法调用时传入参数的顺序一一填充出现在其中的占位符。一些日志提供程序会用一个字典来保存名称和映射值以供以后使用。在下例中,请求路径通过命名占位符传入:

logger.LogInformation("No endpoint found for request {path}", context.Request.Path);

在实际的应用程序中,你会希望基于应用程序级别来添加日志,而不是基于框架级别或事件。例如,你创建了一个 Web API 应用程序来管理 To-Do 条目(参见 用 Visual Studio 和 ASP.NET Core MVC 创建首个 Web API ),你可能会为这些条目的各种操作添加日志记录。

对于 API 的逻辑部分被包含在 TodoController 中,在构造函数中通过依赖注入( dependency-injection )的方式来请求需要的服务。理想情况下,类应当像这个例子一样使用构造函数来 显式定义它们的依赖项 并使其作为参数传入,而不是请求 ILoggerFactory 并显式创建 ILogger 实例。 TodoController 展示了另一种应用程序使用日志记录器的方法——通过请求 ILogger<T> (其中 T 是所请求的记录器的类)。

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

    public TodoController(ITodoRepository todoRepository, 
        ILogger<TodoController> logger)
    {
        _todoRepository = todoRepository;
        _logger = logger;
    }

    [HttpGet]
    public IEnumerable<TodoItem> GetAll()
    {
        _logger.LogInformation(LoggingEvents.LIST_ITEMS, "Listing all items");
        EnsureItems();
        return _todoRepository.GetAll();
    }

在每个控制器 Action 内,通过本地字段 _logger (上例第 17 行所示)来记录日志。这种技术并不仅限于控制器内,通过 dependency-injection 它能被用于应用程序内所有的服务中。

使用 ILogger

如您所见,应用程序可通过构造函数请求到 ILogger<T> 实例,其中 T 是执行日志记录的类型。TodoController 就是用了这种方法。当使用这种技术时,日志记录器会自动使用该类型的名称作为其日志类别的名称。通过请求 ILogger<T> 实例,类自己不必通过 ILoggerFactory 来实例化日志记录器。这种方法可以用在所有的地方——而不必使用 ILoggerFactory

日志记录级别

当应用程序添加一条日志记录时,必须指定 日志级别 。日志级别允许你控制应用程序输出日志的详细程度,以及把不同类型的日志传送给不同的日志记录器。比方说,你可能会希望调试消息在一个本地文件,而把错误消息记录到计算机的事件日志或数据库中。

ASP.NET Core 详尽地定义了六个日志级别,通过增加重要性或严重程度排序:

Trace
用于记录最详细的日志消息,通常仅用于开发阶段调试问题。这些消息可能包含敏感的应用程序数据,因此不应该用于生产环境。默认应禁用。举例:Credentials: {"User":"someuser", "Password":"P@ssword"}

Debug
这种消息在开发阶段短期内比较有用。它们包含一些可能会对调试有所助益、但没有长期价值的信息。默认情况下这是最详细的日志。举例: Entering method Configure with flag set to true

Information
这种消息被用于跟踪应用程序的一般流程。与 Verbose 级别的消息相反,这些日志应该有一定的长期价值。举例: Request received for path /foo

Warning
当应用程序出现错误或其它不会导致程序停止的流程异常或意外事件时使用警告级别,以供日后调查。在一个通用的地方处理警告级别的异常。举例: Login failed for IP 127.0.0.1FileNotFoundException for file foo.txt

Error
当应用程序由于某些故障停止工作则需要记录错误日志。这些消息应该指明当前活动或操作(比如当前的 HTTP 请求),而不是应用程序范围的故障。举例: Cannot insert record due to duplicate key violation

Critical
当应用程序或系统崩溃、遇到灾难性故障,需要立即被关注时,应当记录关键级别的日志。举例:数据丢失、磁盘空间不够等。

Logging 包为每个 LogLevel 值提供 helper 扩展方法 ,允许你调用,例如, LogInformation ,而不是更多详尽的 Log(LogLevel.Information, ...) 方法。每个 LogLevel - 特定扩展方法有多个重载,允许你传递下面的一些或者是所有的参数:

string data
记录消息。

EventId eventId
使用数字类型的 id 来标记日志,这样可以将一系列的事件彼此相互关联。被记录的事件 ID 应该是静态的、特定于指定类型时间的。比如,你可能会把添加商品到购物车的事件 ID 标记为 1000,然后把结单的事件 ID 标记为 1001,以便能智能过滤并处理这些日志记录。

string format
日志消息的格式字符串。

object[] args
用于格式化的一组对象。

Exception error
用于记录的异常实例。

注解
EventId 类型可以隐式转换为 int ,所以,你可以传递一个 int 参数。

注解
像本文中所使用的 ConsoleLogger 这类内建的日志记录器会忽略 eventId 参数。如果你需要显示它,你可以把它包含在消息文本内。在下例中你可以轻松发现 eventId 被关联到每一条消息,但实际上你通常不会将它包含在日志信息中。

TodoController 这个例子中,事件 id 常数为每一个事件定义,根据操作是否成功配置日志语句的详细级别。在这种情况下,成功操作记录为 Information,数据未发现则记录为 Warning (不显示错误处理)。

[HttpGet]
public IEnumerable<TodoItem> GetAll()
{
    _logger.LogInformation(LoggingEvents.LIST_ITEMS, "Listing all items");
    EnsureItems();
    return _todoRepository.GetAll();
}

[HttpGet("{id}", Name = "GetTodo")]
public IActionResult GetById(string id)
{
    _logger.LogInformation(LoggingEvents.GET_ITEM, "Getting item {0}", id);
    var item = _todoRepository.Find(id);
    if (item == null)
    {
        _logger.LogWarning(LoggingEvents.GET_ITEM_NOTFOUND, "GetById({0}) NOT FOUND", id);
        return NotFound();
    }
    return new ObjectResult(item);
}

注解
建议在应用程序及其 API 上执行应用程序日志记录,而不是在框架级别上记录。框架已经有了一个内建的能够简单通过设置启用相应日志级别的日志记录器了。

要查看框架级别的详细日志,可以为日志提供程序调整为指定的日志级别,这样就能得到更为详细的日志记录(如 DebugTrace)。比如,如果你在 Configure 方法中修改 AddConsole 调用的日志级别,改为使用 LogLevel.Trace 并运行应用程序的话,框架级别的每个请求详细日志就会像下图这般显示:

控制台记录器输出时使用前缀「dbug: 」,默认的框架没有追踪的记录器,每一个日志级别都有使用对应的四个字符的前缀,使得日志信息始终一致。

Criticalcrit
Errorfail
Warningwarn
Informationinfo
Debugdbug
Tracetrce

作用域

在应用程序记录日志信息的过程中,你可以将一组逻辑操作用 作用域 打包为一组。作用域也是一种 IDisposable 类型,通过调用 ILogger.BeginScope<TState> 方法来返回,它自创建起持续到释放为止。内建的 TraceSource 日志记录器会返回一个作用域实例用来响应启动与停止跟踪操作。任何诸如事务 ID 这样的日志状态从刚创建便关联到作用域了。

作用域不是必须的,而且需要谨慎使用。它们适合用于具有比较明显的开始和结束的操作,比如在一个事务中调用多个资源。

在应用程序中配置日志

为在 ASP.NET 应用程序中配置日志,你须在 StartupConfigure 方法中解析 ILoggerFactory。ASP.NET 会基于 dependency-injection 以参数的形式自动为 Configure 方法提供 ILoggerFactory 实例。当你把 ILoggerFactory 添作参数时,在 Configure 中,通过在日志记录器工厂上调用方法(或扩展方法)来配置日志记录器。我们已在本文开头处看到,通过简单地调用 loggerFactory.AddConsole 来加入控制台日志记录。除了添加日志记录器,你还可以通过设置日志记录器工厂的 MinimumLevel 属性来控制应用程序日志的详细程度。默认的详细程度是 Verbose

    public void Configure(IApplicationBuilder app,
        IHostingEnvironment env,
        ILoggerFactory loggerFactory)

一旦你以参数的形式添加了 ILoggerFactory,就配置了一个带有日志记录器工厂方法(或扩展方法)的日志记录器。我们已经看到在这篇文章开头的配置例子里,我们通过调用 loggerFactory.AddConsole 添加控制台日志记录。

注解
你可以选择配置日志记录,当设置 hosting 时,而不是在启动时。

每个记录器为 ILoggerFactory 提供了自己的一套扩展方法。控制台,调试和事件日志记录器允许你指定那些应该写的日志消息的最低日志记录级别。控制台和调试记录器根据自己的日志记录级别和/或类别提供的扩展方法接受一个函数来过滤日志消息(例如: logLevel => logLevel >= LogLevel.Warning 或者 (category, loglevel) => category.Contains("MyController") && loglevel >= LogLevel.Trace )。事件日志记录器提供了类似重载接受一个 EventLogSettings 实例作为参数,其 Filter 属性可包含过滤方法。该 TraceSource 记录器不提供任何的重载,因为它的记录级别和其他参数基于他使用的 SourceSwitchTraceListener

一个 LoggerFactory 实例可以选择性地使用自定义 FilterLoggerSettings 配置。下面的示例配置自定义日志级别不同的范围,限制系统和微软内置的日志记录警告,同时允许应用程序在默认情况下记录调试级别的。 WithFilter 方法返回一个新的 ILoggerFactory ,将过滤传递的所有注册的记录器日志信息。它不会影响其它的任何 ILoggerFactory 实例,包括原始的 ILoggerFactory 实例。

loggerFactory
    .WithFilter(new FilterLoggerSettings
    {
        { "Microsoft", LogLevel.Warning },
        { "System", LogLevel.Warning },
        { "ToDoApi", LogLevel.Debug }
    })
    .AddConsole();

配置 TraceSource 日志

当运行在完整的 .NET 框架之上时,你可以使用现有的 System.Diagnostics.TraceSource 类库和提供程序来配置日志,包括轻松访问到 Windows 事件日志。TraceSource 允许你将消息路由到不同的监听器上,而这已经被很多组织所使用。

首先,确保项目已添加了 Microsoft.Extensions.Logging.TraceSource 包(在 project.json 中),与将使用的任何指定的追踪源代码包(这个例子中: TextWriterTraceListener ):

  "Microsoft.AspNetCore.Mvc": "1.0.0",
  "Microsoft.AspNetCore.Server.Kestrel": "1.0.0",
  "Microsoft.AspNetCore.Server.IISIntegration": "1.0.0",
  "Microsoft.AspNetCore.StaticFiles": "1.0.0",
  "Microsoft.Extensions.Logging": "1.0.0",
  "Microsoft.Extensions.Logging.Console": "1.0.0",
  "Microsoft.Extensions.Logging.Filter": "1.0.0",
  "Microsoft.Extensions.Logging.TraceSource": "1.0.0"
},
"tools": {
  "Microsoft.AspNetCore.Server.IISIntegration.Tools": {

在下例中演示了如何在一个应用程序中配置一个的 TraceSourceLogger 实例,日志都只记录 Warning 或者是更高级别的消息。每次调用 AddTraceSource 都需要一个 TraceListener 。调用配置了一个 TextWriterTraceListener,用于将日志写到控制台窗体。这一日志输出将附加于已在本例中添加了的控制台日志,但它们的行为略有不同。

// add Trace Source logging
var testSwitch = new SourceSwitch("sourceSwitch", "Logging Sample");
testSwitch.Level = SourceLevels.Warning;
loggerFactory.AddTraceSource(testSwitch,
    new TextWriterTraceListener(writer: Console.Out));

sourceSwitch 是使用 SourceLevels.Warning 配置的,因此,仅 Warning (或更高) 日志信息被 TraceListener 实例提取。
当指定的 id 没有找到时,下面 API 行为会记录一个警告信息:

using System.Collections.Generic;
using System.Linq;
using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.Logging;
using TodoApi.Core;
using TodoApi.Core.Interfaces;
using TodoApi.Core.Model;

namespace TodoApi.Controllers
{
    [Route("api/[controller]")]
    public class TodoController : Controller
    {
        private readonly ITodoRepository _todoRepository;
        private readonly ILogger<TodoController> _logger;

        public TodoController(ITodoRepository todoRepository, 
            ILogger<TodoController> logger)
        {
            _todoRepository = todoRepository;
            _logger = logger;
        }

        [HttpGet]
        public IEnumerable<TodoItem> GetAll()
        {
            _logger.LogInformation(LoggingEvents.LIST_ITEMS, "Listing all items");
            EnsureItems();
            return _todoRepository.GetAll();
        }

        [HttpGet("{id}", Name = "GetTodo")]
        public IActionResult GetById(string id)
        {
            _logger.LogInformation(LoggingEvents.GET_ITEM, "Getting item {0}", id);
            var item = _todoRepository.Find(id);
            if (item == null)
            {
                _logger.LogWarning(LoggingEvents.GET_ITEM_NOTFOUND, "GetById({0}) NOT FOUND", id);
                return NotFound();
            }
            return new ObjectResult(item);
        }

        [HttpPost]
        public IActionResult Create([FromBody] TodoItem item)
        {
            if (item == null)
            {
                return BadRequest();
            }
            _todoRepository.Add(item);
            _logger.LogInformation(LoggingEvents.INSERT_ITEM, "Item {0} Created", item.Key);
            return CreatedAtRoute("GetTodo", new { controller = "Todo", id = item.Key }, item);
        }

        [HttpPut("{id}")]
        public IActionResult Update(string id, [FromBody] TodoItem item)
        {
            if (item == null || item.Key != id)
            {
                return BadRequest();
            }

            var todo = _todoRepository.Find(id);
            if (todo == null)
            {
                _logger.LogWarning(LoggingEvents.GET_ITEM_NOTFOUND, "Update({0}) NOT FOUND", id);
                return NotFound();
            }

            _todoRepository.Update(item);
            _logger.LogInformation(LoggingEvents.UPDATE_ITEM, "Item {0} Updated", item.Key);
            return new NoContentResult();
        }

        [HttpDelete("{id}")]
        public void Delete(string id)
        {
            _todoRepository.Remove(id);
            _logger.LogInformation(LoggingEvents.DELETE_ITEM, "Item {0} Deleted", id);
        }

        private void EnsureItems()
        {
            if (!_todoRepository.GetAll().Any())
            {
                _logger.LogInformation(LoggingEvents.GENERATE_ITEMS, "Generating sample items.");
                for (int i = 1; i < 11; i++)
                {
                    _todoRepository.Add(new TodoItem() { Name = "Item " + i });
                }
            }
        }
    }
}

为了测试这个代码,你通过运行控制台应用程序并导航到 http://localhost:5000/api/Todo/0 可以触发记录警告。你应该看到类似以下的输出:

以"warn: "为前缀的黄线,随着后面的行,是由 ConsoleLogger 输出。以 “TodoApi.Controllers.TodoController” 开始的下一行,是由 TraceSource logger 输出。还有其他可用的 TraceSource,并且 TextWriterTraceListener 可以通过 TextWriter 实例配置,这对于记录是一个非常灵活的选择。

配置其它提供程序

除内置日志记录器外,你可以配置其它提供商提供的日志。将相应的包添加到 project.json 文件中,并以上文同样的方法配置它们。通常情况下,这些包应该会包含 ILoggerFactory 的扩展方法以便能方便地添加它们。

你也可以创建自己定制的提供程序来支持其他的日志框架或自己内部的日志需求。

日志记录建议

当你在 ASP.NET Core 应用程序中实现日志时可以参考以下有用建议:

  1. 使用正确的 LogLevel ,这将使不同重要级别的日志消息使用和路由到相关的输出目标。

  2. 记录的日志信息要能立即识别问题所在,剔除不必要的冗余信息。

  3. 保证日志内容简单明了,直指重要信息。

  4. 尽管日志记录器被禁用后将不记录日志,但也请在日志方法的周围增加控制代码,以防止多余的方法调用和日志设置的开销,特别是在循环和对性能要求比较高的方法中。

  5. 使用独有的前缀命名日志记录器以确保能快速过滤或禁用。谨记 Create<T> 扩展方法将创建的日志记录器使用该类的完全限定名作为日志记录器的类别名。

  6. 使用作用域时保持谨慎,明晰动作的开始和结束的界限(比如框架提供的 MVC Action 的范围),避免相互嵌套。

  7. 应用程序日志代码应关注应用程序 的业务。提高日志的详细程度级别来记录框架相关的问题,而不是日志记录器自己。

总结

ASP.NET Core 提供了内建支持的日志,能方便地通过 Startup 类来配置,并在应用程序中使用。日志记录的详细程序可以在全局配置,也可以为每个日志提供程序单独配置,以确保可操作信息能恰当地被记录下来。框架内建了控制台和跟踪源的日志提供程序;另外其他的日志框架也可以被方便配置。