コンテンツにスキップ

第12章 デバッグと監視 — 解答例

本文: 第12章 デバッグと監視

→ 参照: 12.2.2節、12.6.1節、12.6.2節

(a) 診断できないこと

  1. モデルがそのとき何を見ていたか。 ツール結果の内容が記録されていないため、「ツールが誤った情報を返した」のか「正しい情報を誤って解釈した」のかを区別できない。12.6.1節のフローチャートの最初の分岐がここで止まる。
  2. どのステップで方向がずれたか。 ツール名しかないため、引数も結果も分からない。エラーが出た場所と原因の場所が離れている(誤りの累積)という前提のもとでは、遡る手がかりが存在しない。
  3. どの条件下での失敗か。 プロンプトのバージョン、要求モデルと応答モデル、パラメータが記録されていない。「たまに」起きるということは、条件の違いが原因である可能性が高いのに、その条件を切り分けられない。

(b) 追加すべき記録項目

項目 何の診断に使えるか
gen_ai.request.model / gen_ai.response.model エイリアス使用時にどのスナップショットが応答したか。モデル更新による挙動変化の切り分け(第2章2.6節)
プロンプトのバージョン(ハッシュまたはコミットID) 「先週の失敗はどのプロンプトのものか」。第11章の評価との突き合わせ
ツールの引数と結果(サイズ・切り詰めの有無を含む) ツール側の誤りか解釈の誤りかの切り分け。コンテキスト膨張の追跡
gen_ai.input.messages / gen_ai.output.messages コンテキストの再現(12.6.2節)。デバッグ速度を最も大きく変える
gen_ai.response.finish_reasons と入出力トークン数 max_tokens での打ち切り検出(第2章2.3.4節)、コンテキスト膨張の検出

(あと2つ挙げるなら: iteration と parent_id(ステップの順序と階層の再構成)、キャッシュ読み書きトークン数(コスト異常の切り分け)。)

(c) 記録を追加しても実行できないステップ

「その時点のコンテキストを丸ごと再現して確認」は、(b)の項目だけでは実行できない。 12.6.2節が明示するとおり、gen_ai.input.messages に加えてシステムプロンプトとツール定義も記録する必要がある。ツール定義が変われば同じメッセージ列でもモデルの挙動は変わるため、これがないと再現にならない。

さらに、記録を完備しても残る限界が2つある。

  • 内容記録は既定でオフであり(12.3.2節)、有効にする時点で機微情報の扱い・マスキング・保持期間を設計する責任が生じる。マスキングした内容で再実行すると、それは元の実行の再現ではない。
  • 「たまに」起きる不具合は、再現しないことがある。 temperature=0 でも完全な再現性はない(第2章2.3.1節)。同じコンテキストで再実行して正常に動いても、それは不具合がないことの証明にはならない。この場合、単発の再現ではなく同じコンテキストを複数回実行して失敗率を測る、あるいは失敗トレースをまとめてモデルに分析させる(12.6.3節)ほうが有効である。

→ 参照: 12.5.1節、12.5.3節、11.3.3節

(a) コストが2週間で1.6倍、完遂率とステップ数は横ばい

11.3.3節の「コストだけが増加 → コンテキストが膨らんでいる」に一致する。ステップ数が同じでコストが上がったのだから、1ステップあたりの入出力が増えている。候補は、①ツール出力サイズの増大(参照先の文書やDBのレコードが増えた)、②キャッシュヒット率の低下、③システムプロンプトやツール定義の肥大化、④エイリアス指定で高価なモデルに切り替わった。

絞り込み: gen_ai.usage.input_tokens をステップ番号別・日別に時系列で見る。cache_read の比率、tool.output_chars をツール別に分布で比較(2週間前と当日)、gen_ai.response.model の値の分布を確認。ツール別の出力サイズが1つだけ跳ねていれば原因は特定できる。

(b) P50 は不変、P95 が3倍

12.5.1節①のとおり P95 の悪化は一部ユーザーの体験を大きく損なう。全体が遅いのではなく、重い尾が伸びている。候補は、①レート制限に当たって再試行とバックオフが入っている(第10章10.2.4節)、②特定のツールが遅くなった(外部APIの劣化)、③特定のテナント・特定の入力だけコンテキストが巨大、④ステップ数の裾が伸びている(停滞)。

