DiagnosticSourceをEventSourceへ出力する

# 始めに

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

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

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

# EventSourceとは

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

DiagnosticSourceよりも優れている点として、外部から情報を収集するための仕組みがあるため、後付けで情報収集を行うことが可能となっている。(例: [dotnet-trace](https://docs.microsoft.com/en-us/dotnet/core/diagnostics/dotnet-trace)、[Application Insights(Azure)](https://docs.microsoft.com/en-us/azure/azure-monitor/app/asp-net-trace-logs)等)

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

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

# 準備

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

```csharp
// 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以降の**アプリ側で作成する。

```csharp
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のソース](https://github.com/dotnet/runtime/blob/v5.0.0-rc.1.20451.14/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSourceEventSource.cs)を確認するのが良いだろう。

### 基本書式

どのようなイベントを捕捉するか、また、捕捉したイベントのパラメーターをどのように解釈するかを指定する
書式は、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

正確なリファレンスは[公式ドキュメント](https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.tracing.eventlevel)を参照

# 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](https://docs.microsoft.com/en-us/dotnet/core/diagnostics/dotnet-trace)による方法を紹介する

## ツールの導入

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

## イベントの収集

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

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

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

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

### providersオプションへの渡し方

FilterAndPayloadSpecsは改行を含むため、シェルによっては値を渡し辛い場合がある。
dotnet-traceはアプリ実行基盤に[System.CommandLine](https://github.com/dotnet/command-line-api)のフレームワークを使用しているため、[応答ファイルを用いて読み込ませることができる](https://github.com/dotnet/command-line-api/blob/main/docs/Features-overview.md#Response-files)。
まず、下記のようなテキストファイルを用意する

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

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

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

## イベント情報の閲覧

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

# 終わりに

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

## 参考記事

* [dotnet-trace](https://docs.microsoft.com/en-us/dotnet/core/diagnostics/dotnet-trace)
* [DiagnosticSourceEventSource](https://github.com/dotnet/runtime/blob/v5.0.0-rc.1.20451.14/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSourceEventSource.cs)
    * 詳細なパラメーターの記述などがある
* [dotnet/diagnosticsリポジトリ](https://github.com/dotnet/diagnostics)
    * EventPipeの仕様、dotnet-traceのソースなど