歡迎光臨
每天分享高質量文章

ASP.NET Core 沉思錄 – 結構化日誌

在 《ASP.NET Core 沉思錄 – Logging 的兩種介入方法》中我們介紹了 ASP.NET Core 中日誌的基本設計結構。這一次我們來觀察日誌記錄的格式,併進一步考慮如何在應用程式中根據不同的需求選擇不同的日誌記錄形式。

太長不讀:直接飛到文章最後 😀

Microsoft.Extension.Logging 體系下的日誌格式

為了便於閱讀,我們仍然將 Microsoft.Extension.Logging 的基本設計結構放在這裡:

奇怪的不合理之處

註:所謂奇怪就是這種不合理是隻是從某一種特定視角看的。

對於記錄日誌而言,雖然一些具體的日誌記錄標的和記錄的格式會有一些聯絡,但是日誌記錄的標的和日誌記錄的格式應該是兩件事情。貌似 Microsoft.Extension.Logging 在此處進行了一些抽象。首先,日誌具體的記錄地點和記錄格式全部由具體的 ILoggerProvider 建立的 ILogger 來完成。而對於日誌的格式化方法,則使用 ILogger.Log 方法中的委託來完成。該委託中包含了一個 formatter 委託引數。該委託接收需要記錄的物件,關聯的異常實體並傳回日誌字串。我們可以在其中定義自己的格式化邏輯。總結起來感覺是:

  • 特定的 ILoggerProvider 建立將日誌記錄到特定種類的目的地的日誌記錄器。例如,ConsoleLogger

  • 指定 ILogger.Log 方法中的 formatter 引數對日誌物件進行格式化。

ILogger.Log 方法除了 formatter 之外還包含如下的引數:

  • logLevel:日誌的級別。

  • eventId:當前事件的標識。

  • state:日誌物件。

  • exception:關聯的異常物件。

formatter 引數將使用其中的 state 引數和 exception 引數對日誌進行格式化。這樣透過替換 formatter 的邏輯就可以更改日誌的形式了。例如,使用如下的邏輯就可以將 state 格式化為 JSON 形式:

// Capture output so that we can assert its content
var writer = new StringWriter();
Console.SetOut(writer);

// Normal initialization logic
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(
    config => config.SetMinimumLevel(LogLevel.Debug).AddConsole());
ServiceProvider provider = serviceCollection.BuildServiceProvider();
var loggerFactory = provider.GetService();
var logger = loggerFactory.CreateLogger("category");

// Write log message
logger.Log(
    LogLevel.Information,
    1,
    new {message = "Hello {name}", name = "World"},
    null,
    (state, exception) => JsonConvert.SerializeObject(state));

// This is very important. The console logger using a async processor to consume
// the queued log message.
Thread.Sleep(1000);

Assert.Equal("...(omitted)...", writer.ToString())

如果您嘗試了上述範例程式就會感到這個設計好像有問題,而如果聯絡整個 Extension.Logging 體系則感覺問題就更大了:

  • formatter只是解決了日誌 message 部分的格式化問題,而無法影響其他資訊的格式化,例如 eventIdlogLevelexception 等。
  • 我們根本不會用到具體的 ILoggerProvider 而是會使用 ILoggerFactory 提供的 Logger 門面。這個 Logger 是一個組合 Logger,也就是它會將 ILogger<>.Log 呼叫分發出來。但是我們很少使用 ILogger<>.Log 方法,而會使用擴充套件方法使用 template message 進行日誌記錄,這意味著所有的子 ILogger 實現都會接到同樣的 formatter。自此,不同的標的採用不同的訊息格式的理想破滅了。

總結一下就是,日誌的記錄標的和日誌的格式混合了起來。職責區分不清。message 的格式化職責交給了門面擴充套件方法;而另一部分格式化職責交給了具體的 ILoggerProvider

從另一種視角看的合理之處

我們換一個視角可能就會得到不一樣的體驗。首先我們更改分析問題的策略。從端到端的角度來思考問題。當我們記錄日誌的時候希望有哪幾類資訊呢?日誌作為追蹤一個事件的依據,應當能夠清晰的說明這個事件。那麼小學語文老師就告訴過我們,記錄一件事情需要有:

  • 時間

  • 地點

  • 人物

  • 起因

  • 經過

  • 結果

如果我們將這些資訊歸一歸類,我們就可以得到這些資訊:

  • 物理世界的環境引數:時間

  • 判斷事件嚴重程度的依據:結果

  • 事件過程的背景關係引數:地點(例如 URI 或代表某種操作的入口)、人物(例如誰進行的操作)、起因(例如方法呼叫引數)、經過(例如呼叫的那個方法)

