はじめに
ActivitySourceの記事で一通り機能は解説できていたと思うが、この記事では、実際にActivityを有効にしたときのオーバーヘッドを確認してみたいと思う。
テストプログラム
テストプログラムは gistにアップロードしている
ここでは以下のようなベンチマークを実施した。
| テスト名 | 使用クラス | 有効 | 備考 |
|---|---|---|---|
| CreateActivityOnly | - | - |
new Activity()のオーバーヘッドの計測のため |
| DiagnosticSource_Disabled | DiagnosticSource | × | |
| DiagnosticSource_Enabled | DiagnosticSource | 〇 | |
| ActivitySource_Disabled | ActivitySource | × | |
| ActivitySource_None | ActivitySource | 〇 | ActivitySamplingResultにNoneを指定 |
| ActivitySource_Propagation | ActivitySource | 〇 | ActivitySamplingResultにPropagationDataを指定 |
| ActivitySource_AllData | ActivitySource | 〇 | ActivitySamplingResultにAllDataを指定 |
| ActivitySource_AllDataAndRecorded | ActivitySource | 〇 | ActivitySamplingResultにAllDataAndRecordedを指定 |
結果
結果は以下のようになった。
BenchmarkDotNet=v0.12.1, OS=Windows 10.0.18363.1139 (1909/November2018Update/19H2)
Intel Core i7-9700 CPU 3.00GHz, 1 CPU, 8 logical and 8 physical cores
.NET Core SDK=5.0.100
[Host] : .NET Core 5.0.0 (CoreCLR 5.0.20.51904, CoreFX 5.0.20.51904), X64 RyuJIT
ShortRun : .NET Core 5.0.0 (CoreCLR 5.0.20.51904, CoreFX 5.0.20.51904), X64 RyuJIT
Job=ShortRun IterationCount=3 LaunchCount=1
WarmupCount=3
| Method | Mean | Error | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|
| CreateActivityOnly | 10.6031 ns | 1.6297 ns | 0.0893 ns | 0.0280 | - | - | 176 B |
| DiagnosticSource_Disabled | 0.5074 ns | 0.1019 ns | 0.0056 ns | - | - | - | - |
| DiagnosticSource_Enabled | 533.8810 ns | 118.0714 ns | 6.4719 ns | 0.1135 | - | - | 712 B |
| ActivitySource_Disabled | 14.6574 ns | 0.3357 ns | 0.0184 ns | - | - | - | - |
| ActivitySource_None | 65.7799 ns | 3.1931 ns | 0.1750 ns | - | - | - | - |
| ActivitySource_Propagation | 635.7652 ns | 193.5533 ns | 10.6093 ns | 0.1001 | - | - | 632 B |
| ActivitySource_AllData | 616.2310 ns | 10.3009 ns | 0.5646 ns | 0.1001 | - | - | 632 B |
| ActivitySource_AllDataAndRecorded | 633.3614 ns | 208.1648 ns | 11.4102 ns | 0.1001 | - | - | 632 B |
考察
有効無効の差
まず、有効と無効の有無で約500～600nsの差が出ていることは大きな特徴として言えるだろう。
CreateActivityOnly(=newのみ)の結果は10ns程度で、ほとんどコストがかかっていないことから、Activity開始処理の中で様々な属性をセットしていることが起因していると思われる。
ActivitySourceとDiagnosticSourceの比較
また、DiagnosticSourceとActivitySourceで比較した場合、若干DiagnosticSourceの方がオーバーヘッドが少ないように見える。
これは、後述するActivitySamplingResultのチェック等も含まれているためと思われる。
ただし、DiagnosticSource経由で使用する場合は使い勝手が悪いため、この辺りはどちらを優先するかという問題になると思う。
ActivitySamplingResultによる違い
それぞれのフラグを比較すると、ActivitySamplingResult.Noneの時が特別に低い状態になっている。
これは同フラグを指定するとActivityを生成しないという動作をするので、オーバーヘッドがフラグのチェックのみになっているためと思われる。
他のフラグについては、今回計測した範囲では有意な差は無かった。
これは、None以外はActivityを構築するアプリケーションが参考にするフラグなので、内部的な動作にはほぼ影響しないということだろう。
ただし、アプリケーション側ではフラグを見てActivityにデータやイベントを追加するということは十分に考えられるので、無意味なフラグというわけではない。
まとめ
今回Activity自体のオーバーヘッドを測ったが、大きくても一回当たり1usec以下なので、これを気にするかどうかはユーザー次第であることは忘れないでおきたい。
シビアな状況においては、有効と無効の差はかなり大きいので、留意しておきたい。
また、オーバーヘッドが気になる状況でも、ActivitySamplingResultによってある程度軽減はできるため、検討しておくといいと思う。