Serilog 最佳實踐

翻譯自：https://benfoster.io/blog/serilog-best-practices/

概述

Serilog是 Microsoft .NET 的結構化日志記錄庫，並已成為[Checkout.com .NET 的首選日志記錄庫。.它支持各種日志記錄目的地（稱為接收器）包從標准控制台和基於文件的接收器到日志服務，如 Datadog。

本指南最初是我們工程手冊中的一篇文章，在收到內部積極反饋后，我決定在我的博客上發布它。

內容

1. 標准日志屬性
2. 日志記錄基礎知識
   1. 記錄一切
   2. 選擇合適的日志記錄級別
   3. 定時操作源
   4. 上下文
   5. HTTP 日志記錄
   6. 日志的職責
3. 日志內容的采集
   1. Serilog標准采集方法
   2. 通過全局屬性采集日志
4. 關聯日志
5. 消息模板
   1. 消息模板推薦
6. 日志和診斷上下文
   1. 日志上下文
   2. 診斷上下文
7. 配置
8. 生產日志
   1. 當日志變得不僅僅是日志
9. 其他工具和實用程序
   1. 在本地使用 Seq
   2. 按日志類型記錄日志
   3. 按屬性塊記錄日志
   4. 按請求記錄日志

標准日志屬性

標准化日志事件屬性使您能夠充分利用日志搜索和分析工具。在適用的情況下使用以下屬性：

ApplicationName	生成日志事件的應用程序的名稱
ClientIP	發出請求的客戶端的 IP 地址
CorrelationId	可用於跨多個應用程序邊界跟蹤請求的 ID
Elapsed	操作完成所用的時間（以毫秒為單位）
EventType	用於確定消息類型的消息模板的哈希值
MachineName	運行應用程序的機器的名稱
Outcome	手術的結果
RequestMethod	HTTP 請求方法，例如 POST
RequestPath	HTTP 請求路徑
SourceContext	日志源自的組件/類的名稱
StatusCode	HTTP 響應狀態碼
UserAgent	HTTP 用戶代理
Version	正在運行的應用程序的版本

上面的很多屬性都來自於 Serilog 自己的擴展，例如Serilog Timings（用於計時操作）和Serilog 請求日志記錄。

日志記錄基礎知識

記錄一切

通常，記錄所有可以深入了解您的應用程序和用戶行為的內容，例如：

• 代碼中的主要分支點
• 遇到錯誤或意外值時
• 任何 IO 或資源密集型操作
• 重大領域事件
• 請求失敗和重試
• 耗時的批處理操作的開始和結束

選擇合適的日志記錄級別

對您的日志記錄要慷慨，但對您的日志記錄級別要嚴格。在幾乎所有情況下，您的日志級別都應該是Debug. 使用Information的日志事件，將在生產中需要確定運行狀態或應用程序的正確性，Warning或Error突發事件，如異常。

請注意，該Error級別應保留用於您打算對其采取行動的事件。如果某些事情成為正常的應用程序行為（例如，請求輸入驗證失敗），您應該降級日志級別以減少日志“噪音”。

定時操作

將應用程序中的每個資源密集型操作（例如 IO）與指標代碼一起記錄下來。這在本地運行應用程序以查看應用程序瓶頸或響應時間消耗的情況時非常有用。該Serilog時序庫提供了一個方便的方式來做到這一點：

using (_logger.TimeDebug("Sending notification to Slack channel {Channel} with {WebhookUrl}", _slackOptions.Channel, _slackOptions.WebhookUrl))
using (_metrics.TimeIO("http", "slack", "send_message"))
{

}

源上下文

該SourceContext屬性用於跟蹤日志事件的來源，通常是使用記錄器的 C# 類。ILogger使用依賴注入將 Serilog 注入到類中是很常見的。為確保SourceContext正確設置，請使用ForContext擴展名：

public TheThing(ILogger logger)
{
    _logger = logger?.ForContext<TheThing>() ?? throw new ArgumentNullException(nameof(_logger));
}

HTTP 日志記錄

使用Serilog 請求日志記錄中間件來記錄 HTTP 請求。這會自動包含上面列出的許多 HTTP 屬性並生成以下日志消息：

HTTP POST /payments responded 201 in 1348.6188 ms

將以下內容添加到您的應用程序啟動中以添加中間件：

public void Configure(IApplicationBuilder app)
{
    app.UseHealthAndMetricsMiddleware();
    app.UseSerilogRequestLogging();
    app.UseAuthentication();
    app.UseMvc();
}

請注意，在health 和 metrics 中間件之后添加了 Serilog中間件。這是為了避免每次 AWS 負載均衡器命中您的健康檢查端點時生成日志。

記錄 HTTP 資源

Serilog 中間件默認記錄請求路徑。如果您確實需要查看對應用程序中特定端點的所有請求，如果路徑包含標識符等動態參數，您可能會遇到挑戰。

為了解決這個問題，記錄資源名稱，在我們的應用程序中，按照慣例，它是Name賦予相應路由的屬性。這是這樣檢索的：

public static string GetMetricsCurrentResourceName(this HttpContext httpContext)
{
    if (httpContext == null)
        throw new ArgumentNullException(nameof(httpContext));

    Endpoint endpoint = httpContext.Features.Get<IEndpointFeature>()?.Endpoint;

#if NETCOREAPP3_1
    return endpoint?.Metadata.GetMetadata<EndpointNameMetadata>()?.EndpointName;
#else
    return endpoint?.Metadata.GetMetadata<IRouteValuesAddressMetadata>()?.RouteName;
#endif
}

日志的職責

過度全面的日志記錄不僅會對您的應用程序產生性能影響，而且還會使診斷問題變得更加困難，並增加暴露敏感信息的風險。

Serilog 支持結構化對象輸出，允許將復雜對象作為日志中的參數傳遞。這應該謹慎使用，如果您的主要目標是對相關屬性進行分組，您最好初始化一個新的匿名對象，這樣您就可以明確哪些信息被推送到日志中。

傾向於使用 Serilog 的診斷上下文功能（下面討論）將日志折疊為單個日志條目。

收集日志

將附加信息推送到您的日志中有助於提供有關特定事件的附加上下文。

標准 Serilog 收集器

您可以使用收集器來豐富應用程序生成的所有日志事件。我們建議使用以下 Serilog 濃縮器：

• 日志上下文收集器 - 內置於 Serilog，此豐富器可確保添加到日志上下文的任何屬性都被推送到日志事件中
• 環境收集器- 使用機器或當前用戶名采集日志

可以使用Enrich.WithSerilog的fluent APILoggerConfiguration或通過您的appsettings.json文件（推薦）指定增強器：

{
  "Serilog": {
    "Using": [
      "Serilog.Sinks.Console"
    ],
    "MinimumLevel": {
      "Default": "Information"
    },
    "WriteTo": [
      {
        "Name": "Console"
      }
    ],
    "Enrich": [
      "FromLogContext",
      "WithMachineName"
    ],
    "Properties": {
      "ApplicationName": "Gateway API"
    }
  }
}

全局屬性采集

您還可以全局指定屬性。上面的片段appsettings.json演示了我們通常如何設置ApplicationName屬性。在某些情況下，我們需要在啟動時計算屬性，這可以使用 Fluent API 來完成：

loggerConfiguration.ReadFrom.Configuration(hostContext.Configuration)
    .EnrichWithEventType()
    .Enrich.WithProperty("Version", ReflectionUtils.GetAssemblyVersion<Program>());

關聯日志

為了關聯屬於同一請求的日志，甚至跨多個應用程序，請CorrelationId向日志添加一個屬性。

在 HTTP 應用程序中，我們通常從HttpContext.TraceIdentifier屬性映射它。這是使用Cko-Correlation-Id標頭在內部 API 之間傳遞的。我們使用以下擴展來獲取 _current_correlation ID：

public static string GetCorrelationId(this HttpContext httpContext)
{
    httpContext.Request.Headers.TryGetValue("Cko-Correlation-Id", out StringValues correlationId);
    return correlationId.FirstOrDefault() ?? httpContext.TraceIdentifier;
}

請注意，如果應用程序面向公眾，則不應依賴提供的相關 ID 標頭。

為了確保將關聯 ID 推送到每個日志事件中，我們使用以下使用 Serilog 的中間件LogContext（本文稍后將詳細討論）：

public class RequestLogContextMiddleware
{
    private readonly RequestDelegate _next;

    public RequestLogContextMiddleware(RequestDelegate next)
    {
        _next = next;
    }

    public Task Invoke(HttpContext context)
    {
        using (LogContext.PushProperty("CorrelationId", context.GetCorrelationId()))
        {
            return _next.Invoke(context);
        }
    }
}

消息模板

日志消息應提供事件的簡短描述。我們通常看到開發人員創建過於冗長的消息作為在事件中包含額外數據的手段，例如：

_logger.Information("Storing payment state in Couchbase for Payment ID {PaymentId} and current state {State}", paymentId, state);

相反，您可以使用ForContext（或本文底部的屬性包豐富器）仍然包含數據但具有更簡潔的消息：

_logger
    .ForContext("PaymentId", paymentId)
    .ForContext("State", state)
    .Information("Storing payment state in Couchbase");

消息模板推薦

Fluent風格指南

好的 Serilog 事件使用屬性名稱作為消息中的內容來提高可讀性並使事件更緊湊，例如：

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

句子與片段

日志事件消息是片段，而不是句子；為了與使用 Serilog 的其他庫保持一致，請盡可能避免尾隨句點/句號。

模板與消息

Serilog 事件具有關聯的消息模板，而不是消息。在內部，Serilog 解析和緩存每個模板（最多固定大小限制）。將日志方法的字符串參數視為消息，如下例所示，會降低性能並消耗緩存內存。例如，避免：

Log.Information("The time is " + DateTime.Now);

而是使用消息屬性：

Log.Information("The time is {Now}", DateTime.Now);

除了在日志消息中使用字符串連接/插值的性能開銷之外，它還意味着無法計算一致的事件類型（請參閱事件類型豐富器），從而無法找到特定類型的所有日志。

日志和診斷上下文

Serilog 支持兩種可用於增強日志的上下文感知功能。

日志上下文

LogContext可用於動態地添加和移除來自周圍“執行上下文”性能; 例如，在事務期間寫入的所有消息都可能帶有該事務的 id，等等。

在RequestLogContextMiddleware上面的介紹演示了如何推動CorrelationId請求到LogContext在請求的開始。這可確保該請求中的所有日志都包含該屬性。

更多信息可以在Serilog wiki上找到。

診斷上下文

日志記錄的一個挑戰是上下文並不總是預先知道。例如，在處理 HTTP 請求的過程中，隨着我們通過 HTTP 管道（例如了解用戶的身份）獲得額外的上下文。雖然LogContext我們所有人都會在附加信息可用時創建新上下文，但此信息僅在 _subsequent_log 條目中可用。這通常會導致日志數量增加，只是為了捕獲有關整個請求或操作的所有信息。

診斷上下文提供了一個執行上下文（類似於LogContext），其優點是可以在其整個生命周期中進行豐富。請求日志中間件然后使用它來豐富最終的“日志完成事件”。這允許我們將許多不同的日志操作折疊為一個日志條目，其中包含來自請求管道中許多點的信息，例如：

在這里您可以看到，不僅有中間件發出的 HTTP 屬性，還有應用程序數據，例如AcquirerId、MerchantName和ResponseCode。這些數據點來自請求中的不同點，但通過IDiagnosticContext接口推送到診斷上下文中：

public class HomeController : Controller
{
    readonly IDiagnosticContext _diagnosticContext;

    public HomeController(IDiagnosticContext diagnosticContext)
    {
        _diagnosticContext = diagnosticContext ?? throw new ArgumentNullException(nameof(diagnosticContext));
    }

    public IActionResult Index()
    {
        // The request completion event will carry this property
        _diagnosticContext.Set("CatalogLoadTime", 1423);

        return View();
    }

在非 HTTP 應用程序中使用診斷上下文

診斷上下文不限於在 ASP.NET Core 中使用。它也可以以與請求日志中間件非常相似的方式在非 HTTP 應用程序中使用。例如，我們使用它在 SQS 使用者中生成完成日志事件。

配置

Serilog 可以使用 Fluent API 或通過 Microsoft 配置系統進行配置。我們建議使用配置系統，因為可以在不發布應用程序新版本的情況下更改日志配置。

為此，添加Serilog.Settings.Configuration包並按如下方式配置 Serilog：

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .UseSerilog((hostContext, loggerConfiguration) =>
        {
            loggerConfiguration.ReadFrom.Configuration(hostContext.Configuration);
        })
        .ConfigureAppConfiguration((hostingContext, config) =>
        {
            config
                .AddEnvironmentVariables(prefix: "FLOW_")
                .AddAwsSecrets();
        })
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();  
        });

