始めに

以前DiagnosticSourceについて記述したが、DiagnosticSourceはあくまでもイベントの発生と、そのイベントの捕捉の仕組みしか提供しないので、最終的にどのように出力するかどうかはユーザーの裁量に大きく任される。

DiagnosticListener.AllListenersをSubscribeして出力するのが標準のやり方だが、ここではEventSourceを通して出力する方法について書いておく。

なお、この記事は.NET 5.0-rc1を元にして記述しているため、今後のリリース等で仕様が変わるかもしれないことに注意。

EventSourceとは

DiagnosticSourceの記事でも触れているが、DiagnosticSourceの先輩のようなもので、.NETFramework時代から存在するもの。
元々ETWに乗っかった仕組みではあったが、クロスプラットフォームにするため、EventPipeという仕組みを.NET Core 3.0より使用するようになり、OS問わずに制限なく使用できるようになった。

DiagnosticSourceよりも優れている点として、外部から情報を収集するための仕組みがあるため、後付けで情報収集を行うことが可能となっている。(例: dotnet-trace、Application Insights(Azure)等)

EventPipe等の仕組みについて、ずばりこういうものであるという資料は無いものの、個別のIPCプロトコル等については dotnet/diagnosticsリポジトリのdocumentationに記述があるので、詳細を知りたい人はこちらで(winでは名前付きパイプ、linuxではunixドメインソケットを介して接続できるらしい)。
頑張れば自分で出力機構を自作することも可能。
この辺りは、dotnet/diagnosticsのクライアントライブラリのドキュメントと、perfviewが提供しているパーサーに関するドキュメントが参考になるかもしれない。

DiagnosticSourceについては直接収集することはできないが、DiagnosticSourceはEventSourceでイベント出力する機能があるので、それを通してイベント情報を取得することができる。

準備

まず、下記のようなDiagnosticSourceがあるとする

// using System.Diagnostics;
class C1
{
    public DiagnosticSource _D = new DiagnosticListener("Diag1");
    public void A()
    {
        if(_D.IsEnabled("ev1"))
        {
            _D.Write("ev1", new { X = "str" });
        }
    }
}

このようにすると、C1.A()の実行時にイベント"ev1"が発生するようになる。

そして、このC1.A()を実行するような処理を netcoreapp3.0以降のアプリ側で作成する。

class Program
{
    static void Main(string[] args)
    {
        while(true)
        {
            // 1秒に一回"ev1"イベントが発生する
            new C1().A();
            Task.Delay(1000).Wait();
        }
    }
}

準備としてはこれだけである。特に追加の実装はアプリ側には必要はない。

イベントの収集

DiagnosticSourceのイベントは、全てMicrosoft-Diagnostics-DiagnosticSourceというプロバイダ(内部的にはEventSource.Name)から出力される。
なので、収集ツール側はEventPipe Providerとして、この名前を指定して収集を行う。

監視開始時に指定できるパラメータとしては、

監視するイベントレベル
監視するイベントキーワード
追加パラメーター

がある。
イベントレベルについては、EventLevel.Informationalに固定となっている。
イベントキーワードについては後述。
追加パラメーターとして、イベントのフィルタリング等を行う"FilterAndPayloadSpec"があるが、これは仕様が複雑なので後述する。

イベントキーワードフラグ

収集するイベントに設定されるビットフラグで、16進数の数字を入れる(最大8桁)
Microsoft-Diagnostics-DiagnosticSourceには以下のようなキーワードフラグが存在する

名前	数値	概要
Messages	0x1	その他のデバッグ的なメッセージ
Events	0x2	DiagnosticSourceやActivitySourceからのイベント発生
IgnoreShortCutKeywords	0x800	trueの時、下記二つのキーワードを無視する
AspNetCoreHosting	0x1000	収集対象にASP.NET Core関連のイベントを追加する
EntityFrameworkCoreCommands	0x2000	収集対象にEFCore関連のイベントを追加する

通常使う分にはEventsを含めておけば問題はない。

AspNetCoreHostingで追加されるイベント

