필사 모드: ログとスタックトレースを探偵のように読む

• はじめに — ログは事件現場だ
• スタックトレースを読む — 一方は現場、もう一方は発端
• 「Caused by」の連鎖 — 本当の根本原因
• 構造化ロギング — 文章ではなくデータで
• 相関IDとtrace_id — 一つのリクエストを貫く
• grep、jq、ripgrep — ログを掘る道具
• ログレベル — 騒音を制御するダイヤル
• サンプリング — 全部は残せないとき
• まとめ — 午前3時の障害を追跡する
• おわりに
• 参考資料

はじめに — ログは事件現場だ

午前3時、ページャーが鳴ります。本番が落ちました。あなたの手にあるのは、再現できない障害と、数十万行のログ、そして一つの赤いスタックトレースだけです。良い知らせは、これらが実は証拠だということです。スタックトレースは事件現場の写真であり、ログは目撃者たちの証言書です。探偵の仕事は、この証拠を読んで犯人を指し示すことです。

問題は、多くの開発者がこの証拠をうまく読めないことです。スタックトレースを見ると目が泳ぎ、上の数行だけ見て推測に飛び、ログは多すぎて諦めて適当にgrepします。しかし証拠を読むには方法があります。この記事は、スタックトレースとログを探偵のように——体系的に、証拠に基づいて——読む技術をまとめます。

スタックトレースを読む — 一方は現場、もう一方は発端

スタックトレースに初めて出会うと圧倒されます。しかし構造を知れば情報の宝庫です。核心のルールを一つだけ覚えてください。一方の端が壊れた場所、もう一方の端がその始まった場所です。

Pythonのスタックトレースを例に見ましょう。

Traceback (most recent call last):
  File "app.py", line 42, in <module>
    result = process_order(order_id)
  File "services/order.py", line 18, in process_order
    total = calculate_total(items)
  File "services/pricing.py", line 7, in calculate_total
    return sum(item.price for item in items)
  File "services/pricing.py", line 7, in <genexpr>
    return sum(item.price for item in items)
AttributeError: 'NoneType' object has no attribute 'price'

読む順序と、抜き出す情報：

1. 一番下の例外行から読む。 AttributeError: 'NoneType' object has no attribute 'price'。何が起きたかの要約です。Noneである何かから.priceを取り出そうとした、ということ。
2. すぐ上のフレームが壊れた地点。 pricing.pyの7行目、item.price。ここでitemがNoneでした。これが事件現場です。
3. 上へ遡って呼び出しの連鎖を見る。 app.py(42) → process_order(18) → calculate_total(7)。リクエストがどの経路でここまで来たか、つまり発端を示します。

ここで重要な判断が一つあります。どのフレームが「自分のコード」か。 スタックトレースにはフレームワークやライブラリ内部のフレームが山ほど混ざっていることがよくあります。例外はライブラリの奥深くで壊れましたが、本当の原因は、ライブラリに変な値を渡した自分のコードにある場合がほとんどです。だからスタックを見て「自分のプロジェクトのパスが最後に登場するフレーム」を探してください。十中八九、そこが調査を始める地点です。

言語によって方向が紛らわしいことがあります。Pythonは「most recent call last」なので一番下が壊れた場所ですが、JavaScriptやJavaはたいてい一番上が壊れた場所で、下に行くほど発端です。ルール自体（「一方の端が現場、反対の端が発端」）は同じなので、その言語がどちらの向きかを確認するだけです。

「Caused by」の連鎖 — 本当の根本原因

Java系で特によく出会う、そして必ず知っておくべきパターンが**「Caused by」の連鎖**です。一つのエラーが別のエラーを包み、層状に積み重なった形です。

Exception in thread "main" com.example.OrderProcessingException: Failed to process order 4821
    at com.example.OrderService.process(OrderService.java:52)
    at com.example.Main.main(Main.java:14)
Caused by: java.sql.SQLException: Connection timed out
    at com.example.db.Pool.getConnection(Pool.java:88)
    at com.example.OrderService.process(OrderService.java:48)
    ... 1 more
Caused by: java.net.SocketTimeoutException: connect timed out
    at java.base/java.net.Socket.connect(Socket.java:507)
    at com.example.db.Pool.getConnection(Pool.java:85)
    ... 2 more

