可観測性(Observability)を一から学ぶシリーズ、ついに最終回です。
- ① メトリクスと外形監視
- ② 構造化ログ
- (補足)yabeda × Prometheus × Grafana:データと認証の流れ
- ③ トレース(OpenTelemetry / Tempo)← この記事
第1回はメトリクスで「異常に気づく」、第2回はログで「何が起きたかを掘る」を学びました。
今回は最後の柱、トレースで「処理の流れを追う」を学びます。図解とたとえ話多めでいきます。
この記事は「トレースを初めて学ぶ人」向けです。前2回を読んでいなくても読めるよう要点は復習しますが、メトリクス・ログの全体像は①②を先に読むとより腑に落ちます。
0. 3本柱の役割分担(復習)
可観測性の「3本柱」は、同じ1リクエストを違う角度で記録します。
┌──────────┬──────────────────────┬────────────────────┐
│ 📊メトリクス │ 数値の折れ線。"異常に気づく"│ Prometheus / Grafana│
│ 📜ログ │ 1件1件の出来事。"なぜ?を掘る"│ Loki / Grafana │
│ 🧵トレース │ 処理の流れ全体。"どこが遅い?"│ OTel / Tempo │
└──────────┴──────────────────────┴────────────────────┘
気づく(📊) → 流れを追う(🧵) → なぜを掘る(📜)
3つを組み合わせて「未知の障害」にも対応できる状態をつくる
この記事の主役は3つ目、🧵トレースです。
1. トレースは「何の問題」を解くのか
ログでは見えにくいもの:「時間がどこに消えたか」
第2回で、ログに request_id という共通IDを振って「1リクエストの出来事」を束ねました。
でも、こんな問いには答えにくいのです。
{request_id:"abc", event:"graphql.operation"}
{request_id:"abc", event:"external.call", dependency:"unleash"}
{request_id:"abc", event:"external.call", dependency:"payment", duration_ms:3200}
{request_id:"abc", event:"order.confirmed"}
↑ "出来事" は分かる。でも…
・どれがどれの "中で" 起きた?(入れ子の関係)
・全体500ms中、どの処理が何msを "占めた"?(時間の内訳)
・並行して動いた? それとも順番待ち?
を、何十行ものログから頭で再構成するのはツライ
トレース = 1リクエストを「滝グラフ(ウォーターフォール)」で見せる
トレースは、1リクエストの内部を時間軸で見える化します。
1リクエスト(500ms)の中身を、時間軸で可視化:
GraphQL: confirmCart ├████████████████████████████┤ 500ms
├ checkFlag(unleash) ├██┤ 30ms
├ payment.charge .....├████████████████┤ 320ms ← 犯人!
└ db.save_order ├███┤ 60ms
└────────── 時間 → ──────────┘
一目で「payment.charge が 320ms で全体の大半を食ってる」と分かる
メトリクス・ログとの分担はこうです。
📊メトリクス … 全体で「遅い」に気づく
📜ログ … 「あのユーザーのこの呼び出し」を特定する
🧵トレース … その1回の処理の "内訳・流れ" を滝で見る
典型ユースケース:N+1 問題
トレースが最も輝く例が N+1 問題です。
「一覧を出すために、1件ごとに追加クエリを投げてしまい、DBアクセスが激増する」やつです。
滝グラフで見ると…
listProducts ├████████████████████████┤ 900ms
├ db.query(products) ├█┤
├ db.query(review #1) ├█┤
├ db.query(review #2) ├█┤
├ db.query(review #3) ├█┤
├ ... (小さなDB Spanが101本ズラーッと連続) ...
└ db.query(review #100) ├█┤
→ 「DBに101回問い合わせてる!」が "目で" 一発で分かる
2. 用語:Span と Trace
トレースの世界の2大用語を押さえます。
Span(スパン)= 処理1区間。開始時刻と終了時刻を持つ「滝の1本のバー」
例: payment.charge という1区間(320ms)
Trace(トレース)= そのリクエストの Span を全部集めた "滝グラフ全体"
= Span の集合
親子関係: confirmCart(親) の中で payment.charge(子) が走る
→ 入れ子で描かれる(ツリー構造)
たとえ話:駅伝のラップタイム表。区間(Span)ごとに「誰が何分」が並び、全体(Trace)のどこで遅れたか一目で分かる、あの感じです。
Span が持っているデータは、こんな感じです(あとで「ログとの違い」で効いてきます)。
┌─ 1つの Span が持つ実データ ───────────────┐
│ span名 : "payment.charge" │
│ 開始時刻 : 10:00:00.100 │
│ 終了時刻 : 10:00:00.420 │ ← この2つから
│ duration : 320ms ←──────────────────────┤ 所要時間が決まる
│ parent_span : "graphql.confirmCart" │ ← 親子関係(滝の入れ子)
│ trace_id : "T-999" │ ← トレース全体の縦串
│ 属性(attrs) : http.status=200 など │
└────────────────────────────────────────────┘
3. OpenTelemetry:トレースの作り方
OpenTelemetry(OTel)= テレメトリの「共通規格」
昔: トレースのライブラリはベンダーごとにバラバラ(A社用, B社用…)
→ 乗り換え困難(ベンダーロックイン)、学び直しのコスト
OTel: "計装の仕方" を業界標準として統一したオープン規格
→ 一度 OTel で計装すれば、送り先(Tempo / 各種SaaS…)を
差し替え自由
読みは「オープンテレメトリー」。トレース・メトリクス・ログを扱える標準ですが、トレースの計装が最も成熟しています。
魔法の核心:自動計装(auto-instrumentation)
OTel の一番ありがたい機能が自動計装です。Ruby(Rails)ならこう。
# Gemfile
gem "opentelemetry-sdk" # 計装の本体
gem "opentelemetry-exporter-otlp" # 送信係(OTLPで送る)
gem "opentelemetry-instrumentation-all" # ← これが魔法
# 初期化(起動時に一度だけ)
require "opentelemetry/sdk"
require "opentelemetry/instrumentation/all"
OpenTelemetry::SDK.configure do |c|
c.service_name = "my-app"
c.use_all # ← よく使うライブラリを丸ごと自動計装する
end
use_all を呼ぶと、自分で計装コードを書かなくても、以下が勝手に Span 化されます。
┌────────────────────────────────────────────────┐
│ Rack … HTTPリクエスト受信 → 親Span │
│ ActionController … コントローラ処理 │
│ ActiveRecord … DBクエリ → 子Span(N+1もここで露見)│
│ Net::HTTP … 外部API呼び出し → 子Span │
│ Redis … Redisアクセス → 子Span │
│ GraphQL … GraphQL operation │
│ Sidekiq … バックグラウンドジョブ │
└────────────────────────────────────────────────┘
第1回の「メトリクスは yabeda が定番計器を自動で揃えてくれた」のと同じ発想です。
よく使うライブラリの計装は "既製品" で付いてくる。だから「DBクエリが101本のSpanで並ぶ」が、手作業なしで実現できます。
トレースの旅(3本柱で形がそろう)
第1回・第2回と並べると、トレースの旅は同じ形をしています。
📊メトリクス: yabeda → /metrics → Prometheus(pull) → Grafana
📜ログ: logger → stdout → fluentd/Promtail → Loki → Grafana
🧵トレース: OTel SDK → OTLP → otel-collector → Tempo → Grafana
▲ ▲ ▲
集約・転送ハブ トレースDB 表示
用語を整理します。
OTLP … OTel の標準プロトコル(テレメトリ送信の共通規格)
OTel Collector … 各アプリの Span を受けて整形し、Tempo へ流す中継ハブ
Tempo … トレース専用DB(ログのLoki・数値のPrometheusに相当)
アプリは「送る側」を実装するだけ。Collector や Tempo は基盤側に用意されている、という構図はメトリクス・ログと全く同じです。
4. trace_id と「伝播(propagation)」:分散トレースの心臓
trace_id = Span版の「縦串」
第2回でログに request_id を振って束ねたのと同じ発想です。
📜ログの縦串 = request_id(全ログ行に同じID)
🧵トレースの縦串 = trace_id(1リクエストの全Spanに同じID)
trace_id="T-999" の Span たち:
{trace_id:T-999, span:"graphql.confirmCart", parent:none} ← 親
{trace_id:T-999, span:"db.query", parent:"graphql.."}← 子
{trace_id:T-999, span:"payment.charge", parent:"graphql.."}← 子
↑ 同じ trace_id + 親子関係 → Tempo が滝グラフに組み立てる
問題:処理が「別サービス」に飛ぶと縦串が切れる
アプリの中だけなら自動で Span は繋がります。でも別サービスを呼ぶと…
my-app ──HTTP──▶ payment-service(別サービス・別プロセス)
↑ ここで「これは T-999 の続きだよ」が伝わらないと
payment側は "別の新しいトレース" を始めてしまう
→ 滝が my-app で途切れる
解決:trace_id をリクエストのヘッダに乗せて運ぶ = 伝播
my-app ──HTTP GET /charge ───────────────▶ payment-service
┌──────────────────────────────┐
│ HTTPヘッダに忍ばせる: │
│ traceparent: 00-T999-spanX-01 │ ← W3C TraceContext という標準形式
└──────────────────────────────┘
▼ payment側がこれを読む
「お、T-999 の続きね。自分のSpanも T-999 の子にしよう」
▼
結果: my-app の Span と payment の Span が "同じ滝" に繋がる
= これが「分散トレース(distributed tracing)」
┌────────────────────────────────────────────────┐
│ Propagation(伝播) = trace情報を │
│ サービスの境界(ネットワーク)を越えて運ぶ仕組み │
│ W3C TraceContext = その "運び方" の世界標準 │
│ → 言語やベンダーが違っても繋がる(OTelの恩恵) │
└────────────────────────────────────────────────┘
たとえ話:宅配の「送り状(伝票番号)」。荷物が別の配送業者に引き継がれても、同じ伝票番号を貼っておけば全行程を1本で追跡できます。trace_id はその伝票番号です。
ありがたいことに、Net::HTTP などの自動計装には「発信時に traceparent ヘッダを自動で付ける」機能が含まれます。だから自分でヘッダを書かなくても trace_id が次のサービスへ運ばれます。
5. よくある誤解:「トレースはログから作ってるんでしょ?」
ここは設計思想のキモなので、丁寧に。
❌ 誤解: trace は "ログから ID をもとに集計して" 作る。実データは持たない
✅ 正解: trace は "独立した実データ"。ログとは別の経路で別に送られ、
Tempo に実体が保存される
アプリは「2つの別々のもの」を独立に送っている
1リクエストにつき、アプリは2本の独立した送信をします。
┌─ アプリ(1リクエスト処理中)────────────────────┐
│ │
│ ①ログを出す ──▶ stdout ──▶ fluentd ──▶ Loki 📜 │
│ {event:"order.failed", trace_id:"T-999"} │
│ │
│ ②Spanを送る ──▶ OTLP ──▶ Collector ──▶ Tempo 🧵 │
│ {span:"payment.charge", start:.., end:.., │
│ duration:320ms, parent:.., trace_id:"T-999"} │
│ │
└──────────────────────────────────────────────────┘
↑ ①と②は別の配線・別のDB。お互いを参照しない
trace_id="T-999" が両方に入ってるから "後で紐づけられる" だけ
証拠は単純で、片方を切ってももう片方は生きること。ログを全部 OFF にしてもトレースの滝は出るし、逆も同じ。互いに依存していません。
「ログからトレースを作らない」3つの理由
「ログにちゃんとIDが付くなら、ログからトレースを組み立てればよくない?」——鋭い疑問ですが、それが割に合わない理由があります。
理由①:滝を作るには全操作の "開始&終了" をログる必要 → ログが激増
滝グラフは「各区間の開始時刻と終了時刻」が無いと描けない。
ログから作るなら、こうログる必要がある:
{ts:100.000, event:"payment.START"} ← 開始も
{ts:100.320, event:"payment.END"} ← 終了も
{ts:100.010, event:"db.START"} ← 全操作ぶん
{ts:100.030, event:"db.END"} ← ×101回のDBなら202行!
一方 Span は「開始/終了/親」を1個のコンパクトな構造で持つ:
{span:"payment", start:100.000, end:100.320, parent:..} ← 1個で完結
→ "ログで代用" する方が重い。専用の Span の方が安い
理由②:トレースは "木(ツリー)"。ログDBは木を組むのが苦手
トレース = 親子の入れ子 = 木構造
confirmCart ├ db
└ payment ├ (さらに子)…
Loki = テキストを "ラベルで検索" するのが得意。
散らばった行を集めて親子に組み立て直すのは苦手・遅い
Tempo = 最初から "trace_id で木を丸ごと保存・取り出す" 専用設計
→ 木は木の専用DB(Tempo)に入れる方が、保存も取り出しも速い・安い
理由③:ログは "取りこぼす" 前提。木が壊れる
ログは現場では、ノイズ除外・サンプリング・rate制限で間引かれる。
1行でも欠けると → 木の枝が切れて滝が崩壊する。
Span は処理の実行中(in-process)に親子関係をその場で確定させるので、
取りこぼしにくく、構造が壊れにくい。
本当のポイント:方向が「逆」
❌ ログ(粗いテキスト) から トレース(精密な構造) を作る
= "粗い素材から精密品を組む" → 無理・高コスト
✅ むしろ Span(精密な構造) が "一番リッチな素材"。
必要なら Span からメトリクスやログを派生させる方が自然
→ だから別々に出し、trace_id で "紐づける" のが最適解
(作り直す(derive)のではなく、結びつける(correlate))
たとえ話:「ビデオ映像(トレース)を撮影メモ(ログ)から復元する」感じ。メモがどれだけ詳しくても映像は作れないし、作れても粗くて高コスト。映像は最初から映像として撮り(Span)、メモとはシーン番号(trace_id)で紐づけるのが正解です。
6. 観測はタダじゃない:コストとサンプリング
「ログとトレースを別々に送るなら、データ量が2倍になるのでは?」——大事な問題意識です。可観測性には**コスト(observability tax)**があります。
3本柱はコストが全然違う
┌──────────┬──────────────────┬──────────────────────────┐
│ 📊メトリクス │ 激安 │ ただの数字。集計済みで桁違いに小さい│
│ 📜ログ │ 中〜高 │ 1行1行のテキスト。量が膨らみやすい │
│ 🧵トレース │ 制御次第 │ Span は構造化データ。"全部は残さない"│
└──────────┴──────────────────┴──────────────────────────┘
量のイメージ: メトリクス ≪ トレース・ログ
トレース量を抑える最大の武器:サンプリング
全リクエストのトレースを "全部" 保存する必要はない:
┌─ サンプリング(間引き)─────────────────────────┐
│ 正常で速いリクエスト → 1%だけ残して99%捨てる │
│ エラー / 異常に遅いリクエスト → 100%残す(これが見たい!)│
└────────────────────────────────────────────────┘
→ "つまらない成功" は間引き、"事件(遅い/エラー)" だけ確実に残す
→ 量を 1/100 にしつつ、欲しい情報は逃さない
「全部捨てる」でも「全部残す」でもなく、何を・どれだけ・いつまで残すか(retention)を設計するのがSREの腕の見せ所。観測は「入れて終わり」ではなく「コストと価値のバランスを調整し続けるもの」です。
7. 3本柱の融合:trace_id で全部が縫い合わさる
最後に、トレースが他の2本柱と「1つの探索体験」になる話です。
ログに trace_id を載せる
構造化ログに trace_id フィールドを足す:
{request_id:"abc", trace_id:"T-999", event:"order.failed", level:"error"}
▲ これを足すだけで…
┌─ 融合が起きる ───────────────────────────────────┐
│ Loki でエラーログ発見 → その trace_id="T-999" を │
│ クリック → Tempo の "その1リクエストの滝グラフ" にジャンプ│
│ → 「このエラーログの裏で payment.charge が3.2秒だった」 │
│ が画面遷移の手間なく分かる │
│ │
│ 逆も可: 遅い滝(trace) → その trace_id でログを引く → │
│ 「その時なにが起きていたか」の文脈が読める │
└─────────────────────────────────────────────────────┘
Prometheus / Loki / Tempo は「別々のDB」
ここでよくある混同を解いておきます。監視のDBは1個ではありません。種類ごとに3個あって、Grafana が束ねています。
┌──────────────── Grafana 🖥️(唯一の "見る窓")────────────┐
│ PromQL LogQL TraceQL │
└────┬───────────────┬────────────────┬────────────────────┘
▼ ▼ ▼
┌──────────┐ ┌──────────┐ ┌──────────┐
│Prometheus │ │ Loki │ │ Tempo │
│📊数値DB │ │📜ログDB │ │🧵トレースDB │
└──────────┘ └──────────┘ └──────────┘
同じ1リクエストが、3つの別の姿で別の場所に保存されます。
┌────────────┬──────────────────┬────────────┐
│ Prometheus │ 数値(集計・軽い) │ 「何件・何%」 │
│ Loki │ ログ(文章) │ 「何が起きた」 │
│ Tempo │ トレース(時間構造)│ 「どこが遅い」 │
└────────────┴──────────────────┴────────────┘
別物だからこそ役割分担できる。共通の trace_id / 時刻 で横断する
たとえ話(健康診断):体重計(📊数値)・問診票(📜文章)・レントゲン(🧵構造)。全部あなたの情報だけど、測り方も保存先も別。医者(Grafana)が3つを並べて総合判断します。
到達点
┌────────────────────────────────────────────────┐
│ 📊 ─時刻/trace_id─▶ 🧵 ─trace_id─▶ 📜 │
│ 気づく 流れを見る なぜ │
│ │
│ 3本の柱が trace_id という "共通の糸" で縫い合わされ、│
│ 「未知の障害」も探索的に追える │
└────────────────────────────────────────────────┘
「500エラーが出た」という1本の問い合わせに対して、
- 📊 メトリクスで「いつ・どれくらい増えたか」
- 🧵 トレースで「そのリクエストのどこで失敗したか」
- 📜 ログで「なぜ失敗したか(Timeout? どの依存先?)」
を、行き来しながら詰めていける。これが可観測性の到達点です。
まとめ
┌──────────────────────────────────────────────────┐
│ 🧵 トレース チートシート │
├──────────────────────────────────────────────────┤
│ Span … 処理1区間(開始/終了時刻を持つ滝の1本のバー) │
│ Trace… Span の集合(= 1リクエストの滝グラフ全体) │
│ 用途 … N+1 / ボトルネック特定 / 原因の切り分け │
│ OTel … テレメトリの共通規格(ベンダーロックイン回避) │
│ 自動計装 use_all → Rack/AR/Net::HTTP/Redis/GraphQL等 │
│ が勝手に Span 化 │
│ 旅 … OTel SDK → OTLP → Collector → Tempo → Grafana│
│ trace_id … Span版の縦串 / 伝播(W3C)でサービス越境 │
│ = 分散トレース │
│ 誤解 … ログから作らない。別データを trace_id で結ぶ │
│ コスト … サンプリングで "事件" だけ残す │
│ 融合 … ログに trace_id → ログ↔トレース↔メトリクス │
└──────────────────────────────────────────────────┘
3回(+補足1本)にわたって、可観測性の3本柱と外形監視を「一から」たどってきました。
- 第1回:📊 メトリクスと 🛰️ 外形監視(Prometheus / Grafana / Blackbox)
- 第2回:📜 構造化ログ(JSON / Loki / request_id / マスキング)
- 第3回:🧵 トレース(OpenTelemetry / Tempo / 分散トレース)
最初は「障害が起きたら再起動して祈る」しかできなかった状態から、
数値で気づき、トレースで流れを追い、ログで理由を読む——そんな「窓のあるシステム」をつくる地図が、これで一通りそろいました。
オブザーバビリティが高いシステムにおいて、最高のデバッガーは組織の中で最も好奇心の強いエンジニアです。
ここまで読んでくださってありがとうございました。あなたのシステムにも、ぜひ窓を開けてみてください 🪟