診断用情報収集にSystem.Diagnostics.DiagnosticSourceを使う

16529 ワード
C# Diagnostics C# テキストリンク

初めに

.NET Coreで、イベント情報収集のためにSystem.Diagnostics.DiagnosticSourceというものが追加された。

一応公式文書として DiagnosticsSource User's Guideはあるが、日本語リソースはあまりなく、かつガイドでも若干自分が知りたいことについてわかりにくい部分があったので記事を書こうと思う。
DiagnosticSourceにはさらにActivityというものも存在するが、記事が長くなるのでこれはまた別の機会に。

DiagnosticSourceとは

簡単に言うと、動作中のアプリから、診断用のイベント情報を収集するためのクラス。
ここでいう診断用のイベント情報とは、ロギング、トレース等、アプリケーションの状態を把握するために、アプリケーション内部から発信される情報を言う。
特徴としては、

  • インプロセスで動く
    • シリアライズしたり、ファイル等プロセス外に持ち出したりする場合には別途仕組みが必要
    • データをオブジェクトとして扱っているため、取り廻す間は余計なエスケープ処理等は不要
  • ログ情報をC#のオブジェクトで共有可能
  • 低負荷
    • 例えばHTTPの1リクエストごとの所要時間などの、高頻度に発生すると予想される処理にも使うことを想定
  • 場所を選ばない
    • 例えばライブラリの中でも使用可能
  • ログを送信する側が主体
    • 上層からロガーインスタンスを渡すのではなく、受信する側がイベントを購読するという形になる
  • ピュアマネージド
    • ETW等の外部フレームワークに依存しない

ただ、

  • 受信側の処理を自前で書く必要がある
    • ファイルやコンソール出力も標準では存在しない
  • イベントの仕様を決める必要がある
  • イベント発生時に渡す値は、必ずヒープに確保する必要がある(構造体の場合は必ずboxingする)

という点があることも注意。

受信側の処理としては、opentelemetryと組み合わせることで、多様なプラットフォームに情報を送信することも可能となる。実際opentelemetryのdotnet実装では、System.Net.Http.HttpClientの統計情報の取得を行うモジュールを、HttpClientが提供するDiagnosticSourceを使って実現している。

ILoggerとの比較

現在のdotnetのメジャーなロギングフレームワークとして、Microsoft.Extensions.Logging.ILoggerとその仲間たちがある。
これはロギングにおいては確かに優秀ではあるが、ログのメイン情報が不定形な文字列であるという前提があるため、型付の情報を扱う場合に、文字列のパース等でオーバーヘッドが大きくなるという欠点がある。
よって、エラー等の不定形な情報を単純にファイルに記録したい等の用途には向いていると思うが、例えば処理経過時間の統計を取りたいという時には、jsonやcsv等の特定の形式に出力して解析する等、回りくどい方法をとる必要があり、また効率も良くない。
それに対して、DiagnosticSourceはイベント受信時点でobjectの状態で渡されるため、キャストの必要はあるものの、型情報を失うことなく統計情報を効率的にトレースサービスに送信することが可能となる。

また、ILoggerは基本的に上層から渡されたILoggerインスタンスを使うという仕組みのため、必ずILoggerを受け取る口を作らなければならず、ライブラリ側がILoggerの取り廻しに苦労してしまう場合がある。

EventSourceとの比較

さて、イベント収集というと、既存の仕組みでも様々あるが、中でも役割が一番重なるのがEventSourceだろう。
EventSourceも昔からあるが、ETWやLTTng等、プラットフォームが持つトレースフレームワークに依存しているのが特徴で、これに由来する制約もあったりする(シリアライズ可能な型しか渡しちゃダメとか)。

ただし、フレームワークに依存する強みとして、外部からの情報取得が容易(dotnet-traceや、APIからの取得等)という点や、ログ出力のオーバーヘッドが小さい特徴がある。

どちらがいいのという話であれば、個人的には制約が少ないDiagnosticSourceを使うのがいいと思う。出力方法については頑張るという感じで。
一応DiagnosticSourceからEventSourceへの出力というものもあるので、どうしてもEventSourceを使う要件が出てきたならば、こちらを使うこともできる(使い方は少々面倒だったりするが)。

使用方法

準備

まず、機能を使うための準備を行う。netcoreappでは1.0のころからあるものなので、特に準備の必要はないが、netstandardでは2.1でも追加はされていないため、ライブラリプロジェクト等で使う場合はnugetで追加する必要がある。

追加されれば、System.Diagnostics.DiagnosticSourceとSystem.Dianostics.DiagnosticListenerが使用できるようになっているはず。

イベント送信側

イベントを送信するには、以下のような実装が必要。

  1. 内部で名前を付けてDiagnosticListener生成
    • 生成時点でグローバルなDiagnosticListener.AllListeners(型はIObservable<DiagnosticListener>)に登録される
  2. 生成したDiagnosticListenerをDiagnosticsSourceにキャストして内部に保持
  3. DiagnosticSource.IsEnabled("[イベント名等]")で出力するか判定
    • 後で使用するイベント名に合わせる必要はないが、関連性は持たせた方が良い
  4. DiagnosticSource.Write("[イベント名]", [イベントに付随するobject])を実行してログ出力