ここで初心者がよくやる間違いは、一番上の例外だけ見て判断することです。OrderProcessingException: Failed to process order 4821は、実は一番外側の包み紙にすぎません。「注文処理に失敗した」は症状であって原因ではありません。

本当の原因は、**連鎖を最後まで追い下りた一番下の「Caused by」**にあります。上の例では：

• 最上位：注文処理失敗（症状）
• Caused by：SQL例外、コネクションタイムアウト（中間の原因）
• Caused by：ソケット接続タイムアウト（根本原因 — DBにネットワークで繋がらなかった）

だから「Caused by」が見えたら最後までスクロールしてください。一番下の根本例外が、実際に直すべき対象です。上の例外たちは、それが各層を通る際に包み直されただけです。この連鎖を「これのせいで → これのせいで → 結局これのせいで」と読むのが、探偵の因果追跡です。

構造化ロギング — 文章ではなくデータで

スタックトレースが「壊れた瞬間」のスナップショットなら、ログは「時間にわたる事象」の記録です。ところがログをどう残すかが、後の調査可能性を完全に分けます。核心は、ログを人が読む文章ではなく、機械がパースする構造化データとして残すことです。

伝統的なログはこんな形です。

2026-06-28 03:14:22 ERROR Failed to process order 4821 for user 91 after 3 retries

人の目には読めますが、これをプログラムで扱うには正規表現でパースする必要があり、フィールドが一つ増えるとパーサーが壊れます。一方、**構造化ロギング（JSON）**はこうです。

{
  "timestamp": "2026-06-28T03:14:22.481Z",
  "level": "ERROR",
  "service": "order-service",
  "message": "failed to process order",
  "order_id": 4821,
  "user_id": 91,
  "retries": 3,
  "duration_ms": 2140,
  "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736"
}

構造化ログの利点は圧倒的です。

• 検索・フィルタ：「order_idが4821のログ」や「duration_msが2000を超えるログ」を正確に問い合わせられる。文字列マッチではなくフィールドクエリだ。
• 集計：「サービス別のエラー数」「retriesの平均」といった統計をログから直接引き出す。
• パースの安定性：フィールドが追加されても既存のパイプラインが壊れない。
• 相関：trace_idのようなフィールドを仕込めば、後で見るように複数サービスのログを一つのリクエストに束ねられる。

原則：ログに入れたい値は文字列に押し込まず、別フィールドとして残せ。 "order 4821 failed"ではなく、messageは"order failed"にしてorder_id: 4821をフィールドとして付けるのです。後で調査するとき、この違いが生死を分けます。

相関IDとtrace_id — 一つのリクエストを貫く

マイクロサービス環境では、一つのユーザーリクエストが複数のサービスを経由します。APIゲートウェイ → 注文サービス → 決済サービス → 通知サービス……。各サービスが自分のログを別々に残すと、問題が起きたとき「このリクエストが残したログ」をどう全部集めるのでしょうか。答えが相関ID（correlation ID）、その標準化された形がtrace_idです。

原理は単純です。リクエストがシステムに最初に入るとき一意のIDを一つ発行し、そのリクエストが経由するすべてのサービスが自分のログにそのIDを一緒に残します。 サービス間の呼び出し時にはHTTPヘッダなどに載せてIDを伝播します。すると後で、そのID一つでフィルタするだけで、複数サービスに散らばったログが一つのリクエストのタイムラインとして再構成されます。

{ "service": "gateway", "trace_id": "abc123", "message": "request received", "path": "/checkout" }
{ "service": "order-service", "trace_id": "abc123", "message": "order created", "order_id": 4821 }
{ "service": "payment-service", "trace_id": "abc123", "message": "charge failed", "reason": "card_declined" }
{ "service": "gateway", "trace_id": "abc123", "message": "responded 402", "duration_ms": 890 }

trace_idがabc123のものだけフィルタすれば、ゲートウェイから入って注文が作られ、決済が拒否されて402で応答した全過程が一目で見えます。相関IDがなければ、この4行は数十万行の中に散らばり、互いに繋がらないまま埋もれます。