Microsoft.AspNetCore/Microsoft.AspNetCore.Hosting.BeginRequest@Activity1Start
Microsoft.AspNetCore/Microsoft.AspNetCore.Hosting.EndRequest@Activity1Stop

この書式については後述の"FilterAndPayloadSpecについて"を参照

EntityFrameworkCoreCommandsで追加されるイベント

Microsoft.EntityFrameworkCore/Microsoft.EntityFrameworkCore.BeforeExecuteCommand@Activity1Start
Microsoft.EntityFrameworkCore/Microsoft.EntityFrameworkCore.AfterExecuteCommand@Activity1Stop

この書式については後述の"FilterAndPayloadSpecについて"を参照

追加パラメーター

今のところFilterAndPayloadSpecのみだが、これが結構複雑。特に指定しない限り、"全てのDiagnosticSourceイベントを捕捉し、ActivitySourceは捕捉しない"という意味になる。

FilterAndPayloadSpecについて

どのイベントを監視するか、また、イベントできたデータをどのように解釈するか、という事を設定する。
特に指定しない限り、"全てのDiagnosticSourceイベントを捕捉し、ActivitySourceは捕捉しない"という意味になる。
ここで紹介するのはごく基本的なことなので、詳細が知りたい場合は、実際のDiagnosticSourceEventSourceのソースを確認するのが良いだろう。

基本書式

どのようなイベントを捕捉するか、また、捕捉したイベントのパラメーターをどのように解釈するかを指定する
書式は、DiagnosticSourceの場合、[DiagnosticSourceの名前]/[イベント名]@[EventSource名]:[変換先パラメーター名]=[変換元パラメーター名];[変換先パラメーター名]=[変換元パラメーター名]のように指定する。
全て書くと長いが、必須なのはDiagnosticSourceの名前のみ。

DiagnosticSourceの指定

[DiagnositicSourceの名前]で指定したものを捕捉対象に入れる。ここにはDiagnosticSource.Nameの名前を使用する。

イベント名

ここにはDiagnosticSource.Writeで指定する名前を入れる。

[EventSource名]の部分は少々わかりにくいが、Activity1Startなどと記述することによって、同イベントをActivity1Startとして捕捉するという意味である。この辺りの記述が無い場合は、イベントは全てイベントID=2の、イベント名="[Activity名].[StartまたはStop]"として処理される。

これを、DiagnosticSourceごとに CRLF区切り で記述する。
つまり、Diag1とDiag2の両方を検出したい場合は、

Diag1<CRLF>
Diag2

のようにパラメーターを設定する。プログラム上であればStringBuilderで設定可能だが、コマンドラインで指定したい場合などは注意が必要。

また、デフォルトではActivitySourceのイベントが捕捉できないが、ActivitySourceのイベントを追加したい場合は、同パラメーターの頭に[AS]を追加する。
この時、特別な記法として[AS]*を指定すれば、全てのActivitySourceのイベントを捕捉することが可能。
例として、Act1なるActivitySourceを追加したい場合は、

[AS]Act1

のように記述する。

イベントレベル

今回紹介するMicrosoft-Diagnostics-DiagnosticSourceのイベントレベルはInformational固定だが、
一応他にもどのようなものがあるか、以下に列挙する。

Critial = 1
Error = 2
Warning = 3
Informational = 4
Verbose = 5
LogAlways = 0

正確なリファレンスは公式ドキュメントを参照

Microsoft-Diagnostics-DiagnosticSource で発生するイベント

