3回目で成功したリクエストは成功か失敗か

一言でいうと

リトライした1つのリクエストをスパン何個で描くか、そしてどのスパンにエラーを付けるかを決めておかないと、ダンプは静かに嘘をつきます。

なぜ必要なのか

決済担当者が尋ねました。「3回試行して3回目に成功した場合、これは成功ですか、失敗ですか」。答えは、どちらも、です。ユーザーにとっては成功で、上流サービスにとっては2回の失敗です。問題は、トレースがその2つのうち片方しか語れない描き方になっていたことでした。

当時のコードは、リトライのループを1つのスパンで包んでいました。画面にはchargeスパンが1つ184ミリ秒で表示され、状態は正常でした。その184ミリ秒の中に、60ミリ秒のタイムアウトが1回、20ミリ秒の503が1回、そして2回の待機が含まれているという事実は、どこにも残っていませんでした。遅くなった理由を尋ねる人に見せられるのは「このスパンが長くかかった」ということだけでした。

反対側へ振れたチームもありました。試行ごとにスパンを作り、失敗した試行にエラー状態を付けたところ、今度はダッシュボードのエラー率が突然2倍になりました。ユーザーが経験した失敗は増えていないのに、数字だけが上がったのです。スパンを数えるとリトライが二重に計算されることを、誰も事前に教えてくれませんでした。

どう動くのか

整理すると、決めるべきことは4つです。

決定	選択肢	このラボが選ぶ側
スパンの分け方	リトライ全体を1つに / 試行ごとに1つ	外側のスパン1個+試行スパンN個
エラーを付ける場所	外側のスパン / 失敗した試行スパン	失敗した試行にだけ
結果として成功した場合の状態	そのままにする / 明示的に正常	明示的に正常と書く
数える単位	スパン / 論理的なリクエスト(ルート)	論理的なリクエスト

外側のスパンはユーザーが経験した1つの出来事です。3回試行して最終的に成功したなら、ユーザーは成功を経験したため、このスパンは正常です。試行スパンは上流に実際に出ていった1回の呼び出しです。失敗した呼び出しは失敗として残してこそ、上流の健全性を見られます。2つの層は異なる問いに答えるため、状態も別々になります。

この区別が立てば、エラー率をどこで数えるべきかは自然に決まります。スパンを分母に使うと、リトライを多く行ったリクエストほど分母と分子が一緒に大きくなって失敗が膨らみ、ルートスパンだけを数えればユーザーが経験した失敗がそのまま出ます。同じデータから53.8%と25.0%が出る、ということが実際に起こります。ラボのステップ4で、その2つの数字を自分で作ります。

待機時間にも行き先が必要です。試行と試行の間のbackoffはどの試行スパンにも入っていないため、外側のスパンの区間から子の区間を引いて残る隙間としてしか見えません。その隙間が何だったのかを人が推測するままにせず、イベントや属性として書き残しておく必要があります。ラボのステップ5で、その隙間を自分で測り、記録と照らし合わせます。

属性は、ルールとして決めてこそ役に立ちます。リトライ回数と最後の失敗理由は論理的なリクエスト1つの性質なので外側のスパンに置き、何回目の試行かは試行ごとに違うので試行スパンに置きます。冪等キーは両方に同じ値で置きます。同じキーで何回も出ていったという事実が見えて初めて、重複処理の事故を見分けられるからです。HTTP計装には同じ意味の標準属性http.request.resend_countがすでに定義されているので、自分で名前を付ける前にHTTPスパンのセマンティックコンベンションを先に見るのがよいです。失敗の分類に使うerror.typeも、エラー属性レジストリに値のルールが書かれています。

ここで扱わないことを1つ、はっきりさせておきます。捕捉した例外をどのAPIでスパンに残し、ステータスコードをどう配線するかは、SDKライフサイクルのモジュールが扱います。このモジュールの問いはその前にあります。複数回試行した1つの作業をスパン何個で表現し、そのうちどこにエラーを付けるかです。ステータスを設定する方法はトレースAPI仕様にあります。

このラボ環境で判定できないことも書いておきます。PodにはOpenTelemetry Collectorもトレースバックエンドもありません。そのため、テールサンプリングが失敗した試行をどう選び出すか、バックエンドの画面でリトライがどんな形に折りたたまれるかは、ここでは確認できません。見られるのはSDKが出力したスパンをそのまま書き出したJSONLダンプだけで、判定はすべてそのダンプの構造と属性で行います。かかった時間はマシンの事情によって数ミリ秒ずつ変わるため、絶対値ではなく関係としてだけ見ます。

現場での姿

ポストモーテムで最もよく出る文が「リトライのおかげでユーザーは何も感じなかった」ですが、その言葉が正しかったかを確認する方法がない場合が多いです。試行スパンがなければ上流がどれだけ頻繁に転んだかを数えられず、外側のスパンがなければユーザーが実際に失敗を経験したかを数えられません。2つの層がそろっていて初めて、「上流は悪かったがユーザーは大丈夫だった」を数字で言えます。

逆の事故もよくあります。あるチームはリトライを3重に入れていました。クライアントライブラリが3回、その上のサービスが3回、ゲートウェイが2回です。上流が1回転ぶと実際には18回の呼び出しが出ていったのに、トレースには外側のスパンが1つしか見えませんでした。試行スパンを作った途端にその18個が目に見えるようになり、その日のうちにリトライの層を1つに減らしました。計装が設計上の欠陥を明らかにしたのです。

次のラボですること

決定論的に2回失敗して3回目に成功する上流を題材に、リトライを1つのスパンに入れたときにダンプが何を失うかをまず見ます。次に試行ごとにスパンを作り、失敗した試行にだけエラーを付けて、同じデータからスパン基準のエラー率とリクエスト基準のエラー率をそれぞれ計算し、どれだけ開くかを確認します。待機時間をイベントとして残して隙間と照合し、属性のルールを表で決めたあと、ループを自分たちでは直せない2つ目のサービスに、同じルールをフックとして差し込みます。最後に、そのルールをリンターで固めて、ルールを破ったダンプを実際に検出します。