Serilog 源码解析——使用方法

在上两篇文章(链接1和链接2)中，我们通过一个简易 demo 了解到了一个简单的日志记录类库所需要的功能，即一条日志有哪些数据，以及如何通过一次记录的方式将同一条日志消息记录到多个日志媒介中。在本文中，针对 Serilog，我们从以下几个方面来了解 Serilog 核心功能需求和用法，并为下一篇正式开始探究源码准备相关工作。(系列目录)

Serilog 核心功能

目前，在 Asp.net core 中，对于日志记录库，除了微软官方准备的 Microsoft.Extensions.Logging 外，Serilog 也算是一个最常用的日志记录的类库。作为一类最常用的日志记录库，Serilog 具有良好的扩展性，其组织所维护的60多个项目均是为 Serilog 提供额外功能的扩展类库。为更好地了解源码具体在做什么，我们需要对 Serilog 有一个最基本的功能了解。

1. Serilog 将日志信息记录到哪里？

Serilog 将日志记录媒介称之为 Sink，在 Serilog 组织维护的类库中，有各种各样的 Sink，比如说写入控制台的 ConsoleSink 以及写入文件的 FileSink 等。这些 Sink 的包名通常命名为 Serilog.Sinks.XXX。

那么 Serilog 如何向多个 Sinks 中写入日志呢？下面给出一个向控制台和文件写入日志的例子。在此之前，我们需要向所在项目添加三个包：

• Serilog
• Serilog.Sinks.Console
• Serilog.Sinks.File

添加完三个包之后，通过以下调用方式即可将日志写入到控制台和文件中。

var log = new LoggerConfiguration()
    .WriteTo.Console()
    .WriteTo.File("./log.txt")
    .CreateLogger();

log.Information("Hello world.");
log.Error("Hello world, again.");        

如果大家对之前的 Demo 了解的话，那么会觉得这段代码非常的熟悉。LoggerConfiguration类似于先前的LogBuilder，通过CreateLogger函数来创建对应的日志记录器，调用Console和File函数类似于先前的AddConsole以及AddFile方法，其输入参数的个数和形式都完全一样。但不同的是这些函数在WriteTo对象上调用而不是LoggerConfiguration上做调用，这一点和先前的 Demo 不一样，不过这一点并不影响我们的理解。再往后，日志的记录是通过Information和Error函数来调用，而LogDemo 中采用LogInformation和LogError函数记录日志。

上图显示的是 Serilog 向控制台中记录的日志信息，可以看到，其最终记录的日志信息和 LogDemo 差不多，均是日志时间+等级+消息。

2. Serilog 向 Sink 中具体写入了什么？

在之前的 LogDemo 中，我们一直认为日志消息本质上就是一字符串。将日志记录下来就是将相关信息组合成字符串并写入到对应 Sink 中,这是非结构化日志记录库常用的做法。然而，这种使用方式有两个问题：

2.1 日志消息不能附带数据。日志消息附带数据有非常多的好处，比如说，如果类库具有自动解析数据的能力，那么我们只需要给出数据以及带有插入位置的消息字符串模板，就可以由类库自行构造对应的日志。在 Serilog 中，这种带有数据的日志消息被称为日志事件，它包含了待解析的字符串模板以及需要渲染的数据。

下面就取官网的例子做说明吧。可以看出，position是一个匿名类对象，它包含经度和纬度两个值。在使用日志记录的时候，向函数中传入三个参数，第一个是字符串模板，后两个是数据。其格式遵循Message Template定义，字符串模板的写法非常像C#中的$开头的字符串，字符串采用{}来标记数据的位置，采用:分割变量名和数据输出格式，二者的区别几乎只有开头有没有$。另外，在字符串模板中的变量名部分，还可以使用@和$来决定数据的渲染方法（即如何将数据内容写入到字符串中）。@采用的是解构方法，将内部内容取出直到基本类型后写入，$则是直接调用数据的ToString方法渲染。在下例中，position采用解构的方式渲染，而整数elapseMs利用000格式化字符串控制其渲染方法。

var position = new { Latitude = 25, Longitude = 134 };
var elapsedMs = 34;

var log = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateLogger();
log.Information("Processed {@Position} in {Elapsed:000} ms.", position, elapsedMs);
// 输出： [20:54:34 INF] Processed {"Latitude": 25, "Longitude": 134} in 034 ms.

2.2 不同的人有不同的日志记录方式。举个例子，日志所包含的时间、等级和消息不同的人希望采用不同的格式输入。可以发现，在之前 Demo 中，通过LogData类给定的Tostring()方法转化不利于不同人的定制化需求。

