キューの向こう側は親子ではなくリンクでつなぐ

一言でいうと

キューの向こう側は、親子ではなくリンクでつなぎます。親子は「この仕事が終わらないとあの仕事が終わらない」という意味ですが、プロデューサーは消費が終わるのを待たないからです。

なぜ必要なのか

注文APIにキューを入れたあと、トレースがおかしくなりました。ユーザーには40ミリ秒で応答が返っているのに、画面のルートスパンは3秒と表示されていました。計装した人は、「注文1件が最後まで処理される様子を1つのトレースで見たい」という良い意図で、消費側のスパンを生産スパンの子にしていました。

親子はそういう意味ではありません。親スパンは、子がすべて終わったあとに終わります。そのため、プロデューサーはすでに応答を返したのにスパンを閉じられずに座り込む形になり、キューが詰まった日には、そのスパンが数分も開いたままになります。ファンアウトが混ざるとさらに悪くなります。注文1件がメッセージ5つを作り、そのうち1つがさらに3つを作ると、1つのトレースが数千個のスパンに育ち、バックエンドがそのトレースだけを特別扱いし始めます。

どう動くのか

OpenTelemetryは、このような場面のためにリンク(Link)を用意しています。リンクは「このスパンはあのスパンと因果でつながっているが、あのスパンが私を待つわけではない」という関係です。スパンを作るときにリンクのリストを一緒に渡し、リンクごとに属性を付けられます。詳しい定義はトレースAPI仕様とTraces概念ドキュメントにあります。

つなぐ方法	意味	使う場面
親子	親が子を待ちます	同じリクエスト内の同期呼び出し
リンク	因果はあるが待ちません	キューの向こう側、バッチ処理、再処理
何もしない	関係が記録されません	本当に無関係な作業

そのため、キューのラボの基本形は次のとおりです。生産側はメッセージを入れるスパンを作り、そのスパンのIDをメッセージに載せて送ります。消費側は新しいトレースのルートとしてスパンを開始しますが、メッセージに載ってきたIDでリンクを作って付けます。そうすると、生産側のトレースはユーザーへの応答と一緒にすぐ終わり、消費側のトレースは自分の時間の分だけ存続します。2つのトレースはリンクでつながっているので、あとでたどれます。

一度に複数件を取り出すバッチ消費は、リンクが複数付いたスパン1つで描きます。メッセージごとにスパンを作ると、バッチを処理した1回の仕事が散らばり、リンクなしで1つだけ作ると、どのメッセージがそのバッチに入っていたかがわかりません。メッセージングのセマンティックコンベンションは、この場合messaging.batch.message_countを書くよう定めています。メッセージングスパンのコンベンションに表があります。

キューで待った時間は、どのスパンにも自然には入りません。生産時刻をメッセージに載せて送り、消費スパンがその差を属性として書く必要があります。この値があれば、「処理が遅い」と「キューが詰まっている」を区別でき、2つは直し方がまったく違います。

スパンの種類も、同じドキュメントが定めています。メッセージを作る、または送るスパンはPRODUCER、アプリケーションがメッセージを処理するスパンはCONSUMERです(取り出してくるだけのreceiveはCLIENT)。この値は飾りではなく、分析ツールがトレース間の関係を解釈する手がかりなので、ルールなしに付けると、ツールがキューを認識できません。

リンクには属性を付けられますし、付けるべきです。リンクだけだと「つながっている」という事実は残りますが、なぜつながっているかは残りません。キューのメッセージのためか、再処理のためか、バッチに一緒に入っていたためかをリンク属性に書いておけば、あとで人が読めます。

このモジュールが扱わないことをはっきりさせておきます。HTTPヘッダーtraceparentの要素を読んで途切れたチェーンをつなぐのは伝播ラボの役割であり、1つのプロセス内でスレッドやTaskにコンテキストを渡すのはコンテキスト境界ラボの役割です。ここで決めるのは、親子でつなぐのが正しくない場面を見分けて、リンクに変える判断です。

ラボ環境で判定できないことも書いておきます。Podにはブローカーも、Collectorも、トレースバックエンドもありません。そのため、バックエンドの画面がリンクをどんな形で描くか、テールサンプリングがリンクでつながった2つのトレースを一緒に残すかは、ここでは確認できません。キューはファイル1つで模倣し、判定はすべてSDKが出力したJSONLダンプの構造と属性で行います。かかった時間はマシンの事情で変わるため、絶対値ではなく関係としてだけ見ます。

現場での姿

最もよくある兆候は、「ルートスパンの時間がユーザーが待った時間と違う」ことです。応答は40ミリ秒で返ったのにトレースが3秒なら、ほぼ必ず非同期の仕事を子としてぶら下げています。そのトレースではレイテンシを測れません。ユーザーが経験した時間とシステムが働いた時間が、1つの数字にまとまってしまっているからです。

もう1つは「特定のトレースだけ開かない」という症状です。ファンアウトを親子でつないでいるシステムで、注文1件が数千スパンに育つと、バックエンドがそのトレースを切り詰めたり、画面が固まったりします。リンクに変えれば、トレース1つ1つは小さく保たれ、全体の道のりはリンクをたどりながら再びつなぎ合わせられます。ラボの最後のステップで、そのつなぎ合わせを自分でやってみます。

次のラボですること

ファイル1つでできたとても小さなキューにメッセージを入れ、あとで取り出して処理します。まず、生産と消費を親子でつないで、ルートスパンがどう膨らみ、隙間がどこにできるかをダンプで見ます。次に、消費側を新しいトレースのルートに変えて、リンクでつなぎます。バッチ消費をリンクが複数付いたスパン1つで描き、キューで待った時間を属性として残し、スパンの種類とメッセージング属性をコンベンションどおりに付け、リンクに理由を書きます。最後に、1つが複数を生み出すファンアウトまで適用し、リンクをたどって、1つの注文の道のりをトレースの向こう側までつなぎ合わせます。