初めに

AI の回答を待っているとき、こんなことはないでしょうか。

回答が返ってくるまで、1 分かかった。
文書の検索が遅いのか、AI が文章を作っているのか、SQL の実行で待っているのか。
「処理中」としか表示されないので、どこを調べればよいか分からない。

Agent が別のシステムを呼ぶと、さらに分かりにくくなります。

Agent は RAG を呼び、RAG は質問の読み取り、文書の検索、rerank を行う。別の質問では、Agent が NL2SQL を呼び、SQL を生成してデータベースで実行する。最終回答だけを見ても、途中で何が起きたかは分かりません。

そこで使うのが Tracing です。処理を区間ごとに記録し、**「何を呼んだか」「どこで時間を使ったか」「どこまで完了したか」**を、呼び出しのつながりと一緒に確認します。

Production Ready Suite では、この記録を Oracle Autonomous AI Database に保存し、Agent、RAG、NL2SQL の「実行履歴」から表示します。この記事では、自分で作った合成データを使い、画面の見方からテーブル設計、プログラムの処理まで確かめます。

文書、質問、テスト表は、この記事のために新しく作った合成データです。既存の業務文書や業務データは使用していません。2026 年 10 月 26 日に実機で確認しました。所要時間は、そのときの実測値です。

先に結論

確認したいこと	Tracing で見るところ	分かること
回答が遅い	「処理の経過」の時間の棒	検索、モデルの呼び出し、SQL 実行など、時間を使った区間
Agent が何を呼んだか	Agent の下にある MCP、RAG、NL2SQL の階層	製品をまたぐ呼び出しのつながり
SQL が実行されたか	NL2SQL の「SQL の安全性の確認」「SQL の実行」	生成しただけか、確認後に実行まで進んだか
あとから同じ処理を調べたい	実行履歴と「処理の詳細」の Trace ID	保存された処理記録との対応
記録はどこにあるか	ADB の `PLATFORM_TRACE_SPANS`	3 製品共通の span の構造、時刻、状態

今回の構成は、次のようになります。

ここで ADB は、処理の記録を保存するデータベースです。以下では、Oracle Autonomous AI Database を ADB と略します。どの区間を測るか、どの ID でつなぐか、画面にどう表示するかは、アプリケーションが実装しています。

なぜ処理の途中を記録するのか

例えば「回答に 60 秒かかった」と分かっても、それだけでは改善箇所を決められません。

記録で分かったこと	次に調べること
文書の検索に時間がかかっている	検索条件、索引、データ量、検索の前後の処理
モデルの呼び出しに時間がかかっている	モデル、入力の量、出力の量、呼び出し回数
SQL の実行に時間がかかっている	実行した SQL、対象表、実行計画
SQL を作る前に失敗している	対象の表や schema の準備、業務プロファイルの設定
Agent のツール呼び出しに時間がかかっている	呼び先の RAG や NL2SQL の内訳

Tracing の目的は、調べ始める場所を、実際の処理記録から絞ることです。

一方で、速く完了したことと、回答が正しいことは別です。回答の根拠や SQL の結果も合わせて確認します。Tracing は「処理をたどる記録」、根拠や評価は「内容を確かめる材料」です。

テスト用のデータを作る

RAG 用の文書

専用のナレッジベースと検索・回答プロファイルを作り、次の tracing-demo.md だけを取り込みました。

# Tracing 検証文書

## 合成の確認手順

これは Qiita 記事のために作成した架空の文書です。実際の業務情報は含みません。
検証用の確認コードは TRACE-DEMO-001 です。認証用の秘密ではありません。

確認手順は次の3つです。
1. 検証画面を開きます。
2. 確認コード TRACE-DEMO-001 を入力します。
3. 「確認」を押して「検証完了」と表示されることを確かめます。

検索対象をこの文書だけにするのは、回答の出典を、自分で確かめられる状態にするためです。取り込みには Unstructured を使用しました。

NL2SQL 用の表

NL2SQL の表形式データの取込機能で、新しい表 QIITA_TRACE_DEMO_20261026 を作りました。CSV の内容は次の 6 行です。

ITEM_ID,GROUP_CODE,AMOUNT
1,A,100
2,A,200
3,B,50
4,B,150
5,C,300
6,C,100

