.NET Core下的日志（3）：如何将日志消息输出到控制台上

当我们利用LoggerFactory创建一个Logger对象并利用它来实现日志记录，这个过程会产生一个日志消息，日志消息的流向取决于注册到LoggerFactory之上的LoggerProvider。说的更加具体一点，日志消息的归宿取决于注册到LoggerFactory的LoggerProvider究竟会提供怎样的Logger。微软提供了一系列原生的LoggerProvider，我们先来认识一下将控制台作为日志输出目的地的ConsoleLoggerProvider。ConsoleLoggerProvider会提供一个名为ConsoleLogger的Logger对象，让后者在进行日志写入的时候会将格式化的日志消息输出到当前控制台上，这两个类型（ConsoleLoggerProvider和ConsoleLogger）均定义在NuGet包“Microsoft.Extensions.Logging.Console”之中。

目录
一、ConsoleLogger
二、ConsoleLogScope
三、ConsoleLoggerProvider
四、扩展方法AddConsole

一、ConsoleLogger

如下所示的代码片段展示了由ConsoleLoggerProvider提供的这个ConsoleLogger类型的定义。ConsoleLogger具有四个属性，代表Logger名称的Name属性最初由ConsoleLoggerProvider提供，实际上就是LoggerFactory在创建Logger时指定的日志类型。出于对跨平台的支持，ConsoleLogger对不同平台下控制台进行了抽象并使用接口IConsole来表示，所示代码当前控制台的Console属性的类型为IConsole。Func<string, LogLevel, bool>类型的Filter属性提供了一个针对日志类型与等级的过滤条件，是否真正需要将提供的日志消息输出到控制台就由这个过滤条件来决定。最后一个属性IncludeScopes与上面提到的关联多次日志记录的上下文范围有关，我们后续内容中对此进行单独介绍。

public class ConsoleLogger : ILogger
{
    public string                           Name { get; }
    public IConsole                         Console { get; set; }
    public Func<string, LogLevel, bool>     Filter { get; set; }
    public bool                             IncludeScopes { get; set; }

    public ConsoleLogger(string name, Func<string, LogLevel, bool> filter, bool includeScopes);public IDisposable BeginScope<TState>(TState state);

    public bool IsEnabled(LogLevel logLevel);
    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter);
    public virtual void WriteMessage(LogLevel logLevel, string logName, int eventId, string message);
}

对于ConsoleLogger的这四个属性，除了表示当前控制台的Console属性，其余三个均可以在创建它的时候通过构造函数的相应参数来指定。接下来我们来了解一下用于抽象不同平台控制台的IConsole接口，如下面的代码片段所示，IConsole接口具有如下三个方法。在调用Write和WriteLine方法写入日志的时候，我们除了指定写入的消息文本之外，还可以控制消息在控制台上的背景和前景颜色。Flush方法与数据输出缓冲机制有关，如果采用缓冲机制，通过Write或者WriteLine方法写入的消息并不会立即输出到控制台，而是先被保存到缓冲区，Flush方法被执行的时候会将缓冲区的所有日志消息批量输出到控制台上。

public interface IConsole
{
    void Write(string message, ConsoleColor? background, ConsoleColor? foreground);
    void WriteLine(string message, ConsoleColor? background, ConsoleColor? foreground);
    void Flush();
}

微软默认提供了两种类型的Console类型，一种是基于Windows平台的WindowsLogConsole，非Windows平台的控制台则通过AnsiLogConsole来表示。它们之间的不同之处在于对日志消息在控制台上显示颜色（前景色和背景色）的控制。对于Windows平台来说，消息显示在控制台颜色是通过显式设置System.Console的静态属性ForegroundColor和BackgroundColor来实现的，但是对于非Windows平台来说，颜色信息会直接以基于ASNI标准的转意字符序列（ANSI Esacpe Sequences）的形式内嵌在消息文本之中）。

