LLM サービングを OpenTelemetry で観測する: vLLM が実際に出力するシグナル、標準との距離、コレクターでの補完

ステータス: ドラフト（2026-10-07、2026-10-09 コレクターコストの実測値補強）。 この記事の数値はすべて筆者が直接測定した値です。環境は 8GB 級 GPU 1枚、vLLM 0.31.0、Qwen3-1.7B、OpenTelemetry Collector contrib 0.162.0、サーバー 1台です。GenAI セマンティック規約はまだ 開発（Development）段階 であるため名前が変更されている最中であり（この記事を書いている日にもメトリクス名が1つ変更されました）、SGLang と Dynamo のトレーシング、トレースストレージ（Tempo、Jaeger など）およびメトリクスストレージは 未実測 です。 作成ルール: 実測データが基本であり、測定できなかったものは「未実測」と表記します。

目次

• 1. 構成
• 2. vLLM が出力するシグナル
  • 2.1 トレース: リクエストごとに llm_request 1つ
  • 2.2 メトリクス: OTLP ではなく Prometheus /metrics
• 3. 有効化のコスト
• 4. 標準との距離、そしてコレクターでの補完
• 5. 遅いリクエストをどのように見つけるか
  • 5.1 スパン属性だけで初トークン時間を切り分ける
  • 5.2 テールサンプリング vs 確率サンプリング
• 6. 遭遇した課題
• 7. OTCA の範囲と合わせて見る
• 8. 制限事項と未実測
• 参考資料

LLM サーバーが遅くなったときに知りたいことは大抵3つあります。リクエストがキューでどれくらい待ったか、計算にどれくらいかかったか、このリクエストがどのサービスのどの呼び出しから始まったか。OpenTelemetry（OTel）はこれら3つを同じ方法で残すための標準であり、試験（OTCA）で問われるコレクター、サンプリング、セマンティック規約、コンテキスト伝播はすべてここで使用されます。この記事では vLLM 単体に実際に接続してみて、5つの疑問に答えます。

1. vLLM は1つのリクエストにどのようなスパンと属性を残し、メトリクスはどのような名前で出力されるのか。
2. クライアントから始まったトレースが vLLM までつながるのか。
3. 有効化のコストはどれくらいか。
4. 標準（GenAI セマンティック規約）とどれくらい異なり、コレクターで補完できるのか。
5. 遅いリクエストのみを残すサンプリングはどのように動作し、確率サンプリングと何が異なるのか。

簡単な答え。 リクエストごとに llm_request スパンが 1つ traceparent に続いて残り、その属性だけでも初トークン時間を待ち時間と計算時間に切り分けることができました。トレーシングを有効化するコストは誤差の範囲内でした。属性名は標準と異なっていましたが（prompt_tokens 対 input_tokens）、コレクターの変換プロセッサーで変更することができました。遅いリクエストのみを残すテールサンプリングは遅いリクエスト 19件をすべて残し、確率サンプリング 10% は遅いリクエスト 22件のうち 1件だけを残しました。

1. 構成

클라이언트(계측, traceparent 전송) ──HTTP──▶ vLLM(--otlp-traces-endpoint) ──OTLP/gRPC──▶ OTel Collector ─▶ 파일(JSON)
                                              └─ /metrics(Prometheus) ◀──스크레이프── Collector(prometheus 수신기)

• vLLM 0.31.0 vllm serve Qwen/Qwen3-1.7B --otlp-traces-endpoint http://127.0.0.1:4317。同じイメージの中に OpenTelemetry SDK（1.40.0）と OTLP エクスポーターがすでに含まれていました。
• コレクターは contrib ディストリビューション 0.162.0 のバイナリを同じポッド内で実行しました。レシーバーは OTLP（gRPC）と prometheus、エクスポーターはファイルエクスポーター（JSON 1行がバッチ1つ）です。
• ストレージ（Tempo、Jaeger、Prometheus など）は接続していません。この記事は「何が出力されるか」までであり、「どこに蓄積してどのように確認するか」は 未実測 です。
• スクリプトと生データはリポジトリの docs/experiments/2026-10-07-otel-llm-serving/ にあります。

