只有累積,沒有奇蹟

2019年5月2日 星期四

[NETCore] 結構化日誌 Serilog - 配置設定

前言
上一篇在 結構化日誌 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

2019年5月1日 星期三

[NETCore] 結構化日誌 Serilog 初體驗

前言
在 .NET 使用日誌框架第一時間會想到 NLog 或是 Log4Net 兩種 Log 常使用的 Library,Serilog 是這幾年快速崛起的 Log 框架之一,Serilog 是以 Structured logging 為基礎進行設計,透過 logging API 可以輕鬆的記錄應用程式中對象屬性,方便快速進行 logging 內容進行查詢與分析,並將其紀錄內容透過 json (可指定) 的方式輸出,這篇就介紹 Serilog 在 ASP.NET Core 中如何的安裝與基本應用使用,若有問題或是錯誤的地方歡迎網路的高手大大給予指導。

安裝
Serilog 支援 NET Framework 與 NET Core 版本,使用前需要透過 Nuget 進行下載的動作,首先先建立一個名稱為 SerilogLab 的 Console 專案,接著開啟 Nuget Package Manager (快速打開方法: Ctrl + Q ) 輸入 "Serilog" 搜尋,安裝最新版的 serilog 套件
或是在 Nuget Package Console 輸入指令,下載核心項目 Serilog 與需要用到的 Logging Sinks 
PM> Install-Package Serilog
PM> Install-Package Serilog.Sinks.Console 
確認是否有安裝成功,可以點擊專案檔內容是否包含以下 package
<PackageReference Include="Serilog" Version="2.8.0" />
<PackageReference Include="Serilog.Sinks.Console" Version="3.1.1" />

Logging Sinks
Serilog 核心負責紀錄 Log 事件的內容,如果要將 Log 輸出則是透過 Snik (槽),Serilog 最常見的是 console 與 file 檔案兩種 sink,另外提供不同的輸出方式如Amazon、Azure、Elasticsearch、Slack等多樣,需要使用時要在 nuget 下載 Sinks library 另外官方也有整理目前支援的 sinks 清單 : 傳送門,有興趣可以自行查閱。

使用
接著在 Console 專案 Program 啟動加入下列代碼
using System;
using Serilog;