ConsoleLogger的IsEnabled方法最终决定了是否需要真正完成对提供日志的写入操作，这方法是由Filter属性返回的委托对象的执行结果。当Log方法执行的时候，它会先调用IsEnabled方法，如果这个方法返回True，它调用另一个WriteMessage方法将提供的日志消息输出到由Console属性表示的控制台上。WriteMessage方法是一个虚方法，如果它输出的消息格式和样式不满足我们的要求，我们可以定义ConsoleLogger的子类，并通过重写这个方法按照我们希望的方式输出日志消息。

{LogLevel} : {Category}[{EventId}]
{Message}

在默认情况下，被ConsoleLogger输出到控制台上的日志消息会采用上面的格式，这也可以通过我们在上面演示的实例来印证。对于输出到控制台表示日志等级的部分，输出的文字与对应的日志等级具有如表1所示的映射关系，可以看出日志等级在控制台上均会显示为仅包含四个字母的简写形式。日志等级也同时决定了改部分内容在控制台上显示的前景色。

二、ConsoleLogScope

在默认情况下针对Log方法的每次调用都是一次独立的日志记录行为，但是在很多情况下多次相关的日志记录需要在同一个上下文范围中进行，我们可以通过调用Logger的BeginScope方法来创建这个上下文范围。对于ConsoleLogger来说，它的BeginScope方法创建的上下文范围与一个具有如下定义的ConsoleLogScope类有关。

public class ConsoleLogScope
{
    internal ConsoleLogScope(string name, object state);
    public static IDisposable Push(string name, object state);
    public override string ToString();

    public static ConsoleLogScope     Current { get; set; }
    public ConsoleLogScope            Parent { get; set; }
}

我们说ConsoleLogger的BeginScope方法返回的日志上下文范围与ConsoleLogScope有关，但并没有说该方法返回的是一个ConsoleLogScope对象，关于这一点从上面给出的ConsoleLogScope类型定义也可以看出来，BeginScope方法返回类型为IDisposable接口，但是ConsoleLogScope并未实现该接口。如上面的代码片段所示，ConsoleLogScope只定义了一个内部构造函数，所以我们不可以直接调用构造函数创建一个ConsoleLogScope对象，ConsoleLogScope的创建实现在它的静态方法Push中，ConsoleLogger的BeginScope方法的返回值其实就是针对这方法的调用结果。

要了解实现在Push方法中针对ConsoleLogScope的创建逻辑，需要先来了解一下ConsoleLogScope的嵌套层次结构。一个ConsoleLogScope可以内嵌于另一个ConsoleLogScope之中，后者被称为前者的“父亲”，它的Parent属性返回的就是这么一个对象。ConsoleLogScope的静态属性Current表示当前的ConsoleLogScope，当我们通过指定name和state这两个参数调用静态方法Push时，该方法实际上会调用静态构造函数创建一个新的ConsoleLogScope对象并将其作为当前ConsoleLogScope的“儿子”。于此同时，当前ConsoleLogScope被切换成这个新创建的ConsoleLogScope。

ConsoleLogScope的Push方法最终返回的是一个DisposableScope对象。如下面的代码片段所示，DisposableScope仅仅是内嵌于ConsoleLogScope的一个私有类型。当它的Dispose方法执行的时候，它仅仅是获取当前ConsoleLogScope的“父亲”，并将后者作为当前ConsoleLogScope。

public class ConsoleLogScope
{
    public static IDisposable Push(string name, object state)
    {
        ConsoleLogScope current = Current;
        Current = new ConsoleLogScope(name, state);
        Current.Parent = current;
        return new DisposableScope();
    }

    private class DisposableScope : IDisposable
    {
        public void Dispose()
        {
            ConsoleLogScope.Current = ConsoleLogScope.Current.Parent;
        }
    }
}

简单地说，我们调用ConsoleLogScope的Push方法创建当前日志上下文范围并返回一个DisposableScope对象，后者的Dispose方法的调用意味着这个上下文范围的终结。与此同时，原来的ConsoleLogScope从新成为当前的上下文范围。下面的代码片段体现了基于ConsoleLogScope的作用域控制方法，这段代码来体现另一个细节，那就是ConsoleLogScope的ToString方法被重写，它返回的是ConsoleLogScope对象被创建时指定的State对象（state参数）的字符串形式（调用ToString方法的返回值）。