2. vLLM が出力するシグナル

2.1 トレース: リクエストごとに llm_request 1つ

クライアントが親スパンを作成し、W3C traceparent ヘッダーを付与してリクエストを3つ送信しました。コレクターに到着した vLLM スパンは3つすべて llm_request（種類 SERVER）であり、 親スパン ID がクライアントスパンの ID と同じであり 、トレース ID も同じでした。つまり、クライアントから始まったトレースが vLLM の内部までつながっていました。

1つのスパンの属性は12個であり、設定を変更しても同じ12個でした。

含まれていないことも重要です。モデル名（ズバリgen_ai.request.model）と gen_ai.operation.name がこのスパンに存在せず、リソースの service.name は unknown_service でした。サービス名を指定しないと、複数のサーバーのスパンが1つの名前の下に混ざってしまいます。環境変数 OTEL_SERVICE_NAME で指定するか、コレクターの resource プロセッサーで service.name を埋めることができます（セクション 4 では後者を使用しました）。

サーバーを起動するプロセスもトレースとして残ります。 llm_request とは別に、起動時の数十個のスパンが1つのトレースとして出力されました。モデルファイルがすでに存在するサーバー4台の平均として、 Overall Loading が 18.7秒、 EngineCoreProc init が 14.1秒、 Prepare model が 6.7秒、 Executor init が 6.1秒、 Load model が 3.4秒、 Warmup (GPU) が 2.7秒、 Load weights が 1.8秒でした（スパンが互いに親子として含まれているため、単純に足し算してはいけません）。最初に起動したサーバーは重みのダウンロードに298秒かかり、 Overall Loading は 341秒でした。「サーバーがなぜ起動に時間がかかったのか」をログを探し回ることなくスパンの時間から読み取ることができます。

2.2 メトリクス: OTLP ではなく Prometheus /metrics

このバージョンでは、メトリクスは /metrics（Prometheus 形式）でのみ確認できました。コレクターの prometheus レシーバーで 5秒ごとに取得すると 93個の名前が出力され、有用なものは以下の通りです（すべて vllm: プレフィックス）。

3つの事柄を確認しました。

• _created シリーズがメトリクスとして漏れ出します。 Prometheus 形式の _created 行がレシーバーによってゲージに変換され、無意味な名前が10個中4個近く（36個）になりました。スクレイプ設定の metric_relabel_configs で .*_created を除外すると 57個に減少しました。
• ヒストグラムは累積（cumulative）であり、単位が空になっています。 レシーバーが作成した TTFT ヒストグラムの aggregationTemporality は累積（2）であり、 unit は空で（標準は秒を表す s）、ラベルは engine と model_name でした。120リクエストの負荷をかけた後の合計が 51.76秒であるため平均は 0.43秒ですが、バケット分布（0.25〜0.5秒 49件、0.5〜0.75秒 19件、1〜2.5秒 7件）が平均値より多いことを示しています。
• メトリクス名のコロン（vllm:...）はそのまま維持されます。

3. 有効化のコスト

同じ負荷（入力 512、出力 128、同時実行 1・8・32）を3つの設定でサーバーを2回ずつ再起動して測定しました。サーバーを起動するたびに KV キャッシュの割り当てが変わる可能性があるため（パート 14）サーバーログを確認し、6つのサーバーすべてで 26,560トークンでした。