実務のヒント：相関IDはリクエストの最前線（ゲートウェイやミドルウェア）で一度発行し、以降すべてのログに自動で注入されるようにしてください。ログごとに手で入れるのではなく、ロガーのコンテキストに一度仕込めば、そのリクエスト処理中のすべてのログに自動で付きます。そしてこのIDをユーザーに見せるエラー画面にも露出すれば（「お問い合わせの際はこのコードをお伝えください：abc123」）、ユーザーの問い合わせをログと即座に繋げられます。

grep、jq、ripgrep — ログを掘る道具

ログを全部集めても、その中から欲しいものを取り出せなければ意味がありません。コマンドラインには、この仕事のための強力な道具があります。

grep / ripgrep（rg）：テキストログからパターンを探す基本技です。ripgrepはgrepより速く、デフォルトが便利です。

# 特定のtrace_idのすべてのログ
rg "abc123" app.log

# ERRORレベルだけ
rg '"level":"ERROR"' app.log

# マッチした行の前後3行まで一緒に見る（文脈の確保）
rg -C 3 "card_declined" app.log

# 複数条件：決済サービスのエラー
rg '"service":"payment-service"' app.log | rg '"level":"ERROR"'

ここで-C（context）オプションが探偵に特に重要です。エラー一行だけを見るのと、その直前に何があったかを前後数行と一緒に見るのは、天と地の差です。事件はたいてい、その直前の事件が原因なのですから。

jq：JSONログを扱う専用のナイフです。構造化ロギングを使っているなら、jqはgrepよりはるかに精密です。

# ERRORレベルのログのorder_idだけ抜き出す
jq 'select(.level == "ERROR") | .order_id' app.log

# duration_msが2000を超える遅いリクエスト
jq 'select(.duration_ms > 2000)' app.log

# 特定のtrace_idのログを、serviceとmessageだけ
jq 'select(.trace_id == "abc123") | {service, message}' app.log

# エラーを理由別に数える
jq -r 'select(.level=="ERROR") | .reason' app.log | sort | uniq -c | sort -rn

これが構造化ロギングの報酬です。duration_ms > 2000のような数値比較やフィールド単位の集計は、文字列grepでは事実上不可能ですが、JSONならjq一行です。

HTTPを扱うサービスなら、ログに状態コードが頻繁に登場します。402が何だったか、499と500がどう違うか紛らわしいときは、HTTPステータスコードのリファレンスで各コードの意味を素早く確認し、ログの中の状態コードが「クライアントのせいかサーバーのせいか」からきちんと切り分けてください。

ログレベル — 騒音を制御するダイヤル

ログをむやみに全部残すと、いざ必要なときに信号が騒音に埋もれます。だからログレベルがあります。各ログに深刻度を付け、状況に応じてどのレベル以上を見るかを調整するのです。標準的な階層はこうです。

• DEBUG：開発・デバッグ用の詳細情報。「この変数の値がこれだ」レベル。本番では通常オフにする。
• INFO：正常な主要事象。「注文4821作成」「サーバー起動」。システムが何をしているかの記録。
• WARN：今すぐ問題ではないが怪しいもの。「3回リトライ後に成功」「設定値がなくデフォルト使用」。潜在的問題の早期警報。
• ERROR：何かが失敗し対処が必要なもの。「決済処理失敗」「DB接続断」。

レベルをうまく使うのは礼儀であり実力です。よくあるアンチパターンを二つ：

• すべてをERRORで出す：些細なものまでERRORなら、本物のERRORが埋もれます。「狼だ」を乱発すると、いざ狼が来たとき誰も見ません。
• 何も出さない：正常経路にINFO一つなければ、問題が起きたとき「ここまでは来たのか？」を知る術がありません。

調査するときはレベルをフィルタとして使います。まずERRORだけ見て大きな事件を掴み、特定の時点が怪しければその近くのINFO・DEBUGへ下りて文脈を埋めます。広く（ERROR）→ 狭く（その時点の全レベル）へ絞るのがコツです。

サンプリング — 全部は残せないとき