絞り込み: トレースを実行時間の降順に並べ、上位5%だけを対象にする。その中で execute_tool スパンの duration_ms をツール別に集計し、遅延がツール側かLLM側かを分ける。LLM側なら入力トークン数との相関を、ツール側ならエラー・再試行の有無を見る。あわせて上限到達率とレート制限エラーの発生率を確認する。

(c) キャッシュヒット率が90%から12%に急落

プロンプトの前方が変わっている(第2章2.2.2節)。キャッシュは接頭辞一致で効くため、先頭に可変要素が入ると一気に無効化される。候補は、①システムプロンプトに現在時刻・ユーザー名・セッションIDなど毎回変わる値を差し込んだ、②ツール定義の順序や内容が変わった(ツールを1つ追加しただけでも前方が変わる)、③cache_control の付け忘れ、④モデルやリージョンの変更。「急落」であることがデプロイ起因を強く示唆する。

絞り込み: 落ち込んだ時刻とデプロイ履歴を突き合わせる。プロンプトのバージョン(12.2.2節で記録を推奨した項目)別に cache_read 比率を集計すれば、どのバージョンから落ちたかが1クエリで分かる。これがプロンプトバージョンを記録しておく価値の実例である。

(d) 完遂率は横ばい、人間へのエスカレーション率が2倍

12.5.1節④の観点。完遂率が横ばいなのにエスカレーションが増えているのは、完遂の定義が「エスカレーションも完遂に数える」形になっている可能性がまずある。それを除くと、①入力分布の変化(これまでなかった種類の依頼が来ている)、②ツールの権限や参照先が変わって自律的に解けなくなった、③ガードレールが過剰に発火している、④ドリフト(12.5.3節)。

絞り込み: エスカレーションしたトレースを理由別に分類する。ツールのエラーで詰まったのか、情報が足りなかったのか、ガードレールで止まったのか。そのうえで2週間前とのコホート比較を行い、入力そのものをクラスタリングして新種の依頼が増えていないかを見る。これは急な障害ではなくドリフトの典型であり、時系列で追わなければ見えない。 第11章11.8節の人間による定期レビューが並行して機能していれば、内容の変化を早く掴める。


→ 参照: 12.3節、13.4節

(a) 開発環境(少人数のチーム)

  • 方針: スパン属性に全文を記録(12.3.2節の中段)。開発では再現デバッグの速さが最優先であり、システムプロンプトとツール定義も含めて記録する(12.6.2節)。
  • 保持期間: 14〜30日程度。 開発中の調査は直近のものが対象であり、長く持つ意味は薄い。
  • 前提となる規律: 本番データを開発環境に持ち込まない。 「開発環境だから何を記録してもよい」のではなく、扱うデータが合成・テスト用だから記録してよいのである。本番のトレースを持ち込んで調査する運用があるなら、その時点で(b)や(c)の基準が適用される。

(b) 本番・医療機関向け(患者情報を含む)

  • 方針: 既定はオフ。 記録するなら外部ストレージ方式(内容はアクセス制御された別ストレージ、スパンには参照のみ)+ 保存前のマスキング。12.3.3節の注意どおり正規表現では人名・住所を捕捉しきれないため、専用のPII検出(第13章13.4.2節)を用いる。
  • 保持期間は2種類に分けて設計する(12.3.3節の注意書き)。
    • デバッグ目的: マスク後の内容を短期(7日程度)。プライバシーの観点が上限を決める。
    • 監査目的: 内容全文ではなく、「どのツールをどの引数で呼び、何を根拠に判断したか」の要点を長期保持。説明責任の観点が下限を決める(第13章13.8.3節)。規制業種では法定の保存期間が下限になる。
  • あわせて確認すること: プロバイダの規約・データの所在地(リージョン)(第13章13.4.2節⑤)、可観測性ツールがSaaSなら送信可否 — 送れないなら自前ホスティング可能なもの(12.7.1節①)。削除要求に応える仕組みも設計に含める。