• トレーシングを有効化しても、スループットと初トークン時間は 1% 以内であまり変わりませんでした。 リクエストごとにスパンを1つ作成するコストは、このモデルの1リクエスト（1トークンあたり約 15ms）に比べて小さかったです。より小さいモデルや、より速いトークン生成速度では比率が大きくなる可能性がありますが、測定はしていません（未実測).
• --collect-detailed-traces all はこのバージョンでスパンも属性も増やしませんでした。 4つのサーバー（有効2、詳細2）で収集した 500個のリクエストスパンはすべて同じ12個の属性を持っていました。オプションの説明には「性能に影響を与える可能性がある」と記載されていますが、この試験では違いを確認できませんでした。
• ストレージ容量は JSON として 500スパンが 612KB（1スパンあたり約 1.2KB）でした。ファイルエクスポーターの JSON サイズであり、OTLP の転送サイズやストレージのサイズではありません。

4. 標準との距離、そしてコレクターでの補完

OpenTelemetry の GenAI セマンティック規約は別のリポジトリ（semantic-conventions-genai）に移行され、ステータスは 開発 です。確認した時点（2026-10-06 の最新コミット）の内容と vLLM が出力したものを比較すると以下の通りです。

標準がまだ開発段階であるため、どちらかが「間違っている」というよりは、vLLM が標準が固まる前の名前を使用している状態です。利用側としては、コレクターに翻訳させればサーバーを変更する必要はありません。以下の設定を実際に動かして確認しました。

processors:
  resource/service:
    attributes:
      - {key: service.name, value: vllm, action: upsert}
  transform/genai:
    trace_statements:
      - context: span
        statements:
          - set(attributes["gen_ai.usage.input_tokens"], attributes["gen_ai.usage.prompt_tokens"]) where attributes["gen_ai.usage.prompt_tokens"] != nil
          - set(attributes["gen_ai.usage.output_tokens"], attributes["gen_ai.usage.completion_tokens"]) where attributes["gen_ai.usage.completion_tokens"] != nil
          - delete_key(attributes, "gen_ai.usage.prompt_tokens")
          - delete_key(attributes, "gen_ai.usage.completion_tokens")
  metrics_transform/genai:
    transforms:
      - {include: "vllm:time_to_first_token_seconds", action: update, new_name: gen_ai.server.time_to_first_token}
      - {include: "vllm:inter_token_latency_seconds", action: update, new_name: gen_ai.server.time_per_output_token}
      - {include: "vllm:e2e_request_latency_seconds", action: update, new_name: gen_ai.server.request.duration}

その結果、スパンのサービス名が vllm になり、トークン数の属性が input_tokens, output_tokens に変更され（旧名称は消滅）、メトリクス名 3つが gen_ai.server.* に変更されました。ただし、値の 意味 まで標準と同じであるかは名前だけでは分かりません。例えば、標準の初トークン時間は「成功したレスポンスの初トークンまで」であり、vLLM の値が同じ区間であるかは確認していません（未実測）。単位も先ほど見たように空であるため、別途補う必要があります。

5. 遅いリクエストをどのように見つけるか

5.1 スパン属性だけで初トークン時間を切り分ける

サーバー 4台（トレーシング有効 2、詳細有効 2）で収集したリクエストスパン 500個のうち、初トークンに 1秒以上かかったリクエスト 69個と 0.2秒未満の 38個を比較しました。

遅いリクエストの初トークン時間のうち、待ち時間が占める割合の中央値は 59% でした。遅いリクエストは計算が遅いからではなく、行列に並んだために遅くなっており、これは「GPU をより速いものにする」のではなく「同時処理の限界とレプリカ数を増やすか、リクエストを制限する」という対策につながります。初トークン時間が待ち時間とプレフィラの和と完全に一致するわけではなく、差の中央値は 78ms、最大 221ms でした（トークナイゼーションや最初のデコード段階などと推測されますが、分解はしていません）。リクエストの全体時間は、初トークン時間とデコード時間の和と 1.1ms 以内で一致していました。

5.2 テールサンプリング vs 確率サンプリング

混雑負荷（入力長が64、512、1,500トークン、同時16）でリクエスト120件を送信しました。クライアントで測定したリクエスト時間は中央値2.08秒、p90 2.73秒、最大3.02秒であり、サーバ側のスパン時間で2.5秒以上のリクエストが19件ありました。

