スパンはあるのに再現できない

目標

失敗したリクエストのスパン1行から出発し、そのスパンだけで同じ失敗をもう一度起こせるだけの属性とイベントを埋めます。入れてはいけない値を変換して残す方法、ユニーク値のバジェットを数える方法、チームの規約をファイルに書いて検査プログラムで強制する方法まで、ひと通り行います。

なぜ重要なのか

自動計装はHTTPの外側を埋めてくれます。パスとステータスコードと長さは出ますが、明け方にそのスパンを開いて「では何を入れればこれがもう一度起きるのか」と問うと、答えがありません。再現入力、そのときの状態、自分たちが行ったことを属性として残してこそ、調査が始まります。逆に、リクエスト本文をまるごと入れると、連絡先やトークンが観測バックエンドにそのままたまります。そのため、生の値の代わりにハッシュ・カテゴリ・長さに変えて残します。時点のある事実は属性ではなくイベントであり、親子ではない関係はリンクです。最後に、キーごとにユニーク値が何種類あるかを数えておかないと、例外メッセージ1つがキーを数千種類の値に膨らませ、検索画面を落としてしまいます。

ステップ

/opt/app/tracelab/tp_attrs/failed.jsonlの1行を読んでください。失敗したリクエストのスパンなのに、再現に必要な値がありません。/root/tp-attrs/01-missing.txtに5行を書いてください。各行は<열쇠이름>=<왜 필요한가>(プレースホルダーはキー名と、それが必要な理由です)で、キーは順にshop.cart.item_count・shop.request.body_bytes・shop.cache.hit・shop.queue.depth・shop.payment.retry_countです。理由はキーごとに25文字以上で、「この値がなければ何を判断できないか」を自分の言葉で書きます。
/root/tp-attrs/02_attrs.pyを作成してください。tracelab.tp_attrs.ordersで注文ord-1010を処理しながら、POST /checkoutという名前のSERVERスパンを1つ作り、ステップ1の5つのキーに注文番号shop.order.idを加えて、6つの属性を付けます。決済はcharge(주문번호, 시도번호)(プレースホルダーは注文番号と試行番号です)を1・2・3で最大3回まで試行し、shop.payment.retry_countは(試行回数−1)です。ダンプのデフォルトのパスは/root/tp-attrs/02-attrs.jsonlで、環境変数TRACELAB_OUTがあればそちらを使います。
/root/tp-attrs/03_redact.pyを作成してください。ステップ2に3つの属性を加えます。shop.customer.email_hashはメールアドレスのSHA-256の16進文字列の先頭16文字、shop.payment.card_brandはカードのbrandの値、shop.auth.token_lenは認証トークンの長さ(整数)です。メールアドレス・カード番号(pan)・トークン・郵便番号の生の値は、どの属性にも残しません。ダンプのデフォルトのパスは/root/tp-attrs/03-redact.jsonlです。
/root/tp-attrs/04_events.pyを作成してください。ステップ3に加えて、(1)キャッシュがミスしたらcache.missイベントを1つ、(2)決済の試行が失敗するたびにpayment.attempt.failedイベントを1つずつ残します。イベント属性はattempt(整数の試行番号)とreason(PaymentErrorのkind)です。(3)3回とも失敗したら、例外メッセージをshop.error.message属性にそのまま入れ、スパンのステータスをERRORに変えます。ダンプのデフォルトのパスは/root/tp-attrs/04-events.jsonlです。このステップのshop.error.messageは、ステップ5でもう一度見ます。
/root/tp-attrs/05_bulk.pyを作成して、orders.ORDER_IDSの200件を同じ計装で1回ずつ処理してください(リクエストごとにスパン1つ)。ダンプのデフォルトのパスは/root/tp-attrs/05-bulk.jsonlです。そのあと/root/tp-attrs/05-cardinality.tsvに、ダンプに現れた属性キーごとに1行ずつ<열쇠><탭><고유값수><탭><판정>(プレースホルダーはキー、タブ、ユニーク値の数、判定です)を、キー名の昇順で書いてください。判定は、shop.order.idとshop.customer.email_hashならfree、それ以外でユニーク値が20以下ならlow、20を超えたらleakです。
/root/tp-attrs/convention.tsvを作成してください。1行が1つのキーで、タブで区切った4つの欄<열쇠><탭><타입><탭><허용값><탭><고유값성격>(プレースホルダーはキー、タブ、型、許容値、ユニーク値の性格です)です。型はstring・int・bool・denyのいずれか、許容値は*(制限なし)か|でつないだリスト、ユニーク値の性格はfreeまたはlowです。ステップ5に現れた10個のキーのうち、shop.error.messageはdenyで禁止し、代わりにshop.error.kindをdeclined|timeoutで新しく入れてください。ステップ8で使うshop.refund.amount(int・free)もあらかじめ入れ、生の値の禁止キーshop.customer.email・shop.payment.card_pan・shop.auth.tokenもdenyとして書きます。denyの行の許容値と性格の欄は-にします。
/root/tp-attrs/lint_spans.pyを作成してください。python3 lint_spans.py <규약파일> <덤프>(プレースホルダーは規約ファイルとダンプです)で呼び出すと、規約を破ったキーごとにVIOLATION <열쇠> <이유>(プレースホルダーはキーと理由です)をキー名の昇順で1回ずつだけ出力して終了コード1、破ったものがなければOKで始まる1行と終了コード0を返します。見るべきものは4つです。規約にないキー、denyで禁止したキー、型が異なる値、許容値のリストにない値。これに加えて、lowと宣言したキーのユニーク値がダンプ内で20を超えたら、それも違反です。作成したら、/root/tp-attrs/05-bulk.jsonlと/opt/app/tracelab/tp_attrs/noisy.jsonlにそれぞれ実行し、/root/tp-attrs/07-violations.tsvに2行<덤프파일이름><탭><깨진 열쇠들을 쉼표로 이은 것>(プレースホルダーはダンプのファイル名、タブ、破られたキーをカンマでつないだものです)をその順に書いてください。
/root/tp-attrs/08_refund.pyを作成して、キューが依頼した返金ord-1027を処理するPOST /refundのSERVERスパンを1つ作ってください。属性はshop.order.id・shop.refund.amount・shop.queue.depth・shop.customer.email_hash・shop.payment.card_brand・shop.auth.token_len・shop.payment.retry_countで、失敗で終わったらshop.error.kindを加えてステータスをERRORにします(生のメッセージは入れません)。失敗した試行ごとにpayment.attempt.failedイベントを残し、orders.job_context(주문번호)(プレースホルダーは注文番号です)が返すトレース座標をリンクとして付けます(親としては付けません)。ダンプのデフォルトのパスは/root/tp-attrs/08-refund.jsonlで、ステップ7の検査プログラムをこのダンプに実行すると、OKが出る必要があります。

