[NETCore] 結構化日誌 Serilog - 配置設定 ~ m@rcus 學習筆記

前言
上一篇在結構化日誌 Serilog 初體驗介紹了關於 Serilog 的基本操作，這篇是針對 Serilog 在 ASP.NET Core 的設定與 Config 做進一步的介紹，若有問題或是錯誤的地方歡迎提出來一起討論或是給予指導。

基本使用
首先先來回顧一下基本使用方式，在 Serilog 如果要紀錄 Log 資訊必須使用 LoggerConfiguration 產生 ILogger 的 instance，Serilog 核心負責紀錄 Log 事件的內容，要輸出 Log 則需要指定其 Snik (槽) 也就是接收器，舉例來說如果要將 log 輸出至 Console 中呈現，第一步為下載 Console 的 Sink library 套件

PM > Install-Package Serilog.Sinks.Console

接著可以使用 LoggerConfiguration 產生 ILogger 實體以及 sinks 提供的 writeTo.Console 擴充方法(extension method) 方法將內容輸出至 Console 中

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateLogger();
 
Log.Information("avengers 4 endgame !");

如果有多個輸出端 (skins) 需求，則可以同時指定多個項目，下面為同時輸出 Console 與 File， File 格式定義檔案輸出位置在 logs 資料夾的 log-.txt 檔案，區間為每天

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .WriteTo.File("log-.txt", rollingInterval: RollingInterval.Day)
    .CreateLogger();

以上代碼輸出內容如下，黑底的為 Console，白底的為 file 檔案

Output templates
Serilog 預設輸出格式為 {Timestamp：yyyy-MM-dd HH：mm：ss.fff zzz} [{Level：u3}] {Message：lj} {NewLine} {Exception}，如果與開發者需要自訂輸出格式時可以透過 outputTemplate 參數自行定義，也可以透過 {Properties:j} 自行加入所需要的字串到輸出模板，以下範例為自定義輸出格式不包含日期的範例

var template = "{Timestamp:HH:mm:ss} [{Level:u3}] {Message}{NewLine}{Exception}";
 
Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .WriteTo.File("logs/log-.txt", outputTemplate: template)
    .CreateLogger();
 
Log.Information("avengers 4 endgame !");

結果會是

05:48:38 [INF] avengers 4 endgame !

LogLevel
Seril紀錄 log 時候都會指定紀錄等級 LogLevel ，在 Serilog 可以透過 MinimumLevel 來設定 LogLevel 層級，其中提供六個等級，每個等級都具有代表其意義，舉例來說在開發 API 接口時可以使用 info 紀錄 Request 的參數資訊，找不到 id 資料時可能會用 warning 方法，當執行異常時會用 Error 記錄其 exception 內容；都可以依據需求使用團隊覺得最合適的方式來記錄，使用方式如下

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console()
    .CreateLogger();

當輸出到不同接收器時會用到 skins ，所有接收器都支援 restrictedToMinimumLevel 參數來設定各自輸出的 loglevel，舉例來說以下代碼設定 File loglevel 為 debug，Console 輸出為 informarion

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.File("log.txt")
    .WriteTo.Console(restrictedToMinimumLevel: LogEventLevel.Information)
    .CreateLogger();

設定列舉值代表等級高越需要記錄，紀錄 log 是會有成本的，在開發環境時時可能為了得到夠多的紀錄資訊因而選擇 verbose 或是 debug 設定值，在 Production 時可能會設定成 information，看團隊的需求而定，另外如果未定義 loglevel 時預設會是 information 層級 loglevel，在 serilog 定義的 logLevel 列舉如下

/// <summary>
/// Specifies the meaning and relative importance of a log event.
/// </summary>
public enum LogEventLevel
{
    Verbose,
    Debug,
    Information,
    Warning,
    Error,
    Fatal,
}

其各自的 logLevel 說明可以參考官方說明

