インフラ●●●●○

分散トレーシング

Distributed Tracing ・ ぶんさんとれーしんぐ

1つのリクエストが複数サービスを渡る経路を、トレースとしてつないで追う可観測性の手法。

✦ 30秒で試す — 航海10個のサービスを渡るリクエスト、遅いのはどこ?キューを通った通知サービスの記録は、どうなる?予想してみる

概要

分散トレーシング(distributed tracing)は、1つのリクエストが複数のサービスを渡り歩く経路を端から端まで1本の線としてつなぎ、どこで何秒かかったかを見えるようにする監視の手法です。ユーザーが「注文」ボタンを押した1回のリクエストが、内部では在庫サービス、決済サービス、通知サービスと次々に呼び出されているとします。このときリクエスト全体を「トレース(trace)」、各サービスの中の個々の処理区間を「スパン(span)」と呼び、スパンを親子関係でつなぎ合わせて一連の処理を組み立て直します。

これはマイクロサービスで作られたシステムの障害調査や性能分析に欠かせない道具です。処理が1つのプロセスに閉じていたモノリスなら、遅い箇所は1台の中を追えば分かりました。処理が何十ものサービスに散らばると、「全体で3秒かかったが、どのサービスのどの処理が遅いのか」が途端に見えなくなります。分散トレーシングは、この見えなくなった1本の流れをサービスをまたいで復元し、遅延やエラーの発生源を特定できるようにします。

なぜ生まれたか

システムがモノリスだった頃、1回のリクエストの処理はすべて1つのプロセスの中で完結していました。遅ければプロファイラ(関数ごとの所要時間を測る道具)をかけ、エラーが出れば1本のログを追えば原因にたどり着けます。処理はコールスタックという一続きの線でつながっていて、全体像は最初から手元にありました。

マイクロサービス化が進むと、この線が断ち切られます。1回のリクエストは複数のサービスへの独立したネットワーク呼び出しに分かれ、各サービスはそれぞれ別のプロセス・別のマシンで動き、自分に来た処理のログしか持ちません。ユーザーからは3秒遅いのに、各サービスのログを個別に見ると、どれも「自分は速い」と言います。どのサービスも部分しか知らないので、全体の因果関係が誰にも分からなくなります。

この「サービスをまたいで1リクエストを追えない」問題を解くために生まれたのが分散トレーシングです。Google が自社の大規模システム向けに作った Dapper の論文(2010年)が原型になり、その考え方が Twitter の Zipkin、Uber の Jaeger へと受け継がれました。各社がばらばらの形式でトレースを運んでいたため、2020年に W3C がサービス間で運ぶヘッダの形式(Trace Context)を標準にし、計装の部品は OpenTelemetry に一本化されていきます。

詳細

トレースIDを伝播させる

分散トレーシングの核心は驚くほど単純で、「リクエストの入口で一意なトレースIDを発行し、以降すべてのサービス呼び出しにそのIDを添えて運ぶ」ことに尽きます。入口の APIゲートウェイ(または最初のサービス)がトレースIDを作り、次のサービスを呼ぶときに HTTP ヘッダに埋めて渡します。受け取った側も同じIDを次へ渡します。こうして、リクエストが通ったすべてのサービスに同じトレースIDが行き渡ります。

各サービスは自分の処理区間を「スパン」として記録し、そこに「このトレースID」「自分のスパンID」「親スパンのID」「開始・終了の時刻」を刻んで、中央のバックエンドへ送ります。あとはトレースIDをキーに全スパンを集め、親スパンIDで木に組めば、1本のトレースが復元できます。

決済サービス在庫サービス注文サービスAPIゲートウェイユーザー決済サービス在庫サービス注文サービスAPIゲートウェイユーザートレースID t1 を発行し スパンを開始親はゲートウェイのスパン全スパンが t1 で束ねられ 1本のトレースになる注文リクエスト処理を依頼 traceparent に t1在庫確認 traceparent に t1在庫あり決済実行 traceparent に t1完了注文確定レスポンス

トレース・スパン・コンテキスト

構成要素を整理します。トレースは「1リクエスト全体」を表すいちばん上の単位で、スパンは「その中の1つの作業単位(あるサービスでの HTTP 処理、DB クエリ、外部 API の呼び出しなど)」を表す区間です。スパンには開始・終了の時刻のほか、HTTP ステータスやエラーの情報、任意の属性(ユーザーの地域・アプリの版など)を付けられ、これが後の絞り込みに効きます。

サービス間でトレースIDと親スパンIDを運ぶ入れ物が「トレースコンテキスト」で、これを標準にしたのが W3C の traceparent ヘッダです。00-<トレースID 32桁>-<親スパンID 16桁>-01 のような1行で、末尾はサンプリングする(記録する)かどうかの印です。形式が統一されたおかげで、言語もベンダーも違うサービスが混在していても、1本のトレースをつなげられるようになりました。

集めたトレースは、可視化ツールの上で横棒を入れ子に並べた「ウォーターフォール」として表示されます。横軸が時間、1行が1スパンで、子のスパンは親の棒の中に収まります。親は子の応答を待っているので、子が遅ければ親の棒も同じだけ伸びます。どの棒が長く伸びているかが一目で分かり、「全体3秒のうち2.8秒は在庫サービスの DB クエリだった」といったボトルネックが見えます。