• テールサンプリングはトレース終了後に遅延を確認して決定するため、遅いリクエストをすべて残しました。 残ったトレースの最小遅延は2,551msであり、全体トレースの16%のみを保管しました。
• 確率サンプリングは遅いかどうかを知らずに抽出するため、遅いリクエストがサンプル比率の通りにしか残りませんでした。 10%を抽出したところ実際には13%（ハッシュの偏り）が残り、その中で遅いものは1件でした。平均遅延は似たように見えても、最も確認したいテールが消えてしまいます。
• テールサンプリングの代償は、トレース全体を同じコレクターが集めて decision_wait の間メモリに保持していなければならないという点です。このテストはトレースが120〜300件しかないためコストが見えないため、同じコレクター（0.162.0）と同じポリシーをMacBook（Apple M1 Max）で合成負荷（トレースあたりスパン2個、属性12個）を用いて個別に測定しました。決定前に失わないように num_traces を「秒間トレース × decision_wait × 1.2」に設定すると、Goヒープがメモリ上のトレース1つあたり約4KB（2.6〜4.7KB）ずつ増加しました。秒間1万スパンでdecision_waitが5秒、10秒、30秒の場合、ヒープは161MB、293MB、850MB（RSSは385MB、546MB、1.2GB、30秒はCPU競合が少なかった1回目の値）であり、秒間4万3千〜4万5千スパンで10秒と30秒の場合は1.2GBと3.3GB（RSSは1.7GB、4.0GB）でした。テールサンプリングのない同じパイプラインのRSSは同じ速度で268〜292MBでした。メモリは結局「スパン速度 × decision_wait」に比例します。
• num_traces を小さく（10,000）設定して大きな負荷を受けると、トレースを静かに破棄します。 マップが一杯になると最も古いトレースから削除しますが、決定前に削除されたトレースは残りません。秒間1,000スパンでは失われたものはありませんでしたが、秒間1万スパンでは新しいトレースの88.5〜88.7%、秒間3万9千〜4万7千スパンでは97.3〜97.6%が決定前に消え、10%確率ポリシーが実際に残したのは1.2%と0.3%でした。コレクターのログには警告がなく、 otelcol_processor_tail_sampling_sampling_trace_dropped_too_early の指標だけで確認できました。 num_traces は少なくとも「秒間トレース × decision_wait」より大きく設定し、この指標にアラートを設定する方が安全です。
• 複数のサービスを経由するトレースでは、サービスごとに異なるコレクターに送信してはならず、トレースIDで同じ場所に集める必要があります（公式ドキュメントの説明であり、このテストでは確認していません）。

6. 発生した問題

• tail_sampling の numeric_attribute ポリシーはこの属性では何も残しませんでした。 最初の試行は最初のトークン時間属性（浮動小数点数、秒）の最小値でフィルタリングしたところ、残ったトレースは0であり、警告やエラーもありませんでした。原因は特定できていません（ドキュメントの例は整数値であり、 min_value も整数に見えます）。トレース長を確認する latency ポリシーに変更して動作しました。ポリシーが何も残さなかったときに静かである点が危険です。サンプリングを変更する時は、残った数を必ず数えてみる必要があります。
• metricstransform の名前はもはや推奨されません。 コレクターの起動時に「エイリアスが非推奨となったため metrics_transform を使用せよ」と警告されました。
• コレクターが開いたファイルを切り詰めると、ファイルの先頭がNULバイトで埋め尽くされます。 エクスポートファイルを : > file で空にしたところ、コレクターが以前の位置に追記し、前半部分が \0 で埋められ、JSONの読み込みが最初の行で失敗しました。ファイルを空にするには、コレクターを停止するか、新しいパスを使用する方が安全です。
• Prometheusレシーバーは、サーバーが起動する前にスクレイプ失敗の警告を5秒ごとに発生させます。 サーバーの準備が整った後に消え、データには影響がありませんでした。
• vLLMサーバーのKVキャッシュ容量が最初に起動したサーバーで最小だった現象（第14回）が、今回のテストでも発生しました。 最初に起動したサーバー（22,048トークン）とその後のサーバー（26,560トークン）で異なっており、オーバーヘッドの比較にはその後のサーバーのみを使用しました。