イベントID	イベント名	イベントキーワード	概要
1	Message	Messages	その他のメッセージ
2	Event	Events	`DiagnosticSource.Write`で発生するイベント
3	EventJson	Events	Eventと同じだが、net45のみで発生し、イベントパラメーターがjson化されている
4	Activity1Start	Events	`DiagnosticSource.StartActivity`したときに発生するイベント
5	Activity1Stop	Events	`DiagnosticSource.StopActivity`したときに発生するイベント
6	Activity2Start	Events	`DiagnosticSource.StartActivity`したときに発生するイベント
7	Activity2Stop	Events	`DiagnosticSource.StopActivity`したときに発生するイベント
8	RecursiveActivity1Start	Events	ネストしたActivityが開始されたときに発生するイベント
9	RecursiveActivity1Stop	Events	ネストしたActivityが終了されたときに発生するイベント
10	NewDiagnosticListener	Events	DiagnosticListenerが追加された時に発生するイベント
11	ActivityStart	Events	ActivitySourceでActivityが開始した時に発生するイベント
12	ActivityStop	Events	ActivitySourceでActivityが終了した時に発生するイベント

dotnet-traceによる収集

EventSourceの出力を捕捉する方法は色々あるが、ここではdotnet-traceによる方法を紹介する

ツールの導入

dotnet toolとして提供されているので、dotnet-sdkをインストールして、dotnet tool install -g dotnet-traceでインストール可能($HOME/.dotnet/toolsにパスを通す必要がある)

イベントの収集

以下のようにして情報を収集する。

アプリの起動
PIDの取得
- OSコマンド(tasklistやps)の他に、dotnet-trace psでもPIDを取得可能
dotnet-trace collect -p [PID] [その他オプション] --providers "Microsoft-Diagnostics-DiagnosticSource[追加オプション]"で収集開始
- デフォルトでは、DiagnosticSource全てのイベント情報が出力される
Ctrl-CまたはEnterで収集を止める

以上で、イベント情報を記録したトレースファイルが生成される(デフォルトはtrace.nettrace)。
なお、アプリを起動したと同時に監視を開始する、という機能はないため、スタートアップ時のイベントログ等は取得できない場合があることに注意

追加オプションの書式は、[イベントキーワード]:[イベントレベル]:[K=V形式で指定される追加パラメーター]となる

providersオプションへの渡し方

FilterAndPayloadSpecsは改行を含むため、シェルによっては値を渡し辛い場合がある。
dotnet-traceはアプリ実行基盤にSystem.CommandLineのフレームワークを使用しているため、応答ファイルを用いて読み込ませることができる。
まず、下記のようなテキストファイルを用意する

--providers
Microsoft-Diagnostics-DiagnosticSource:[イベントキーワード]:[イベントレベル]:FilterAndPayloadSpecs=[FilterAndPayloadSpecsに渡したい内容]

なお、改行は、\r\nで表現できる。
ファイルが用意出来たら、以下のようにして実行する。

dotnet trace collect -p [PID] "@[ファイルへのパス]"

イベント情報の閲覧

イベント情報の閲覧は、Perfviewで閲覧可能。PerfviewはWindows専用だが、chromiumのトレースファイル形式(Chromium)や、SpeedScopeの形式に変換することも可能なので、Linux上でのログ閲覧も可能。ただし、一次フォーマットはnettraceなので、他二つの形式は情報が欠落する可能性があることに注意。

終わりに

実際はDiagnosticSourceとActivitySourceは、直接どうこうするよりもopentelemetry等、よりユーザーフレンドリなライブラリを通して間接的に利用していくことになると思うが、それでも何かあったとき、アドホックに情報を得られる手段があるのは良いことだと思う。
後、個人的にはActivitySourceは別個のEventSourceを持った方が良かったとは思う。

参考記事

dotnet-trace
DiagnosticSourceEventSource
- 詳細なパラメーターの記述などがある
dotnet/diagnosticsリポジトリ
- EventPipeの仕様、dotnet-traceのソースなど

DiagnosticSourceをEventSourceへ出力する

始めに

EventSourceとは

準備

イベントの収集

イベントキーワードフラグ

AspNetCoreHostingで追加されるイベント

EntityFrameworkCoreCommandsで追加されるイベント

追加パラメーター

FilterAndPayloadSpecについて

基本書式

DiagnosticSourceの指定

イベント名

イベントレベル

Microsoft-Diagnostics-DiagnosticSource で発生するイベント

dotnet-traceによる収集

ツールの導入

イベントの収集

providersオプションへの渡し方

イベント情報の閲覧

終わりに

参考記事