.NET Worker Service 新增 Serilog 日誌記錄

前面我們瞭解了 .NET Worker Service 的入門知識^[1] 和 如何優雅退出 Worker Service ^[2]，今天我們接著介紹一下如何為 Worker Service 新增 Serilog 日誌記錄。

在實際的生產環境中，應用程式中記錄日誌是非常寶貴的。在許多情況下，開發人員無法直接訪問生產環境來除錯問題。高質量的日誌記錄為解決線上問題提供了線索和依據。

日誌記錄是將應用程式操作和狀態記錄到輔助介面的過程。

.NET 日誌記錄框架

.NET 中有很多預設的日誌記錄提供程式^[3]，它們可以將日誌輸出到控制檯、Debug、EventSource 和 EventLog 等，例如在上一篇的示例中，預設的實現是將日誌記錄輸出到了控制檯視窗。

但是 .NET 中沒有可以幫我們將日誌資訊輸出到檔案和資料庫的內建提供程式，而這卻是我們在生產環境中十分常見的應用場景。為了實現這一功能，我們需要為 .NET 實現自定義的日誌記錄提供程式^[4]，這需要大量時間，因為需要考慮很多事情，比如讀寫效能、儲存空間、配置等等。

幸運的是，一些優秀的第三方程式包可以為我們提供幫助，.NET 中三種最流行的日誌框架分別是：log4net、NLog、Serilog，我們只需從 NuGet 包儲存庫中獲取它們，然後簡單地配置一下便可以愉快地使用它們了。

log4net

log4net^[5] 是一個始於 2001 年的領先的日誌記錄框架，最初是 Java 框架 log4j 的埠。多年來，Apache Logging Services 專案持續進行開發，沒有其他框架能像 log4net 一樣久經考驗。log4net 是所有現代 .NET 日誌記錄框架的鼻祖，在日誌框架中，日誌級別（log levels）、記錄器(logger)和輸出模組(appenders/targets/sinks)等概念幾乎都是通用的^[6]。相信所有多年使用 .NET 程式設計的朋友對 log4net 都相當熟悉。

log4net 好用、穩定且靈活，但是它的配置相對來說比較複雜一些，而且很難實現結構化的日誌記錄。

NLog

NLog^[7] 也是一個相當老的專案，最早的版本釋出於 2006 年，不過目前仍在積極開發中。NLog 從 v4.5 版本開始新增了對結構化日誌記錄的支援。

與 log4net 相比，NLog 的配置更加容易，並且基於程式碼的配置也比較簡潔。NLog 中的預設設定比 log4net 中的預設設定會更合理一些。需要注意的一點是，當使用這兩個框架，您可能會遇到同一個問題，那就是配置有問題（比如忘記複製配置檔案）時，不會得到任何提示，也不會輸出日誌資訊。假如您將應用部署上線以後遇到這個情況，這將是致命的，因為許多問題的檢查都是依賴於日誌記錄的。當然，這麼設計的初衷是避免讓應用程式因日誌問題而導致崩潰。

Serilog

Serilog^[8] 日誌記錄框架釋出於 2013 年，相對來說是一個較新的框架。與其他日誌框架不同的是，Serilog 在設計時考慮了強大的結構化事件資料，提供了開箱即用的結構化日誌實現。所以 Serilog 對結構化日誌的支援非常好，而且配置簡潔。Serilog 中的日誌可以傳送到許多終端，Serilog 稱這些終端為“輸出模組庫(sinks)”。您可以在 https://github.com/serilog/serilog/wiki/Provided-Sinks 頁面檢視非常全面的列表。

Serilog 中還有一個功能強大的概念是Enricher，可以通過各種方式來豐富日誌事件的屬性，從而向日志新增新的資訊。NuGet 中提供了一些預建的 Enricher，您也可以通過實現 ILogEventEnricher 構建自己的 Enricher。

結構化日誌記錄

或許您已注意到了，前面我多次提到結構化日誌記錄，那麼什麼是結構化日誌記錄，為什麼我要強調結構化日誌記錄呢？

通常情況下，您會發現日誌資訊基本上包含兩部分內容：訊息模板和值，而 .NET 通常只接受諸如 string.Format(...) 這樣的的輸入字串。比如：

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

var elapsedMs = 34;

log.Information("Processed Position, Latitude:{0}, Longitude: {1} in Elapsed:{2} ms.", position.Latitude, position.Longitude, elapsedMs);

這條日誌只是簡單地被轉換為文字輸出到日誌檔案中：

[INF] Processed Position, Latitude:25, Longitude: 134 in Elapsed:34 ms.