using (ConsoleLogScope.Push("App", "Scope1"))
{
    Debug.Assert("Scope1" == ConsoleLogScope.Current.ToString());
    using (ConsoleLogScope.Push("App", "Scope1"))
    {
        Debug.Assert("Scope2" == ConsoleLogScope.Current.ToString());
    }
    Debug.Assert("Scope1" == ConsoleLogScope.Current.ToString());
}

当ConsoleLogger的BeginScope方法被执行的时候，它会将自己的名称（Name属性）和指定的State对象作为参数调用ConsoleLogScope的静态方法Push。只要我们没有调用返回对象的Dispose方法，就可以表示当前日志上下文范围的ConsoleLogScope对象，这个对象和我们指定的State对象的ToString方法返回相同的字符串。

public class ConsoleLogger : ILogger
{
   public IDisposable BeginScope<TState>(TState state)
   {
      return ConsoleLogScope.Push(this.Name, state);
   }
}

如果一个ConsoleLogger对象的IncludeScopes属性返回True，意味着我们希望针对它的日志记录会在一个预先创建的日志上下文范围中执行执行，输出到控制台的日志消息会包含当前上下文范围的信息。在次情况下，ConsoleLogger会采用如下的格式呈现输出在控制台上的日志消息，其中{State}表示调用BeginScope方法传入的State对象。

{LogLevel} : {Category}[{EventId}]
             =>{State}
          {Message}

比如在一个处理订购订单的应用场景中，需要将针对同一笔订单的多条日志消息关联在一起，我们就可以针对订单的ID创建一个日志上下文范围，并在此上下文范围内调用Logger对象的Log方法进行日志记录，那么订单ID将会包含在每条写入的日志消息中。

ILogger logger = new ServiceCollection()
    .AddLogging()
    .BuildServiceProvider()
    .GetService<ILoggerFactory>()
    .AddConsole(true)
    .CreateLogger("App");

using (logger.BeginScope("订单: {ID}", "20160520001"))
{
    logger.LogWarning("商品库存不足(商品ID: {0}, 当前库存:{1}, 订购数量:{2})", "9787121237812",20, 50);
    logger.LogError("商品ID录入错误(商品ID: {0})","9787121235368");
}

如上面的代码片段所示，我们按照依赖注入的方式创建了一个注册有ConsoleLoggerProvider的LoggerFactory，并利用创建了一个Logger对象。在调用注册ConsoleLoggerProvider的AddConsole方法时，我们传入True作为参数，意味着提供的ConsoleLogger会在当前的日志上下文范围中进行日志记录（它 的IncludeScope属性被设置为True）。我们通过Logger对象记录了两条针对同一笔订单的日志，两次日志记录所在的上下文范围是调用BeginScope方法根据指定 的订单ID创建的。这段程序执行之后会在控制台上输出如下所示的两条日志消息。

三、ConsoleLoggerProvider

ConsoleLogger最终通过注册到LoggerFactory上的ConsoleLoggerProvider来提供。当我们在创建一个ConsoleLogger的时候，除了需要指定它的名称之外，还需要指定一个进行日志过滤的Func<string, LogLevel, bool>类型的委托对象和确定是否将日志写入操作纳入当前上下文范围的布尔值。由于这两个对象最终都需要通过ConsoleLoggerProvider来提供，所以它具有对应的构造函数。

public class ConsoleLoggerProvider : ILoggerProvider, IDisposable
{
    public ConsoleLoggerProvider(Func<string, LogLevel, bool> filter,bool includeScopes);
    public ConsoleLoggerProvider(IConsoleLoggerSettings settings);

    public ILogger CreateLogger(string name);
    public void Dispose();
}

ConsoleLoggerProvider还具有另一个构造函数重载，它接受一个IConsoleLoggerSettings接口的参数，该接口表示为创建的ConsoleLogger而指定的配置。配置的目的是为了指导ConsoleLoggerProvider创建正确的ConsoleLogger，所以它最终还是为了提供日志写入过滤条件和是否将日志写入操作纳入当前上下文范围的布尔值，前者体现为IConsoleLoggerSettings接口的TryGetSwitch方法，后者自然对应其IncludeScopes属性。