注意点として、DiagnosticListenerは名前(Nameプロパティ)でその一意性を判断するように設計されているため、DiagnosticListenerの名前つけは非常に重要な要素となる。
dotnet core開発チームが推奨しているルールとしては、

  • DiagnosticListenerの名前はクラスの名前空間分けのようにする("."で区切る)
  • 頻度が高いイベントと低いイベントが存在する場合、DiagnosticListenerを分ける
  • 名前の後に"Listener"を付けない
  • イベント名は短めに(16文字以内)
  • 始まりと終わりがあるイベントにはActivityを使用する
  • 何らかの事情があってActivityを使えない場合は、イベントの末尾にそれぞれ"Start"と"Stop"を付ける
  • Writeする前に必ずIsEnabledで有効かどうか確認する
    • 余計なオブジェクト生成等のオーバーヘッドを防ぐため
  • Writeで渡すオブジェクトは匿名オブジェクトを基本とするが、データが巨大になる場合はインスタンスの使い回しも考える
    • 生存期間の問題が出てくるが
  • DiagnosticListenerはpublicにせず、AllListeners経由でSubscribeさせるようにする

等がある。ただし、これらはあくまでも推奨なので、従わなくても良い。

イベント受信側

受信する側は以下の処理が必要

  1. System.Diagnostics.DiagnosticListener.AllListeners(IObservable<DiagnosticListener>)をSubscribeして、どのDiagnosticListenerを使用するか選択
  2. Subscribeの中で、受信するものをNameで判断して、Subscribeする
    • この時、第二引数にFunc<string, object, object>またはPredicate<string>をとるものがあるが、これはDiagnosticSource.IsEnabled("[イベント名]")またはDiagnosticSource.IsEnabled("[イベント名]", object, object)を実行したときに呼ばれるものとなり、デフォルトは常にtrueとなる
    • Subscribeの中で、イベントを処理する
    • Subscribeの中では基本的にasyncは使えないと思っていいので、非同期性を重視するならば、System.Threading.Channelsに処理を投げるのもあり(オブジェクトの生存期間に注意)
    • とりあえず出したいだけならばILogger等の他のフレームワークに丸投げするのもいいかも

実装例

// added System.Reactive and System.Diagnostics.DiagnosticSource to PackageReference 
using System;
using System.Diagnostics.Tracing;
using System.Diagnostics;

namespace diagtest
{
    class SampleClass
    {
        public const string DiagnosticName = "dntracetest.SampleClass";
        private static readonly DiagnosticListener _listener = new DiagnosticListener(DiagnosticName);
        public void X()
        {
            Console.WriteLine($"X");
            if(_listener.IsEnabled("Event1"))
            {
                _listener.Write("Event1", new { X = 1, Y = "aaa" });
            }
        }
    }
    class Program
    {
        static void Main(string[] args)
        {
            DiagnosticListener.AllListeners.Subscribe(dl =>
            {
                if(dl.Name == SampleClass.DiagnosticName)
                {
                    dl.Subscribe(kv =>
                    {
                        Console.WriteLine($"event written: {kv.Key}, {kv.Value}");
                    });
                }
            });
            new SampleClass().X();
        }
    }
}

便利ツール

Microsoft.Extensions.DiagnosticAdapter

dotnet/extensionsから提供されているもので、NuGetで取得可能(Microsoft.Extensions.DiagnosticAdapter)
Subscribeの引数をより楽に記述できるようにしよう、という趣旨のライブラリ。

参照を追加すると、以下の機能が拡張メソッドとして使用できる

  • DiagnosticListener.SubscribeWithAdapter(object target)
  • DiagnosticListener.SubscribeWithAdapter(object target, Func<string, bool> isEnabled)
  • DiagnosticListener.SubscribeWithAdapter(object target, Func<string, object, object, bool> isEnabled)

isEnabledはDiagnosticSource.IsEnabledで使用されるものということで分かりやすい。しかし、第一引数のobjectは説明も少ないため使い方がわかり辛い。

例えば、以下のようにDiagnosticSourceを使用しているクラスがあったとする。

class Hoge
{
    private static readonly DiagnosticSource _src = new DiagnosticListener("Hoge");
    public F()
    {
        if(_src.IsEnabled("EventName1"))
        {
            src.Write("EventName1", new { X = "aaa", Y = 1 });
        }
    }
}

targetとして、以下のようなクラスを実装する。

class X
{
  // 引数を指定しない場合は[DiagnosticName("[メソッド名]")]と等価
  [DiagnosticName("EventName1")]
  public void OnEventName1(string x, int y)
  {
  }
}

ポイントは2点

  • [DiagnosticName("[EventName]")]属性を付ける
  • 引数に、イベント時に指定されるオブジェクトの メンバー名 と同じ名前(大文字小文字の違いはOK)を指定する

以上のクラスを作り、以下のようにする

DiagnosticListener.AllListeners.Subscribe(d =>
{
    if(d.Name == "Hoge")
    {
        d.SubscribeWithAdapter(new X());
    }
});

すると、リフレクションを使って対応するイベント名に対して自動的に振り分けてメソッドを実行してくれるように設定を行ってくれる。なお、戻り値は見ないので、async Taskを使うとおかしなことになるので注意。

終わりに

DiagnosticSourceは単純にログを出力するには面倒な部分もあるが、やはりちゃんとした統計情報を取りたい場合は避けて通れない道だろうとは思う。
また、ライブラリ側で何らかのログ機構を作りたい場合、上からILoggerを受け取るよりもすっきりした設計にできるので、ライブラリを作成している場合は有用だろう。

今回は紹介していないが、EventSourceに流す方法や、Activityの使い方も、そのうち記事にしてみたい。