C#と.NETによるロギング

5 読了時間

Picture of Denis Troller

Denis Troller

Product Manager

TL;DR 概要

  • C#での適切なロギングは、可観測性、デバッグ、セキュリティにとって重要ですが、一般的なロギングのミスはログインジェクションの脆弱性、パフォーマンスの問題、誤解を招く診断データを引き起こします。
  • SonarQubeのC#ルールは、ログステートメントでの安全でない文字列連結(ログインジェクションのリスク)、ログ呼び出しでの不要な文字列フォーマット(ログレベルが無効な場合のパフォーマンス問題)、およびログレベルチェックの欠如を検出します。
  • 名前付きプレースホルダーを使用した構造化ロギング(例: logger.LogInformation("Processing {OrderId}", orderId))が推奨されるアプローチです。これはより安全で、パフォーマンスが高く、機械可読なログを生成します。
  • .NETの組み込みILoggerやSerilog、NLogのような人気のあるライブラリを使用しているチームは、SonarQubeのルールがMicrosoftのガイドラインで推奨されるロギングのベストプラクティスを強制することを発見するでしょう。

今日は、アプリケーション開発の重要でありながらしばしば見過ごされがちな側面、つまりロギングに焦点を当てます。具体的には、.NETフレームワークでのロギングを探ります。経験豊富なC#開発者であれ、.NETを始めたばかりであれ、このガイドは、潜在的なエラーの種類を示し、ログの品質を損なう可能性があることを示します。

ロギングは、どのアプリケーションにおいても重要な部分です。それは飛行機のブラックボックスのようなものです。何かがうまくいかないとき、開発者は何が起こったのかを理解するために最初にログを確認することが多いです。その重要性にもかかわらず、ロギングはしばしば後回しにされ、適切な計画や理解なしに実装されます。アプリの問題を調査する際に、ログが必要な情報を提供していないことを発見するのは非常に苛立たしいことです。

Sonarでは、コード内の問題を見つけ、それをクリーンに保つための支援を行います。最終的に、コードの問題は、日々あなたや顧客が依存するソフトウェアの品質に影響を与えます。新しいルールで.NETのロギングコードをターゲットにし、見つけた問題を修正する方法を案内し、将来的にそれを避ける方法を教えます。

なぜSonarがC#ロギングルールを提供するのか

素晴らしい.NETライブラリである構造化ロギングの登場により、SerilogNLog、またはMicrosoftのデフォルトのロギングライブラリを使用して、大量のログを最適に処理することが可能になりました。クラウドネイティブアプリを開発している場合、OpenTelemetry標準は、優れたロギング基盤を基に、アプリの完全な可観測性を提供します。これらの優れたロギングツールは、必要な情報をログに記録する際にミスを避ける能力に依存しています。

本番環境で特定のバグの経路を理解しようとしてログを見たことがありますか?ログメッセージが間違っていることに気づいたことはありますか?構造化ロギングを実装し、ログを集中管理システムに取り込むのに貴重な時間を費やしたのに、必要な詳細をログに記録していなかったことに気づいたことはありますか?システムが毎日何百万ものログを生成し、構造化ロギングが最適でない場合、ログバックエンドの検索機能を妨げることで、生活をより困難にしている可能性があります。また、ログコードに小さなミスが潜んでいることもあります。それは数ヶ月間コードに潜んでおり、最終的には良いログがないために別の問題を診断するのに数週間かかりました。問題を理解するために新しいバージョンを出荷する必要があり、問題が再び発生することを祈りました。最初にコードを書いたときに、ビルドシステムがプルリクエストのコメントで小さなミスをしたことを教えてくれたら、もっと役立ったのではないでしょうか?それがSonarがあなたのためにできることです…このようなフラストレーションと時間の浪費を避けることができます。

このようなミスをすることは非常に一般的です。ほとんどのAPIが文字列ベースであるためです。ロギングコードを追加する際には、コピー・ペースト・修正が多用されます。ロギングコードを書くことは非常に反復的だからです。これにより、小さく、しばしば見過ごされがちな問題が発生し、数ヶ月、場合によっては数年後にしか明らかになりません。これらの問題は最終的に開発者の時間と会社の資金を浪費させます。迅速に対応する能力を低下させ、インシデントに効率的に対応する能力を低下させます。また、インフラストラクチャとDevOpsの取り組みの効果を低下させます。

最悪のミスのいくつかを見てみましょう。そして、コード内でそれらをどのように見つけるかを見てみましょう。

メッセージの構文と意味

C#でロギングを行う際には、書いたコードが期待通りの結果をもたらすことを確認することが重要です。これは、メッセージが正しく、正しい情報が正しい場所に含まれていることを確認することを意味します。APIが文字列と型なしの引数に依存しているため、ミスをするのは驚くほど簡単です。