列	型	内容
`ITEM_ID`	`NUMBER`	合成の行番号
`GROUP_CODE`	`VARCHAR2(255 CHAR)`	集計するグループ
`AMOUNT`	`NUMBER`	合成の数値

業務プロファイル QIITA_TRACE_DEMO の許可表は、この表だけにしました。画面に表示される所有者名は、検証環境の接続先に応じた値です。

集計の正解は、あらかじめ手計算できます。

GROUP_CODE	計算	合計
A	100 + 200	300
B	50 + 150	200
C	300 + 100	400

小さいデータを使うのは、SQL の実行結果と処理記録の両方を、迷わず確認するためです。

Agent から RAG を呼び出す

質問する

下書きの業務 Agent に「業務 RAG 調査」のスキルを設定し、利用できるデータの範囲を、先ほどの検索・回答プロファイルだけにしました。

質問は次のとおりです。

合成の検証文書に書かれた確認コードと確認手順を教えてください。

Agent は文書を検索し、確認コード TRACE-DEMO-001 と 3 つの確認手順を、文書の根拠付きで返しました。

「実行履歴」で処理の経過を開く

「AI 活用 › 実行履歴」で対象の実行を開き、「処理の経過」のステップ数を押すと、時間の棒と親子の階層が表示されます。

今回の実行では、次の区間を確認できました。

画面の区間	実測の表示	読み取れること
全体	約 1 分 1 秒	質問に対する実行全体の時間
根拠の取得	約 15 秒	Agent が RAG から根拠を取るまでの区間
文書の検索	約 12 秒	RAG の検索工程の区間
回答の作成	約 2.2 秒	Agent が回答を作った区間
資料との照合	約 34 秒	回答を資料と照合するツールの区間

この結果なら、回答の作成よりも、資料との照合に長く時間を使っていたと分かります。照合の区間を次の調査対象にできます。

「文書の検索」の時間は、その工程全体の時間です。表示された秒数を、Oracle の 1 本の SQL の実行時間と読み替えないようにします。

呼び先の中まで見える理由

Agent の画面に RAG の工程が並ぶのは、処理名を手で列挙しているからではありません。

Agent の実行
└─ 根拠の取得
   └─ MCP の呼び出し
      └─ RAG の検索
         ├─ 質問の条件の読み取り
         ├─ 文書の検索
         │  └─ 埋め込みの作成
         └─ 検索結果の並べ替え
            └─ rerank

各区間に親の区間の ID を保存し、製品をまたいでつないでいます。階層があるので、**「RAG が単独で動いた」のか、「この Agent から呼ばれた RAG なのか」**を区別できます。

「処理の詳細」を開くと、この実行の Trace ID も確認できます。

RAG 単独で質問する

同じ文書と検索・回答プロファイルを使い、RAG からも同じ質問を実行しました。回答の生成を含む処理です。

実行履歴で「処理の経過」を開くと、質問の読み取りから文書の検索、回答の作成までが表示されます。

今回の全体は約 22 秒でした。文書の検索が約 10 秒、回答の作成と根拠の確認が約 11 秒です。Embedding と rerank も、該当する工程の子として確認できます。

処理	使用したサービス
回答を作る LLM	OCI Enterprise AI
Embedding	OCI Generative AI の Cohere Embed v4
Rerank	OCI Generative AI の Cohere Rerank v4 fast
ベクトル検索	Oracle AI Vector Search
処理の span の保存	Oracle Autonomous AI Database

AI が文章を作る処理と、Embedding・rerank は別の処理です。分けて記録すると、どちらで時間を使っているかも分かります。

「処理の詳細」では Trace ID と使用したモデルを確認できます。

この実行の「回答の安全チェック」はスキップ表示でした。工程が表示されていても、必ず実行したとは限りません。完了、失敗、スキップの状態まで読むことが大切です。

NL2SQL で SQL を生成して実行する

対象の表を絞って質問する

「SQL 生成」で、実行エンジンを Enterprise AI Direct、業務プロファイルを QIITA_TRACE_DEMO にして、次の質問を入力します。

QIITA_TRACE_DEMO_20261026のGROUP_CODEごとにAMOUNTの合計を集計し、GROUP_CODEの昇順で表示してください。

SQL と実行結果を確認する

生成された SQL は次の内容でした。