您現在可以通過任何支持的配置提供程序配置 Serilog。通常我們appsettings.json用於全局設置並通過生產中的環境變量配置實際接收器（因為我們不想在本地運行時使用我們的遠程日志服務）：

{
  "Serilog": {
    "Using": [
      "Serilog.Sinks.Console",
      "Serilog.Sinks.Datadog.Logs"
    ],
    "MinimumLevel": {
      "Default": "Information"
    },
    "WriteTo": [
      {
        "Name": "Console"
      }
    ],
    "Enrich": [
      "FromLogContext",
      "WithMachineName"
    ],
    "Properties": {
      "ApplicationName": "Flow API"
    }
  }
}

生產環境下使用日志

在生產中部署應用程序時，請確保相應地配置日志記錄：

• 控制台日志記錄應限於Error. 在 .NET 中，寫入控制台是一個阻塞調用，會對性能產生重大影響。
• 應為Information及以上配置全局日志記錄。

據了解，在新項目發布期間，您可能需要更多信息來建立對解決方案的信心或診斷任何預期的初期問題。與其Information為此升級您的日志條目，不如考慮Debug在有限的時間內啟用級別。

從開發人員那里聽到的一個常見問題是他們如何在運行時動態切換日志級別。雖然這是可能的，但也可以使用藍/綠部署來實現。使用降低的日志級別配置和部署非活動環境，然后通過加權目標組切換部分或全部流量。