对于这个需求，如果大家对前一个问题充分了解的话，可以发现，日志事件、日志等级以及日志消息都可以算是日志事件中的数据，我们可以通过设置输出模板（output template）达到。实际上，在 Serilog 中，大部分 Sink 都提供了一个默认的输出模板，通过提供自定义的输出模板可以达到日志信息定制化的目的。

var log = new LoggerConfiguration()
    .WriteTo.Console(outputTemplate: "({Timestamp:HH:mm:ss}/{Level}) {Message:lj}{NewLine}{Exception}")
    .CreateLogger();

log.Information("Hello world.");
// 输出： (21:22:14/Information) Hello world.

这里通过设置outputTemplate输入参数来控制日志的输出格式。输出模板的改变会导致日志的输出内容发生变化，但可以看到其数据内容是一样的。

2.3 在完成前两个需求后，通过结合这二者，我们可以提供一个新的功能。即向日志中添加其他的自定义数据并将其渲染到日志中。

这个功能非常的方便，比如说，我们在日志记录的时候还需要记录当前上下文的用户名称。一种简单的办法是将用户名称放在消息字符串中，但这样处理的方法会在每次记录一条日志都需要手动填写相关数据和模板。更好的一种操作是，将用户名称这个数据项放在日志事件中，就像日志时间和等级一样，在合适的位置自动记录而不是每次调用。

var log = new LoggerConfiguration()
    .Enrich.WithProperty("User", "Dave")
    .WriteTo.Console(outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] [{User}] {Message:lj}{NewLine}{Exception}")
    .CreateLogger();
log.Information("Hello world.");
// 输出： [21:44:04 INF] [Dave] Hello world.

在 Serilog 中，这种向日志事件中添加数据的行为叫 Enrichment，对应数据对象是 Enricher。Enrichment 是 Serilog 在数据方面一个具有强大扩展性的功能，通过向 Serilog 日志记录时塞入新数据，并在日志模板中进行使用，可以大大降低了调用时代码的重复性，且减少了遗漏的可能。比如说，有的人希望每次日志记录都记录当前运行的线程信息、进程信息以及环境变量数据等，通过添加相应的 Enricher 可以达到无需过多关心这些值而直接记录。甚至，像这些较为常用的 Enrichers，官方组织早已给出了相应的扩展包：

• Serilog.Enrichers.Thread：附带当前处理的进程信息
• Serilog.Enrichers.Process：附带当前处理的线程信息
• Serilog.Enrichers.Environment：附带当前的环境信息

3. Serilog 该不该记录这条日志

对于一条日志记录，很多时候，我们并不是要求每条都记录下来，往往是需要丢弃一些日志。这看起来似乎挺反直觉的，数据是重要的，不应该隐式地丢弃某些数据，但是，在实际应用中这样的需求确实是合理的，有时候我们仅希望记录最为重要的日志而不是全部的日志信息。

日志的过滤有两种形式，一种是在将日志记录到各个 Sink 前需要过滤一遍，这种通常是全局过滤。另一种则是每个 Sink 对象有其自己的过滤方式，通常是局部过滤。这里通过两个例子说明。

全局过滤

全局过滤应用场景是日志记录器会记录海量的日志，通常大部分是等级非常低的日志，这类日志往往在开发时候有用，运行期间不应该再输出出来。这种情况下，我们需要设置最小日志输出等级为Information即可。其使用方式如下：

var log = new LoggerConfiguration()
    .WriteTo.Console()
    .MinimumLevel.Information()
    .CreateLogger();

log.Debug("Test here."); // 没有任何输出

另外，全局的过滤条件也可以很复杂，甚至我们可以将之前的 Enricher 结合在一起，比如说，在原先带有用户名的 Enricher 中，我们希望只记录用户名为 Lily 的日志，其他用户名都不记录。这里ForContext也是一种添加 Enricher 的方法，和之前不同的是，它将 Enricher 添加到子Logger中，即所添加的数据只有log1和log2有，log中并没有。

var log = new LoggerConfiguration()
    .Filter.ByIncludingOnly(Matching.WithProperty("User", "Lily")) // 添加过滤条件
    .WriteTo.Console(outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] [{User}] {Message:lj}{NewLine}{Exception}")
    .CreateLogger();

var log1 = log.ForContext("User", "Lily");
log1.Information("Log successed.");  // 输出

var log2 = log.ForContext("User", "Dave");
log2.Information("Log failed.");  // 不输出

局部过滤

同样地，Serilog 允许我们将日志的过滤条件从全局设置缩小到对某个 Sink 的过滤，即只有指定的 Sink 具有过滤日志的功能。

var log = new LoggerConfiguration()
    .WriteTo.Console(restrictedToMinimumLevel: LogEventLevel.Debug)
    .WriteTo.File("log.txt")
    .CreateLogger();

log.Information("Hello world."); // 在Console中没有记录，在File中被记录