7. OTCAの範囲と関連リンク

この実験がテスト範囲のどの項目を直接示しているのかを整理します。

LabHubのOTCAコースには、この内容を実際のスパンとヒストグラムで直接計算してみるモジュール（otca-llm-serving、実習7段階）を追加しました。デプロイが完了した環境で表示されます。

8. 制限事項と未計測事項

• サーバー1台、モデル1つ（1.7B）、GPU1枚です。複数のサーバー間でトレースがどのようにつながるか（ゲートウェイ、ルーター、分離サービングのワーカー間）は測定していません（未計測).
• SGLangのトレーシングとDynamoのOTelエクスポートは測定していません（未計測）。vLLMの値を他のエンジンに一般化することはありません。
• トレースとメトリクスのストレージを連携させていません。可視化とアラート、ストレージのコストは 未計測 です。
• プロンプトと応答の内容をスパンやイベントとして残す設定、それに伴うプライバシーの問題は扱っていません。
• コレクター自体のコストは、MacBook（Apple M1 Max）で同じコレクター（0.162.0）と合成負荷を用いて個別に測定しました。CPUはスパン速度にほぼ比例し、秒間1万スパンあたり0.13〜0.15コア（受信してファイルに書き込むだけ）、変換プロセッサを追加して0.14〜0.16コアであり、秒間4万5千〜4万7千スパンで0.57〜0.63コア、RSSは約290MBでした。ほぼアイドル時でもRSSは186〜199MBでした。受信拒否とエクスポート失敗はすべての条件で0でした。遅延はコレクターの処理自体が中央値3.5msであり、残りは設定によって決まりました。この記事と同様の batch 1秒とファイルエクスポートの1秒のflushを設定すると、スパンがファイルに現れるまでに0.94〜1.99秒（中央値1.46秒）、テールサンプリングを追加すると6.0〜7.0秒でした。この値は、他の実験が同時に実行されてCPUがほぼ飽和状態だったMacBookで測定したものであるため、サーバーのCPUの値とは異なる可能性があります。絶対値よりも「CPUは速度に比例する」、「遅延はバッチとdecision_waitによって決まる」という方向性を信頼する方が得策です。OTLPでリモートストレージに送信する際のネットワークとリトライのコスト、コレクターが受信拒否を開始する限界速度は測定していません（未計測).
• オーバーヘッドはサーバーを2回起動した値であり、標準偏差は求めていません。1%以内という結論の方向性は確実ですが、小数点以下は信用しない方が良いです。
• GenAI規約は開発段階であるため、この記事の表は2026-10-06時点のものであり、まもなく変更される可能性があります。

参考資料

• OpenTelemetry GenAIセマンティック規約（リポジトリ）：https://github.com/open-telemetry/semantic-conventions-genai（推論スパン docs/gen-ai/client-inference.md、サーバー指標 docs/gen-ai/gen-ai-metrics.md)
• OpenTelemetry Collector contrib 0.162.0とテールサンプリングプロセッサのドキュメント：https://github.com/open-telemetry/opentelemetry-collector-contrib/tree/v0.162.0/processor/tailsamplingprocessor
• vLLMのトレーシング： vllm serve --help=all の --otlp-traces-endpoint, --collect-detailed-traces、およびインストール版の vllm/tracing/ コード
• このシリーズの第14回（vLLMの負荷とKVキャッシュ）、第24回（Dynamo）、第20回（リアルタイム音声遅延の分解）