第20章:観測の最低ライン(ログ+CorrelationId)🧾🔗
CorrelationId でログを束ねるイメージ 🔗🧵
この章のゴール 🎯✨
- Sagaが途中でコケても「どこで・なぜ・いま何が起きてるか」をログだけで追跡できるようになる🕵️♀️🔍
- そのために、**CorrelationId(相関ID)**を中心に「最低限のログ設計」を作れるようになる🔗🧩
- ついでに、後の章(メトリクス&トレース)につながる「TraceId」の位置づけも軽く理解する🧵📈
20-1. Sagaは“失敗が普通”だから、ログが命 🧯😵💫
Sagaは「複数ステップがまたがる」から、次のどれかがよく起きるよね👇
- ネットワークが不安定でリトライが入る🔁
- 外部APIが一瞬落ちる💥
- 片方だけ成功して“部分成功”になる🧩
- 失敗後に補償が走るけど、その補償も失敗することがある😇
このときに必要なのが 「追跡できるログ」 なんだ〜!🧾✨ ポイントは超シンプルで、最低ラインはこの2本柱👇
20-2. 最低ラインの2本柱(これだけは入れる!)🧱✨
✅ ① ログ(重要イベントが残る)
- 「Saga開始」「各ステップ成功/失敗」「補償開始/完了」「最終結果」など
- “後から見て復元できる”粒度で残す🧠📝
✅ ② CorrelationId(追跡の“ひも”)
- 1つのSaga(または1リクエスト)を 1本の糸でつなぐID🧵
- ログもメッセージも全部これで束ねる🔗📦
おまけで覚えると強い:TraceId .NETはW3C TraceContext(trace-id / span-id)を標準サポートしてて、HTTP越しに自動で流れる仕組みがあるよ(.NET 5+で既定がW3C)。(Microsoft Learn)
20-3. CorrelationIdの設計ルール(迷わない版)🔗🧠
まずはコレだけでOK 🙆♀️
-
CorrelationId = “SagaインスタンスID”(GUIDが無難)
- 例:
c1d2...(32桁)みたいなやつ
- 例:
できれば一緒に持ちたいID(強い順)🏋️♀️✨
- SagaId:SagaそのもののID(CorrelationIdと同一でもOK)
- MessageId:そのメッセージの一意ID(重複排除にも使う)
- CausationId:直前の原因メッセージID(因果チェーン追跡)
- StepName:いまのステップ名(
Pay,ReserveInventoryみたいな) - State:状態機械の状態(
Running,Compensatingなど)
まとめると、「束ねるID(CorrelationId)」+「追いかけるためのメタ情報」って感じ!🧷✨
20-4. “必ず残すログ”チェックリスト ✅🧾
ログに「何を書けばいいの?」問題、ここで固定しちゃおう💪😊
✅ 最低限のログ項目(まずはこれ)
- Timestamp(いつ)
- LogLevel(重要度:Info/Warn/Error…)(Microsoft Learn)
- Service/Component(どのサービス・どのクラス)
- CorrelationId(追跡の糸)
- SagaId(同一でもOK)
- StepName(どの工程)
- Event名(SagaStarted / StepFailed…)
- 理由(失敗時は特に:例外型、エラーコード、外部応答など)
✅ “Sagaで重要イベント”おすすめテンプレ(これだけは残す)🧾✨
- SagaStarted(開始)
- StepStarted(各ステップ開始)
- StepSucceeded(各ステップ成功)
- StepFailed(各ステップ失敗)
- CompensationStarted(補償開始)
- CompensationSucceeded / CompensationFailed(補償の結果)
- SagaCompleted / SagaAborted(最終結果)
20-5. .NETのログ基礎(初心者がハマりがちな所だけ)🧠🧾
ログは「カテゴリ」「レベル」「スコープ」📌
ILogger<T>は **カテゴリ(だいたいクラス名)**を持ってログを出すよ(Microsoft Learn)- ログレベルは Trace〜Critical まで段階があるよ(設定で出し分ける)(Microsoft Learn)
- Log Scope を使うと、CorrelationIdみたいな共通項目を“まとめて付与”できる!(Microsoft Learn)
スコープ(BeginScope)がSagaと相性抜群 🔗✨
「毎回 CorrelationId=... を書く」より、スコープで包んだ方がミスが減るよ😊
20-6. 実装:ログをJSONにして、CorrelationIdをスコープで付ける 💻🧾✨
ログをJSONにすると、あとで検索・集計がめっちゃ楽! .NETはコンソールログのJSONフォーマット(
AddJsonConsole)を公式に用意してるよ(Microsoft Learn)
① Program.cs(JSONログ+スコープ有効化)🧾
using System.Text.Json;
using Microsoft.Extensions.Logging;
var builder = WebApplication.CreateBuilder(args);
// ログをJSONで出す(IncludeScopes=true が超大事!)
builder.Logging.ClearProviders();
builder.Logging.AddJsonConsole(options =>
{
options.IncludeScopes = true; // スコープ出力ON
options.TimestampFormat = "yyyy-MM-ddTHH:mm:ss.fffZ ";
options.UseUtcTimestamp = true;
options.JsonWriterOptions = new JsonWriterOptions { Indented = false };
});
builder.Services.AddSingleton<OrderSagaOrchestrator>();
var app = builder.Build();
app.UseMiddleware<CorrelationIdMiddleware>();
app.MapPost("/orders/{orderId:guid}/checkout", async (Guid orderId, HttpContext ctx, OrderSagaOrchestrator saga) =>
{
var correlationId = (string?)ctx.Items[CorrelationIdMiddleware.ItemKey] ?? ctx.TraceIdentifier;
await saga.RunAsync(orderId, correlationId, ctx.RequestAborted);
return Results.Ok(new { orderId, correlationId });
});
app.Run();
AddJsonConsoleやIncludeScopesは公式のコンソールログフォーマッタ機能だよ(Microsoft Learn)- 「JSONログに、すでにJSON文字列を渡すと二重シリアライズで壊れることがある」って注意も公式にあるよ(ログ本文に“JSON文字列”を突っ込まない)(Microsoft Learn)
② CorrelationIdMiddleware(HTTPリクエストにCorrelationIdを付ける)🔗
using System.Diagnostics;
public sealed class CorrelationIdMiddleware
{
public const string HeaderName = "X-Correlation-Id";
public const string ItemKey = "CorrelationId";
private readonly RequestDelegate _next;
private readonly ILogger<CorrelationIdMiddleware> _logger;
public CorrelationIdMiddleware(RequestDelegate next, ILogger<CorrelationIdMiddleware> logger)
{
_next = next;
_logger = logger;
}
public async Task Invoke(HttpContext context)
{
var correlationId =
context.Request.Headers.TryGetValue(HeaderName, out var v) && !string.IsNullOrWhiteSpace(v)
? v.ToString()
: Guid.NewGuid().ToString("N");
context.Items[ItemKey] = correlationId;
context.Response.Headers[HeaderName] = correlationId;
// おまけ:TraceId(分散トレースの糸)も取れたら入れると強い🧵
var traceId = Activity.Current?.TraceId.ToString();
using (_logger.BeginScope(new Dictionary<string, object?>
{
["CorrelationId"] = correlationId,
["TraceId"] = traceId,
["Path"] = context.Request.Path.Value
}))
{
await _next(context);
}
}
}
.NETは W3C TraceContext の trace-id / span-id を標準で扱えて、HTTP越しのID伝播も “箱の中” が理解してくれる(HTTPなら特別なコードなしで自動で流れる)っていうのが強みだよ(Microsoft Learn) だから「最低ラインはCorrelationId」でも、TraceIdをログに載せておくと将来の拡張がラク💡😊
③ Sagaオーケストレーター(重要イベントだけを綺麗に出す)🧑✈️🧾
using Microsoft.Extensions.Logging;
public static class SagaEventIds
{
public static readonly EventId SagaStarted = new(2000, nameof(SagaStarted));
public static readonly EventId StepSucceeded = new(2001, nameof(StepSucceeded));
public static readonly EventId StepFailed = new(2002, nameof(StepFailed));
public static readonly EventId CompensationDone = new(2003, nameof(CompensationDone));
public static readonly EventId SagaCompleted = new(2004, nameof(SagaCompleted));
}
public sealed class OrderSagaOrchestrator
{
private readonly ILogger<OrderSagaOrchestrator> _logger;
public OrderSagaOrchestrator(ILogger<OrderSagaOrchestrator> logger)
=> _logger = logger;
public async Task RunAsync(Guid orderId, string correlationId, CancellationToken ct)
{
var sagaId = Guid.NewGuid().ToString("N");
using var scope = _logger.BeginScope(new Dictionary<string, object?>
{
["CorrelationId"] = correlationId,
["SagaId"] = sagaId,
["OrderId"] = orderId
});
_logger.LogInformation(SagaEventIds.SagaStarted, "Saga started");
try
{
await StepAsync("Pay", ct);
_logger.LogInformation(SagaEventIds.StepSucceeded, "Step succeeded: {Step}", "Pay");
await StepAsync("ReserveInventory", ct);
_logger.LogInformation(SagaEventIds.StepSucceeded, "Step succeeded: {Step}", "ReserveInventory");
await StepAsync("CreateShipment", ct);
_logger.LogInformation(SagaEventIds.SagaCompleted, "Saga completed");
}
catch (Exception ex)
{
_logger.LogError(SagaEventIds.StepFailed, ex, "Saga failed. Start compensation.");
await CompensateAsync(ct);
_logger.LogWarning(SagaEventIds.CompensationDone, "Compensation done");
throw;
}
}
private static async Task StepAsync(string step, CancellationToken ct)
{
await Task.Delay(200, ct);
// デモ:わざと失敗させる
if (step == "ReserveInventory")
throw new TimeoutException("Inventory service timeout (demo)");
}
private static Task CompensateAsync(CancellationToken ct)
=> Task.Delay(200, ct);
}
- EventId を付けると、ログ基盤側でフィルタしやすくなるよ(公式ドキュメントにも例がある)(Microsoft Learn)
- LogScope を使うと、スコープ内のログに共通情報を載せられるよ(Microsoft Learn)
20-7. “ログで追跡”のやり方(運用の最短手順)🕵️♀️🔍
手順(これができれば最低ラインOK)✅
-
失敗報告を受ける(例:「注文が失敗した」)📩
-
そのときの CorrelationId を入手する
- APIのレスポンスに入れる(例:
X-Correlation-Id) - 画面やエラーメッセージにも表示してOK(漏らしていい情報だけね)🫣
- APIのレスポンスに入れる(例:
-
ログ検索:CorrelationIdで絞り込む🔎
- PowerShellなら
Select-Stringが楽✨ - 例:
Select-String -Path .\logs\app.log -Pattern "CorrelationId\":\"xxxx"
- PowerShellなら
-
同じCorrelationIdのログを時系列で読む🧾
-
「どのステップで」「何が起きて」「補償はどうなったか」を復元する🧠✨
20-8. よくある事故と対策(Sagaログ編)💥😇
❌ 事故1:CorrelationIdが途中で変わる
- 原因:ステップごとに新しくGUID作っちゃう😭
- 対策:入口で1回作って、以後ずっと引き回す🔗
❌ 事故2:ログが多すぎて読めない
-
原因:全部
Informationで垂れ流し🌊 -
対策:
- “重要イベント”は Info/Warn/Error に寄せる
- 細かいデバッグは Debug/Trace に落とす
- ログレベルは設定で制御できるよ(Microsoft Learn)
❌ 事故3:ログに個人情報・機密を出しちゃう
-
対策:カード番号、住所、トークン、パスワードは絶対NG🙅♀️
- 必要ならマスク(例:
****1234)🔒
- 必要ならマスク(例:
20-9. ミニ演習(この章のゴールに直結)📝✅
演習A:チェックリストを自分の案件に合わせて作る📋
次の欄を埋めてみよ〜😊
- 「重要イベントログ」:何を残す?(開始/成功/失敗/補償/完了…)
- 「必須項目」:CorrelationId / SagaId / StepName / ErrorCode…
- 「表示したい粒度」:1ステップ1行? 失敗だけ詳細? など
演習B:わざと失敗させて、ログで追跡する💥🔍
-
ReserveInventoryをわざと失敗させる(上のデモのままでOK) -
CorrelationIdで絞って、
- どの順番でログが出た?
- 補償ログは出た?
- “原因”が読み取れる? を確認✅😊
20-10. AI活用(Copilot / Codex に投げると強い指示)🤖✨
✅ ログ設計レビューを頼む(超おすすめ)🧠
- 「Sagaの重要イベント一覧を作って。ログに残すべきイベント名を提案して」
- 「このログ項目で運用追跡できる?不足してるキーある?」
- 「CorrelationId / SagaId / MessageId / CausationId の使い分けを、初心者向けに説明して」
✅ 文言を整える(ログは“読みやすさ”が正義)📣
- 「ログメッセージを短く統一して。英語なら過去形で統一して」
- 「StepNameの命名を揃えて(Pay / ReserveInventory / CreateShipment…)」
✅ ありがちなミス検出🧯
- 「CorrelationIdが途中で変わる可能性がある箇所を指摘して」
- 「例外ログに機密情報が含まれる可能性を洗い出して」
まとめ 🧾🔗✨
- Sagaの観測は、まず ログ+CorrelationId が最低ライン🧱
- LogScope(BeginScope)でCorrelationIdを自動付与すると、追跡が一気にラクになる🔗😆
- JSONログにしておくと検索・集計が超強い(
AddJsonConsoleなど公式サポートあり)(Microsoft Learn) - .NETはW3C TraceContextのTraceIdも扱えるので、ログにTraceIdを添えると将来の拡張がスムーズ(Microsoft Learn)