public interface IConsoleLoggerSettings
{
    bool IncludeScopes { get; }
    IChangeToken ChangeToken { get; }

    IConsoleLoggerSettings Reload();
    bool TryGetSwitch(string name, out LogLevel level);
}

由于配置数据具有不同的载体，或者具有不同来源，比如文件、数据库和环境变量等，所以需要考虑应用于配置源的同步问题。IConsoleLoggerSettings的ChangeToken提供了一个向应用通知配置源发生改变的令牌，另一个Reload则在配置源发生改变时从新加载配置。

在NuGet包“Microsoft.Extensions.Logging.Console”中提供了两个实现了IConsoleLoggerSettings接口的类型，其中一个是具有如下定义的ConsoleLoggerSettings。ConsoleLoggerSettings的实现方式非常简单，它通过一个字典对象来保存日志类型与最低等级（低于该等级的日志将被ConsoleLogger忽略）之间的映射，并利用它来实现TryGetSwitch方法。由于配置原数据体现为一个内存变量，所以无需考虑配置的同步问题，所以ConsoleLoggerSettings的Reload方法的返回值是它自己，ChangeToken被定义成简单的可读写的属性。

public class ConsoleLoggerSettings : IConsoleLoggerSettings
{
    public bool                              IncludeScopes { get; set; }
    public IChangeToken                      ChangeToken { get; set; }
    public IDictionary<string, LogLevel>     Switches { get; set; } = new Dictionary<string, LogLevel>();

    public IConsoleLoggerSettings Reload() => this;
    public bool TryGetSwitch(string name, out LogLevel level)=> Switches.TryGetValue(name, out level);
}

IConsoleLoggerSettings接口的另一个实现者ConfigurationConsoleLoggerSettings则直接采用真正的配置来提供创建ConsoleLogger使用的设置。如下面的代码片段所示，ConfigurationConsoleLoggerSettings的构造函数的唯一参数类型为IConfiguration接口，它的IncludeScopes属性和TryGetSwitch方法的返回值都是利用这个Configuration对象承载的配置计算出来的。至于数据的同步，则直接借助配置模型自身的同步机制来实现。

public class ConfigurationConsoleLoggerSettings : IConsoleLoggerSettings
{
    public bool             IncludeScopes { get; }
    public IChangeToken     ChangeToken { get; }

    public ConfigurationConsoleLoggerSettings(IConfiguration configuration);

    public IConsoleLoggerSettings Reload();
    public bool TryGetSwitch(string name, out LogLevel level);
}

如下所示的代码片段以JSON格式定义了ConfigurationConsoleLoggerSettings期望的配置结构。我们可以看到这个配置和ConsoleLoggerSettings一样，除了直接提供与日志上下文范围的IncludeScopes属性之外，还定义一组日志类型与最低等级直接的映射关系。对于这组映射关系中指定的某种类型的日志，只有在不低于设定的等级才会被ConsoleLogger输出到控制台。