SELECT GROUP_CODE, SUM(AMOUNT) AS TOTAL_AMOUNT
FROM ADMIN.QIITA_TRACE_DEMO_20261026
GROUP BY GROUP_CODE
ORDER BY GROUP_CODE ASC

ADMIN は、この検証環境でテスト表が作成された所有者名です。再現するときは自分のテスト表の所有者に合わせます。

実行結果は A=300、B=200、C=400。先ほどの手計算と一致しました。

最初の実行後に、画面からも同じ質問を再実行して一致を確認しています。結果画面は再実行時のスクリーンショットです。

Tracing で生成と実行を分けて読む

最初の実行の履歴は、次のようになりました。

工程	記録された時間	目的
質問と対象の表の準備	約 36 ms	質問と参照対象を準備する
SQL の生成	約 2,580 ms	OCI Enterprise AI で SQL を作る
SQL の安全性の確認	約 607 ms	SELECT のみか、許可された表かなどを確認する
SQL の実行	約 153 ms	データベースで SQL を実行する
結果のまとめ	約 352 ms	取得した結果を返せる形にする
全体	約 3,805 ms	上記を含む実行全体

表は製品の工程別の計測値です。画面の時間の棒は span の開始・終了時刻から描くため、丸めや測定範囲によって表示と細部が異なります。

今回、時間を使っているのは主に SQL の生成です。SQL の実行は約 0.15 秒でした。この区別ができると、SQL の索引だけを調べ続ける、といった遠回りを減らせます。

Agent から NL2SQL を呼び出す

同じテスト表を対象に、「構造化データ照会」のスキルを設定した下書きの Agent も作りました。使える業務プロファイルは QIITA_TRACE_DEMO だけです。

質問は次のとおりです。

合成のテスト表の全行数を数えてください。絞り込み条件はありません。

Agent の下に MCP、その下に NL2SQL の確認、SQL の生成、安全性の確認、SQL の実行が表示されました。実行した SQL は SELECT COUNT(*) FROM ADMIN.QIITA_TRACE_DEMO_20261026 で、回答は 6 件です。

今回の全体は約 11 秒でした。MCP の呼び出しは約 8.8 秒で、その中には、SQL を生成する前の確認のためのモデル呼び出し約 6.9 秒も含まれています。

SQL の生成だけを見ていると、この確認の時間を見落とします。Agent 側から呼び先の処理を一緒に読む目的は、こうした ツールの中の待ち時間を見分けることにもあります。

SQL の前で止まった実行も確認する

グループごとの集計を Agent 経由でも試したところ、今回は列名の確認に戻りました。

この実行では、MCP の呼び出しは完了していますが、返却値は needs_clarification で、SQL と結果の行はありません。SQL の実行まで進んだ例としては扱いません。

単一の許可表に存在する列が、未修飾の列名では「範囲外」と判定される事象を確認しました。完全修飾名では列を解決できるため、回答前の確認での列名解決の問題として切り分けています。この問題は SQL 生成・実行が成功した前節の経路とは分けて扱います。Issue #3396 に記録しています。

Trace と span は何が違うのか

Trace は、つながった処理全体。span は、その中の 1 つの処理区間です。OpenTelemetry も、span とその親子関係で分散処理を表現します。OpenTelemetry の説明

例えば、1 回の質問で 8 つの処理区間が記録されれば、同じ Trace ID に複数の Span ID がぶら下がります。

ID	例	何を識別するか
Trace ID	32 桁の 16 進数	製品をまたいでつながった処理全体
Span ID	16 桁の 16 進数	1 つの処理区間
Parent Span ID	親の Span ID	どの区間の中から呼ばれたか
Operation ID	製品の実行 ID やジョブ ID	各製品が管理する実行単位

画面の「実行 ID」と「Trace ID」は、同じものとは限りません。 今回も、RAG の実行 ID と「処理の詳細」の Trace ID は異なっていました。NL2SQL では、履歴の ID、ジョブの ID、Trace ID をそれぞれ持ちます。

実行 ID は履歴やジョブを開くために、Trace ID は span をまとめて読むために使います。

Oracle Autonomous AI Database を使う理由

このシステムでは、アプリケーションの状態と処理の記録を、Oracle のデータベースに保存します。

