• 项目

2016 年 4 月

第 31 卷，第 4 期

必备 .NET - 使用 .NET Core 的日志记录

作者 Mark Michaelis

Mark Michaelis在 2 月份期刊中，我探讨了新命名的 .NET Core 1.0 平台中包含的新配置 API（请参阅 bit.ly/1OoqmkJ）。（我认为大多数读者都已听说过最近重命名的 .NET Core 1.0，以前称为.NET Core 5 和 ASP.NET 5 平台的一部分 [请参阅 bit.ly/1Ooq7WI]。） 在那篇文章中我使用了单元测试，以便探索 Microsoft.Extensions.Configuration API。在这篇文章中我使用了类似的方法（Microsoft.Extensions.Logging 除外）。我的方法中的主要区别是，我从 .NET 4.6 CSPROJ 文件进行测试，而不是从 ASP.NET Core 项目。这强调了一个事实，.NET Core 可供您立刻使用，即使您没有迁移到 ASP.NET Core 项目也立刻使用。

日志记录？ 我们究竟为何需要一个新的记录框架？ 我们已经拥有了 NLog、Log4Net、Loggr、Serilog 和内置 Microsoft.Diagnostics.Trace/Debug/TraceSource。这只是其中一些例子而已。事实证明，存在如此之多的记录框架实际上是使 Microsoft.Exten­sions.Logging 相关的驱动因素之一。作为一个面对无数选择的开发人员，您很可能选择一个熟悉的，稍后您可能不得不切换到另一个。因此，您很可能想要编写您自己的记录 API 包装器，以调用您或您的公司本周选择的任何特定记录框架。类似地，您可能在您的应用程序中使用一个特定的记录框架，却发现您要利用的库之一正在使用另一个记录框架，致使您不得不编写一个侦听器，用于将消息从一个记录框架传递到另一个记录框架。

Microsoft 使用 Microsoft.Extensions.Logging 提供的正是这种包装器，因此并不是每个人都必须编写其自己的包装器。此包装器提供了一组 API，随后会转发到您选择的提供程序。而且，当 Microsoft 包括用于控制台 (Microsoft.Extensions.Logging.Console)、调试 (Microsoft.Extensions.Logging.Debug)、事件日志 (Microsoft.Extensions.Logging.EventLog) 和 TraceSource (Microsoft.Estensions.Logging.TraceSource) 等功能的提供程序时，它还与各种记录框架团队（其中包括 NLog、Serilog、Loggr、Log4Net 等第三方）协作，从而也存在来自它们的与 Microsoft.Extensions.Logging 兼容的提供程序。

开始使用

日志记录活动的根始于日志工厂，如图 1 中所示。

图 1 如何使用 Microsoft.Extensions.Logging

public static void Main(string[] args = null)
{
  ILoggerFactory loggerFactory = new LoggerFactory()
    .AddConsole()
    .AddDebug();
  ILogger logger = loggerFactory.CreateLogger<Program>();
  logger.LogInformation(
    "This is a test of the emergency broadcast system.");
}

正如代码所示，您以实例化 Microsoft.Extensions.Logging.LoggerFactory 开始，这可在同一命名空间内实施 ILoggerFactory。接下来，您通过利用 ILoggerFactory 的扩展方法指定您想使用的提供程序。在图 1 中，我专门使用了Microsoft.Extensions.Logging.ConsoleLoggerExtensions.AddConsole 和 Microsoft.Extensions.Log­ging.DebugLoggerFactoryExtensions.AddDebug。（虽然这两个类均在 Microsoft.Extensions.Logging 命名空间中，但实际上可分别在 Microsoft.Extensions.Log­ging.Console 和 Microsoft.Extensions.Logging.Debug NuGet 包中找到它们。）

扩展方法仅仅是添加提供程序的更通用方式的方便快捷方式 — ILoggerFactory.AddProvider­(ILoggerProvider provider)。快捷方式是 AddProvider 方法需要日志提供程序的一个实例（很可能该实例的构造函数需要一个日志级别筛选器表达式），而扩展方法为这类表达式提供默认值。例如，ConsoleLoggerProvider 的构造函数签名是：