参考

作業ディレクトリは/root/tp-attrsです。なければ先に作ってください。
計装プログラムは必ず/opt/otel-lab/bin/pythonで実行します。ダンプを読んで数えるスクリプトは、システムのpython3で十分です。
共通の配線は/opt/app/tracelab/dump.py(provider・flush)、材料は/opt/app/tracelab/tp_attrs/orders.py(注文処理が知っている事実)と/opt/app/tracelab/tp_attrs/failed.jsonl(ステップ1で見る失敗スパン)、/opt/app/tracelab/tp_attrs/noisy.jsonl(ステップ7で検査プログラムを実行してみる他人のダンプ)です。2つのダンプは/opt/app/tracelab/tp_attrs/make_fixtures.pyが作ります。
よくある間違い: ダンプファイルを削除せずにプログラムを再実行してしまいます。ダンプは追記なのでスパンがたまります。
よくある間違い: 関係を属性の文字列(parent_trace_id=...)として書いてしまいます。ツールがつなげず、人が目で探すことになります。関係はリンクです。
このPodにはコレクターがありません。運用ではコレクターのredactionプロセッサーがもう一度ふるいにかけますが、ここではアプリケーションが自分で除去した結果だけを見ます。バックエンドのインデックスコストも測れないため、ユニーク値の数で代用します。
OpenTelemetry: Traces・機密データの取り扱い・属性名の規約・Python API参考(add_event・Link)・コレクター設定のベストプラクティス(redaction)

失敗したスパンを見て、足りない値を書き出す

