欠けたスパンの原因を一つずつ消していく

目標

報告された事案の証拠2枚を突き合わせてないリクエストを数字にし、共通点で範囲を絞ったあと、4つの候補原因を自分で再現して、それぞれがダンプに残す痕跡がどう違うかを確認します。その違いを分類表にまとめ、診断スクリプトに固めて、原因が異なる2つ目の事案に実行し、異なる答えが出るところまで見ます。

なぜ重要なのか

スパンがない理由は複数あるのに、画面に見える症状は1つ、つまり「ない」です。そのため、推測で直し始めると、サンプリング比率を上げたりエクスポーターをいじったりして、数日が過ぎます。実際にそうして2日を費やしたあとで、ログとダンプをリクエスト識別子で突き合わせたところ、なくなっているのはすべて1つの経路のリクエストであるという事実が、その場で明らかになりました。診断が先である理由は2つです。何件がないのかを数字にしておかないと、直したあとも良くなったかわからず、ないもの同士の共通点を見ないと、全体の設定をいじるべき問題なのか、1つの経路のコードを見るべき問題なのかを選べません。4つの候補はダンプに異なる痕跡を残すので、その痕跡を一度自分で作ってみれば、次からはダンプ1枚で切り分けられます。欠陥のある配線を見つけて直す作業はSDKライフサイクルのモジュールの役割で、ここで作るのは、分類表と診断スクリプトです。

ステップ

事案1つの証拠が/opt/app/tracelab/tp_missing/case1/にあります。リクエストログapp.logとスパンダンプspans.jsonlです。ログの1行のrequest_id=の値と、ダンプのスパン属性request.idを突き合わせて、ログにはあるのにダンプにはないリクエストを探してください。結果を2つのファイルに残します。/root/tp-missing/01-missing.txtには3行を書きます。logged=の後ろにログのリクエスト数、traced=の後ろにダンプで見つかったリクエスト数、missing=の後ろにないリクエスト数です。/root/tp-missing/01-missing-ids.txtには、ないリクエストの識別子を昇順に、1行に1つずつ書きます。
同じ事案で、ないリクエストがどこに集中しているかを見ます。/root/tp-missing/02-shape.tsvに、タブで区切った4つの欄を書いてください。まず経路ごとに1行ずつroute<탭><경로><탭><로그 건수><탭><없는 건수>(プレースホルダーは順に、タブ、経路、ログの件数、ないものの件数です)を経路名の昇順で、次に分ごとに1行ずつminute<탭><HH:MM><탭><로그 건수><탭><없는 건수>(プレースホルダーは同様です)を時刻の昇順で書きます。最後の行はverdict<탭><route 또는 minute><탭><가장 많이 빠진 값><탭><그 값에서 빠진 건수>(プレースホルダーは順に、タブ、routeまたはminute、最も多く抜けた値、その値で抜けた件数です)です。どの軸に集中しているかを選ぶ行です。
ダンプに何も残さない原因2つを、自分で作ってみます。/root/tp-missing/sampling.pyは、材料tracelab.tp_missing.samplers.drop_requests(["e-02", "e-05"])をサンプラーとして使い、webapp.REQUESTSの6件を処理します(デフォルトのダンプのパスは/root/tp-missing/03-sampling.jsonl)。/root/tp-missing/early_exit.pyは、サンプラーなしで同じ6件を処理しますが、e-05の番になったらos._exit(0)でプロセスを終了します(デフォルトのダンプのパスは/root/tp-missing/03-exit.jsonl)。どちらもルートスパン名はGET <경로>(プレースホルダーはパスです)で、属性request.idをスパンを開始するときに渡し、その中でwebapp.work(tracer, req)を呼びます。そのあと/root/tp-missing/03-nothing.tsvに、タブで区切った3つの欄の2行を書いてください。1行目はsampling、2行目はearly-exitで、2つ目の欄はそのダンプにないリクエストの識別子をカンマでつないだもの、3つ目の欄は、そのないものが6件の末尾から連続していればtail、そうでなければscatteredです。
/root/tp-missing/unfinished.pyを作成してください(デフォルトのダンプのパスは/root/tp-missing/04-unfinished.jsonl)。同じ6件を処理しますが、e-02とe-05の2件は、ルートスパンをtracer.start_span(...)で作り、終了しません(end()を呼びません)。その2件も子スパンは正常に作る必要があるので、webapp.work(tracer, req, context=trace.set_span_in_context(span))のようにコンテキストを渡して呼んでください。残りの4件はステップ3と同じ方式です。実行すると、ダンプにスパンが10行入っていて、そのうち2行は、parent_idがダンプのどのspan_idでもないはずです。
/root/tp-missing/broken_parent.pyを作成してください(デフォルトのダンプのパスは/root/tp-missing/05-split.jsonl)。6件すべてを正常に処理しますが、e-03とe-06の2件だけ、子をwebapp.work(tracer, req, context=Context())で呼んで、空のコンテキストに付けます(from opentelemetry.context import Context)。実行すると、スパンは12行で、ないリクエストは1件もないのに、request.idが付いたスパンが1つもないトレースが2つできます。
前の3つのステップで作った4つのダンプを見て、/root/tp-missing/06-fingerprints.tsvに、タブで区切った4つの欄の4行を書いてください。1つ目の欄は原因名で、順にsampled-out・unfinished・early-exit・broken-parentです。2つ目の欄は、なくなったリクエストのルートスパンがダンプにあるかどうかで、noneまたはpresent。3つ目の欄は、子スパンがどんな形かで、none(ない)・orphan(あるが、指す親がダンプにない)・detached(あるが、別のトレースのルートになった)のいずれか。4つ目の欄は、ないリクエストの分布で、scattered・tail・none(ないリクエストがそもそもない)のいずれかです。
/root/tp-missing/classify.pyを作成してください。python3 classify.py <app.log> <spans.jsonl>で実行すると、2行を出力します。verdict=<원인 이름>とmissing=<없는 요청 수>です(プレースホルダーは原因名と、ないリクエスト数です)。ルールは、この順序で見ます。(1)parent_idがダンプのどのspan_idでもないスパンがあればunfinished。(2)request.id属性を持つスパンが1つもないtrace_idがあればbroken-parent。(3)ないリクエストが1つもなければok。(4)ないリクエストがログの最後の行から連続していればearly-exit。(5)それ以外はsampled-out。作成したスクリプトを/opt/app/tracelab/tp_missing/case1/に実行した出力を、そのまま/root/tp-missing/07-verdict.txtに保存してください。
2つ目の事案/opt/app/tracelab/tp_missing/case2/に同じスクリプトを実行して、出力を/root/tp-missing/08-verdict.txtに保存してください。最初の事案とは異なる答えが出る必要があります。そして/root/tp-missing/08-report.mdに、次の人が読む調査記録を残します。見出しを4つ、この順序で置き、各見出しの下に60文字以上を書いてください。## 무엇이 없었나(韓国語で「何がなかったか」を意味する見出しです。2つの事案で何件がなく、どこに集中していたか)、## 어떻게 갈랐나(韓国語で「どう切り分けたか」を意味する見出しです。どの痕跡で候補を除外したか)、## 원인(韓国語で「原因」を意味する見出しです。2つの事案の判定名をそのまま書きます)、## 다음 사람에게(韓国語で「次の人へ」を意味する見出しです。同じ報告がまた来たら、何から始めるか)。本文のどこかにcase1とcase2の両方が出てくる必要があります。