這看起來很好，但它可以更好！

當我們遇到問題的時候，我們需要根據一些已知的資訊來檢索日誌記錄。比如，假設我們已知 Latitude 為 25，Longitude 為 134，我們要查詢這條日誌的話，該怎麼做呢？由於上面輸出的日誌資訊是簡單的文字，有經驗的您可能立馬會想到使用正則表示式或者簡單的字串匹配，但這樣不僅不夠直觀，實現起來也比較麻煩。有沒有更好的方法呢？

如果我們在儲存日誌的時候，將其中包含值的部分作為特徵提取出來，形成由鍵和值組成的有結構的 JSON 物件，作為每條日誌記錄的屬性(properties)：

{"Position": {"Latitude": 25, "Longitude": 134}, "Elapsed": 34}

然後，在我們檢索的時候只需要查詢日誌記錄的 properties 就可以了，它是結構化的，檢索起來既方便又直觀。

Serilog 幫我們實現了這一點，您只需改動一行程式碼就可以了：

log.Information("Processed {@Position} in {Elapsed:000} ms.", position, elapsedMs);

Position 前面的 @ 是解構操作符，它告訴 Serilog 需要將傳入的物件序列化，而不是呼叫 ToString() 轉換它。

Elapsed 之後的 :000 是一個標準的 .NET 格式字串，它決定該屬性的呈現方式。

為 Worker Service 新增 Serilog 日誌

現在，您已經大概瞭解了 Serilog，以及為什麼我會選用它的原因。下面我用一個例項來介紹一下它的用法。

需要用到的開發工具：