0秒1秒2秒3秒APIゲートウェイ注文サービス在庫サービスDBクエリ2.8秒(全体の93%)決済サービス在庫の後に短く字下げ = 親子関係(親は子を待つ)DBクエリが伸びると、在庫・注文・ゲートウェイの棒も同じだけ伸びる。根から「いちばん長い子」をたどると、遅さの原因の葉に行き着く。
ウォーターフォール。子のスパンは親の棒の中に収まり、親は子を待つ。全体3秒のうち2.8秒を在庫サービスの DB クエリが占めている

伝播の切れ目

分散トレーシングのいちばん典型的な落とし穴は「伝播の切れ目」です。どこか1つのサービスがトレースコンテキストを次へ渡し忘れると、受け取った側は親を知らないので、新しいトレースIDで自分を根にした別のトレースを始めます。するとウォーターフォールは2本に裂け、本体のトレースには「注文サービスが何かを1秒待っていた」という空白だけが残ります。遅いスパンは親のいない別のトレースにあって、どのユーザーのどのリクエストを遅くしたのかをたどれません。

切れ目はたいてい、自動の計装が効かない場所で起きます。自前の HTTP クライアント、スレッドをまたぐ非同期処理、そしてメッセージキューです。キューには HTTP ヘッダのような決まった入れ物がないので、送る側がメッセージの属性に traceparent を載せ、受け取る側がそれを読んで親にする、という手当てが要ります(キューの向こうの処理は応答を待たせないので、親子ではなく「リンク」として結ぶこともあります)。下の部品で、葉のスパンを伸ばしてから、サービス間の矢印を押して受け渡しを切ってみてください。

⚡ 体験: トレースコンテキストを運ぶ・切る
APIゲートウェイ4bf92f…注文4bf92f…在庫4bf92f…DB在庫から呼ぶ決済4bf92f…外部決済API社外キュー通知19e0f7…金の実線 = traceparent を運ぶ / 朱の破線 = 運ばない(押して切り替え)ウォーターフォール0s1s2s3strace 4bf92f…trace 19e0f7…(親なし)APIゲートウェイ645ms注文サービス620ms在庫サービス245msDBクエリ220ms決済サービス325ms外部決済API300msキューへ送る8ms?(伝播が切れた)通知サービス260ms
トレースの本数2本ゲートウェイの応答645ms

下のウォーターフォールで、在庫サービスの「DBクエリ」の棒の右端(金のつまみ)を右へドラッグして遅くしてください。上のトポロジの矢印は、押すとトレースコンテキストの受け渡しを切れます。

実装・運用と落とし穴

実装では、OpenTelemetry(OTel)というベンダー中立の標準が事実上の共通言語になっています。各言語の SDK を組み込み、フレームワーク向けの計装ライブラリを入れれば、HTTP や DB の呼び出しは自動でスパンになり、送信先(Jaeger、Zipkin、各クラウドの可観測性サービスなど)は設定で差し替えられます。トレース単体では足りない情報は、同じトレースIDをログやメトリクスにも埋め込むことで結び付けられ、「トレースで遅いスパンを見つけ、そのスパンのログへ飛ぶ」「メトリクスのグラフの跳ねた点から、その時刻の代表的なトレース(エグゼンプラー)へ飛ぶ」という調査の動線が作れます。

運用で最大の悩みはコストです。全リクエストの全スパンを保存すると、データ量は本番のトラフィックに比例して膨らみます。そこで一部だけを保存する「サンプリング」が定石です。入口で確率的に間引くヘッドサンプリングは安く単純ですが、まれなエラーのトレースも同じ確率で捨ててしまいます。トレースが完了してから、エラーや遅延を含むものを選んで残すテールサンプリングは賢い代わりに、すべてのスパンをいったん1か所に集めて待つ仕組みが要ります。入口で決めた「記録する・しない」は traceparent の末尾に載って下流へ伝わるので、途中のサービスが勝手に違う判断をしてトレースが歯抜けになることはありません。

分散トレーシングは「入れれば見える」ものではありません。伝播をどこまで途切れさせずに通せるかが、そのまま見える範囲になります。

試問

APIゲートウェイ → 注文 → 在庫・決済、そしてキュー経由の通知サービスへとリクエストが渡る画面です。上のトポロジの矢印は traceparent(どのトレースの一部かを示す番号)を運ぶ受け渡しで、押すと運ぶ・運ばないが切り替わります。下のウォーターフォールでは、DBクエリ・外部決済API・通知サービスの棒の右端をドラッグして遅くできます。

✦ 命題挑戦中

入口から通知サービスまでを1本のトレースにつなぎ、通知を1.5秒以上に遅くしても、ゲートウェイの応答が1秒未満のままであることを1本の図で見せよ

  • 入口(APIゲートウェイ)から通知サービスまで、トレースが1本
  • 通知サービスのスパンを 1.5 秒以上に伸ばす
  • それでもゲートウェイの応答は 1 秒未満
⚡ 体験: トレースコンテキストを運ぶ・切る
APIゲートウェイ4bf92f…注文4bf92f…在庫4bf92f…DB在庫から呼ぶ決済4bf92f…外部決済API社外キュー通知19e0f7…金の実線 = traceparent を運ぶ / 朱の破線 = 運ばない(押して切り替え)ウォーターフォール0s1s2s3strace 4bf92f…trace 19e0f7…(親なし)APIゲートウェイ645ms注文サービス620ms在庫サービス245msDBクエリ220ms決済サービス325ms外部決済API300msキューへ送る8ms?(伝播が切れた)通知サービス260ms
トレースの本数2本ゲートウェイの応答645ms

下のウォーターフォールで、在庫サービスの「DBクエリ」の棒の右端(金のつまみ)を右へドラッグして遅くしてください。上のトポロジの矢印は、押すとトレースコンテキストの受け渡しを切れます。