次の方法で共有

.NET での高パフォーマンス ログ記録

.NET 6 以降のバージョンで高パフォーマンスのログ記録シナリオの場合は、LoggerMessageAttributeでを使用します。 この方法では、実行時にボックス化、一時的な割り当て、メッセージ テンプレートの解析を排除することで、最適なパフォーマンスが得られます。

ソース生成ログは、やLogInformationなどのLogDebugよりも次のパフォーマンス上の利点を提供します。

  • ボックス化を排除します。 ロガー拡張メソッドでは、 intなどの値型を objectに "ボックス化" (変換) する必要があります。 ソース生成によるログでは、厳密に型指定されたパラメーターを使用することでボックス化を回避します。
  • コンパイル時にテンプレートを解析します。 ロガー拡張メソッドは、ログ メッセージが書き込まれるたびに、メッセージ テンプレート (名前付き書式指定文字列) を解析する必要があります。 ソース生成ログは、コンパイル時にテンプレートを 1 回解析します。
  • 割り当てを減らします。 ソース ジェネレーターは、オブジェクトの割り当てと一時的なメモリ使用量を最小限に抑える最適化されたコードを作成します。

サンプル アプリでは、優先度の高いキュー処理ワーカー サービスを使用した高パフォーマンスのログ機能を示します。 アプリは、作業項目を優先順位で処理します。 これらの操作が発生すると、ソース生成ログを使用してログ メッセージが生成されます。

ヒント

ログのサンプル ソース コードはすべて、サンプル ブラウザーでダウンロードできます。 詳細については、コード サンプルの参照: .NET でのログ記録に関するページをご覧ください。

ソース生成を使用してロガー メッセージを定義する

.NET 6 以降で高パフォーマンスのログ メッセージを作成するには、partialで修飾LoggerMessageAttributeメソッドを定義します。 ソース ジェネレーターは、コンパイル時に実装を作成します。

基本的なログ記録方法

単純なログ メッセージの場合は、イベント ID、ログ レベル、およびメッセージ テンプレートを指定する属性を持つ部分メソッドを定義します。

public static partial class Log
{
    [LoggerMessage(
        EventId = 13,
        Level = LogLevel.Critical,
        Message = "Epic failure processing item!")]
    public static partial void FailedToProcessWorkItem(
        ILogger logger, Exception ex);
}

メッセージ テンプレートでは、メソッド パラメーターによって入力されるプレースホルダーが使用されます。 プレースホルダー名は、テンプレート間でわかりやすい一貫性を持つ必要があります。 これらは、構造化ログ データ内のプロパティ名として機能します。 プレースホルダー名には Pascal casing を使用することをお勧めします。 たとえば、{Item} や {DateTime} などは使用できません。

コードからログ 記録メソッドを呼び出します。 たとえば、作業項目の処理中に例外が発生した場合は、次のようになります。

try
{
    // Process work item.
}
catch (Exception ex)
{
    Log.FailedToProcessWorkItem(logger, ex);
}

このコードでは、次のようなコンソール出力が生成されます。

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.

パラメーターを使用したログ記録

ログ メッセージにパラメーターを渡すには、それらをメソッド パラメーターとして追加します。 パラメーター名は、メッセージ テンプレートのプレースホルダーと一致します。

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

ロガーとパラメーター値を使用してメソッドを呼び出します。

var workItem = queue.Dequeue();
Log.PriorityItemProcessed(logger, workItem);

このコードでは、次のようなコンソール出力が生成されます。

info: WorkerServiceOptions.Example.Worker[1]
      Processing priority item: Priority-Extreme (50db062a-9732-4418-936d-110549ad79e4): 'Verify communications'

構造化ログ ストアでは、イベント ID を指定したときにイベント名を使用してログ記録を強化できます。 たとえば、 Serilog はイベント名を使用します。

ソース生成を使用してロガー メッセージ スコープを定義する

ログ スコープを定義して、一連のログ メッセージを追加のコンテキストでラップできます。 ソース生成ログでは、 LoggerMessageAttribute メソッドを標準の ILogger.BeginScope メソッドと組み合わせます。

appsettings.jsonのコンソール ロガー セクションでIncludeScopesを有効にします。

{
    "Logging": {
        "Console": {
            "IncludeScopes": true
        },
        "LogLevel": {
            "Default": "Information",
            "Microsoft": "Warning",
            "Microsoft.Hosting.Lifetime": "Information"
        }
    }
}

ソース生成のログ記録方法を作成し、 BeginScopeを使用してスコープにラップします。

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

アプリケーション コードのスコープ内でログ記録メソッドを使用します。

using (_logger.BeginScope("Processing scope, started at: {DateTime}", DateTime.Now))
{
    Log.PriorityItemProcessed(_logger, workItem);
}

アプリのコンソール出力でログ メッセージを調べます。 次の結果は、ログ スコープ メッセージが含まれるログ メッセージの優先順位を示しています。

info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Extreme (7d153ef9-8894-4282-836a-8e5e38319fb3): 'Verify communications'

レガシ アプローチ: LoggerMessage.Define (.NET Framework および .NET Core 3.1 用)

ソース生成ログが .NET 6 で導入される前は、キャッシュ可能なデリゲートを作成するために LoggerMessage.Define メソッドを使用することをお勧めします。 この方法は下位互換性のために引き続きサポートされていますが、新しいコードでは、代わりにソース生成ログと LoggerMessageAttribute を使用する必要があります。