/opt/app/tracelab/tp_attrs/failed.jsonlの1行を読んでください。失敗したリクエストのスパンなのに、再現に必要な値がありません。/root/tp-attrs/01-missing.txtに5行を書いてください。各行は<열쇠이름>=<왜 필요한가>(プレースホルダーはキー名と、それが必要な理由です)で、キーは順にshop.cart.item_count・shop.request.body_bytes・shop.cache.hit・shop.queue.depth・shop.payment.retry_countです。理由はキーごとに25文字以上で、「この値がなければ何を判断できないか」を自分の言葉で書きます。

ダンプを見やすく整形するにはpython3 -m json.tool /opt/app/tracelab/tp_attrs/failed.jsonlが便利です。スパンに今あるのはHTTPの外側だけです。パス、ステータスコード、長さです。それだけで同じ失敗をもう一度起こせるか、自分に問いかけてみてください。採点ツールは、5つのキーが本当にそのスパンにないかも確認します。

再現に必要な値を属性として追加する

/root/tp-attrs/02_attrs.pyを作成してください。tracelab.tp_attrs.ordersで注文ord-1010を処理しながら、POST /checkoutという名前のSERVERスパンを1つ作り、ステップ1の5つのキーに注文番号shop.order.idを加えて、6つの属性を付けます。決済はcharge(주문번호, 시도번호)(プレースホルダーは注文番号と試行番号です)を1・2・3で最大3回まで試行し、shop.payment.retry_countは(試行回数−1)です。ダンプのデフォルトのパスは/root/tp-attrs/02-attrs.jsonlで、環境変数TRACELAB_OUTがあればそちらを使います。

orders.payloadがリクエスト本文を、orders.body_bytesがそのサイズを、orders.cache_lookupとorders.queue_depthがそのときの状態を返します。決済の失敗はorders.PaymentErrorです。計装プログラムは/opt/otel-lab/bin/pythonで実行してください。システムのpython3にはOpenTelemetryがありません。

入れてはいけない値はハッシュ・カテゴリ・長さに変える

/root/tp-attrs/03_redact.pyを作成してください。ステップ2に3つの属性を加えます。shop.customer.email_hashはメールアドレスのSHA-256の16進文字列の先頭16文字、shop.payment.card_brandはカードのbrandの値、shop.auth.token_lenは認証トークンの長さ(整数)です。メールアドレス・カード番号(pan)・トークン・郵便番号の生の値は、どの属性にも残しません。ダンプのデフォルトのパスは/root/tp-attrs/03-redact.jsonlです。

生の値をまるごと捨てずに変換して残す理由は、それでも答えられる問いがあるからです。ハッシュは「同じユーザーに繰り返し起きているか」、カテゴリは「特定のカード会社でだけ起きているか」、長さは「トークンが途中で切れて入ってきたか」です。ハッシュはhashlib.sha256(문자열.encode("utf-8")).hexdigest()(プレースホルダーは文字列です)で作ります。

時点のある事実はイベントに移す

/root/tp-attrs/04_events.pyを作成してください。ステップ3に加えて、(1)キャッシュがミスしたらcache.missイベントを1つ、(2)決済の試行が失敗するたびにpayment.attempt.failedイベントを1つずつ残します。イベント属性はattempt(整数の試行番号)とreason(PaymentErrorのkind)です。(3)3回とも失敗したら、例外メッセージをshop.error.message属性にそのまま入れ、スパンのステータスをERRORに変えます。ダンプのデフォルトのパスは/root/tp-attrs/04-events.jsonlです。このステップのshop.error.messageは、ステップ5でもう一度見ます。

リトライを2回行ったというのは1つの数字なので属性であり、1回目のリトライがいつなぜ起きたかは時刻のある記録なのでイベントです。両者は競合しません。数えるものは属性、起きた瞬間はイベントです。ステータスはspan.set_status(Status(StatusCode.ERROR, "..."))で変えます。

キーごとにユニーク値を数えてバジェット表を作る

/root/tp-attrs/05_bulk.pyを作成して、orders.ORDER_IDSの200件を同じ計装で1回ずつ処理してください(リクエストごとにスパン1つ)。ダンプのデフォルトのパスは/root/tp-attrs/05-bulk.jsonlです。そのあと/root/tp-attrs/05-cardinality.tsvに、ダンプに現れた属性キーごとに1行ずつ<열쇠><탭><고유값수><탭><판정>(プレースホルダーはキー、タブ、ユニーク値の数、判定です)を、キー名の昇順で書いてください。判定は、shop.order.idとshop.customer.email_hashならfree、それ以外でユニーク値が20以下ならlow、20を超えたらleakです。

