.NET Core的日志[2]:将日志输出到控制台

对于一个控制台应用，比如采用控制台应用作为宿主的ASP.NET Core应用，我们可以将记录的日志直接输出到控制台上。针对控制台的Logger是一个类型为ConsoleLogger的对象，ConsoleLogger对应的LoggerProvider类型为ConsoleLoggerProvider，这两个类型都定义在 NuGet包“Microsoft.Extensions.Logging.Console”之中。 本文已经同步到《ASP.NET Core框架揭秘》之中]

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

一、ConsoleLogger

如下所示的代码片段展示了ConsoleLogger类型的定义。它具有四个属性，代表Logger名称的Name属性最初由ConsoleLoggerProvider提供，实际上就是LoggerFactory在创建Logger时指定的日志类型（Category）。ConsoleLogger的Console属性代表当前控制台，它的类型为IConsole接口。之所以没有直接采用System.Console向控制台输出格式化的日志消息，是因为需要提供跨平台的支持，IConsole接口表示的就是这么一个与具体平台无关的抽象化的控制台。

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的Filter属性通过一个委托对象来过滤真正需要写到控制台的日志消息，该属性的返回类型为Func<string, LogLevel, bool>，两个输入参数分别表示分发给它的日志消息的类型和等级，如果执行该委托对象返回False，日志消息将会被直接忽略。ConsoleLogger的IsEnabled方法会直接将指定日志等级作为参数（ConsoleLogger的Name属性作为另一个参数）调用这个委托对象得到最终的返回结果。ConsoleLogger的IncludeScopes与上面介绍的日志上下文范围有关，我们会在后续的部分对它进行单独介绍。

对于ConsoleLogger的这四个属性，除了表示当前控制台的Console属性，其余三个均可以在创建它的时候通过构造函数的相应参数来指定。接下来我们来简单了解一下表示抽象化控制台的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的Log方法被调用的时候，它会先将指定的日志等级作为参数调用IsEnabled方法。如果这个方法返回True，ConsoleLogger会调用WriteMessage方法将提供的日志消息输出到由Console属性表示的控制台上。WriteMessage方法是一个虚方法，如果它输出的消息格式和样式不满足我们的要求，我们可以定义ConsoleLogger的子类，并通过重写这个方法按照我们希望的方式输出日志消息。

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

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

日志等级	显示文字	前景颜色	背景颜色
Trace	trce	Gray	Black
Debug	dbug	Gray	Black
Information	info	DarkGreen	Black
Warning	warn	Yellow	Black
Error	fail	Red	Black
Critical	crit	White	Red

二、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对象，一旦我们调用这个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());
}

再次将我们目光从ConsoleLogScope转移到ConsoleLogger上面，当ConsoleLogger的BeginScope方法被调用的时候，它会将自己的名称（Name属性）和指定的State对象作为参数调用ConsoleLogScope的静态方法Push并返回一个DisposableScope对象。只要我们没有调用DisposableScope的Dispose方法，就可以通过调用ConsoleLogScope的静态属性Current得到当前日志上下文，它的ToString方法和指定的State对象的ToString方法返回相同的字符串。

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

默认情况下，ConsoleLogger针对日志上下文范围的支持是关闭的，我们需要利用它的IncludeScopes属性开启这个特性。如果ConsoleLogger的Log方法是在某个日志上下文范围中被调用，它会采用如下的格式输出日志消息，其中{State}表示调用BeginScope方法传入的State对象。

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

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

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

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

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

warn: Ordering[0]
      => Order ID: 20160520001
      商品库存不足(商品ID: 9787121237812, 当前库存:20, 订购数量:50)
fail: Ordering[0]
      => Order ID: 20160520001
      商品ID录入错误(商品ID: 9787121235368)

三、ConsoleLoggerProvider

ConsoleLogger最终通过注册到LoggerFactory上的ConsoleLoggerProvider来提供。当我们在创建一个ConsoleLogger的时候，除了需要指定它的名称之外，还需要指定一个用于过滤日志的Func<string, LogLevel, bool>对象，以及用于确定是否将日志写入操作纳入当前上下文范围的布尔值。这两者最终都需要通过ConsoleLoggerProvider来提供，我们在调用构造函数创建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，所以它最终还是为了提供日志过滤条件和是否将日志写入操作纳入当前上下文范围的布尔值，前者体现为TryGetSwitch方法，后者对应其IncludeScopes属性。由于配置数据具有不同的载体，或者具有不同来源，比如文件、数据库和环境变量等，所以需要考虑应用于配置源的同步问题。IConsoleLoggerSettings接口的ChangeToken属性提供了一个向应用通知配置源发生改变的令牌，Reload则在配置源发生改变时从新加载配置。

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

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

在NuGet包“Microsoft.Extensions.Logging.Console”中提供了两个实现了IConsoleLoggerSettings接口的类型，其中一个是具有如下定义的ConsoleLoggerSettings。ConsoleLoggerSettings的实现方式非常简单，它通过一个字典对象来保存日志类型与最低等级之间的映射，并利用它来实现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则直接采用真正的配置。如下面的代码片段所示，一个ConfigurationConsoleLoggerSettings对象实际上是对一个Configuration对象的封装。它的IncludeScopes属性和TryGetSwitch方法的返回值都来源于Configuration对象承载的配置。ConfigurationConsoleLoggerSettings的同步直接利用配置模型的同步机制来实现，具体来说它的ChangeToken属性也是直接由这个Configuration对象提供（GetChangeToken方法返回的ChangeToken）。

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对象会直接作为返回值。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。我们将ConsoleLogger的相关配置按照如下的形式定义在一个JSON文件中，并将其命名为logging.json。通过这个配置，我们要求创建的ConsoleLogger忽略当前的日志上下文范围，并为日志类型“App”设置的最低的等级“Warning”。

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

我们在project.json文件中添加了针对如下几个NuGet包的依赖。为了在项目编译时自动将配置文件logging.json拷贝到输出目录下，我们将这个配置文件名设置为配置项“buildOptions/copyToOutput”的值。

{
  ...
  "buildOptions": {
    ...
    "copyToOutput": "logging.json"
  },

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

我们在作为入口的Main方法中编写了下面一段程序。如下面的代码片段所示，我们通过加载这个logging.json文件创建了一个Configuration对象。在成功创建LoggerFactory后，我们将Configuration对象作为参数调用扩展方法AddConsole创建一个ConsoleLoggerProvider并注册到LoggerFactory之上。我们最终利用LoggerFactory创建了一个Logger对象，并利用后者记录三条日志。Logger采用的类型为“App”，这与配置文件设置的类型一致。

Encoding.RegisterProvider(CodePagesEncodingProvider.Instance);

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

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

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

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

---

.NET Core的日志[1]:采用统一的模式记录日志
.NET Core的日志[2]:将日志写入控制台
.NET Core的日志[3]:将日志写入Debug窗口
.NET Core的日志[4]:利用EventLog写日志
.NET Core的日志[5]:利用TraceSource写日志