{
  "includeScopes": true|false,
  "logLevel"：{
    "Category1": "Debug",
    "Category2": "Error"，
    …
}

关于ConsoleLoggerProvider针对ConsoleLogger的创建，有一个细节值得一提。当我们调用它的CreateLogger方法的时候，ConsoleLoggerProvider并不总是直接创建一个新的ConsoleLogger对象。实际上它会对创建的ConsoleLogger根据其名称进行缓存，如果后续调用CreateLogger方法时指定相同的名称，缓存的ConsoleLogger对象会直接作为返回值。ConsoleLoggerProvider针对ConsoleLogger的缓存体现在如下所示的代码片段中。

ConsoleLoggerProvider loggerProvider = new ConsoleLoggerProvider(new ConsoleLoggerSettings());
Debug.Assert(ReferenceEquals(loggerProvider.CreateLogger("App"), loggerProvider.CreateLogger("App")));

四、扩展方法AddConsole

针对ILoggerFactory接口的扩展方法AddConsole帮助我们根据提供的参数创建一个ConsoleLoggerProvider对象并将其注册到指定的LoggerFactory之上。我们在前面的使用了少数几个AddConsole方法重载之外，实际上AddConsole方法还存在很多其他的重载。对于如下所示的这些AddConsole方法，它提供了不同类型的参数帮助我们创建ConsoleLoggerProvider对象。经过了上面对ConsoleLoggerProvider的详细介绍，相信大家对每个参数所代表的含义会有正确的理解。

public static class ConsoleLoggerExtensions
{
    public static ILoggerFactory AddConsole(this ILoggerFactory factory);
    public static ILoggerFactory AddConsole(this ILoggerFactory factory, IConfiguration configuration);
    public static ILoggerFactory AddConsole(this ILoggerFactory factory, IConsoleLoggerSettings settings);
    public static ILoggerFactory AddConsole(this ILoggerFactory factory, LogLevel minLevel);
    public static ILoggerFactory AddConsole(this ILoggerFactory factory, bool includeScopes);
    public static ILoggerFactory AddConsole(this ILoggerFactory factory, Func<string, LogLevel, bool> filter);
    public static ILoggerFactory AddConsole(this ILoggerFactory factory, LogLevel minLevel, bool includeScopes);
    public static ILoggerFactory AddConsole(this ILoggerFactory factory, Func<string, LogLevel, bool> filter, bool includeScopes);
}

接下来通过一个实例来演示通过指定一个Configuration对象来调用扩展方法AddConsole来创建并注册ConsoleLoggerProvider。我们在一个.NET Core控制台应用的project.json文件中添加了针对如下几个NuGet包的依赖。

{
  "dependencies": {
    …
    "Microsoft.Extensions.DependencyInjection"     : "1.0.0-rc2-final",
    "Microsoft.Extensions.Logging"                : "1.0.0-rc2-final",
    "Microsoft.Extensions.Logging.Console"        : "1.0.0-rc2-final",
    "Microsoft.Extensions.Configuration.Json"     : "1.0.0-rc2-final",
    "System.Text.Encoding.CodePages"              : "4.0.1-rc2-24027"
  }
}

我们将ConsoleLogger的相关配置按照如下的形式定义在一个JSON文件中，并将其命名为log.json。通过这个配置，我们要求创建的ConsoleLogger忽略当前的日志上下文范围，并为类型“App”的日志设置的最低的等级“Warning”。

{
  "IncludeScopes": false,
  "LogLevel": {
    "App": "Warning"
  }
}

我们在作为入口的Main方法中编写了下面一段程序。我们通过加载上面这个log.json文件创建了一个Configuration对象，并将其作为参数调用扩展方法AddConsole将创建的ConsoleLoggerProvider注册到LoggerFactory上面。我们利用LoggerFactory针对日志类型“App”创建了一个Logger对象，并利用后者记录三条日志。

public class Program
{
    public static void Main(string[] args)
    {
        Encoding.RegisterProvider(CodePagesEncodingProvider.Instance);

        IConfiguration settings = new ConfigurationBuilder()
            .AddJsonFile("log.json")
            .Build();

        ILogger logger = new ServiceCollection()
            .AddLogging()
            .BuildServiceProvider()
            .GetService<ILoggerFactory>()
            .AddConsole(settings)
            .CreateLogger("App");

        int eventId = 3721;
        logger.LogInformation(eventId, "升级到最新版本({version})", "1.0.0.rc2");
        logger.LogWarning(eventId, "并发量接近上限({maximum}) ", 200);
        logger.LogError(eventId, "数据库连接失败(数据库：{Database}，用户名：{User})", "TestDb", "sa");
    }
}

根据定义在配置文件中的日志开关，只有等级不低于Warning的日志才会真正被ConsoleLogger输出到控制台上，所以对于上面程序中记录的三条日志，控制台上只会按照如下的形式呈现出等级分别为Warning和Error的两条，等级为Information的日志直接被忽略。