切れてもスパンは残る

一言でいうと

伝播が途切れても、各サービスのスパンはそのまま残ります。そのため、症状が「トレーシングができない」ではなく「リクエストの後ろの部分が見えない」として現れます。

なぜ本物のリクエストが行き交う必要があるのか

前のモジュールで、伝播とコレクターを扱いました。しかし、それらのラボが動く場所ではリクエストが行き交わないため、伝播が途切れる現象そのものが起こりませんでした。OTCAで最もよく問われる箇所なのに、です。

途切れたものは静かである

伝播が途切れても、各サービスのスパンはそのまま残ります。画面を開くとトレースがあり、名前も時間も正常です。ただ、1つにつながらないだけです。

そのため、症状は「トレーシングができない」ではなく、なぜこのリクエストの後ろの部分が見えないのかという形になります。原因を探すのがずっと難しくなります。

1. 라이브러리가 헤더를 안 붙인다      직접 만든 HTTP 클라이언트가 흔하다
2. 프록시가 헤더를 지운다             허용 목록에 traceparent 가 없다
3. 큐를 건너갈 때 잃는다              메시지 본문에 넣어 손으로 이어야 한다
4. 스레드·비동기 경계에서 끊긴다      컨텍스트가 따라가지 않는다

このコードブロックの韓国語は、順に、ライブラリがヘッダーを付けない(自作のHTTPクライアントによくある)、プロキシがヘッダーを消す(許可リストにtraceparentがない)、キューをまたぐときに失う(メッセージ本文に入れて手でつなぐ必要がある)、スレッドや非同期の境界で途切れる(コンテキストがついてこない)、という4つの原因を述べています。

後ろの2つが特に静かです。HTTPはヘッダーを見ればわかりますが、キューと非同期は、のぞき込む場所が見当たりません。

気づくには、親のないスパンの割合をメトリクスとして置く必要があります。あるサービスで常にルートスパンが作られているなら、その前が途切れているのです。

スパンが到着したのに画面にないとき

ラボを作る中で、実際に引っかかった箇所です。コレクターのログにはスパンが入ってきたと出力されるのに、画面には何もありませんでした。

タイムスタンプが原因でした。小さい数を入れたところ、1970年として索引付けされ、デフォルトの照会範囲(最近)で見つかりませんでした。そして、JaegerのクエリAPIは、時間範囲を渡さないと空の結果を返します。

キューをまたぐ伝播を手でつなぐ

HTTPは計装ライブラリがヘッダーを付けますが、メッセージキューは、誰も代わりにやってくれません。発行するときにコンテキストをメッセージに入れ、消費するときに取り出す必要があります。

from opentelemetry import propagate, trace

# 발행 쪽 — 현재 컨텍스트를 헤더 맵에 주입한다
def publish(body):
    carrier = {}
    propagate.inject(carrier)                  # traceparent 가 여기 들어간다
    queue.send({"body": body, "otel": carrier})

# 소비 쪽 — 꺼낸 컨텍스트를 부모로 삼는다
def consume(msg):
    ctx = propagate.extract(msg.get("otel") or {})
    with tracer.start_as_current_span("handle", context=ctx,
                                      kind=trace.SpanKind.CONSUMER):
        handle(msg["body"])

start_as_current_spanにcontext=を渡さないと、新しいルートスパンができ、トレースがその地点で途切れます。これが、親のないスパンが増える最もよくある原因です。

非同期の境界では、kindも合わせます。PRODUCERとCONSUMERを指定しておくと、UIがキューの区間を別の描き方で表示してくれ、キューで待った時間が目に見えるようになります。

カーディナリティがコストを決める

スパンの属性(attribute)に何を入れるかが、保存コストと照会の速度を左右します。

入れてよいもの	入れてはいけないもの
`http.route` (`/users/{id}`)	`http.target`の全文(`/users/48213`)
`db.system`, `db.operation`	SQL全文(パラメーター込み)
`messaging.destination`	メッセージ本文
テナントID(値が数百個)	ユーザーID(値が数百万個)

パスをそのまま入れると、属性値がリクエスト数の分だけ増えて、索引が爆発します。テンプレートに正規化したルートを使います。そして、個人情報は、どのような場合でも属性に入れません。トレースは、たいてい保持ポリシーがゆるく、多くの人が見ます。

何から計装するか

すべてを計装しようとすると、始められません。順序があります。

エントリポイント: HTTPサーバーとキューのコンシューマーです。ここだけでも、「どのリクエストが遅いか」には答えられます。
外へ出ていく呼び出し: HTTPクライアント、DB、キャッシュです。ここまであれば、「どこで遅いか」がわかります。
アプリケーションの内部: 重い計算の部分だけを選んで入れます。関数ごとにスパンを作ると、コストが増えるだけで、画面が読みにくくなります。

1と2は、自動計装でほとんど得られます。手で書くのは、3からです。

実務で本当に大切なこと

親のないスパンの割合をメトリクスとして置きます。伝播が途切れたことを人が見つける、事実上唯一の方法です。あるサービスで常にルートスパンが作られているなら、その前が途切れているということで、そうすれば地点を特定できます。

キューと非同期の境界は、手でつなぐ必要があります。HTTPは計装ライブラリがヘッダーを付けてくれますが、メッセージ本文にコンテキストを入れて取り出す作業は、誰も代わりにやってくれません。キューを使う区間があるなら、その区間の伝播は設計の段階で入れておく必要があります。

スパンが見えないときは、まずタイムスタンプを見ます。ナノ秒ではない値を入れると、1970年として索引付けされ、デフォルトの照会範囲では永遠に見つかりません。コレクターのログに「受け取った」と出力されるのに画面が空なら、ほぼこのケースです。

次のラボで、これらを本物のコレクターと本物のリクエストの上で、自分で確認します。