public ConsoleLoggerProvider(Func<string, LogLevel, bool> filter,
  bool includeScopes);

第一个参数是一个谓词表达式，允许您基于已记录文本的值和日志级别定义某个消息是否将出现在输出中。

例如，您可以使用从比 LogLevel.Information 级别更高（更重要）的所有消息的筛选器构造的特定 Console­LoggerProvider 实例调用 AddProvider：

loggerFactory.AddProvider(
  new ConsoleLoggerProvider(
    (text, logLevel) => logLevel >= LogLevel.Verbose , true));

（有趣的是，与返回 ILoggerFactory 的扩展方法不同，AddProvider 返回 void，防止出现图 1 中所示的流式语法。）

重要的是要认识到，很遗憾，关于日志级别越高的值是更重要还是更不重要，日志提供程序之间存在一些不一致性。日志级别为 6 是否表示发生了严重错误，或者它只是冗长的诊断信息？ Microsoft.Extensions.Logging.LogLevel 使用的值越高表示下面的 LogLevel 枚举声明的优先级越高：

public enum LogLevel
{
  Debug = 1,
  Verbose = 2,
  Information = 3,
  Warning = 4,
  Error = 5,
  Critical = 6,
  None = int.MaxValue
}

因此，通过实例化仅在 logLevel >= LogLevel.Verbose 时写入消息的 ConsoleLoggerProvider，您将只排除将调试级别信息写入到输出。

请注意，您可以将多个提供程序添加到日志工厂，甚至是同一个类型的多个提供程序。因此，如果我将 ILoggerFactory.AddProvider 的调用添加到图 1，ILogger.LogInformation 的调用将在控制台上显示两次某条消息。第一个控制台提供程序（由 AddConsole 添加的那个提供程序）默认显示 LogLevel.Information 或更高级别的任何消息。然而，仅在第二个提供程序（通过 AddProvider 方法添加的）成功避免被筛选掉时，ILogger.LogVerbose 调用才会只出现一次。

日志记录模式

正如图 1 所示，所有日志记录的根始于日志工厂，从中您可以通过 ILoggerFactory.CreateLogger<T> 方法请求 ILogger。此方法中的泛型类型 T 用于确定执行代码的类，因此可能写出记录器将在其中写入信息的类名。换句话说，通过调用 loggerFactory.CreateLogger<Program>，您基本上可启动一个特定于 Program 类的记录器，以便每次写入一条信息，还可能写入 Program 类中的执行上下文。因此，图 1 的控制台输出是：

info: SampleWebConsoleApp.Program[0]
      This is a test of the emergency broadcast system.

此输出基于以下内容：

  • “info”事实上是一个 LogInformation 方法调用。
  • “SampleWebConsoleApp.Program”是由 T 确定的。
  • “[0]”是事件 ID（一个值），我没有指定，因此默认为 0。
  • “This is a test of the emergency broadcast system.”是传递到 LogInformation 的消息参数。

因为值 Program 表示类级别上下文，您将很可能想要为您要从中进行记录的每个类实例化不同的记录器实例。例如，如果 Program 创建并调用到 Controller 类实例中，您将想要拥有通过另一个方法调用创建的 Controller 类中的新记录器实例，其中 T 现在是 Controller：

loggerFactory.CreateLogger<Controller>()

您可能会注意到，这需要访问先前在其上配置提供程序的相同记录器工厂实例。而且可以想象，当您可以将该记录器工厂实例传递到您想要从中执行日志记录的每个类中时，它会很快成为一个需要请求重构的麻烦。

解决方案是将单个静态 ILoggerFactory 保存为一个静态属性，当实例化类的对象的特定 ILoggger 实例时可用于所有这些类。例如，考虑添加一个包含静态 ILoggerFactory 实例的 ApplicationLogging 静态类：

public static class ApplicationLogging
{
  public static ILoggerFactory LoggerFactory {get;} = new LoggerFactory();
  public static ILogger CreateLogger<T>() =>
    LoggerFactory.CreateLogger<T>();
}

这样的类中的明显问题是 LoggerFactory 是否是线程安全型的。而且幸运的是，图 2 中所示的 AddProvider 方法正好说明了这个问题。

