Serilog 最佳實踐

溪源More發表於2021-08-05

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/

相關文章