LoggerMessage クラスは、やLogInformationなどのLogDebugと比較して、オブジェクトの割り当てが少なく、計算オーバーヘッドを削減するキャッシュ可能なデリゲートを作成する機能を公開します。 LoggerMessage は、ロガー拡張メソッドよりも次のパフォーマンス上の利点を提供します。

  • ロガー拡張メソッドでは、int などの値の型を object に "ボックス化" (変換) する必要があります。 LoggerMessage パターンでは、静的な Action フィールドと、厳密に型指定されたパラメーターを持つ拡張メソッドを使用してボックス化を回避します。
  • ロガー拡張メソッドでは、ログ メッセージが書き込まれるたびにメッセージ テンプレート (名前付きの書式文字列) を解析する必要があります。 LoggerMessage では、メッセージを定義するときに、一度テンプレートを解析する必要があるだけです。

注

LoggerMessage.Defineを使用するコードを維持する場合は、ソース生成ログへの移行を検討してください。 .NET Framework または .NET Core 3.1 アプリケーションの場合は、引き続き LoggerMessage.Defineを使用します。

ロガー メッセージを定義する

Define(LogLevel、EventId、String) を使用して、メッセージをログ記録するためのAction デリゲートを作成します。 Define オーバーロードを使用すると、名前付き書式指定文字列 (テンプレート) に最大 6 つの型パラメーターを渡すことが可能です。

Define メソッドに提供される文字列はテンプレートであり、補間文字列ではありません。 プレースホルダーは、型が指定された順序で入力されます。 テンプレート内のプレースホルダー名は、テンプレート間でわかりやすい一貫性を持つ必要があります。 これらは、構造化ログ データ内のプロパティ名として機能します。 プレースホルダー名には Pascal casing を使用することをお勧めします。 たとえば、{Item} や {DateTime} などは使用できません。

各ログ メッセージは、Action によって作成された静的フィールドに保持されるです。 たとえば、サンプル アプリは、作業項目を処理するためのログ メッセージを記述するフィールドを作成します。

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

Actionの場合は、次のように指定します。

  • ログ レベル。
  • 静的拡張メソッドの名前を持つ一意のイベント識別子 (EventId)。
  • メッセージ テンプレート (名前付き書式指定文字列)。

作業項目が処理のためにデキューされると、ワーカー サービス アプリによって次の設定が行われます。

  • ログ レベルをLogLevel.Criticalに設定する。
  • FailedToProcessWorkItem メソッド名を持つ13 のイベント ID。
  • メッセージテンプレート（名前付きフォーマット文字列）を文字列に変換します。
s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

LoggerMessage.Define メソッドは、ログ メッセージを表すAction デリゲートを構成および定義するために使用されます。

構造化ログ ストアでは、イベント ID を指定したときにイベント名を使用してログ記録を強化できます。 たとえば、 Serilog はイベント名を使用します。

Actionは、厳密に型指定された拡張メソッドを介して呼び出されます。 PriorityItemProcessed メソッドは、作業項目が処理されるたびにメッセージをログに記録します。 FailedToProcessWorkItem は、例外が発生した場合に呼び出されます。

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

アプリのコンソール出力を調べます。

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.
         at WorkerServiceOptions.Example.Worker.ExecuteAsync(CancellationToken stoppingToken) in
         ..\Worker.cs:line 27

ログ メッセージにパラメーターを渡すには、静的フィールドの作成時に最大 6 つの型を定義します。 サンプル アプリでは、WorkItem フィールドのActionの種類を定義して、アイテムの処理時に作業項目の詳細をログに記録します。

private static readonly Action<ILogger, WorkItem, Exception> s_processingPriorityItem;

デリゲートのログ メッセージ テンプレートは、指定された型からプレースホルダー値を受け取ります。 サンプル アプリは、item パラメーターが WorkItemである作業項目を追加するためのデリゲートを定義します。

s_processingPriorityItem = LoggerMessage.Define<WorkItem>(
    LogLevel.Information,
    new EventId(1, nameof(PriorityItemProcessed)),
    "Processing priority item: {Item}");

作業項目が処理されていることをログに記録するための静的拡張メソッド ( PriorityItemProcessed) は、作業項目の引数値を受け取り、 Action デリゲートに渡します。

public static void PriorityItemProcessed(
    this ILogger logger, WorkItem workItem) =>
    s_processingPriorityItem(logger, workItem, default!);

ワーカー サービスの ExecuteAsync メソッドで、メッセージをログに記録するために PriorityItemProcessed が呼び出されます。

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

アプリのコンソール出力を調べます。

info: WorkerServiceOptions.Example.Worker[1]
      Processing priority item: Priority-Extreme (50db062a-9732-4418-936d-110549ad79e4): 'Verify communications'

ログレベルのガードされた最適化

対応するLogLevel メソッドを呼び出す前に、ILogger.IsEnabled(LogLevel)でLog*を確認することで、パフォーマンスを最適化できます。 特定の LogLevelに対してログ記録が構成されていない場合、 ILogger.Log は呼び出されません。 さらに、値型ボックス化と object[] の割り当て (パラメーターを表すために) は回避されます。

詳細については、以下を参照してください。

こちらも参照ください

  • Last updated on