图2 Microsoft.Extensions.Logging.LoggerFactory AddProvider 实现

public void AddProvider(ILoggerProvider provider)
{
  lock (_sync)
  {
    _providers = _providers.Concat(new[] { provider }).ToArray();
    foreach (var logger in _loggers)
    {
      logger.Value.AddProvider(provider);
    }
  }
}

因为 ILogger 实例中仅有的数据是由泛型类型 T 确定的，所以您可能会认为每个类都可以有一个每个类的对象可以利用的静态 ILogger。然而，假设确保线程安全性的编程标准适合所有静态成员，这种做法将需要 ILogger 实现内的并发控制（默认情况下不存在），而且占用和释放锁很可能导致一个重大瓶颈。为此，事实上建议一个类的每个实例都拥有单独的 ILogger 实例。因此，结果是您支持日志记录的每个类上的 ILogger 属性（请参见图 3）。

图 3 添加 ILogger 实例到需要日志记录的每个对象

public class Controller
{
  ILogger Logger { get; } =
    ApplicationLogging.CreateLogger<Controller>();
  // ...
  public void Initialize()
  {
    using (Logger.BeginScopeImpl(
      $"=>{ nameof(Initialize) }"))
    {
      Logger.LogInformation("Initialize the data");
      //...
      Logger.LogInformation("Initialize the UI");
      //...
    }
  }
}

了解作用域

通常，提供程序支持“作用域”的概念，以便您可以（例如）记录您的代码如何遍历调用链。继续上述示例，如果 Program 调用 Controller 类上的方法，相应地该类使用它自己的 T 类型的上下文实例化它自己的记录器实例。然而，不是简单地显示后跟 info: SampleWebConsoleApp.Controller[0] 的 info: SampleWebConsoleApp.Program[0] 的消息上下文，您可能希望记录 Program 调用的 Controller，可能甚至包括方法名本身。要实现这一点，您可激活提供程序内作用域的概念。图 3 提供了一个在 Initialize 方法内调用 Logger.BeginScopeImpl 的示例。

使用日志记录模式的同时利用作用域激活将产生 Program 类，可能看起来有点像图 4。

图 4 更新的 Program 实现

public class Program
{
  static ILogger Logger { get; } =
    ApplicationLogging.CreateLogger<Program>();
  public static void Main(string[] args = null)
  {
    ApplicationLogging.LoggerFactory.AddConsole(true);
    Logger.LogInformation(
      "This is a test of the emergency broadcast system.");
    using (Logger.BeginScopeImpl(nameof(Main)))
    {
      Logger.LogInformation("Begin using controller");
      Controller controller = new Controller();
      controller.Initialize();
      Logger.LogInformation("End using controller");
    }
    Logger.Log(LogLevel.Information, 0, "Shutting Down...", null, null);
  }
}

图 3 与图 4 结合的输出如图 5 中所示。

图 5 包含作用域的控制台日志记录输出

info: SampleWebConsoleApp.Program[0]
      This is a test of the emergency broadcast system.
info: SampleWebConsoleApp.Program[0]
      => Main
      Begin using controller
info: SampleWebConsoleApp.Controller[0]
      => Main => Initialize
      Initialize the data
info: SampleWebConsoleApp.Controller[0]
      => Main => Initialize
      Initialize the UI
info: SampleWebConsoleApp.Program[0]
      => Main
      End using controller
info: SampleWebConsoleApp.Program[0]
      Shutting down...

注意作用域如何自动展开，不再包含 Initialize 或 Main。之所以提供此功能，是因为使用语句调用 Dispose 时 BeginScopeImpl 返回可自动展开作用域的 IDisposable 实例。

利用第三方提供程序

为了使一些最为突出的第三方记录框架可用，Microsoft 与其开发人员协作并确保每个记录框架都有提供程序。无需指明首选项，只需考虑如何接上 NLog 框架，如图 6 所示。

图 6 将 NLog 配置为 Microsoft.Extensions.Logging 提供程序