保存するもの	保存先
処理の区間、親子関係、時刻、状態	共通の `PLATFORM_TRACE_SPANS`
回答、SQL、ジョブの最終状態、表示用の詳細	各製品の記録
RAG の文書や Chunk、検索用のベクトル	RAG のテーブルと Oracle AI Vector Search
今回の合成の数値データ	新しく作ったテスト表

ADB に span を保存する目的は、履歴を開いたときに、あとから同じ処理の経過を読めるようにすることです。ブラウザで一時表示するだけでは、画面を閉じた後に調べにくくなります。

また、今回の設計では、時刻や製品名は通常の列、表示の補足や属性は JSON として保存しています。ADB は JSON と通常のリレーショナルデータを組み合わせて扱えます。Oracle の JSON の説明

この構成なら、SQL で「1 回の Trace の全区間」「製品ごとの件数」「親子のつながり」を確認できます。今回も、画面表示だけでなく、ADB の実際の行を読み取りました。

ここで保存しているのは、アプリケーションが計測した処理区間です。Oracle の SQL Trace や AWR の情報とは、測定する範囲が異なります。SQL の実行計画やデータベース内部の待機を調べる場合は、それに対応するデータベース側の情報を使います。

テーブルは 1 span を 1 行で保存する

共通テーブルの設計

3 製品の共通テーブルは PLATFORM_TRACE_SPANS です。

列	型	用途
`TRACE_ID`	`VARCHAR2(32)`	処理全体をまとめる ID
`SPAN_ID`	`VARCHAR2(16)`	この処理区間の ID
`PARENT_SPAN_ID`	`VARCHAR2(16)`	呼び出し元の区間の ID
`PRODUCT`	`VARCHAR2(16)`	`agent`、`rag`、`nl2sql`
`OPERATION_ID`	`VARCHAR2(128)`	製品側の実行やジョブの ID
`ATTEMPT`	`NUMBER(5)`	再試行を区別する値
`IS_ROOT`	`NUMBER(1)`	各実行のルート span かどうか
`OWNER_USER_UUID`	`VARCHAR2(36)`	実行した利用者の識別子
`NAME`	`VARCHAR2(128)`	`mcp.request`、`nl2sql.execute` などの処理名
`SPAN_KIND`	`VARCHAR2(16)`	`internal`、`client`、`server` などの種別
`STATUS`	`VARCHAR2(16)`	実行中、完了、失敗などの状態
`STARTED_AT`	`TIMESTAMP(6) WITH TIME ZONE`	開始時刻
`FINISHED_AT`	`TIMESTAMP(6) WITH TIME ZONE`	終了時刻。実行中は未設定
`DISPLAY_KIND`	`VARCHAR2(64)`	画面の工程の表示種別
`DISPLAY_PARAMS_JSON`	`VARCHAR2(4000)`	件数など、表示名の組み立てに使う JSON
`ATTRIBUTES_JSON`	`VARCHAR2(4000)`	許可された属性の JSON
`UPDATED_AT`	`TIMESTAMP(6) WITH TIME ZONE`	行の最終更新時刻

主キーは (TRACE_ID, SPAN_ID) です。同じ Trace 内の親子関係は、PARENT_SPAN_ID と親の SPAN_ID を対応させて復元します。

IS_ROOT は、Trace 全体に必ず 1 行だけという意味ではありません。Agent の実行、MCP の受信、呼び先の実行は、それぞれの記録単位のルートになれます。同じ Trace 内でも、親があるルート span が存在します。

実際の DDL

次は、共通基盤の migration にある DDL です。