参考

作業ディレクトリは/root/tp-missingです。なければ先に作ってください。
計装プログラムは必ず/opt/otel-lab/bin/python <파일>(プレースホルダーはファイル名です)で実行します。システムのpython3にはOpenTelemetry SDKがありません。逆に、ログとダンプだけを読むプログラムは、システムのpython3で実行してください。
材料は、事案フォルダー/opt/app/tracelab/tp_missing/case1から/opt/app/tracelab/tp_missing/case5まで(それぞれapp.logとspans.jsonl)、実験用のリクエストと子スパンのヘルパー/opt/app/tracelab/tp_missing/webapp.py、実験用のサンプラー/opt/app/tracelab/tp_missing/samplers.pyです。事案を作ったジェネレーターは/opt/app/tracelab/tp_missing/make_cases.pyで、共通の配線は/opt/app/tracelab/dump.py、ダンプ読み込みのヘルパーは/opt/lab/checks/_tplib.pyです。
よくある間違い: ダンプファイルを削除せずにプログラムを2回実行してしまいます。ダンプは追記されるので、スパンが2倍になります。
よくある間違い: サンプリングの判定に使われる属性を、set_attributeであとから付けてしまいます。サンプリングの決定はスパンが開始されるときに行われるため、そのとき渡した属性だけをサンプラーが見ます。
サンプリングの概念・Trace SDK仕様(ForceFlush・Shutdown・ShouldSample)・W3C Trace Context・Tracesの概念・Python計装ドキュメント

ログとダンプを突き合わせて、ないもののリストを作る