[TestClass]
public class NLogLoggingTests
{
  ILogger Logger {get;}
    = ApplicationLogging.CreateLogger<NLogLoggingTests>();
  [TestMethod]
  public void LogInformation_UsingMemoryTarget_LogMessageAppears()
  {
    // Add NLog provider
    ApplicationLogging.LoggerFactory.AddNLog(
      new global::NLog.LogFactory(
        global::NLog.LogManager.Configuration));
    // Configure target
    MemoryTarget target = new MemoryTarget();
    target.Layout = "${message}";
    global::NLog.Config.SimpleConfigurator.ConfigureForTargetLogging(
      target, global::NLog.LogLevel.Info);
    Logger.LogInformation(Message);
     Assert.AreEqual<string>(
      Message, target.Logs.FirstOrDefault<string>());
  }
}

熟悉 NLog 即可知道此代码的大部分。首先，我实例化和配置 NLog.Targets.MemoryTarget 类型的 NLog target。（有许多 NLog target，而且每个 target 均可在 NLog 配置文件中确定和配置，还可以使用配置代码，如图 6 中所示。） 注意，虽然外观相似，但是为 Layout 分配的是参数值 ${message}，而不是字符串内插值。

一旦添加到 LoggerFactory 并进行了配置，该代码便与任何其他提供程序代码完全相同。

异常处理

当然，要记录的最常见原因之一是要在引发异常时（更具体地说，是在处理异常时而不是重新引发异常时，或者在完全未处理异常时）记录（请参阅 bit.ly/1LYGBVS）。正如您所期望的，Microsoft.Extensions.Logging 具有处理异常的特定方法。大多数这样的方法是作为 ILogger 的扩展方法在Microsoft.Extensions.Logging.LoggerExtensions 中实施的。而且，它来自针对特定的日志级别（ILogger.LogInformation、ILogger.LogDebug、ILogger.LogCritical 等等）实施每个方法的类。例如，如果您想记录与异常相关的 LogLevel.Critical 消息（或许在从容地关闭应用程序之前），您将调用：

Logger.LogCritical(message,
  new InvalidOperationException("Yikes..."));

日志记录和异常处理的另一个重要方面是日志记录（特别是在处理异常时）不应引发异常。如果您在记录时引发异常，可能消息或异常将永远不会被写入，而且不管多么严重都可能会被完全忽视。遗憾的是，现成的 ILogger 实现 (Microsoft.Extensions.Logging.Logger) 没有此类异常处理，因此，如果发生异常，将需要调用代码来处理，而且想要这样做的话，每次都得调用 Logger.LogX。解决此问题的常规方法可能是包装记录器以捕获异常。然而，您可能想要实施您自己的 ILogger 和 ILoggerFactory 版本（有关示例，请参阅 bit.ly/1LYHq0Q）。由于 .NET Core 是开源的，您甚至可以克隆类以及在您自己的 LoggerFactory 和 ILogger 实现中故意实施异常处理。

总结

我开始问到“我们究竟为何还想要 .NET 中的其他记录框架？” 我希望现在已经清楚了。新框架将创建一个抽象层或包装器，使您可以将任何您想要的记录框架用作提供程序。这确保您作为开发人员在工作中有最大的灵活性。此外，即使它仅随附 .NET Core 提供，引用 .NET Core NuGet 包（如 Microsoft.Extensions.Logging）对于标准的 Visual Studio .NET 4.6 项目是没有问题的。

Mark Michaelis是 IntelliTect 的创始人，担任首席技术架构师和培训师。在近二十年的时间里，他一直是 Microsoft MVP，并且自 2007 年以来一直担任 Microsoft 区域总监。Michaelis 还是多个 Microsoft 软件设计评审团队（包括 C#、Microsoft Azure、SharePoint 和 Visual Studio ALM）的成员。他在开发者会议上发表了演讲，并撰写了大量书籍，包括最新的“必备 C# 6.0（第 5 版）”(itl.tc/EssentialCSharp)。可通过他的 Facebook facebook.com/Mark.Michaelis、博客 IntelliTect.com/Mark、Twitter @markmichaelis 或者通过电子邮件 mark@IntelliTect.com 与他联系。

感谢以下 IntelliTect 技术专家对本文的审阅： Kevin Bost、Chris Finlayson 和 Michael Stokesbary