-- 現行の migration から抜粋した参照用 DDL。既存環境への再実行用ではありません。
CREATE TABLE PLATFORM_TRACE_SPANS (
    TRACE_ID VARCHAR2(32) NOT NULL,
    SPAN_ID VARCHAR2(16) NOT NULL,
    PARENT_SPAN_ID VARCHAR2(16),
    PRODUCT VARCHAR2(16) NOT NULL,
    OPERATION_ID VARCHAR2(128) NOT NULL,
    ATTEMPT NUMBER(5) DEFAULT 0 NOT NULL,
    IS_ROOT NUMBER(1) DEFAULT 0 NOT NULL,
    OWNER_USER_UUID VARCHAR2(36) NOT NULL,
    NAME VARCHAR2(128) NOT NULL,
    SPAN_KIND VARCHAR2(16) NOT NULL,
    STATUS VARCHAR2(16) NOT NULL,
    STARTED_AT TIMESTAMP(6) WITH TIME ZONE NOT NULL,
    FINISHED_AT TIMESTAMP(6) WITH TIME ZONE,
    DISPLAY_KIND VARCHAR2(64),
    DISPLAY_PARAMS_JSON VARCHAR2(4000),
    ATTRIBUTES_JSON VARCHAR2(4000),
    UPDATED_AT TIMESTAMP(6) WITH TIME ZONE DEFAULT SYSTIMESTAMP NOT NULL,
    CONSTRAINT PK_PLATFORM_TRACE_SPANS PRIMARY KEY (TRACE_ID, SPAN_ID),
    CONSTRAINT CK_PLATFORM_TRACE_SPANS_PRODUCT CHECK (PRODUCT IN ('rag', 'nl2sql', 'agent')),
    CONSTRAINT CK_PLATFORM_TRACE_SPANS_ROOT CHECK (IS_ROOT IN (0, 1)),
    CONSTRAINT CK_PLATFORM_TRACE_SPANS_STATUS CHECK (
        STATUS IN ('running', 'done', 'failed', 'cancelled', 'skipped')
    ),
    CONSTRAINT CK_PLATFORM_TRACE_SPANS_PARAMS CHECK (DISPLAY_PARAMS_JSON IS JSON),
    CONSTRAINT CK_PLATFORM_TRACE_SPANS_ATTRS CHECK (ATTRIBUTES_JSON IS JSON)
);

CREATE INDEX IX_PLATFORM_TRACE_SPANS_OP ON PLATFORM_TRACE_SPANS (PRODUCT, OPERATION_ID);
CREATE INDEX IX_PLATFORM_TRACE_SPANS_STARTED ON PLATFORM_TRACE_SPANS (STARTED_AT);

STATUS は CHECK 制約で、running、done、failed、cancelled、skipped に制限しています。JSON 列には IS JSON の制約もあります。

索引は用途に対応しています。

索引	対象	目的
主キー	Trace ID と Span ID	Trace 内の区間を一意にする
`IX_PLATFORM_TRACE_SPANS_OP`	製品と Operation ID	製品の実行から記録を探す
`IX_PLATFORM_TRACE_SPANS_STARTED`	開始時刻	時間に基づく検索や保持期限の処理に使う

共有テーブルに全文を詰め込まない

共有テーブルには、構造、時刻、状態、表示の補足を保存します。画面で開く詳細は、製品の記録側の span_details などに保存します。

製品	製品側の保存場所の例	span との対応
Agent	Oracle checkpoint 構成の `AGENT_RUNTIME_ENTITIES.ENTITY_JSON`。実行は `ENTITY_KIND='run'`	Run の `trace_id`、`span_details` など
RAG	実行履歴の `RAG_RUN_HISTORY.STAGES_JSON` 内の `trace`	`trace_id`、`trace_dropped_spans`、`span_details`
NL2SQL	`NL2SQL_STATE_DOCUMENTS.PAYLOAD_JSON`。ジョブや履歴を collection ごとに保存	ジョブや履歴の `trace_id`、`span_details` など

Agent の表名は、ここで使用した Oracle checkpoint 構成のものです。テスト用の memory 構成などまで、同じ保存先になるわけではありません。

この分担により、共通の処理の木を読みながら、詳細の表示は各製品の権限と記録に沿って行えます。

プログラムはどのように記録するのか

全体と個々の区間を計測する

共通基盤には、実行全体の operation_trace と、個々の区間の observed_span があります。

次は、使い方を絞った説明用の例です。実際のシステムでは、製品ごとの listener と owner を渡します。

with operation_trace(
    "demo.execute",
    operation_id=operation_id,
    listener=writer.listener(owner),
):
    with observed_span("demo.prepare"):
        prepare()

    with observed_span("demo.execute_sql", kind="client"):
        execute_sql()

demo.execute の下に、準備と SQL 実行の span ができます。終了したら時刻と状態を更新し、例外が発生した区間は失敗として扱います。

現行の NL2SQL が実行全体を囲む部分は、次のようになっています。長い関数のうち、該当する箇所の抜粋です。

