[解決済み】ログのベストプラクティス【クローズド

2022-04-18 07:26:48

質問

実際のアプリケーションでトレースやロギングをどのように扱っているか、話を聞きたいと思います。以下は、あなたの答えを説明するのに役立つかもしれないいくつかの質問です。

フレームワーク

使用しているフレームワークについて教えてください。

ログ4ネット
System.Diagnostics.Trace
System.Diagnostics.TraceSource
ロギングアプリケーションブロック
その他？

トレースを使用する場合、Trace.Correlation.StartLogicalOperationを利用していますか？

このコードを手動で書いていますか、それとも何らかの形でアスペクト指向プログラミングを使って書いていますか？コードスニペットを共有する気になりますか？

トレースソースの粒度はどうなっていますか？例えば、WPF TraceSourcesでは、様々なレベルでそれらを設定することができます。

システム.ウィンドウズ WPFのすべての設定
System.Windows.Animation アニメーションのために特別にオーバーライドします。

リスナー

ログ出力はどのようなものを使っていますか？

テキストファイル
XMLファイル
イベントログ
その他？

ファイルを使用する場合、ローリングログを使用しますか、それとも1つのファイルだけを使用しますか？ログをどのように利用可能にするのですか？

閲覧について

ログを閲覧するためのツールは？

メモ帳
テール
イベントビューア
Systems Center Operations Manager/Microsoft Operations Manger
WCFサービストレースビューア
その他？

ASP.NETソリューションを構築している場合、ASP.NETヘルスモニタリングも使用しますか？ヘルスモニターイベントにトレース出力を含めていますか？Trace.axdはどうでしょうか？

カスタムパフォーマンスカウンターについてはどうですか？

解決方法は？

更新しました。 System.Diagnosticsの拡張機能で、必要なリスナーの一部を提供するものについては、CodePlexの Essential.Diagnostics を参照してください ( http://essentialdiagnostics.codeplex.com/ )

フレームワーク

Q：使用しているフレームワークについて教えてください。

A: System.Diagnostics.TraceSource は、.NET 2.0 に組み込まれています。

アプリケーションに強力で柔軟、かつ高性能なロギング機能を提供しますが、多くの開発者はその機能を知らず、十分に活用できていません。

しかし、これは、（拡張できるように設計されている）ロギングフレームワーク全体を捨てて、いくつかの一般的な代替品（NLog、log4net、Common.Logging、および EntLib Logging）のように完全に置き換えることを意味するものではありません。

アプリケーションにロギングステートメントを追加する方法を変更して車輪を再発明するよりも、必要ないくつかの場所で System.Diagnostics フレームワークを拡張するだけでよいのです。

他のフレームワークは、EntLib さえも、単に Not Invented Here Syndrome に苦しんでいるように見えます。そして、存在するわずかなギャップを埋めるのではなく、System.Diagnostics ですでに完全に機能している基本（ログ文の書き方など）を再発明することに時間を浪費していると思います。要するに、使わないでください -- 必要ないのです。

意外と知らない機能

フォーマット文字列と引数を取る TraceEvent オーバーロードを使用すると、Filter.ShouldTrace() が成功するまで、パラメータが別の参照として保持されるため、パフォーマンスが向上します。これは、システムがメッセージが実際に記録されることを確認するまで、パラメータ値に対する高価な ToString() の呼び出しがないことを意味します。
Trace.CorrelationManager は、同じ論理操作に関するログステートメントを相関させることができます（下記参照）。
VisualBasic.Logging.FileLogTraceListener は、ログファイルへの書き込みに適しており、ファイルローテーションをサポートします。VisualBasicネームスペースにありますが、C#（または他の言語）プロジェクトでもDLLを含めるだけで同様に簡単に使用することができます。
EventLogTraceListener を使用するとき、複数の引数で、空または null 形式の文字列で TraceEvent を呼び出すと、ローカライズされたメッセージリソースを使用している場合、引数が直接 EventLog.WriteEntry() に渡されます。
サービストレースビューアツール（WCFから）は、アクティビティに関連するログファイルのグラフを表示するのに便利です（WCFを使用していない場合でも同様です）。これは、複数のスレッド/アクティビティが関与している複雑な問題をデバッグするのに非常に役立ちます。
すべてのリスナーをクリアする (または Default を削除する) ことで、オーバーヘッドを回避します。そうしないと Default はすべてをトレースシステムに渡してしまいます (そして ToString() のオーバーヘッドが発生します)。

必要であれば）拡張を検討したい領域。

データベーストレースリスナー
カラーコンソールトレースリスナー
MSMQ / Email / WMI トレースリスナー (必要な場合)
動的な設定変更のために Trace.Refresh を呼び出す FileSystemWatcher を実装する。

その他の推奨事項

構造化されたイベントIDを使用し、参照リストを保持する（例：enumで文書化する）。

システム内の（重要な）イベントごとに一意のイベントIDを持つことは、特定の問題を関連付け、発見するのに非常に有効です。イベントIDを記録・使用する特定のコードを追跡するのは簡単で、一般的なエラーに対するガイダンスを提供するのも簡単です。例えば、エラー5178はデータベース接続文字列が間違っていることを意味するなど。

イベントIDは何らかの構造（メールやHTTPで使われる返信コードの理論に似ている）に従うべきで、それによって特定のコードを知らなくてもカテゴリーごとに扱うことができるようになります。

例：最初の桁は一般的なクラスを詳細に示すことができます。1xxxは「開始」操作、2xxxは正常動作、3xxxはアクティビティトレース、4xxxは警告、5xxxはエラー、8xxxは「停止」操作、9xxxは致命的エラーなどに使用できる。

2桁目は領域の詳細、例えば21xxはデータベース情報（41xxはデータベース警告、51xxはデータベースエラー）、22xxは計算モード（42xxは計算警告など）、23xxは別のモジュール、などです。

割り当てられた構造化イベントIDは、フィルターで使用することもできます。

Q: トレースを使用する場合、Trace.Correlation.StartLogicalOperationを利用していますか？

A: Trace.CorrelationManager は、あらゆる種類のマルチスレッド環境（最近はほとんど何でもそうです）でログステートメントを相関させるのに非常に便利です。

相関をとるためには、少なくとも論理演算ごとにActivityIdを1回設定する必要があります。

Start/StopとLogicalOperationStackは、単純なスタックベースのコンテキストに使用することができます。より複雑なコンテキスト（例：非同期操作）では、新しいActivityIdにTraceTransferを使用すると（変更する前に）相関が可能になります。

サービストレースビューアツールは、アクティビティグラフを表示するのに便利です（WCFを使用していない場合でも）。

Q: このコードは手作業で書いているのですか？それとも何らかのアスペクト指向プログラミングを使って書いているのですか？コードスニペットを共有する気になりますか？

A: 例えばLogicalOperationScopeのような、(a)生成時にコンテキストを設定し、(b)破棄時にコンテキストをリセットするスコープクラスを作成するとよいでしょう。

これにより、以下のようなコードを記述することで、自動的に操作をラップすることができます。

  using( LogicalOperationScope operation = new LogicalOperationScope("Operation") )
  {
    // .. do work here
  }

スコープを作成すると、まず ActivityId を設定し、StartLogicalOperation を呼び出し、TraceEventType.Start メッセージを記録することができます。破棄時には、Stop メッセージを記録し、StopLogicalOperation を呼び出すことができます。

Q: トレースソースの粒度はどうなっていますか？例えば、WPF TraceSourcesでは、様々なレベルで設定することができます。

A: はい、複数のトレースソースはシステムが大きくなるにつれて便利で重要です。

あなたはおそらく、すべての警告や上記のメッセージ、またはすべての情報や上記のメッセージを一貫して記録したい一方で、合理的なサイズのシステムでは、アクティビティトレース（開始、停止など）とバーボースログの量が単に多くなりすぎています。

1つのスイッチですべてをオンまたはオフにするのではなく、システムの1つのセクションに対して一度にこれらの情報をオンにすることができると便利です。

この方法では、通常のロギング（すべての警告、エラーなど）から重大な問題を特定し、必要なセクションにズームインして、アクティビティトレースまたはデバッグレベルに設定することができます。

必要なトレースソースの数は、アプリケーションによって異なります。例えば、アセンブリごと、またはアプリケーションの主要セクションごとに、1つのトレースソースが必要な場合があります。

さらに細かい制御が必要な場合は、個別のブールスイッチを追加して、生メッセージダンプなど、特定の大量トレースのオン/オフを切り替えます。(または、WCF/WPFと同様に、別のトレースソースを使用することもできます)。

また、アクティビティトレースと一般的な（他の）ロギングのために別々のトレースソースを検討すると、正確にどのようにフィルターを構成するかを少し簡単にすることができます。

なお、異なるソースを使用した場合でも、メッセージはActivityIdを介して関連付けることができますので、必要な数だけ使用するようにしてください。

リスナー

Q：どのようなログ出力を行っていますか？

これは、あなたが書いているアプリケーションの種類と、ログに記録される内容に依存します。通常、異なるものは異なる場所に出力されます（つまり、複数の出力）。

私は一般的にアウトプットを3つのグループに分類しています。

(1) イベント - Windows イベントログ (およびトレースファイル)

例：サーバーやサービスを書いている場合、WindowsのベストプラクティスはWindowsイベントログを使うことです（報告するUIがない）。

この場合、すべての致命的な、エラー、警告、および（サービスレベルの）情報イベントは、Windowsイベントログに送られるべきです。例えば、"Service Started", "Service Stopped", "Connected to Xyz", そしておそらく "Schedule Initiated", "User Logged On" などです。

場合によっては、イベントログへの書き込みをトレースシステム経由ではなく、アプリケーションのビルトインにしたい場合があります（つまり、イベントログのエントリーを直接書き込む）。これは、誤ってオフにすることができないことを意味します。(トレースシステムで同じイベントを記録し、関連付けることができることに注意してください)。

一方、WindowsのGUIアプリケーションでは、一般的にこれらの情報をユーザーに報告します（Windowsイベントログに記録することもありますが）。

イベントはまた、関連するパフォーマンスカウンター（例えば、エラー数/秒）を持つかもしれません。そして、イベントログへの直接書き込み、パフォーマンスカウンター、トレースシステムへの書き込み、ユーザーへの報告などを調整し、それらが同時に起こるようにすることが重要になる場合があります。

i.e. ユーザーが特定の時間にエラーメッセージを見た場合、Windows イベントログで同じエラーメッセージを見つけることができ、次に同じタイムスタンプで同じイベントをトレースログで（他のトレース詳細と一緒に）見つけることができるはずです。

(2) 活動内容 - アプリケーションログファイルまたはデータベーステーブル(およびトレースファイル)

これは、システムが行う通常の活動で、例えば、ウェブページが提供された、株式市場の取引が成立した、注文が行われた、計算が実行された、などです。

アクティビティトレース（開始、停止など）は、ここで（適切な粒度で）役に立ちます。

また、特定のアプリケーションログ（監査ログと呼ばれることもある）を使用することは非常に一般的である。通常、これはデータベーステーブルまたはアプリケーションログファイルであり、構造化されたデータ（すなわち、一連のフィールド）を含んでいます。

アプリケーションによっては、ここで少し曖昧になることがあります。同じような例として、メッセージングシステムや計算システムがあり、各操作がアプリケーション固有の詳細とともにログに記録されます。

あまり良くない例としては、株式市場の取引や販売注文システムなどがあります。これらのシステムでは、重要なビジネス価値があるため、おそらくすでに活動を記録していると思われますが、他の行動と関連付けるという原則は依然として重要です。

カスタムアプリケーションログと同様に、アクティビティもまた、しばしば関連するパフォーマンスカウンタ（例：1秒あたりのトランザクション数）を持っています。

一般的に、異なるシステム間でアクティビティのログを調整する必要があります。つまり、パフォーマンスカウンターを増やすと同時にアプリケーションログに書き出し、トレースシステムにログを記録します。もし、すべてを同時に（またはコード内で互いに直後）行うなら、（それらがすべてコード内の異なる時間/場所で発生する場合よりも）問題のデバッグが容易になります。

(3) デバッグトレース - テキストファイル、またはXMLやデータベース。

これはVerboseレベル以下の情報です（例：生のデータダンプをオン/オフするためのカスタムブールスイッチ）。これは、サブアクティビティレベルでシステムが行っていることの詳細な情報を提供します。

これは、アプリケーションの個々のセクションでオン/オフできるようにしたいレベルです（そのため、複数のソースがあります）。Windowsのイベントログを散らかさないようにしたいものです。データベースが使用されることもありますが、一定時間後に削除されるローリングログファイルが使用されることが多いようです。

この情報がアプリケーションログファイルと大きく異なるのは、構造化されていないことです。アプリケーションログにはTo、From、Amountなどのフィールドがありますが、Verboseデバッグトレースにはプログラマーが書き込んだもの、例えば "値X={value}、Y=false" や、 "Done it, trying again" などのランダムコメント/マーカーが含まれます。

重要なプラクティスの1つは、アプリケーションログファイルやWindowsイベントログに記録されたものが、同じ詳細（例：タイムスタンプ）でトレースシステムに記録されることを確認することです。これにより、調査時に異なるログを関連付けることができます。

サービストレースビューアなど、複雑な相関関係があるため、特定のログビューアを使用する予定がある場合、適切なフォーマット（XMLなど）を使用する必要があります。それ以外の場合は、単純なテキストファイルで十分です。下位レベルでは、情報はほとんど構造化されていないので、配列のダンプやスタックダンプなどが見つかるかもしれません。より高いレベルの、より構造化されたログに関連付けることができるのであれば、問題はないはずです。

Q: ファイルを使用する場合、ローリングログを使用するのですか、それとも1つのファイルだけを使用するのですか？また、ログをどのように利用できるようにしますか？

A: ファイルの場合、一般的には管理性の観点からローリングログファイルが必要です (System.Diagnostics では、単に VisualBasic.Logging.FileLogTraceListener を使用してください)。

可用性はまた、システムに依存します。ファイルについてだけなら、サーバーやサービスの場合、ローリングファイルには必要なときにアクセスすればよいのです。(Windowsイベントログやデータベースアプリケーションログは、独自のアクセスメカニズムがあります)。

ファイルシステムに簡単にアクセスできない場合は、データベースへのデバッグ・トレースが簡単かもしれません。[すなわち、データベース TraceListener を実装することです。］

私が見たWindows GUIアプリケーションの興味深いソリューションの1つは、実行中に非常に詳細なトレース情報をフライトレコーダーに記録し、問題がなければシャットダウン時にそのファイルを削除することでした。

しかし、クラッシュしたり、問題が発生した場合、ファイルは削除されません。エラーを検出するか、次に実行したときにファイルに気づき、例えば7zipなどで圧縮してメールで送ったり、その他の方法で利用できるようにするなどの措置を取ることができます。

最近の多くのシステムは、失敗を中央サーバーに自動報告する機能を取り入れている（プライバシー上の理由などから、ユーザーに確認した上で）。

閲覧について

Q：ログを閲覧するためのツールは？

A: 異なる理由で複数のログがある場合、複数のビューアを使用することになります。

メモ帳/vi/メモ帳++などのテキストエディタがプレーンテキストのログの基本です。

複雑な操作、例えば転送を伴うアクティビティがある場合は、当然ながら、Service Trace Viewerのような専用ツールを使用することになるでしょう。(しかし、それが必要ないのであれば、テキストエディタの方が簡単です）。

私は一般的にWindowsイベントログに高レベルの情報を記録するので、構造化された方法で概要を把握する素早い方法を提供します（きれいなエラー/警告のアイコンを探してください）。ログに十分な情報がない場合、テキストファイルを探し始める必要がありますが、少なくともログはあなたに出発点を与えてくれます。(このとき、ログが協調して記入されていることを確認すると便利です）。

一般に、Windowsイベントログは、MOMやOpenViewのような監視ツールがこれらの重要なイベントを利用できるようにします。

その他

データベースにログを記録すれば、情報のフィルタリングやソートが簡単にできます（例えば、特定のアクティビティIDにズームインする。テキストファイルでは、Grep/PowerShellなどを使用して、必要な部分的なGUIDでフィルタリングすることができます）。

MS Excel（または他のスプレッドシートプログラム）。適切な区切りでインポートし、異なる値を異なる列に入れることができれば、構造化または半構造化された情報の分析に便利です。

デバッグ/テストでサービスを実行する場合、私は通常、単純化のためにコンソールアプリケーションでそれをホストします。カスタムのトレースリスナーを実装する必要があります。

フレームワークには、カラーコンソールロガーやデータベースロガーは含まれていませんので、今のところ、必要であればこれらを書く必要があることに注意してください（それほど難しいことではありません）。

いくつかのフレームワーク（log4net、EntLib など）が、車輪の再発明に時間を浪費し、基本的なロギング、フィルタリング、テキストファイル、Windows イベントログ、XML ファイルへのロギングをそれぞれ異なる方法で再実装している（ログ文がそれぞれ異なる）のは本当に腹立たしいことです。重複した努力の大きな無駄の話です。

Q: ASP.NETソリューションを構築している場合、ASP.NET Health Monitoringも使用しますか？ヘルスモニターイベントにトレース出力は含まれますか？Trace.axdについてはどうですか？

これらは必要に応じてオン/オフを切り替えることができます。Trace.axdは、サーバーが特定の物事にどう反応するかをデバッグするのに非常に便利だと思いますが、一般に、使用頻度の高い環境や長期のトレースには役に立ちません。

Q: カスタムパフォーマンスカウンターはどうですか？

プロフェッショナルなアプリケーション、特にサーバー/サービスでは、パフォーマンスモニターのカウンターとWindowsイベントログへのロギングの両方で完全にインストルメント化されているのを見ることを期待します。これらはWindowsの標準ツールであり、使用されるべきものです。

使用するパフォーマンス・カウンターとイベント・ログのインストーラーが含まれていることを確認する必要があります。これらはインストール時（管理者としてインストールする場合）に作成されるべきです。これらはインストール時（管理者としてインストールする場合）に作成する必要があります。アプリケーションが正常に動作している場合、管理者権限を持つ必要はありません（したがって、見つからないログを作成することはできません）。

これは、非管理者としての開発を実践する良い理由です（サービスをインストールする必要がある場合などには、別の管理者アカウントを持ってください）。イベントログに書き込む場合、.NETは初めて書き込んだときに自動的に欠落ログを作成します。非管理者として開発すれば、これを早期に発見でき、顧客がシステムをインストールしたときに、管理者として実行していないために使用できない、という厄介な事態を避けることができます。