(c) 本番・社内の開発者向けコード検索アシスタント

  • 方針: スパン属性に記録、ただしシークレットのマスキングは必須。 PIIは少ないが、コードやリポジトリ設定にはAPIキー・トークンが混入しうる。12.3.3節の sk-... / Bearer ... のパターンは最低限適用する。ソースコード自体が機密であるなら、データの所在(SaaSか自前ホスティングか)を先に判断する。
  • 保持期間: 30〜90日。 利用者が社内の開発者であり、内容の機微性は(b)より低い一方、デバッグ需要は高い。加えて、本番トレースから評価データセットを作る回路(第11章11.8.2節)を回すには、ある程度の期間残っている必要がある。
  • 量の問題に注意(12.3.1節)。コードは長いため、全入出力を保存するとストレージコストが無視できない。サンプリング(全体の10%だけ内容を記録する等)も選択肢になる。

→ 参照: 12.2.3節、第10章10.2.4節

(a) 非同期処理では正しく動かない。

Tracer は親子関係を self._stack という単一のリストで管理している。同期的な入れ子なら成立するが、asyncio.gather で複数のツールを並列実行すると、複数のスパンが同時に開いた状態になる。このとき、

  • タスクBで開いたスパンの parent_id が、たまたま直前にタスクAが積んだスパンになる。親子関係が嘘になる。
  • finally の self._stack.pop() が自分のスパンとは限らないものを取り除く。以降の親子関係が全面的に崩れる。

対処は、共有リストをやめて contextvars.ContextVar で「現在のスパン」を持つことである。asyncio はタスク生成時にコンテキストをコピーするため、gather に渡した各コルーチンは独立した値を持つ。

(b) スパン終了時にしか emit() されないため、長時間かかるスパンは終わるまで一切見えない。 数時間動くエージェントでは、ルートスパン(invoke_agent)の記録が最後まで出てこない。対処は2つ。

  1. 開始時にも1レコード出す。 同じ span_id で phase: "start" / phase: "end" の2レコードにする。開始側には duration_ms がない代わりに、開いたまま終わっていないスパン(=いま動いている処理、あるいはハングした処理)が検出できるようになる。
  2. 途中経過をイベントとして出す。 span.event("tool_progress", processed=120) のようなメソッドを設け、節目で1行出す。長時間のツール実行やステップの進行状況はこれで追える。

(c) trace_id が Tracer インスタンスに固定されているため、1つの Tracer を共有して複数タスクを処理すると、全タスクが同じ trace_id になり、トレースが混ざって分離できない。 対処は、タスクごとに Tracer を作るか、trace_id も ContextVar に移す。後者なら1つの Tracer をアプリケーション全体で共有できる。

(a)(c) をまとめた修正版

import contextvars, time, uuid, json, logging
from contextlib import contextmanager
logger = logging.getLogger("agent.trace")
_current_span: contextvars.ContextVar["Span | None"] = \
contextvars.ContextVar("current_span", default=None)
_trace_id: contextvars.ContextVar[str | None] = \
contextvars.ContextVar("trace_id", default=None)
class Tracer:
@contextmanager
def trace(self, name: str = "invoke_agent", **attributes):
"""1タスク = 1トレース。ここで trace_id を確定させる。"""
token = _trace_id.set(uuid.uuid4().hex)
try:
with self.span(name, **attributes) as root:
yield root
finally:
_trace_id.reset(token)
@contextmanager
def span(self, name: str, **attributes):
parent = _current_span.get() # (a) 共有スタックをやめる
span = Span(
name=name,
trace_id=_trace_id.get(), # (c) トレース単位で切り替わる
span_id=uuid.uuid4().hex[:16],
parent_id=parent.span_id if parent else None,
attributes=attributes,
)
token = _current_span.set(span)
span.emit(phase="start") # (b) 開始時にも出す
try:
yield span
except BaseException as e:
span.error = f"{type(e).__name__}: {e}"
raise
finally:
span.end = time.monotonic()
_current_span.reset(token) # 自分のトークンだけを戻す
span.emit(phase="end")