• Visual Studio Code：(https://code.visualstudio.com/)
• 最新的 .NET SDK：(https://dotnet.microsoft.com/download)
• DBeaver：(https://dbeaver.io/)

本示例基於上一篇文章中的 Worker Service 原始碼^[9]修改，如果您安裝有 git，可以用下面的命令獲取它：

git clone [email protected]:ITTranslate/WorkerServiceGracefullyShutdown.git

然後，使用 Visual Studio Code 開啟此專案，執行一下，以確保一切正常：

dotnet build

dotnet run

您在 Serilog 官方文件中可以看到很多例子，不過大部分示例都是使用編碼的方式配置 Serilog，或者以 xml 的方式配置在老舊專案的 AppSettings 檔案中。

在本文的示例中，我將以 JSON 的方式把 Serilog 的配置放置在現在流行的 appsettings.json 配置檔案中。我們只需要修改 Program.cs 和 appsettings.json，不需要修改 Worker.cs。

安裝依賴程式包

首先，安裝我們所需的程式包：

dotnet add package Serilog

dotnet add package Serilog.Settings.Configuration

dotnet add package Serilog.Extensions.Hosting

dotnet add package Serilog.Sinks.Console

dotnet add package Serilog.Sinks.RollingFile

修改 Program

然後，修改 Program 中的 Main 方法，從 appsettings.json 讀取配置並根據配置構建 Serilog 日誌記錄器的例項：

public static void Main(string[] args)

{

    var configuration = new ConfigurationBuilder()

        .SetBasePath(Directory.GetCurrentDirectory())

        .AddJsonFile("appsettings.json")

        .AddJsonFile($"appsettings.{Environment.GetEnvironmentVariable("DOTNET_ENVIRONMENT") ?? "Production"}.json", true)

        .Build();

    // 全域性共享的日誌記錄器

    Log.Logger = new LoggerConfiguration()

        .ReadFrom.Configuration(configuration)

        .Enrich.FromLogContext()

        .CreateLogger();

    try

    {

        var separator = new string('-', 30);

        Log.Information($"{separator} Starting host {separator} ");

        CreateHostBuilder(args).Build().Run();

        Log.Information($"{separator} Exit host {separator} ");

    }

    catch (Exception ex)

    {

        Log.Fatal(ex, "Host terminated unexpectedly");

    }

    finally

    {

        Log.CloseAndFlush(); // 釋放資源

    }

}

修改 Program 中的 CreateHostBuilder 方法，將 Serilog 設定為日誌提供程式：

public static IHostBuilder CreateHostBuilder(string[] args) =>

    Host.CreateDefaultBuilder(args)

        .ConfigureServices((hostContext, services) =>

        {

            services.AddHostedService<Worker>();

        })

        .UseSerilog(); //將 Serilog 設定為日誌提供程式

修改配置檔案 appsettings.json

修改應用程式配置檔案 appsettings.json，新增 Serilog 節點(Section)。

Serilog 所需的配置節點名稱預設為 Serilog；當然，您也可以改變它，但要在讀取的時候指定節點名。

{

  "Serilog": {

    "Using": [

      "Serilog.Sinks.Console",

      "Serilog.Sinks.RollingFile"

    ],

    "MinimalLevel": {

      "Default": "Information",

      "Override": {

        "System": "Warning",

        "Microsoft": "Information"

      }

    },

    "WriteTo": [

      {

        "Name": "Console"

      },

      {

        "Name": "RollingFile",

        "Args": {

          "pathFormat": "Logs\\{Hour}.txt",

        }

      }

    ]

  }

}

看一下我們都配置了什麼：

您可以在 Serilog.Settings.Configuration 包^[10] 的文件中找到這些配置的說明。

Using 節點

Using 節點包含了所需的程式集列表，用於自動發現 WriteTo 和 Enrich 等節點中配置的方法所屬的程式集。

對於 .NET Core 專案，構建工具會生成 .deps.json 檔案，並且 Serilog.Settings.Configuration 包使用 Microsoft.Extensions.DependencyModel 實現了一個約定，從而可以從名稱任意位置帶有Serilog 的依賴程式包中找出正確的包，並從中提取配置的方法。因此，上面示例中的 Using 節點是可以省略的。

MinimalLevel 節點

MinimumLevel 物件配置輸出日誌的最低級別。新增 MinimalLevel.Override 項，可以覆蓋某些特定名稱空間的最小級別。

WriteTo 節點

使用 WriteTo 物件配置輸出模組(sinks)，可以同時配置並激活多個輸出模組。本示例中我們配置了 Console 和 RollingFile，前者將日誌輸出到控制檯，後者將日誌輸出到滾動檔案中。

將日誌輸出到檔案，您還可以使用 Serilog.Sinks.File 程式包，它也支援滾動檔案。

Args 用於配置 Sink 的選項。本例中 pathFormat 配置了日誌檔案的存放位置，該項的值中 {Hour} 是滾動日誌檔案的 檔名格式說明符。該輸出模組支援三種不同的檔名格式說明符（區分大小寫）：

• {Date}：每天建立一個檔案。檔名使用 yyyyMMdd 格式。
• {Hour}：每小時建立一個檔案。檔名使用 yyyyMMddHH 格式。
• {HalfHour}：每半小時建立一個檔案。檔名使用 yyyyMMddHHmm 格式。

完成以上這些配置後，我們執行應用程式：

dotnet build

dotnet run

您會發現在應用程式根目錄下多了一個 Logs 資料夾，可以將日誌資訊正常輸出到檔案了。同時，控制檯也有輸出日誌。兩者的輸出格式略有不同，控制檯中的輸出更簡潔一些。

新增 Enricher 和格式化輸出

前文我提到過 Serilog 中還有一個功能強大的概念是Enricher，這裡我就以預建的 Enricher 來舉例說明一下它的使用。

新增以下依賴程式包：

dotnet add package Serilog.Enrichers.Thread

dotnet add package Serilog.Enrichers.Environment

dotnet add package Serilog.Enrichers.Process

這三個 Enricher 分別提供了不同的資訊以豐富日誌事件的屬性。

• Serilog.Enrichers.Environment 提供 WithMachineName() 和 WithEnvironmentUserName()
• Serilog.Enrichers.Process 提供 WithProcessId()
• Serilog.Enrichers.Thread 提供 WithThreadId()

修改 appsettings.json，向 Serilog 配置物件新增 Enrich 配置節點，以豐富日誌事件的資訊：

"Enrich": [

  "WithMachineName",

  "WithProcessId",

  "WithProcessName",

  "WithThreadId"

]

修改 appsettings.json，向 WriteTo 下的 RollingFile 物件節點的 Args 新增一個 outputTemplate 選項，以自定義輸出訊息模板：

{

  "Name": "RollingFile",

  "Args": {

    "pathFormat": "Logs\\{HalfHour}.txt",

    "outputTemplate": "{Timestamp:o} [{Level:u3}] ({MachineName}/{ProcessId}/{ProcessName}/{ThreadId}) {Message}{NewLine}{Exception}"

  }

}

修改好配置後，重新執行應用程式：

dotnet build

dotnet run

再檢視一下日誌檔案，您會發現日誌已經按我們自定義的格式輸出了，並且多了一些我們使用 Enricher 獲得的資訊：(計算機名/程序ID/程序名稱/執行緒ID)。

2021-05-27T18:15:40.2992230+08:00 [INF] (DESKTOP-6LTYU3O/54376/MyService/1) Worker running at: 05/27/2021 18:15:40 +08:00

將日誌儲存到資料庫

前文我提到過日誌檔案的屬性(properties)，為什麼直到現在還沒有看到過它呢？

這是因為，當 Serilog 將日誌事件寫入檔案或控制檯時，訊息模板和屬性將僅會呈現為易於閱讀的友好文字。而當我們將日誌事件傳送到基於雲的日誌伺服器、資料庫和訊息佇列等輸出模組(sinks)時，就可以儲存為結構化的資料了。

為了簡便起見，我以 SQLite 資料庫為例來介紹一下。

新增 SQLite 依賴程式包：

dotnet add package Serilog.Sinks.SQLite

修改 appsettings.json，在 Serilog 配置中的 WriteTo 節點下新增以下配置節點，以向 SQLite 輸出日誌：

{

  "Name": "SQLite",

  "Args": {

    "sqliteDbPath": "Logs\\log.db",

    "tableName": "Logs",

    "maxDatabaseSize": 1,

    "rollOver": true

  }

}

解釋一下 Args 各個選項的作用：

• sqliteDbPath： SQLite 資料庫的路徑。
• tableName： 用於儲存日誌的 SQLite 表的名稱。
• maxDatabaseSize： 資料庫的最大檔案大小，可以以 MB 為單位增加。預設為 10MB，最大為 20GB。為了方便測試，我在這裡將其設定為 1MB。
• rollOver： 如果檔案大小超過最大資料庫檔案大小，則建立滾動備份，預設為 true。

此時，再次執行應用程式：

dotnet build

dotnet run

您將會在應用程式目錄下的 Logs 資料夾中看到一個 SQLite 資料庫檔案 log.db。使用 DBeaver 開啟檢查一下：

可以看到，SQLite 輸出模組自動為我們建立了資料庫和表，日誌記錄成功了。

我們配置了資料庫檔案大於 1MB 時自動滾動備份，可以多輸出一些日誌測試一下，看它是否有自動滾動備份。我的測試結果如下圖：

再看一下 Serilog 捕獲的日誌事件的屬性(properties)：

Serilog 使用訊息模板、以及命名和位置引數擴充套件 .NET 的格式化字串，不過 Serilog 捕獲與每個命名引數相關聯的值，而不是直接將事件格式化為文字。我們新增幾行程式碼，測試一下 Serilog 捕獲日誌事件的情況：

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

var elapsedMs = 34;

Log.Information("Processed {@Position} in {Elapsed:000} ms.", position, elapsedMs);

上面的示例在日誌事件中記錄了兩個屬性：Position 和 Elapsed，Position 前面的 @ 操作符告訴 Serilog 要序列化傳入的物件。最終我們在資料庫中儲存的結構化的 Properties 如下所示：

{"Position":{"Latitude":25,"Longitude":134},"Elapsed":34,"MachineName":"DESKTOP-6LVG1OL","ProcessId":54332,"ProcessName":"MyService","ThreadId":1}

Serilog 對結構化事件資料深入且豐富的支援，開創了原本使用傳統日誌記錄器所沒有的巨大的診斷可能性。

總結

在本文中，我介紹了 .NET 中常用的結構化事件日誌框架 Serilog，以及使用它的原因和好處；並通過一個 .NET Worker Service 例項，說明如何將日誌儲存到滾動檔案和資料庫中。

Serilog 是一個穩定的、配置簡潔的、功能強大的、可擴充套件的、支援結構化日誌事件的 .NET 日誌記錄提供程式，值得我們在應用中廣泛使用。

您可以從 GitHub 下載本文中的原始碼^[11]。

作者 ： 技術譯民

出品 ： 技術譯站

---

1. https://mp.weixin.qq.com/s/ujGkb5oaXq3lqX_g_eQ3_g .NET Worker Service 入門介紹 ︎

2. https://mp.weixin.qq.com/s/voxAxh9rQQogE3_Yc1-eCQ 如何優雅退出 Worker Service ︎

3. https://docs.microsoft.com/zh-cn/dotnet/core/extensions/logging-providers ︎

4. https://docs.microsoft.com/zh-cn/dotnet/core/extensions/custom-logging-provider ︎

5. https://logging.apache.org/log4net/ ︎

6. https://stackify.com/nlog-vs-log4net-vs-serilog/ ︎

7. https://nlog-project.org/ ︎

8. https://serilog.net/ ︎

9. https://github.com/ITTranslate/WorkerServiceGracefullyShutdown ︎

10. https://github.com/serilog/serilog-settings-configuration ︎

11. https://github.com/ITTranslate/WorkerServiceWithSerilog 原始碼下載 ︎