トラフィックが大きいサービスでは、すべてのログを100%残すのは不可能か不経済です。毎秒数万リクエストがそれぞれ複数行のログを残せば、保存コストと処理負荷が耐えられません。だからサンプリングをします。一部だけ代表として残すのです。

核心原則は、正常はサンプリングしつつ、問題は全量残すことです。

• 成功した正常なリクエスト：全部残す必要はありません。たとえば1%だけサンプリングしても、全体の傾向を把握するには十分です。
• エラー・遅いリクエスト：100%残します。まさに調査が必要なのはこれらで、これは相対的に稀なので全量残しても量は耐えられます。

こうすれば保存量は劇的に減りつつ、実際に掘る事件（エラー・異常）は一つも取りこぼしません。前の記事（オブザーバビリティ）で扱ったトレースのテールサンプリングが、まさにこの哲学のトレース版です。「終わってみてエラーか遅ければ必ず残す」というルールですね。

注意すべき罠：サンプリングをかけるときは、同じリクエストのログが一緒に残るか一緒に捨てられるようにtrace_id単位で決めなければなりません。リクエスト一つで、あるログは残りあるログは捨てられると、後でそのtrace_idで調査するときタイムラインに穴が空きます。「このtraceはサンプリング対象」ならそのtraceのすべてのログを残す、というように、リクエスト全体を原子的に扱ってください。

まとめ — 午前3時の障害を追跡する

ここまでの道具を一つの捜査に編んでみましょう。ページャーが鳴りました。「決済成功率が急落」。

1. スタックトレースの確保：エラーレポーティングツールで代表的なスタックトレースを開く。一番下の「Caused by」を最後まで追うとSocketTimeoutException。DBか外部APIにネットワークで繋がっていない。
2. どちら側？：スタックの「自分のコード」フレームを見ると決済ゲートウェイのクライアント。うちのDBではなく外部カード会社のAPIに繋がらないと絞られる。
3. ログで裏取り：失敗したリクエスト一つのtrace_idを掴み、jqでそのリクエストの全タイムラインを引き出す。payment-serviceでカード会社の呼び出しがちょうどタイムアウト値で死んでいる。
4. 範囲の把握：エラーを理由別に集計（jq ... | sort | uniq -c）。すべて同じカード会社エンドポイントのタイムアウト。うちのバグではなくカード会社の障害の可能性が高い。
5. 文脈の確保：rg -C 5で最初のタイムアウト直前のログを見る。特定の時刻から遅延が急増した。カード会社のステータスページを確認すると、ちょうどその時刻に障害告知。

スタックトレースが「何が（ネットワークタイムアウト）」を、trace_idベースのログが「どこで（カード会社API）」を、集計が「どれだけ（全量）」を、文脈が「いつから（その時刻）」を答えました。推測なしに、証拠だけで犯人がうちの外にいることを明らかにしました。

おわりに

ログとスタックトレースは、面倒な赤いテキストではなく、事件が残した証拠です。探偵の技術を再びまとめると：

• スタックトレースは一方の端が現場、反対の端が発端。「自分のコード」フレームを探せ。
• 「Caused by」は最後まで追え。根本原因は一番下にある。
• ログは文章ではなく**構造化データ（JSON）**で残せ。
• trace_idで散らばったログを一つのリクエストに貫け。
• grep/rg/jqで掘りつつ、文脈（-C）も一緒に見よ。
• ログレベルで騒音を制御し、サンプリングで正常は減らしつつ問題は全量残せ。

次にスタックトレースに出会ったら、目を閉じて推測しないでください。それは自白書です。最後まで読んでください。次にログの海に出会ったら、絶望しないでください。それは目撃者の証言です。trace_idで召喚してください。証拠はすでに全部あります。読むだけでいいのです。

参考資料

• 「Structured Logging」(honeycomb.io ブログ): https://www.honeycomb.io/blog/structured-logging-and-your-team
• jq マニュアル: https://jqlang.github.io/jq/manual/
• ripgrep ユーザーガイド: https://github.com/BurntSushi/ripgrep/blob/master/GUIDE.md
• W3C Trace Context (trace_id 伝播の標準): https://www.w3.org/TR/trace-context/
• Python 公式ドキュメント — トレースバックを読む: https://docs.python.org/3/tutorial/errors.html