事案1つの証拠が/opt/app/tracelab/tp_missing/case1/にあります。リクエストログapp.logとスパンダンプspans.jsonlです。ログの1行のrequest_id=の値と、ダンプのスパン属性request.idを突き合わせて、ログにはあるのにダンプにはないリクエストを探してください。結果を2つのファイルに残します。/root/tp-missing/01-missing.txtには3行を書きます。logged=の後ろにログのリクエスト数、traced=の後ろにダンプで見つかったリクエスト数、missing=の後ろにないリクエスト数です。/root/tp-missing/01-missing-ids.txtには、ないリクエストの識別子を昇順に、1行に1つずつ書きます。

リクエスト識別子はサーバースパンにだけ付いています。子スパン(db.query)にはないので、ダンプ全体からattributesのrequest.idを集めて集合を作ってください。ログの1行は、空白で区切られた열쇠=값(プレースホルダーはキーと値です)の並びなので、split()したあと、request_id=で始まる断片だけを見れば済みます。ダンプを読むのにotelは不要なので、システムのpython3で実行してください。

ないもの同士の共通点で調査範囲を絞る

同じ事案で、ないリクエストがどこに集中しているかを見ます。/root/tp-missing/02-shape.tsvに、タブで区切った4つの欄を書いてください。まず経路ごとに1行ずつroute<탭><경로><탭><로그 건수><탭><없는 건수>(プレースホルダーは順に、タブ、経路、ログの件数、ないものの件数です)を経路名の昇順で、次に分ごとに1行ずつminute<탭><HH:MM><탭><로그 건수><탭><없는 건수>(プレースホルダーは同様です)を時刻の昇順で書きます。最後の行はverdict<탭><route 또는 minute><탭><가장 많이 빠진 값><탭><그 값에서 빠진 건수>(プレースホルダーは順に、タブ、routeまたはminute、最も多く抜けた値、その値で抜けた件数です)です。どの軸に集中しているかを選ぶ行です。

ログの1行にroute=が入っていて、時刻は行頭の2026-09-16T09:00:00Zの11文字目から5文字がHH:MMです。一方の軸は値1つにすべて集中し、もう一方の軸は均等に広がっているはずです。集中しているほうがverdictです。ないリクエストのリストは、ステップ1ですでに作ったので、そのまま使ってください。

何の痕跡も残さない2つの原因は、分布でしか切り分けられない

ダンプに何も残さない原因2つを、自分で作ってみます。/root/tp-missing/sampling.pyは、材料tracelab.tp_missing.samplers.drop_requests(["e-02", "e-05"])をサンプラーとして使い、webapp.REQUESTSの6件を処理します(デフォルトのダンプのパスは/root/tp-missing/03-sampling.jsonl)。/root/tp-missing/early_exit.pyは、サンプラーなしで同じ6件を処理しますが、e-05の番になったらos._exit(0)でプロセスを終了します(デフォルトのダンプのパスは/root/tp-missing/03-exit.jsonl)。どちらもルートスパン名はGET <경로>(プレースホルダーはパスです)で、属性request.idをスパンを開始するときに渡し、その中でwebapp.work(tracer, req)を呼びます。そのあと/root/tp-missing/03-nothing.tsvに、タブで区切った3つの欄の2行を書いてください。1行目はsampling、2行目はearly-exitで、2つ目の欄はそのダンプにないリクエストの識別子をカンマでつないだもの、3つ目の欄は、そのないものが6件の末尾から連続していればtail、そうでなければscatteredです。

サンプラーはスパンが開始されるときに決定するので、set_attributeであとから付けたrequest.idは見えません。start_as_current_span(이름, attributes={...})(プレースホルダーはスパン名です)で渡してください。osは、os._exitを使うために、あらかじめimport osしておく必要があります。2つのダンプとも、ないリクエストは、ルートも子も1行もないはずです。ダンプを作り直す前にファイルを削除してください。ダンプは追記されます。

終了しなかったスパンは、親のない子を残す

/root/tp-missing/unfinished.pyを作成してください(デフォルトのダンプのパスは/root/tp-missing/04-unfinished.jsonl)。同じ6件を処理しますが、e-02とe-05の2件は、ルートスパンをtracer.start_span(...)で作り、終了しません(end()を呼びません)。その2件も子スパンは正常に作る必要があるので、webapp.work(tracer, req, context=trace.set_span_in_context(span))のようにコンテキストを渡して呼んでください。残りの4件はステップ3と同じ方式です。実行すると、ダンプにスパンが10行入っていて、そのうち2行は、parent_idがダンプのどのspan_idでもないはずです。

with文はブロックを抜けるときにend()を代わりに呼んでくれるので、終了しないスパンを作るには、withを使ってはいけません。tracer.start_spanは作るだけで、現在のスパンとして立てることもしません。そのため、子が親を見つけられるようにするには、コンテキストを手で渡す必要があります。終了していないスパンはエクスポーターに渡らないため、ダンプにはまったく現れません。

