0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

監視と可観測性を一から学ぶ③ トレース(OpenTelemetry / Tempo)【図解】

0
Posted at

可観測性(Observability)を一から学ぶシリーズ、ついに最終回です。

第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 / 分散トレース)

最初は「障害が起きたら再起動して祈る」しかできなかった状態から、
数値で気づき、トレースで流れを追い、ログで理由を読む——そんな「窓のあるシステム」をつくる地図が、これで一通りそろいました。

オブザーバビリティが高いシステムにおいて、最高のデバッガーは組織の中で最も好奇心の強いエンジニアです。

ここまで読んでくださってありがとうございました。あなたのシステムにも、ぜひ窓を開けてみてください 🪟

0
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?