namespace SerilogLab
{
    class Program
    {
        static void Main(string[] args)
        {
            var log = new LoggerConfiguration()
                .WriteTo.Console()
                .CreateLogger();

            log.Information("Hello, Serilog!");
            log.Debug("This is debug");
            log.Error("Something error");
            log.Fatal("This is fatal");

            Console.ReadKey();
        }
    }
}
程式說明

  • LoggerConfiguration : 使用 LoggerConfiguration 建立 ILogger 物件
  • WriteTo.Console : 使用 Console 輸出至主控台
  • CreateLogger : 使用配置的 sink 接收器也就是 Console,新增 Logger 物件
  • 採用 Fluent Interface 流利介面的設計 ( LINQ 很常見),讓代碼看起來更簡潔。以上代碼輸出如下

    Log
    在 Serilog 中提供靜態 Log 讓開發者使用,有時在開發時會在建構子注入 logging 物件方便記錄,舉例來說常常可以看到在 Controller、service 或是 repository 上建構子注入 ILog 的 interface,可以透過以下方式統一建立 Log 實體存放在 Serilog Log 的 Static Logger 中,代碼如下 
    Log.Logger = new LoggerConfiguration()
                    .WriteTo.Console()
                    .CreateLogger();
    
    Log.Information("Hello, Serilog by Log!");
    輸出如下,與一般輸出是相同的
    注意 : 使用 Static 的方式缺點就是在測試時會造成不便,因此可以依據需求來決定是否需要使用

    結構化日誌
    為了瞭解 Serilog 背後的設計理念與原由,作者 Nicholas Blumhardt 在個人部落格寫了一系列相關文章來說明設計概念,以下為小弟粗淺的整理文章重點,想了解更多的朋友也請透過文章傳送門自行服用內容 : Structured logging concepts in .NET Series ,在應用程式紀錄 Log 時,大致來說紀錄方式可以分為 Text logging 也是一般常見的 log 檔記錄方式 與 Structured logging 與結構化的方式記錄 Log
    Text logging :
    12:23:10 [INF] Service "loyalty-card-printer" starting up on host 8fd342hkg22u
    12:23:11 [INF] Listening on http://8fd342hkg22u.example.com:1234
    12:40:55 [INF] Card replacement request received for customer-98048
    … 
    內容清楚且容易閱讀,清楚紀錄發生的時間點、問題層級以及內容資訊,呈現格式對開發者閱讀是方便地但如果搜尋 Log 內容時則需使用全文檢索或是正規表達式進行 parse 的動作,才可以找到正確的資訊。
    Structured logging : 
    time=12:23:11, level=INF, endpoint=http://8fd342hkg22u.example.com:1234, activity=listening
    time=12:23:20, level=INF, customer=customers-1099972, activity=replacement
    time=12:40:55, level=INF, customer=customer-98048, activity=replacement
    …
    時間戳記加上其屬性值 key / value 的組合,透過結構化的方式可以讓 Log 更容易得讓機器閱讀,更方便於大規模的搜尋與分析。其 logging 規範名為 message template,同時滿足開發者閱讀方便性與機器可解讀格式,下圖為 message template 概念的示意圖
    碎碎念 : 好的 Log 設計與監控可以讓問題快速被定位,而不是讓 oncall 同仁透過觀落陰解決。

    結構化數據
    一開始有輸出 Hello Serilog 簡單提到 serilog 基本使用方式,接著在說明 serilog 結構化資料的方法,下面範例是使用 Serilog information 方法紀錄 var 與集合 fruit 內容
    // var
    var count = 456;
    log.Information("Retrieved {Count} records", count);
    
    // Collections 
    var fruit = new[] { "Apple", "Pear", "Orange" };
    log.Information("In my bowl I have {Fruit}", fruit);
    上面代碼 Console 輸出如下
    [11:30:59 INF] Retrieved 456 records
    [11:30:59 INF] In my bowl I have ["Apple", "Pear", "Orange"]
    Serilog 可以將事件的屬性記錄到 Log 中,舉例來說如果希望輸出為 Json 格式取代既有的 txt 檔案 (也可輸出其他格式),可以指定其 formatter 並載入  Serilog.Formatting.Compact  設定格式化設定,即可將輸出內容轉為 json 檔案
    var log = new LoggerConfiguration()
        .WriteTo.Console()
        .WriteTo.File(new CompactJsonFormatter(), "log.txt")
        .CreateLogger();
    原本範例 count 會加上屬性,時間會加上@t,並輸出定義的模板(message template) @mt 及參數內容
    {
      "@t": "2019-05-01T03:30:59.7633809Z",
      "@mt": "Retrieved {Count} records",
      "Count": 456
    } 
    另一個範例 fruit 輸出如下
    {
      "@t": "2019-05-01T03:30:59.8247590Z",
      "@mt": "In my bowl I have {Fruit}",
      "Fruit": [
        "Apple",
        "Pear",
        "Orange"
      ]
    } 
    關於 Serilog 的輸出格式就先介紹到這裡,詳細更多細節可以參考官方網站詳細介紹 : Formatting Output

    感想
    這篇針對 Serilog 的設計概念與基本使用進行了簡單的介紹,相信在使用上對大家來說難度都不高,自己在新專案上也有導入,之後有時間會在介紹一些關於設定與實作的細節部分,最後推薦對於結構化紀錄有興趣的可以參考作者的部落格介紹 Structured logging concepts in .NET Series,相信可以對於相關知識有更進一步的了解,也可以在.NET Framework 或是 ASP.NET Core 選擇 Logging 時有不一樣的選擇 :)

    參考
    Structured logging concepts in .NET Series

    Copyright © m@rcus 學習筆記 | Powered by Blogger

    Design by Anders Noren | Blogger Theme by NewBloggerThemes.com