注意点: ContextVar がタスクごとに独立するのは、コルーチンが asyncio.Task として起動されたときである(asyncio.gather はコルーチンをタスクに包むため成立する)。同一タスク内で直接 await するだけの場合はコンテキストが共有されるが、その場合はそもそも同時に開かないので問題にならない。スレッドプールに逃がす処理(run_in_executor)では別途コンテキストの伝搬が必要になる点は残る。


→ 参照: 12.5節、第11章11.4.2節、12.3節

(a) 同じ指標でも意味が異なる理由は、入力の分布が統制されているかどうかにある。

評価は、固定されたデータセットに対して測る。 入力が変わらないので、スコアの変化はシステム側の変化だけを意味する。だから「プロンプトを変えたら完遂率が3ポイント落ちた」は因果に近い情報になる。

監視は、本番の実トラフィックに対して測る。 入力の分布は統制されておらず、日々変わる。だから「完遂率が3ポイント落ちた」は、システムが劣化したのかもしれないし、難しい依頼が増えただけかもしれない。監視の数値は、単独では原因を特定しない。

この非対称性から、実務上の含意が出る。

  • 監視で異常を見つけたら、同じ条件を評価セットで再現できるかを確かめる。再現すればシステムの問題、再現しなければ入力分布の変化である。
  • 逆に、評価スコアが良くても安心はできない。評価セットが本番の分布から乖離していれば、その良さは本番の良さを意味しない。 これが11.4.2節で回帰テストセットに本番の失敗を追加し続けるべき理由でもある。

(b) この回路が、評価基盤を育てる唯一の現実的な経路だからである。

11.4.2節が述べるとおり、回帰テストセットは評価基盤の中で最も費用対効果が高く、そして本番で起きた失敗の蓄積からしか作れない。想像で書いたテストケースは、実際に起きる失敗を予測できない。

デバッグは1件の不具合を直すが、テストがなければ次のプロンプト変更やリファクタリングで静かに元に戻る。修正した記憶は数か月で失われる。「直す前に評価セットに追加する」という順序が重要なのは、追加してから直せばそのケースで確かに直ったことが測定として確認でき、以後は自動で守られるからである。

つまり、12.6.1節の手順は「不具合を直す作業」ではなく、デバッグの成果を資産に変換する作業として設計されている。この最後の一歩がなければ、デバッグは何度でも同じことを繰り返す。

(c) 12.3節の制約は、この回路の入口を狭める。

  1. 内容記録がオフだと、そもそもケースを起こせない。 ツール名と最終出力しかないトレースからは、再現可能な評価ケースを作れない。評価データセットを本番から作る意図があるなら、内容記録の方針はその要件から逆算して決める必要がある(12.7.1節④の「評価との統合」)。
  2. マスキング済みの内容は、そのままではケースにならない。 [PERSON_1] に置き換わった入力を評価セットに入れると、実際の入力とは違う挙動になりうる。第13章13.4.2節の注意どおり、種別を保った仮名化であっても意味は変わる。
  3. 保持期間が短いと、発見が遅れたときには素材が消えている。 週次レビューで見つけた問題のトレースが7日で消えていれば、ケース化できない。

対処: 評価セットに採用すると決めた時点で、トレースの保持ルールから切り離して別管理にする。具体的には、手作業で匿名化するか合成データに置き換えたうえで、評価データセットとして別のストアに保存する(第11章11.9節の「ツールに依存しない形で保持する」とも整合する)。これは「トレースの保持期間」と「評価データの保持期間」を別要件として扱うということであり、12.3.3節がデバッグ目的と監査目的を分けたのと同じ発想である。あわせて、利用者データを評価に使うことが規約・同意の範囲内かを確認する。


→ 参照: 12.4.4節、12.4.3節

設計方針は3つ。(i) 規約に沿って計装する、(ii) 属性名を1か所に集約する、(iii) 独自属性は接頭辞で分離する。

① 属性名を定数モジュールに集約する。 呼び出し側が文字列リテラルを書かない状態を作る。

