この記事の議論で、私はついにAPIロガーの速度特性を数値で評価したいと思いました。
NLogロガーとLog4Netロガーを使用する場合の遅延を比較し、.NetとMonoのコードセクションのパフォーマンス測定に関する一般的な質問をいくつか取り上げることにしました。
ログがオンの場合、パフォーマンスは次のコンポーネントで構成されます。
- メッセージのレンダリング。 一部のパラメーターをキャッシュし、他のパラメーターを非同期的に計算することができます。
- ターゲット/アペンダーにメッセージを配信するシステム。
- メッセージフロー保存システム。
NLogとLog4Netでは、これらのシステムはすべて、構成とアーキテクチャの両方で大きく異なります。 さらに、パフォーマンスを改善するために、それらを異なる方法で調整できます。 したがって、含まれているログについては、非「holivarnyh」テストを定式化できませんでした。
ただし、既に述べたように、無効化されたロガーはアプリケーションの速度に最小限の影響しか与えません。 したがって、無効なロガーのパフォーマンスを比較してみましょう。 この場合、ロギングコール自体へのパラメータの転送と現在のロギングレベルの決定のみが影響を受けます。
そもそも、私は悔い改めて、jitコンパイルによる最適化への期待がまだ実現していないことを認めています。 仮想のインライン挿入によるパフォーマンスの加速は見つかりませんでした。 しかし、知っている人は、おそらく後のフレームワークが学習するでしょう...
テスト方法
コンソールアプリケーションは、デバッグメッセージが表示される関数をループします。
6つの機能を使用。
- N0_1-定数文字列の出力。
- N0_100-100の異なるスレッドからの定数文字列の出力
- N1_1-1つのパラメーターでフォーマットされたメッセージを出力します。
- N3_1-3つのパラメーターを持つフォーマットされたメッセージを出力します。
- P0_1-事前チェック付きの出力行（パラメーターの数は関係ありません）
- Em_1-空（測定ストラップの速度を推定するため）
精度を高めるために、測定値はグループ化され、グループがシステムタイマーを100ティック以上実行しました。 グループ測定の合計数は、各機能で200,000です。
得られたデータの分布の予備評価のために、ヒストグラムが作成されました。 値の右5％は、オペレーティングシステムの影響によるランダムな遅延として除外されました。 したがって、表には、ケースの95％の平均推定値とそれらの偏差が示されています。
測定は、.Net（Windows 7）およびMono 2.10.2（OpenSUSE 11.3）で行われました。
「スローダウン」列は、NLogと比較したLog4Netのスローダウンです。 関数呼び出しの実行時間（時間Em_1）に合わせて調整して計算されました。
テストの後続の各実行は、計算された信頼区間を超える結果を返す可能性があり、1回の実行内でこの区間は違反されません。 したがって、パフォーマンス評価は相対的な場合にのみ使用できます。 したがって、両方のロギングシステムの測定は1回の実行で実行されます。
測定結果
.Netでのテスト（Windows 7）
| Log4net | Nlog |
| 機能 | 平均時間（ns） | 平均時間（ns） | 減速 |
| N0_1 | 31.4（-0.3 +0.4） | 6.83（-0.05 +0.02） | 8.4 |
| N0_100 | 31.9（-0.8 +3.8） | 6.83（-0.06 +0.01） | 8.5 |
| N1_1 | 40.4（-1.3 +2.9） | 7.25（-0.13 +0.01） | 10 |
| N3_1 | 60.6（-1.2 +8.8） | 7.93（-0.04 +0.03） | 13 |
| P0_1 | 27.7（-0.3 +0.3） | 4.438（-0.004 +0.031） | 26 |
| Em_1 | 3.51（-0.12 +0.24） | --- | --- |
Log4Netを使用した関数の実行時間の分布：
ここ：青-N0_1、紫-N0_100、緑-N1_1、赤-N3_1。
NLogの分布は引用していません。なぜなら、 2-3の値の非常に狭い外れ値であり、グラフにはまだ分布の形式がありません。
Mono 2.10.2（OpenSUSE 11.3）でのテスト
| Log4net | Nlog |
| 機能 | 平均時間（ns） | 平均時間（ns） | 減速 |
| N0_1 | 80.0（-36.5 +5.5） | 6.924（-0.004 + 0.016） | 21 |
| N0_100 | 78.0（-34.6 +11.3） | 6.924（-0.004 + 0.016） | 21 |
| N1_1 | 92.4（-34.9 +13.3） | 6.926（-0.006 +0.054） | 24 |
| N3_1 | 141（-52 +848） | 7.635（-0.015 +0.005） | 32 |
| P0_1 | 69.6（-30.2 + 4.8） | 4.351（-0.011 +0.009） | 62 |
| Em_1 | 3.285（-0.005 +0.005） | --- | --- |
Log4Netを使用した関数の実行時間の分布：
ここ：青-N0_1、紫-N0_100、緑-N1_1、赤-N3_1。
同様に、NLogの配布は引用していません。
興味があれば、自分でグラフを作成できます。
ベンチマークのソースコードは
こちらです。 バイナリ、テスト結果、ヒストグラムおよびグラフのデータは別々に
保存さ
れます。 GnuPlotのヒストグラムを作成する例もあります。
結果分析
測定は異なるマシンで実行されたため、Monoと.Netのパフォーマンスを比較しないでください。 プラットフォームのパフォーマンスを比較することが興味深い場合は、
この作業で
これについて詳しく読むことができます。
表から、些細な呼び出しでは、Log4Netの速度が8倍以上低下することが明らかです。 より現実的なアプリケーションの場合、3つのパラメーターを持つ出力の例を見てください。 DotNetおよびMonoのそれぞれ13および32。
Log4Netでは、ログレベルの検証時間が非常に長くなっています。 そのため、事前チェックを使用してもほとんど意味がありません。
Log4NetがMonoで使用されている場合、かなり奇妙な分布を観察できます。 私の経験に基づいて、これらはGCの陰謀であるとすぐに言うことができます。 どうやら、Monoは関数パラメーターの大規模なボックス化により悪化し、Log4Netは
object型のすべてのパラメーターにつながり
ます 。 このため、ランタイムはさらに予測可能ではありません-絶対エラーは値自体を超えています。
適用性
実際には、ほとんどの場合、無効化されたログの呼び出し速度がアルゴリズムの速度に影響するほど詳細なロギングは必要ありません。 このようなログを有効にすると、サービスがどのように動作するか想像するのは困難です。 また、数十ナノ秒について話していることに注意してください。
ログに記録されたセクションのペイロードは、通常、ログ呼び出しよりも3桁大きく（数十マイクロ秒）、I / O操作はさらに3桁（10ミリ秒）大きくなります。 したがって、ロガーを選択するときの速度基準はまだ重要ではありません。
良い開発を！