with (
    bind_log_context(job_id=job_id),
    attach_trace_context(carrier),
    operation_trace(
        "nl2sql.execute",
        operation_id=job_id,
        attributes={"pr.attempt": trace_attempt},
        listener=self._job_progress_listener(
            job_id,
            owner_user_uuid=owner,
            attempt=max(0, trace_attempt - 1),
        ),
        links=trace_links(link_carrier),
    ) as summary,
):
    with self._lock:
        running = self._jobs.get(job_id)
        if running is not None and summary.telemetry_trace_id:
            running.trace_id = summary.telemetry_trace_id
    self._run_job_attempt_safely(job_id)

ジョブの ID と利用者、試行の番号を付け、作成された Trace ID をジョブの記録へ保存しています。これにより、あとからジョブの履歴から span を読めます。

本処理は queue に入れ、別の thread が ADB に書く

細かい区間のたびに、質問への処理が DB の保存完了を待っていると、観測のための待ち時間が増えてしまいます。

そこで TraceSpanWriter は、開始・更新・終了の通知を、まずプロセス内の queue に入れます。同じ (TRACE_ID, SPAN_ID) の未保存の通知は、最新の状態にまとめます。

書き込み部分の実際のコードは、次のとおりです。

with self.connection_factory() as connection:
    cursor = connection.cursor()
    cursor.setinputsizes(**_timestamp_input_sizes(_TIMESTAMP_BINDS))
    cursor.executemany(_MERGE_SQL, [pending.row for pending in batch])
    connection.commit()

時刻は DB_TYPE_TIMESTAMP を指定して bind しています。秒より短い処理を測るため、マイクロ秒の部分を残す設計です。

INSERT ではなく MERGE を使う

開始と終了は、別の span ではありません。同じ span の状態の変化です。

開始時   同じ Trace ID と Span ID   STATUS = running
終了時   同じ Trace ID と Span ID   STATUS = done
                                  FINISHED_AT を設定

そのため、同じ主キーの行があれば更新し、無ければ追加する MERGE を使います。実際の SQL の先頭は次のとおりです。

MERGE INTO PLATFORM_TRACE_SPANS t
USING (SELECT :trace_id AS TRACE_ID, :span_id AS SPAN_ID FROM DUAL) s
ON (t.TRACE_ID = s.TRACE_ID AND t.SPAN_ID = s.SPAN_ID)
WHEN MATCHED THEN UPDATE SET
  t.PARENT_SPAN_ID = :parent_span_id,
  t.STATUS = :status,
  t.FINISHED_AT = CASE WHEN :finished_at IS NULL THEN NULL
    ELSE FROM_TZ(CAST(:finished_at AS TIMESTAMP), '+00:00') END,
  t.DISPLAY_KIND = :display_kind,
  t.DISPLAY_PARAMS_JSON = :display_params_json,
  t.ATTRIBUTES_JSON = :attributes_json,
  t.UPDATED_AT = SYSTIMESTAMP

この後に WHEN NOT MATCHED THEN INSERT が続きます。開始通知と終了通知を、すべて別行として蓄積する表ではありません。 各 span の最新状態を保持する表です。

queue がいっぱいになったらどうするか

通常の queue には上限があります。満杯のときは開始の通知を捨てて件数を数え、終了の通知を優先します。ルートや MCP の受信など、処理のつながりに関わる区間は別の queue で扱います。

DB 書き込みに失敗した場合は再送しますが、永遠に保証される記録ではありません。失われた span の件数を記録し、画面では記録が一部であることを示せるようにしています。

実行が成功したかどうかの正本は、各製品の実行やジョブの記録です。span の保存が少し遅れたことだけで、成功した処理を失敗と判断しない設計です。

Agent と呼び先の記録をどうつなぐのか

MCP で Trace の情報を渡す

Agent は、RAG や NL2SQL を MCP で呼ぶときに、W3C の traceparent を渡します。

Agent の span
  → HTTP の traceparent
  → JSON-RPC の params._meta.traceparent
  → 呼び先の mcp.server
  → 呼び先の処理の span

受信側の共通コードでは、認証したサービストークンによる呼び出しの場合に、受け取った Trace の親子関係を継続します。

実際のコードの該当箇所です。