而要記錄這些資訊,則可以對應到程式中的以下幾種形式的資料:

  • 物理世界的環境引數:例如 DateTimeDateTimeOffset

  • 判斷事件嚴重程度的依據:例如 LogLevel

  • 事件過程背景關係的引數:例如事件的類別 CategoryName;一個包含各種各樣背景關係引數的 object[] 物件;以及對人類友好,能夠將這些引數串起來的訊息模板。

至此,你能夠看到這些引數正是 Microsoft.Extension.Logging 中門面擴充套件方法中需要你來提供的引數。它本來也沒有希望你呼叫 ILogger.Log 方法。而是希望你呼叫擴充套件方法用最舒服的方式達成日誌記錄的目的。

而作為 ILoggerProvider 開發者,你並不一定必須得接受 formatter 生成的格式化後的日誌訊息。你可以選擇處理每一個傳入引數。具體的請參見 FormattedLogValues 型別的原始碼。

階段性總結

  • 日誌記錄和記敘文一樣,只要滿足了六要素就可以說清楚一件事情。而記錄這六要素的形式正式 Extension.Logging 提供給我們的擴充套件方法的引數形式。

  • 分析問題從端到端分析是一種非常靠譜的分析方法。可以避免走彎路。

  • ILogger 的擴充套件方法負責生成日誌訊息,ILoggerProvider 和負責記錄工作的 ILogger 實現負責格式化日誌訊息並將日誌記錄到特定的標的上去。

利用 SeriLog 實現靈活的日誌記錄形式

透過上述分析我們應該能夠看到這種設計的合理性。但是不爭的事實是 ILoggerProvider 一系包攬兩種職能,並沒有進一步抽象,有沒有人來對日誌記錄的標的和日誌記錄的整體格式進行抽象呢?有!那就是被千萬人喜愛的 SeriLog。它在 ILoggerProvider 一級抽象了 ITextFormatter 解決了這個問題:

我不會在這裡介紹 SeriLog 的具體使用方法。網上教程一大堆大家去搜搜好了。我建議直接去官網。

例如,我可以將日誌記錄到 Console 中,預設情況下,這種日誌的格式是給人看的:

// normal initialization logic
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(b =>
{
    Logger seriLogger = new LoggerConfiguration()
        .WriteTo.Console()
        .MinimumLevel.Debug()
        .CreateLogger();

    b.AddSerilog(seriLogger);
});
ServiceProvider provider = serviceCollection.BuildServiceProvider();

// create logger
var loggerFactory = provider.GetService();
var logger = loggerFactory.CreateLogger("category");

// write log
logger.LogInformation("Hello {name}""world");

此時螢幕上會輸出高亮版的,適於閱讀的日誌,類似這樣:

[18:41:27 INF] Hello world

但是如果希望使用其他的格式,則可以透過 ITextFormatter 快速的轉換格式:

var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(b =>
{
    Logger seriLogger = new LoggerConfiguration()
        // PLEASE NOTE that we use JsonFormatter as input paramter
        .WriteTo.Console(new JsonFormatter())
        .MinimumLevel.Debug()
        .CreateLogger();

    b.AddSerilog(seriLogger);
});

ServiceProvider provider = serviceCollection.BuildServiceProvider();

var loggerFactory = provider.GetService();
var logger = loggerFactory.CreateLogger("category");

logger.LogInformation("Hello {name}""world");

這樣就會得到以下的日誌:

{
    "Timestamp":"2019-03-24T19:38:54.4833240+08:00",
    "Level":"Information",
    "MessageTemplate":"Hello {name}",
    "Properties":{"name":"world","SourceContext":"category"}
}

如果還需要 formatter 格式化之後的完整訊息,可以在建立 JsonFormatter 時指定 new JsonFormatter(renderMessage: true) 這樣就會得到包含完整可讀訊息的結果:

{
    "Timestamp":"2019-03-24T19:44:51.0430260+08:00",
    "Level":"Information",
    "MessageTemplate":"Hello {name}",
    "RenderedMessage":"Hello \"world\"",
    "Properties":{"name":"world","SourceContext":"category"}
}

這樣,在實際的操作中。我們可以直接使用 Microsoft.Extension.Logging 預設體系對 ILoggerProvider 進行擴充套件達到對記錄標的和記錄格式的控制;也可以將其與 SeriLog 整合。透過 Sink 和 ITextFormatter 組合的方式分別對記錄標的和記錄格式進行控制。

總結

一圖勝千言:

圖-1 預設 Microsoft.Extension.Logging 型別及資訊傳遞路徑

圖-2 整合 SeriLog 後型別及資訊傳遞路徑

如果您覺得本文對您有幫助,也歡迎分享給其他的人。我們一起進步。歡迎關註我的部落格(https://clrdaily.com)

    贊(0)

    分享創造快樂