# telemetry/attrs.py — 規約の属性名はこのファイルにしか現れない
SEMCONV_VERSION = "1.30.0" # 準拠した規約のバージョンを明示する
# --- GenAI セマンティック規約(Development ステータス。変わりうる) ---
PROVIDER_NAME = "gen_ai.provider.name"
OPERATION_NAME = "gen_ai.operation.name"
REQUEST_MODEL = "gen_ai.request.model"
RESPONSE_MODEL = "gen_ai.response.model"
FINISH_REASONS = "gen_ai.response.finish_reasons"
INPUT_TOKENS = "gen_ai.usage.input_tokens"
OUTPUT_TOKENS = "gen_ai.usage.output_tokens"
CACHE_READ = "gen_ai.usage.cache_read.input_tokens"
CACHE_CREATE = "gen_ai.usage.cache_creation.input_tokens"
REASONING_OUT = "gen_ai.usage.reasoning.output_tokens"
TOOL_NAME = "gen_ai.tool.name"
INPUT_MESSAGES = "gen_ai.input.messages"
OUTPUT_MESSAGES = "gen_ai.output.messages"
MCP_METHOD = "mcp.method.name"
# --- 独自属性。接頭辞を分けて、規約側の名前と衝突しないようにする ---
APP_PROMPT_VERSION = "app.prompt.version" # 12.2.2節
APP_TOOL_OUTPUT_CHARS = "app.tool.output_chars"
APP_TOOL_TRUNCATED = "app.tool.truncated"
APP_BUDGET_SPENT_USD = "app.budget.spent_usd"

② 記録の入口を関数にする。 呼び出し側は属性名を知らず、意味だけを渡す。属性名が変わったらこのファイルだけを直せばよい。

telemetry/record.py
from . import attrs as A
def record_llm_call(span, *, request_model, response, prompt_version):
"""LLM呼び出しの結果をスパンに記録する。属性名の知識はここに閉じる。"""
u = response.usage
span.attributes.update({
A.PROVIDER_NAME: "anthropic",
A.OPERATION_NAME: "chat",
A.REQUEST_MODEL: request_model,
A.RESPONSE_MODEL: response.model, # 12.4.3節: 要求と応答を分ける
A.FINISH_REASONS: [response.stop_reason],
A.INPUT_TOKENS: u.input_tokens,
A.OUTPUT_TOKENS: u.output_tokens,
A.CACHE_READ: getattr(u, "cache_read_input_tokens", None),
A.APP_PROMPT_VERSION: prompt_version,
"semconv.version": A.SEMCONV_VERSION, # 後から解釈できるようにする
})
def record_tool_call(span, *, name, outcome):
span.attributes.update({
A.OPERATION_NAME: "execute_tool",
A.TOOL_NAME: name,
A.APP_TOOL_OUTPUT_CHARS: len(outcome.content),
A.APP_TOOL_TRUNCATED: outcome.truncated,
"error.type": outcome.error_type if outcome.is_error else None,
})

呼び出し側は次のようになる。

with tracer.span("chat") as s:
response = client.messages.create(...)
record_llm_call(s, request_model=model, response=response,
prompt_version=PROMPT_VERSION)

③ 設計上の要点

  • semconv.version を各スパンに載せる。 規約が Development ステータスである以上、属性名は変わりうる。古いデータをどの規約で解釈すべきかが分からなくなると、時系列の比較(12.5.3節のドリフト検出)が壊れる。バージョンを記録しておけば、名前が変わっても後から読み替えられる。
  • 独自属性は禁じられていない(12.4.4節)。ただし app. のように接頭辞を分け、将来 gen_ai. 側に同じ意味の標準属性ができたときに衝突しないようにする。
  • 値が取れないなら省略する(12.4.3節)。トークン数が取得できない場合に推定値を入れない。上の例で cache_read を getattr(..., None) にしているのはそのためで、None の項目はエクスポート時に落とす。
  • record_* 関数に対するテストを書く。 属性名の定数を変えたときに、期待するキーで出力されることを確認するテストがあれば、規約の更新への追随が安全な作業になる。
  • 12.7.1節③のとおり、この構造はバックエンド乗り換えへの備えでもある。 Span の実装を OTel SDK に差し替えるとき、変更は telemetry/ 配下に閉じる。

Built with Astro ・ Deployed on Cloudflare Pages

© 2026 watakumi — made with 💜 & ☕ ・watakumi.page