當日志變得不僅僅是日志

日志可以提供對應用程序的大量洞察，並且在許多情況下足以處理日常支持請求或故障排除。然而，在某些情況下，日志不是工作的正確工具，有許多警告信號：

• 您發現自己向非技術用戶開放應用程序日志
• 日志用於生成應用程序指標
• 更多信息被“塞進”日志以滿足常見的支持請求或報告要求

在這些情況下，您可能需要為您的產品考慮專用工具。許多團隊開發了類似“Inspector”的應用程序，將關鍵系統和業務數據聚合在一起，以處理可以提供給非技術利益相關者的 BAU 請求。此外，您可能會發現需要將應用程序中的數據推送到報告和分析工具中。

日志的有效性取決於您記錄的內容和未記錄的內容。

其他工具和實用程序

在本地使用 Seq

Seq是由 Serilog 的作者創建的免費（供本地使用）日志記錄工具。它提供高級搜索和過濾功能以及對結構化日志數據的完全訪問。雖然我們的日志記錄要求現在超出了 Seq 所能提供的范圍，但它仍然是本地測試的一個很好的選擇。

我們通常在 docker 中啟動 Seq 作為單獨的 docker-compose 文件 ( docker-compose-logging.hml) 的一部分：

version: "3.5"

services:

seq:
    image: datalust/seq:latest
    container_name: seq
    ports:
    - '5341:80'
    environment:
    - ACCEPT_EULA=Y
    networks:
    - gateway-network