これらのエラーがどのように見えるかを見てみましょう。

不正なメッセージ構文

.NETでの構造化ロギングには特定の構文を使用する必要があります。例えば、次のコードを見てみましょう:

logger.LogError("Login failed for {User}. Invalid credentials", user);

これはどのアプリケーションでも標準的なロギングコードです。Userプロパティの閉じ中括弧を省略するというミスは、手遅れになるまで簡単に見逃される可能性があります:

logger.LogError("Login failed for {User. Invalid credentials", user);

閉じ中括弧を省略すると、ログ出力(プレーンテキストまたは構造化JSON)に期待される情報が含まれなくなります。

上記のロギングコードのもう一つの一般的なミスは次の通りです:

logger.LogError("Login failed for {User-Name}", user);

この場合、プレースホルダーの名前が問題です。構造化ロギングは、各プレースホルダーにプロパティを作成することで機能します。そのプロパティの名前は、ほとんどの言語での識別子の標準構文に従う必要があります。文字またはアンダースコアで始まり、文字、数字、またはアンダースコアのみを含む必要があります。プロパティ名にダッシュを使用することは不正確であり、ファイル名のような名前にダッシュを使用することが一般的であるため、ログコードを書く際に開発者がよく犯す典型的なミスです。

ここでは、整列のために数字の代わりに文字を使用するというタイプミスが行われています:

logger.LogDebug("Retry attempt {Cnt,r}", cnt);

Sonarは、フォーマット指定子の欠如も検出します:

logger.LogDebug("Retry attempt {Cnt:}", cnt);

ルールS6674は、これらの問題をすべて検出します。

プレースホルダーの重複

ロギングメッセージでは、すべてのプレースホルダーが一意でなければなりません。同じ名前を繰り返すことは、次のコードで示される一般的なミスです:再び、これは構造化ロギングの目的に関連しています。プレースホルダーは特定のプロパティを生成します。複数回使用すると、使用しているロギングフレームワークによって結果が異なる場合があります。いくつかは提供された最後の値のみを使用します。他のものは、舞台裏で一意の名前を生成します。ルールS6677はこの問題を検出し、警告します。

logger.LogDebug("User {Id} purchased order {Id}", user.Id, order.Id);

プレースホルダーの順序が不正

イライラする一般的なミスは、プレースホルダーの順序が引数の順序と一致しない場合です。これはコードを再構築する際に簡単に発生します。コードをざっと読むときには検出が難しく、本番環境での問題の診断をさらに困難にする可能性があります。

例を見てみましょう:

logger.LogError("File {FileName} not found in folder {Path}", file.DirectoryName, file.Name, second);

よく見ると、意図はコードが行うことの逆であることがわかります。引数が間違った順序であるためです。その結果、次のようになります:

  • メッセージが間違っている。
  • 構造化ロギングによって生成されるフィールドも間違っており、ログのクエリ機能を台無しにします。

ルールS6673はこれらのタイプのエラーを検出します。意図を発見し、キャメルケース、アンダースコア、ドット文字から単語のリストを作成し、それらを一致させることで、プレースホルダーの名前の単語と引数の式の単語を一致させます。

手動で作成されたメッセージ

構造化ロギングの登場前は、文字列連結を使用してロギングメッセージを作成するのが普通でした。C#での文字列補間により、ロギングメッセージの作成がさらに簡単になりました。例えば、次のコードは有効で動作します:

logger.LogError("Login failed for {user}”);

しかし、ILoggerとすべてのロギングバックエンドは構造化ロギングを使用しており、メッセージだけでなく、名前付きフィールドで個々の引数をキャプチャすることができ、ログをはるかにクエリしやすくします。次のように書く方がはるかに良いです:

logger.LogError("Login failed for {UserName}”, user);

OpenTelemetryのような標準を通じてログを発行する場合、バックエンドがフィールドの効率的なストレージとインデックスを提供する必要があるため、これはさらに重要です。ルールS2629はこの古いパターンを検出し、ロギングライブラリを完全に活用する方法を示します。

間違ったオーバーロードの使用

ほとんどのロギングフレームワーク、特にC#でのロギングに使用されるものには、ログレベル、イベントID、または例外を渡すための特定のオーバーロードがあります。オーバーロード値をプレースホルダー引数として渡すメソッドを呼び出す場合、おそらく意図したことを行っていません。

例えば、次のコードを書いた場合:

logger.LogDebug("An exception occurred {Exception} with {EventId}.", ex, eventId); 

次のように書くべきです:

logger.LogDebug(eventId, ex, "An exception occurred.");