識別子はリクエストごとに違うのが正常で、カテゴリ型のキーは値が数種類だけであるのが正常です。カテゴリであるべき場所に生の値が漏れ込むと、キー1つが数千種類の値を持つことになります。このダンプではleakが1つ出ますが、それがステップ4でわざと入れた、あの属性です。

チームの規約をファイルに書く

/root/tp-attrs/convention.tsvを作成してください。1行が1つのキーで、タブで区切った4つの欄<열쇠><탭><타입><탭><허용값><탭><고유값성격>(プレースホルダーはキー、タブ、型、許容値、ユニーク値の性格です)です。型はstring・int・bool・denyのいずれか、許容値は*(制限なし)か|でつないだリスト、ユニーク値の性格はfreeまたはlowです。ステップ5に現れた10個のキーのうち、shop.error.messageはdenyで禁止し、代わりにshop.error.kindをdeclined|timeoutで新しく入れてください。ステップ8で使うshop.refund.amount(int・free)もあらかじめ入れ、生の値の禁止キーshop.customer.email・shop.payment.card_pan・shop.auth.tokenもdenyとして書きます。denyの行の許容値と性格の欄は-にします。

規約を文章だけで残すと、次の人は読みません。機械が読める表にしてこそ検査プログラムを付けられます。禁止キーを一緒に書く理由は、「入れないようにしよう」という合意がコードレビューの中だけで生きていると、結局漏れるからです。行数は15です。

規約を破ったスパンを見つける検査プログラムを作る

/root/tp-attrs/lint_spans.pyを作成してください。python3 lint_spans.py <규약파일> <덤프>(プレースホルダーは規約ファイルとダンプです)で呼び出すと、規約を破ったキーごとにVIOLATION <열쇠> <이유>(プレースホルダーはキーと理由です)をキー名の昇順で1回ずつだけ出力して終了コード1、破ったものがなければOKで始まる1行と終了コード0を返します。見るべきものは4つです。規約にないキー、denyで禁止したキー、型が異なる値、許容値のリストにない値。これに加えて、lowと宣言したキーのユニーク値がダンプ内で20を超えたら、それも違反です。作成したら、/root/tp-attrs/05-bulk.jsonlと/opt/app/tracelab/tp_attrs/noisy.jsonlにそれぞれ実行し、/root/tp-attrs/07-violations.tsvに2行<덤프파일이름><탭><깨진 열쇠들을 쉼표로 이은 것>(プレースホルダーはダンプのファイル名、タブ、破られたキーをカンマでつないだものです)をその順に書いてください。

違反をスパンごとに出力すると200行になります。キー単位で1回だけまとめて出力してください。noisy.jsonlは他のチームのダンプなので、直せません。このステップですることは「何がずれているかを機械が教えてくれるようにすること」で、直すのはステップ8で自分のコードで行います。

規約どおりに2つ目のハンドラーを計装してリンクでつなぐ

/root/tp-attrs/08_refund.pyを作成して、キューが依頼した返金ord-1027を処理するPOST /refundのSERVERスパンを1つ作ってください。属性はshop.order.id・shop.refund.amount・shop.queue.depth・shop.customer.email_hash・shop.payment.card_brand・shop.auth.token_len・shop.payment.retry_countで、失敗で終わったらshop.error.kindを加えてステータスをERRORにします(生のメッセージは入れません)。失敗した試行ごとにpayment.attempt.failedイベントを残し、orders.job_context(주문번호)(プレースホルダーは注文番号です)が返すトレース座標をリンクとして付けます(親としては付けません)。ダンプのデフォルトのパスは/root/tp-attrs/08-refund.jsonlで、ステップ7の検査プログラムをこのダンプに実行すると、OKが出る必要があります。

リンクはLink(SpanContext(trace_id=int(16진문자열, 16), span_id=int(16진문자열, 16), is_remote=True, trace_flags=TraceFlags(0x01)))(プレースホルダーは16進文字列です)を作り、start_as_current_span(..., links=[link])に渡します。キューの仕事を親として付けると、数時間前に始まって今終わるおかしな親ができます。関係はあるけれど親子ではない位置こそが、リンクです。検査プログラムがVIOLATIONを出したら、規約ではなく計装のほうを直してください。