Enrichers
Enrich 是添加自定義屬性到 Log 的方式，也是我個人覺得很喜歡的功能，使用方法是在建立 ILogger 的 instance 時設定自定義的屬性值，接著設定 output template 屬性要輸出的位置，自己使用後的感覺很像是在寫程式時設定區域變數與相對的值 (value)，接著在方法中都可以使用到，以下範例是使用 Enrich.WithProperty 設定 API Version 與 MachineName 值，指定格式為 [{Timestamp:hh:mm:ss} {Level:u3}] {Message,-30:lj} {Properties:j} {NewLine}{Exception}，代碼如下

Log.Logger = new LoggerConfiguration()
    .Enrich.WithProperty("API Version", "1.0.1")
    .Enrich.WithProperty("MachineName", Environment.MachineName)
    .WriteTo.Console(outputTemplate: "[{Timestamp:hh:mm:ss} {Level:u3}] {Message,-30:lj} {Properties:j} {NewLine}{Exception}")
    .CreateLogger();
 
Log.Information("avengers 4 endgame !");

以下為輸出結果，可以看到在 message 後面加上了指定的 Property 內容

[07:05:39 INF] avengers 4 endgame ! {API Version="1.0.1", MachineName="MarcusBlog"}

另外，也可以透過實做 ILogEventEnricher 介面實作自定義 Enricher，以下範例是自定義 ThreadId

class ThreadIdEnricher : ILogEventEnricher
{
    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
        logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty(
                "ThreadId", Thread.CurrentThread.ManagedThreadId));
    }
}
 
Log.Logger = new LoggerConfiguration()
                .Enrich.With(new ThreadIdEnricher())
                .WriteTo.Console(
                    outputTemplate: "{Timestamp:HH:mm} [{Level}] <{ThreadId}> {Message}{NewLine}{Exception}")
                .CreateLogger();
 
Log.Information("avengers 4 endgame !");

輸出的 Log 就可以看到號內容所使用的 ThreadID 為 <1>

07:13 [Information] <1> avengers 4 endgame !

以上為簡單的範例，在新增 ThreadId 也可以透過 nuget 下載 Serilog.Enrichers.Thread，可以直接使用 Enrich.WithThreadId() 達到相同效果，詳細更多細節可以參考官方網站詳細介紹 : Enrichment

Setting
在專案開發時都會透過設定檔儲存相關資訊，如果是建立 .NET Core Application 時預設使用 appsettings.json 與 appsettings.{ENVName}.json 來存放設定與隔離環境設定，Serilog 也支援可以將設定資訊存放在 config 中，config 檔案格式可以是 json、xml 或是 yml 檔案，在使用時必須先到 nuget 下載 Serilog.Settings.Configuration ，並在設定檔 appsettings.json 中加入 Serilog 相關設定如下

{
  "Serilog": {
    "Using": [ "Serilog.Sinks.Console" ],
    "MinimumLevel": "Debug",
    "WriteTo": [
      { "Name": "Console" },
      {
        "Name": "File",
        "Args": {
          "path": "D:\\logs\\serilog-configuration-sample.txt",
          "OutputTemplate": "{Timestamp:yyyy/MM/dd HH:mm:ss.fff zzz} {Application} [{Level}] {Message}{NewLine}{Exception}"
        }
      }
    ],
    "Enrich": [ ],
    "Destructure": [ ],
    "Properties": {
      "Application": "DemoLab"
    }
  }
}

設定內容為輸出至 Console 與 File 檔案，並指定檔案路徑 (Path) 與輸出格式 (outputTemplate) ，最後還自訂 Accpilcation 屬性為 DemlLab，希望在寫 log 時可以出現。設定完 Config 內容接下來就是在 Program 底下的 main.cs 輸入以下代碼，主要目的是定義產生 ILogger 的來源是使用 ReadFrom.Configuration 讀取設定檔中的 Serilog 設定 config

var configuration = new ConfigurationBuilder()
    .SetBasePath(Directory.GetCurrentDirectory())
    .AddJsonFile("appsettings.json")
    .Build();
 