parent = traceparent if trusted else None
linked = _span_context(traceparent) if traceparent and not trusted else None
carrier_context = _PROPAGATOR.extract({"traceparent": parent}) if parent else context.Context()
token = context.attach(carrier_context)

外部の MCP クライアントの API キーやブラウザから渡された値を、そのまま既存 Trace の親にはしません。新しい Trace を作り、必要な相関は OpenTelemetry の span link に残します。span link は export 側の情報で、この span テーブルには保存しません。

この区別は、外から任意の Trace ID を渡して、別の実行の記録へ混ぜられないようにするためです。

ADB の行で親子関係を確認する

Agent から RAG を呼び出した実行について、ADB の PLATFORM_TRACE_SPANS を Trace ID で絞りました。

Trace の対象	PRODUCT	行数
Agent → RAG	`agent`	21
同じ Trace の呼び先	`rag`	16
RAG 単独の実行	`rag`	22
NL2SQL 単独の最初の実行	`nl2sql`	8
Agent → NL2SQL の全行数の実行	`agent`	10
同じ Trace の呼び先	`nl2sql`	10

件数は、画面に出すステップ数と一致するとは限りません。ルートなど、表示上まとめる span も含むためです。

Agent → RAG の 1 組を抜き出すと、次の対応がありました。

PRODUCT	NAME	SPAN_ID	PARENT_SPAN_ID
`agent`	`mcp.request`	`8768a7f48a1d3ffd`	Agent 側の親 span
`rag`	`mcp.server`	`c6c94390d17fd14e`	`8768a7f48a1d3ffd`

呼び先の PARENT_SPAN_ID が、呼び出し元の SPAN_ID と一致しています。 画面で見えた階層は、この関係に対応しています。

管理者が確認する SQL は、例えば次のように書けます。:trace_id には、対象の「処理の詳細」にある Trace ID を指定します。

SELECT PRODUCT, COUNT(*) AS SPAN_COUNT
FROM PLATFORM_TRACE_SPANS
WHERE TRACE_ID = :trace_id
GROUP BY PRODUCT
ORDER BY PRODUCT;

親子の接続を確認する場合です。

SELECT
    c.PRODUCT AS CHILD_PRODUCT,
    c.NAME AS CHILD_NAME,
    c.SPAN_ID AS CHILD_SPAN_ID,
    p.PRODUCT AS PARENT_PRODUCT,
    p.NAME AS PARENT_NAME,
    p.SPAN_ID AS PARENT_SPAN_ID
FROM PLATFORM_TRACE_SPANS c
JOIN PLATFORM_TRACE_SPANS p
  ON p.TRACE_ID = c.TRACE_ID
 AND p.SPAN_ID = c.PARENT_SPAN_ID
WHERE c.TRACE_ID = :trace_id
ORDER BY c.STARTED_AT;

これらは DB の調査用 SQL です。通常の利用者向け画面は、DB へ直接問い合わせる代わりに、認可を行う製品の API から表示します。

誰でも Trace ID だけで読めるのか

実行履歴を読む API は、まず、その利用者が製品の実行やジョブを開けるかを確認します。その記録に結び付いた Trace ID で、共通テーブルを読みます。

一般の利用者は自分の実行を対象とし、システム管理者は管理のために全員の実行を閲覧できます。共有テーブルの OWNER_USER_UUID も、読み取り範囲を絞るために使います。

したがって、画面に Trace ID があることと、任意の利用者がその Trace を読めることは、別です。認証・認可を通した実行履歴の表示と組み合わせています。

ADB への保存と OpenTelemetry の export を分ける

このシステムでは、次の 2 つの経路を分けています。

経路	目的	送り先
画面用の記録	実行履歴から処理をたどる	ADB の共通テーブルと製品の記録
OpenTelemetry の export	外部の観測先との連携	設定された OTLP endpoint

今回の確認では OTLP endpoint は未設定でした。それでも、ADB に保存された span を使い、3 製品の画面で処理を確認できました。

export する内容を絞る

OpenTelemetry に export する属性は、共通コードの許可リストで絞っています。

属性の例	用途
`gen_ai.request.model`	呼び出したモデル
`gen_ai.usage.input_tokens`	取得できた入力 token 数
`gen_ai.usage.output_tokens`	取得できた出力 token 数
`gen_ai.tool.name`	呼び出したツール名
`mcp.method.name`	MCP の method
`pr.operation.id`	実行との対応
`pr.stage`	工程の種別
`error.type`	エラーの型