networks:
gateway-network:
    name: gateway-network

並配置我們的appsettings.Development.json文件以使用 Seq 接收器：

{
  "Serilog": {
    "Using": [
      "Serilog.Sinks.Console",
      "Serilog.Sinks.Seq"
    ],
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Warning"
      }
    },
    "WriteTo": [
      {
        "Name": "Console"
      },
      {
        "Name": "Seq",
        "Args": {
          "serverUrl": "http://localhost:5341",
          "apiKey": "none"
        }
      }
    ]
  }
}

事件類型收集器

通常我們需要唯一標識相同類型的日志。一些接收器（例如Seq）通過散列消息模板來自動執行此操作。為了在其他接收器中復制相同的行為，我們創建了以下使用Murmerhash 算法的收集器：

internal class EventTypeEnricher : ILogEventEnricher
{
    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
        if (logEvent is null)
            throw new ArgumentNullException(nameof(logEvent));

        if (propertyFactory is null)
            throw new ArgumentNullException(nameof(propertyFactory));

        Murmur32 murmur = MurmurHash.Create32();
        byte[] bytes = Encoding.UTF8.GetBytes(logEvent.MessageTemplate.Text);
        byte[] hash = murmur.ComputeHash(bytes);
        string hexadecimalHash = BitConverter.ToString(hash).Replace("-", "");
        LogEventProperty eventId = propertyFactory.CreateProperty("EventType", hexadecimalHash);
        logEvent.AddPropertyIfAbsent(eventId);
    }
}