4. Serilog中的日志记录器的配置

从上述几个问题中可以看到，所有的日志记录器都是通过LogConfiguration对象的相关属性执行配置后通过CreateLogger方法而生成的。因为在之前都已经或多或少提到，这里就不细谈了。值得一提的是 Serilog 不光提供了代码文本的设置方法（即通过调用某个函数执行设置），还提供了一套通过配置字符串的设置方法，这种方法较为动态，且不需要写固定的代码流程而只需要提供相关配置文件，具体处理流程在后续再提。

Serilog 源码准备

好了，终于开始接触 Serilog 的源码了。这部分主要准备好源码，以便为了后续的学习。

准备源码

Serilog 的地址为 https://github.com/Serilog/Serilog 。我们打开 Windows terminal，通过下面命令将其下载下来。

git clone https://github.com/Serilog/Serilog

下载完成后我们就可以看到Serilog文件夹。然后命令行进入该文件夹。

cd ./Serilog

Serilog源码的默认分支在dev上，这个分支主要是开发的版本，主要用于开发新功能以及修复bug，其变动通常会比较大，不利于学习。通常我们采用发行的最新版本去看，这里采用2.9.0版本，Serilog已经为其打上标签，我们只要切换过去就可以了。

截止到文章发出为止，Serilog已经出了2.10.0版本，不过因为当时还未更新，我看的是2.9.0版本，两个版本差距不大。

git chekckout v2.9.0

之后，需要还原包，编译代码，Serilog 的开发人员编写了一个文件帮助我们编译这个项目，在 windows 下运行 build.ps1 文件，在 Linux 下运行 build.sh 文件即可。

./build.ps1

可能有部分人会遇到无法运行的情况，可能需要修改 powershell 脚本的运行权限。

build.ps1 文件不光会还原项目所需的包，还会重新执行一遍测试代码，检测会不会有错。考虑Serilog是多平台（.net framwork 以及 .net core），在验证测试时，如果没有相应的运行框架，也会报错，不过这个没有关系，只要有其中一个就可以了，我们不是修改源码，阅读源码只要能在一个框架上运行就可以了。本系列主要关注的是 .net core 上的代码流程。

以上步骤全部完成后，就可以利用 vs 打开研究了。

项目架构

通过 vs 打开 Serilog.sln 文件后，整个项目如下所示。

可以发现，其结构比较清晰。

• assert文件夹：一般称为资产文件夹，这里通常保存的是一些说明性文件以及配置文件。比如说README.md、build.ps1以及build.sh等，这里和本系列没有太多关系，可以忽略。
• src文件夹：src是source的简写，里面保存的是Serilog的源码文件，是本次研究的重点，基本上大多工作都在这里面进行。
• test文件夹：里面保存的是针对源码的测试功能代码文件。该文件夹下包含3个项目，Serilog.PerformanceTests应该是Serilog性能测试的项目，Serilog.Tests应该是源码功能测试项目，最后的TestDummies是为相关测试准备的数据类和功能类。考虑到测试代码使用了测试框架，该部分不是本文重点，因而对这块不会过多涉及。当然，如果大家对软件测试有所了解，测试代码能够帮你快速理解某些函数的具体功能。

接下来，我们看下 src 内具有有些什么。Serilog 组织者对这部分的代码维护较为仔细，基本上一个文件夹负责一个功能，这一点和之前的 LogDemo 一样，因此大部分文件夹可以一眼看出大概负责什么功能。

• 根目录：根目录包含四个文件，这点和LogDemo差不多，从LogDemo的结构和之前的使用经验可以猜出来，ILogger是核心功能接口，Log是静态类，它有着类似于ILogger的调用方法，LogConfiguration和LogBuilder一样，专门用来构造ILogger的对象，而LogExtensions则是扩展方法。
• Core目录：从名字上可以猜的出来大概是 Serilog 项目最为核心的处理逻辑。
• Events目录：在 Serilog 中，日志的记录不叫日志消息而叫日志事件，Events 内部保存的应该是和描述日志事件相关的结构，类似于 LogDemo 中的 Data 文件夹。
• Confiuration目录：从名字以及LogConfiguration上可以看出，它内部应该是用于设置相关配置功能。
• Debugging目录：用于调试功能。
• Filters目录：用于设置过滤器。
• Properties目录：这个目录很多项目里面都有，里面保存了AssemblyInfo类，该类主要用于描述当前程序集的一些相关信息，没有太大作用，可以忽略。

总结

今天这篇文章到这里就结束了，本文主要讲述了两个内容，一个是 serilog 的需求分析，它需要有哪些功能。另一个则是 Serilog 项目的源码，做了极其浅显的猜测和分析，为后面的分析提供基础。从下一篇开始，我们就正式进入项目的源码啦。