はじめに
ILogger は .NET に標準で組み込まれているため、とりあえず _logger.LogInformation($"...") と書けば動きます。
しかし、この「とりあえず」の書き方が、検索性の低いログ、パフォーマンス劣化、機密情報の漏えいといった問題を引き起こします。
この記事では、実務でよくあるロギング設計の落とし穴と、構造化ログを活かした改善Tipsをまとめます。コピペで試せるサンプルを多数用意しています。
ロギングの基本
仕組みの要点
-
ILoggerはログレベル(Trace/Debug/Information/Warning/Error/Critical)ごとに出力を制御できる - 構造化ログ とは、メッセージテンプレート内のプレースホルダーに名前を付け、ログを検索・集計可能なデータとして扱う手法
- 文字列補間(
$"...")ではなく、メッセージテンプレート+パラメータの形式で書くことが構造化ログの基本
基本的な使い方
public class OrderService
{
private readonly ILogger<OrderService> _logger;
public OrderService(ILogger<OrderService> logger)
{
_logger = logger;
}
public void Process(int orderId)
{
_logger.LogInformation("Order {OrderId} processed", orderId);
}
}
パターン1 文字列補間によるログ出力
ポイント
-
$"..."で文字列補間したメッセージを渡すと、構造化ログのメリットが失われる - メッセージテンプレートのプレースホルダーに変数を渡す形式にする
サンプル
// ❌ 文字列補間で埋め込む
_logger.LogInformation($"Order {orderId} processed for user {userId}");
この書き方だと、ログ基盤(Application Insights、Seq、Elasticsearchなど)側で OrderId や UserId を個別のフィールドとして検索・集計できません。すべて1つの文字列としてしか扱えないため、「特定の注文IDのログだけを抽出する」といった操作が困難になります。
// ⭕ メッセージテンプレート+パラメータ
_logger.LogInformation("Order {OrderId} processed for user {UserId}", orderId, userId);
こう書くことで、ログ基盤側が OrderId と UserId を構造化データとして認識し、フィルタや集計に使えるようになります。
パターン2 ログレベルの誤用
ポイント
- すべて
LogInformationで済ませると、重要なエラーが大量のログに埋もれる - 状況に応じて適切なログレベルを使い分ける
サンプル
// ❌ すべてInformationで出力
try
{
await ProcessOrderAsync(orderId);
}
catch (Exception ex)
{
_logger.LogInformation("Failed to process order {OrderId}: {Message}", orderId, ex.Message);
}
例外発生時に LogInformation を使うと、本番環境で Information レベルのログを大量に出している場合に埋もれてしまい、アラートの対象にもなりません。
// ⭕ 状況に応じたレベルを使う
try
{
await ProcessOrderAsync(orderId);
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to process order {OrderId}", orderId);
}
LogError に例外オブジェクトを渡すことで、スタックトレースも構造化データとして記録され、監視ツール側でのアラート設定も容易になります。目安として、Warning は想定内の異常系、Error は処理継続不能な異常、Critical はシステム全体に影響する障害、という切り分けをしておくと運用がぶれません。
パターン3 高頻度パスでのログ出力コスト
ポイント
- ループや高頻度に呼ばれるメソッド内でのログ出力は、文字列生成コストとI/Oコストが積み重なる
- ログレベルが無効な場合でも引数の評価コストは発生するため、
IsEnabledで事前チェックするか、ソース生成ロガーを使う
サンプル
// ❌ 高頻度パスで毎回ログを出す
foreach (var item in items)
{
_logger.LogDebug("Processing item {ItemId} with payload {Payload}", item.Id, JsonSerializer.Serialize(item));
}
JsonSerializer.Serialize(item) は引数として毎回評価されるため、Debug レベルが無効化された本番環境でもシリアライズのコストだけは発生してしまいます。
// ⭕ ソース生成ロガー(LoggerMessage)を使う
public static partial class LogMessages
{
[LoggerMessage(Level = LogLevel.Debug, Message = "Processing item {ItemId}")]
public static partial void ProcessingItem(this ILogger logger, int itemId);
}
foreach (var item in items)
{
logger.ProcessingItem(item.Id);
}
LoggerMessage 属性によるソース生成ロガーは、ログレベルが無効な場合の呼び出しコストをほぼゼロに抑えられ、ボクシングも回避できます。高頻度パスでは積極的に採用する価値があります。
パターン4 機密情報のログ出力
ポイント
- パスワード、トークン、個人情報などをそのままログに出さない
- 必要な場合はマスキングするか、そもそもログ対象から除外する
サンプル
// ❌ 機密情報をそのまま出力
_logger.LogInformation("User login attempt: {Email} / {Password}", email, password);
ログは監視ツールやファイルに長期間保存されることが多く、アクセス権限の管理が甘いと機密情報の漏えいにつながります。パスワードのような値は本来ログに出す必要がないものです。
// ⭕ 機密情報を除外・マスキングする
_logger.LogInformation("User login attempt: {Email}", email);
どうしても値の一部を確認したい場合(クレジットカード番号の下4桁など)は、専用のマスキング処理を通してから出力します。「そのログは誰が見ても問題ないか」を出力前に確認する習慣をつけましょう。
パターン5 例外の握りつぶしと再スロー時のスタックトレース消失
ポイント
-
catchした例外をログに残さずに握りつぶさない - 再スローする場合は
throw;を使い、throw ex;でスタックトレースを消さない
サンプル
// ❌ スタックトレースが消える
try
{
await ProcessOrderAsync(orderId);
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to process order {OrderId}", orderId);
throw ex; // ここでスタックトレースがリセットされる
}
// ⭕ throw; でスタックトレースを保持する
try
{
await ProcessOrderAsync(orderId);
}
catch (Exception ex)
{
_logger.LogError(ex, "Failed to process order {OrderId}", orderId);
throw;
}
throw ex; は例外を再スローする際にスタックトレースを現在地点にリセットしてしまうため、本来の発生箇所が分からなくなります。ログに例外を残しつつ、throw; で元のスタックトレースを保持するのが基本です。
よくある落とし穴と回避策
-
文字列補間によるログ出力
- 問題:ログが構造化データとして扱えず、検索・集計ができない。
- 回避:メッセージテンプレート+パラメータの形式で出力する。
-
ログレベルの誤用
- 問題:すべて
Informationで出力し、重要なエラーが埋もれる。 - 回避:状況に応じて
Warning/Error/Criticalを使い分ける。
- 問題:すべて
-
高頻度パスでのログコスト
- 問題:無効なログレベルでも引数の評価コストが発生する。
- 回避:
LoggerMessageによるソース生成ロガーを使う。
-
機密情報の出力
- 問題:パスワードや個人情報がそのままログに残り、漏えいリスクになる。
- 回避:ログ対象から除外するか、マスキングする。
-
例外の握りつぶし・再スロー時のスタックトレース消失
- 問題:
throw ex;によって本来の発生箇所が分からなくなる。 - 回避:
throw;を使い、ログには必ず例外オブジェクトを渡す。
- 問題:
実務チェックリスト
- 文字列補間(
$"...")でログを出力していないか - 例外発生時に適切なログレベル(
Warning/Error/Critical)を使っているか - 高頻度パスで
LoggerMessageによるソース生成ロガーを検討したか - パスワードやトークンなどの機密情報をログに出していないか
- 再スロー時に
throw;を使い、throw ex;を避けているか - ログメッセージのプレースホルダー名がログ基盤側で一貫しているか(
{OrderId}の表記ゆれがないか)
テストとデバッグのコツ
-
ILoggerをモックしてログ出力を検証する- 単体テストで、特定のログレベル・メッセージが出力されているかを確認できます。
[Fact]
public void Process_LogsError_WhenExceptionThrown()
{
var loggerMock = new Mock<ILogger<OrderService>>();
var service = new OrderService(loggerMock.Object);
Assert.Throws<InvalidOperationException>(() => service.Process(-1));
loggerMock.Verify(
l => l.Log(
LogLevel.Error,
It.IsAny<EventId>(),
It.IsAny<It.IsAnyType>(),
It.IsAny<Exception>(),
It.IsAny<Func<It.IsAnyType, Exception?, string>>()),
Times.Once);
}
-
開発環境でログ出力先をコンソールに切り替えて目視確認する
- 構造化ログの各フィールドが意図通りに分離されているか、実際の出力を見て確認する習慣をつけると、本番投入前に気づけます。
まとめ
- ログは「とりあえず出す」のではなく、検索・集計・監視で使える形を意識して設計することが重要です。
- 文字列補間ではなくメッセージテンプレート形式で書くことが、構造化ログの第一歩です。
- ログレベルの使い分け、高頻度パスでのコスト、機密情報の扱い、
throw;によるスタックトレースの保持は、いずれも実務で頻出する落とし穴です。 - ログの設計は後から直すコストが高いため、プロジェクトの初期段階でルールを決めておくと運用が楽になります。
おわりに
この記事がロギング設計の見直しに役立てば嬉しいです。
よければストック・フォローお願いします!