屬性包收集器

如果您想向日志事件添加多個屬性，請使用PropertyBagEnricher：

public class PropertyBagEnricher : ILogEventEnricher
{
    private readonly Dictionary<string, Tuple<object, bool>> _properties;

    /// <summary>
    /// Creates a new <see cref="PropertyBagEnricher" /> instance.
    /// </summary>
    public PropertyBagEnricher()
    {
        _properties = new Dictionary<string, Tuple<object, bool>>(StringComparer.OrdinalIgnoreCase);
    }

    /// <summary>
    /// Enriches the <paramref name="logEvent" /> using the values from the property bag.
    /// </summary>
    /// <param name="logEvent">The log event to enrich.</param>
    /// <param name="propertyFactory">The factory used to create the property.</param>
    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
        foreach (KeyValuePair<string, Tuple<object, bool>> prop in _properties)
        {
            logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty(prop.Key, prop.Value.Item1, prop.Value.Item2));
        }
    }

    /// <summary>
    /// Add a property that will be added to all log events enriched by this enricher.
    /// </summary>
    /// <param name="key">The property key.</param>
    /// <param name="value">The property value.</param>
    /// <param name="destructureObject">
    /// Whether to destructure the value. See https://github.com/serilog/serilog/wiki/Structured-Data
    /// </param>
    /// <returns>The enricher instance, for chaining Add operations together.</returns>
    public PropertyBagEnricher Add(string key, object value, bool destructureObject = false)
    {
        if (string.IsNullOrEmpty(key)) throw new ArgumentNullException(nameof(key));

        if (!_properties.ContainsKey(key)) _properties.Add(key, Tuple.Create(value, destructureObject));

        return this;
    }
}

用法：

_logger
    .ForContext(
      new PropertyBagEnricher()
        .Add("ResponseCode", response?.ResponseCode)
        .Add("EnrollmentStatus", response?.Enrolled)
    )
    .Warning("Malfunction when processing 3DS enrollment verification");

收集請求日志

Serilog 請求日志記錄中間件允許提供一個函數，該函數可用於將來自 HTTP 請求的附加信息添加到完成日志事件。我們使用它來記錄ClientIP,UserAgent和Resource屬性：

public static class LogEnricher
{
    /// <summary>
    /// Enriches the HTTP request log with additional data via the Diagnostic Context
    /// </summary>
    /// <param name="diagnosticContext">The Serilog diagnostic context</param>
    /// <param name="httpContext">The current HTTP Context</param>
    public static void EnrichFromRequest(IDiagnosticContext diagnosticContext, HttpContext httpContext)
    {
        diagnosticContext.Set("ClientIP", httpContext.Connection.RemoteIpAddress.ToString());
        diagnosticContext.Set("UserAgent", httpContext.Request.Headers["User-Agent"].FirstOrDefault());
        diagnosticContext.Set("Resource", httpContext.GetMetricsCurrentResourceName());
    }
}

用法

app.UseSerilogRequestLogging(opts
  => opts.EnrichDiagnosticContext = LogEnricher.EnrichFromRequest);

© 2021 Ben Foster https://benfoster.io/