在上兩篇文章(鏈接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 項目的源碼,做了極其淺顯的猜測和分析,為后面的分析提供基礎。從下一篇開始,我們就正式進入項目的源碼啦。