Log.Logger = new LoggerConfiguration()
    .ReadFrom.Configuration(configuration)
    .CreateLogger();
 
Log.Information("Hello, i like iron man.");

測試輸出結果 log 如下

// console 
[12:01:29 INF] Hello, i like iron man.
 
// File 
2019/05/02 12:01:29.082 +08:00 DemoLab [Information] Hello, i like iron man.

有關 settings 部分還有很多細節可以自行定義，像是本篇文章提到的 LogLevel、Enrichers、IConfiguration 都可以在設定檔中設定，更多細節可以參考官方 GitHub 網站介紹 : Serilog.Settings.Configuration

感想
連續兩篇介紹了 Serilog 的基本使用與設定方式，也加深了自己對 Serilog 的認識與正確的使用方式，最近在專案中也有在 .NET Core API 與 Generic Host Console 專案中應用，有時間也整理實作的部分在分享給有需要朋友，也希望這兩篇基本的介紹文有加深各位對 Serilog 的認識 :)

參考
Structured logging concepts in .NET Series

Serilog

[NETCore] ASP.NET Core Task block 檢測器 - Ben.BlockingDetector前言微軟從 ASP.NET Framework 4.5 開始支援 async / await 語法，提供開發者在撰寫非同步作業時更輕鬆與容易上手，如果對於 async / await 不夠熟悉可以看黑暗大之前的好文 ASP.NET async 基本心法，但有時在一知半解寫出來的代碼有時殺傷力才會是最可怕的，如果沒有正確使用 async / await 會造成 Thread block 的問題發生，因此在撰寫&nbs… Read More
[NETCore] 初探 ASP.NET Core 3.0 新朋友 - System.Text.Json前言相信大家都發現 JSON 格式已經取代過去的 XML 成為資料交換的首選，在 ASP.NET Core 3.0 專案範本設定檔也是使用 JSON 作為設定檔的格式，並內建廣受好評的 Json.NET 做為處理 JSON 格式的函式庫，依存放在 Microsoft.AspNetCore.App 無須在透過 Nuget 另外下載，但老牌的 Json.NET 雖然好用但也相對的存在過去一些沉重的包袱，為了提高性能&n… Read More
[NETCore] ASP.NET Core 靜態檔案設定 - UseStaticFiles前言在過去開發 .NET Framework 時代在專案使用靜態檔案是一塊小蛋糕，只需要在專案指定 Folder 加入需要的靜態檔案內容即可，像是圖片就放在 image、javascript 內容就放在 js 資料底下...等等，但同樣事情在 ASP.NET Core 專案可就完全不同，在 .NET Core 專案中是無法直接瀏覽靜態檔案的，需要透過一些設定方式才可以在專案看到像是 HTML、CSS、Image 或是 javascript 靜態… Read More
[NETCore] 使用 BenchmarkDotNet 測試程式碼效能前言在開發或是 POC 時為了記錄代碼程式執行的時間，都會採用在代碼上加上 stopWatch 紀錄花費時間，使用方式不外乎就是 new Stopwatch、Start、Stop、Reset、ElapsedMilliseconds，以詳細記錄代碼所花費的時間，接下來為了要顯示在 console 上可能還要針對 log 在輸出內容做簡單排版方便記錄，最近發現上述惱人的事情都可以使用 Benc… Read More
[VisualStudio] ASP.NET Core 非同步代碼分析工具 - Threading.Analyzers前言在上一篇介紹了 ASP.NET Core Task block 檢測器 - Ben.BlockingDetector ，可以在 ASP.NET Runtime 時偵測 task block 的情境並透過 log 輸出，但預防的工作總是希望越早進行越好，越快發現就更早的預防不好的寫法及早修改，本篇要介紹的是非同步代碼分析套件，可以分析靜態代碼中可能用法"不正確"的代碼，可以若有問題或是錯誤的地方歡迎高手大大給予指導或討論。 … Read More

m@rcus 學習筆記

只有累積，沒有奇蹟

2019年5月2日星期四