親コンテキストが途切れると、ないリクエストがないままトレースが分かれる

/root/tp-missing/broken_parent.pyを作成してください(デフォルトのダンプのパスは/root/tp-missing/05-split.jsonl)。6件すべてを正常に処理しますが、e-03とe-06の2件だけ、子をwebapp.work(tracer, req, context=Context())で呼んで、空のコンテキストに付けます(from opentelemetry.context import Context)。実行すると、スパンは12行で、ないリクエストは1件もないのに、request.idが付いたスパンが1つもないトレースが2つできます。

空のContext()には現在のスパンがないため、その中で開始したスパンは親を見つけられず、新しいトレースのルートになります。この原因が前の3つと違う点は、突き合わせ表に何も引っかからないことです。そのため、数えるべきものは、ないリクエストではなく、リクエスト識別子のないトレースです。python3 /opt/lab/checks/_tplib.py summary <덤프>(プレースホルダーはダンプのパスです)で、トレースが何個あるかを見られます。

原因ごとに異なる痕跡を分類表に固める

前の3つのステップで作った4つのダンプを見て、/root/tp-missing/06-fingerprints.tsvに、タブで区切った4つの欄の4行を書いてください。1つ目の欄は原因名で、順にsampled-out・unfinished・early-exit・broken-parentです。2つ目の欄は、なくなったリクエストのルートスパンがダンプにあるかどうかで、noneまたはpresent。3つ目の欄は、子スパンがどんな形かで、none(ない)・orphan(あるが、指す親がダンプにない)・detached(あるが、別のトレースのルートになった)のいずれか。4つ目の欄は、ないリクエストの分布で、scattered・tail・none(ないリクエストがそもそもない)のいずれかです。

4行のうち3行は、ステップ3・4・5で自分で作ったダンプが、そのまま答えを示してくれます。紛らわしいのは1行目と3行目で、その2つはダンプだけを見ると同じで、4つ目の欄でしか分かれません。採点ツールは、作成したダンプを読み直して、表の各行と合っているかを見ます。暗記して書く表ではなく、自分のダンプの要約です。

同じ判定をスクリプトに固めて事案に実行する

/root/tp-missing/classify.pyを作成してください。python3 classify.py <app.log> <spans.jsonl>で実行すると、2行を出力します。verdict=<원인 이름>とmissing=<없는 요청 수>です(プレースホルダーは原因名と、ないリクエスト数です)。ルールは、この順序で見ます。(1)parent_idがダンプのどのspan_idでもないスパンがあればunfinished。(2)request.id属性を持つスパンが1つもないtrace_idがあればbroken-parent。(3)ないリクエストが1つもなければok。(4)ないリクエストがログの最後の行から連続していればearly-exit。(5)それ以外はsampled-out。作成したスクリプトを/opt/app/tracelab/tp_missing/case1/に実行した出力を、そのまま/root/tp-missing/07-verdict.txtに保存してください。

順序が重要です。終了しなかったスパンは、「リクエスト識別子のないトレース」も一緒に作り出すので、(1)を(2)より先に見ないと、2つの原因が入れ替わります。missingは、どの原因でも同じ方法で数えます(ログのリクエストのうち、ダンプにrequest.idがないもの)。採点ツールは、作成したスクリプトを/opt/app/tracelab/tp_missingの下のほかの事案フォルダーにも実行するので、ファイル名や特定の識別子で判定してはいけません。

原因が異なる2つ目の事案に実行して、調査記録を残す

2つ目の事案/opt/app/tracelab/tp_missing/case2/に同じスクリプトを実行して、出力を/root/tp-missing/08-verdict.txtに保存してください。最初の事案とは異なる答えが出る必要があります。そして/root/tp-missing/08-report.mdに、次の人が読む調査記録を残します。見出しを4つ、この順序で置き、各見出しの下に60文字以上を書いてください。## 무엇이 없었나(韓国語で「何がなかったか」を意味する見出しです。2つの事案で何件がなく、どこに集中していたか)、## 어떻게 갈랐나(韓国語で「どう切り分けたか」を意味する見出しです。どの痕跡で候補を除外したか)、## 원인(韓国語で「原因」を意味する見出しです。2つの事案の判定名をそのまま書きます)、## 다음 사람에게(韓国語で「次の人へ」を意味する見出しです。同じ報告がまた来たら、何から始めるか)。本文のどこかにcase1とcase2の両方が出てくる必要があります。

2つの事案のダンプは、見た目が似ています。どちらも16件がありません。分かれるのは、その16件がログのどこにあるかと、ダンプに親のない子が残っているかどうかです。記録を書くときは、結論だけを書かず、何を見て何を除外したかを書いてください。次の人に必要なのは、答えではなく手順です。