質問の全文、プロンプト、SQL 全文、ツールの引数・結果の全文、例外のメッセージは、この export の対象にしていません。

画面で見る SQL や根拠などの詳細は、必要な製品の記録側で扱います。画面に見える詳細が、すべてそのまま外部へ export されるわけではありません。

最初に確認する設定

設定は共通の platform/.env にあります。今回は既存の設定を使い、Tracing の設定値は変更していません。

最初に読む項目を 5 つに絞ると、次のとおりです。

設定	今回の値	意味
`PLATFORM_TRACE_ENABLED`	`true`	OpenTelemetry 側の trace を有効にする。画面用の capture と保存は別に扱う
`PLATFORM_TRACE_OTLP_ENDPOINT`	空	外部の OTLP 送信先。空でも画面用の記録は利用できる
`PLATFORM_TRACE_RETENTION_DAYS`	`0`	span の自動削除を行わない。正の値なら保持日数
`PLATFORM_TRACE_STORE_FLUSH_SECONDS`	`0.5`	ADB への書き込みをまとめる間隔
`PLATFORM_TRACE_STORE_BATCH_SIZE`	`100`	まとめて書く最大件数

FLUSH_SECONDS=0.5 は、必ず 0.5 秒以内に画面へ出るという保証ではありません。queue、DB の書き込み、読み取りのタイミングも関係します。

ほかに外部 export の sampling、queue の上限、画面用 span 数の上限もあります。sampling を下げることを、画面用記録を同じ割合で間引く設定だと読み替えないようにします。

時間の棒を見るときの注意点

親と子の時間は足さない

SQL の生成                 2.5 秒
└─ モデルの呼び出し         1.5 秒

この場合、モデルの呼び出しは「SQL の生成」の中に含まれます。合計を 4 秒にすると二重に数えてしまいます。横の棒の重なりと、階層を合わせて読みます。

token が分からない場合は分からないまま扱う

モデルや呼び出し経路によって、取得できる token の情報は異なります。未取得の値を、使用量が 0 だったとは判断しません。

また、cache の入力 token や reasoning の出力 token を、対応する入力・出力 token に重ねて加えると二重計上になります。画面の token 数を、呼び先も含めたすべての処理の請求額に直接読み替えることもできません。

Trace の完了と質問への回答の成立を分ける

「完了」は、その区間の処理が終わったという意味です。呼び先が「追加の確認が必要」と返した場合も、通信や確認処理自体は正常に完了することがあります。

SQL が実行されたかは「SQL の実行」の工程と結果を確認します。MCP の呼び出しが完了したことだけで、SQL まで実行したとは判断しません。

参照した実装

プログラムの責務は次のように分かれています。

ファイル	主な責務
tracing.py	span の計測、表示用の capture、安全な属性
trace_store.py	queue、ADB への MERGE、読み取り、画面用イベントへの変換
mcp_trace.py	MCP の Trace の受け渡しと信頼する境界
migrations.py	共通 span テーブルの DDL
trace_store.py	RAG の実行と共通テーブルの対応
trace_spans.py	NL2SQL のジョブ、履歴と共通テーブルの対応
trace_spans.py	Agent の実行と共通テーブルの対応

ソースは Production Ready Suite で確認できます。上記のコードと DDL は、確認時点の実装（365a6355b7）から抜粋しました。

まとめ

Tracing を使うと、AI の回答を待つ時間を、文書の検索、モデルの呼び出し、SQL の実行、資料との照合などの区間に分けて確認できます。

このシステムでは、そのつながりを TRACE_ID、SPAN_ID、PARENT_SPAN_ID で表し、Oracle Autonomous AI Database の PLATFORM_TRACE_SPANS に保存しています。Agent から RAG、Agent から NL2SQL を呼んだ処理も、それぞれ同じ Trace の親子関係で確認できました。

調べるときは、まず「実行履歴」を開き、「処理の経過」で時間を使った区間を探します。その後、必要に応じて「処理の詳細」の Trace ID と、回答の根拠や SQL の結果を確認する。この順番にすると、どこから調べればよいかが分かりやすくなります。