Codexの子エージェントの時間とトークンをログから集計するビューアを作った
目次
前回、Codexのオーケストレーションを組み直して使用量を抑えた。
それでも1つの処理に何時間もかかることがあった。
どこで何が動いているかは、PC上のプロセスを見れば大まかには分かる。
ただ、オーケストレーションで動いている子エージェントが何をしているかまでは、プロセスからは取れなかった。
一部のリポジトリでは、子が起動・終了するたびにMarkdownファイルへ状況を記録させて追っていたが、指示頼みだと記録が抜けたりして、全リポジトリで運用するのは無理がある。
そこでエージェント自身に記録させるのをやめて、CodexとClaude Codeが残しているセッションログから、子の状態と時間を組み立てるビューアを作った。
ログを追っていくとトークンの量も取れたので、30日分をまとめて集計した。
環境
| 項目 | 内容 |
|---|---|
| マシン | Mac mini（M4） |
| Codex CLI | 0.154.0 |
| Claude Code | 2.1.274 |
| ビューア | SwiftUIの画面と、ログを集計するPythonスクリプト（標準ライブラリのみ） |
| 集計期間 | 2026年8月19日〜9月18日の30日間、257セッション（子のいるもの129） |
子エージェントの実体はスレッド
最初は ps と lsof でプロセスを探し、作業フォルダとセッションログの更新時刻から最後の活動時刻を出す一覧を作っていた。
これで「どこでどのタスクが動いているか」は分かる。
ただ、Codexにオーケストレーションさせている最中でも、codexのプロセスは1つしか見えなかった。
lsof でそのプロセスが開いているファイルを確認すると、~/.codex/sessions/ の下にあるセッションログ（rollout-*.jsonl）を6本同時に開いていた。
子は別のプロセスではなく同じプロセスの中のスレッドで、スレッドごとにログ（rollout）を1本書いている。
各rolloutの1行目（session_meta）に親子関係が入っていた。
| 項目 | 例 | 意味 |
|---|---|---|
parent_thread_id | 親のスレッドID | 親子をつなぐ |
agent_path | /root/review_worker | 親が付けた子の役割名 |
agent_nickname | Pasteur | Codexが付ける子の呼び名 |
source.subagent.thread_spawn.depth | 1 | 親から数えた深さ |
子が何をしたかも、同じrolloutに残っている。
実行したコマンド、apply_patch で編集したファイル、wait_agent での子待ち、task_complete の完了報告と所要時間が平文で入っていた。
親が子に渡した指示本文（spawn_agent や send_message の message）だけは、平文では残っていなかった。
Claude Codeの子（Agentツールで起動したサブエージェント）は、会話ログと同じ場所の <セッションID>/subagents/agent-*.jsonl に書かれている。
隣の .meta.json に、起動時の説明、エージェントの種類、モデル、親の呼び出しID（toolUseId）が入っていた。
ログから時間を分類する
どちらのログも、全イベントに時刻が付いている。
イベントを順に追ってスレッドの状態を遷移させていくと、各状態の滞在時間を集計できる。
ビューアを開いていなかった間の分も、あとから同じように組み立てられる。
| 状態 | 始まるイベント | 中身 |
|---|---|---|
| 思考 | ターン開始、ツールの結果が返った時 | モデルが次の一手を出すまで。APIの待ち時間を含む |
| ツール | ツールを呼んだ時 | 結果が返るまで |
| 子待ち | wait_agent、sleep、Claude Codeの前面の子を呼んだ時 | 待っている間に子が作業していた時間 |
| その他の待ち | 同上 | 待っていたが、作業中の子がいなかった時間 |
| 入力待ち | task_complete、turn_aborted、end_turn、中断 | 次の入力が来るまで |
flowchart TD
A[入力を受ける] --> B[思考]
B --> C[ツール]
C --> B
B --> D[子待ち]
D --> B
B --> E[入力待ち]
E --> Aターンを終えて止まっている間に子が作業していた時間も、子待ちに数えている。
Claude Codeのバックグラウンドの子のように、親が待つ呼び出しをせずに止まる場合があるため。
内訳の合計はプロセスの稼働時間と一致し、30日分257セッションで合計がずれたものはなかった。
rolloutは1本で17MB規模になることもあり、3秒ごとにファイル全体をパースし直すと重くて耐えられない。
処理済みのバイト位置と積算値を保持しておき、追記された分だけを差分処理している。
数え方の調整
最初に組んだ数え方は、実データに当ててみるといくつかズレがあった。
| 最初の数え方 | 出た数字 | 実際に起きていたこと | 直し方 |
|---|---|---|---|
子待ちは wait_agent の間だけ | 子21体のセッションで親の実活動99% | 親は sleep 49回と list_agents 76回で子を待っていた | sleep も待ちに数える。直した後は実活動82%、子待ち13% |
Claude Codeの子は end_turn で完了 | 子の完了率50%、思考1回1時間34分 | 直近の子300本のうち167本は end_turn を書かず、文章だけの応答で終わっていた | 最後が文章だけの応答なら完了とみなす。完了率100% |
| 画面は開いているrolloutだけを見る | 親の「その他の待ち」1時間19分 | Codexは完了した子のrolloutを閉じる | 同じセッションの閉じた子のrolloutも集計に含める。その他の待ちはほぼ0 |
| Claude Codeのトークンは応答ごとに1回数える | 出力が少なく出る | 1つの応答が複数行に分かれて記録され、複数行に分かれた1,386件のうち604件は行を追うごとに値が増えていた | 同じ応答は最後の値で数える |
Codexの子のツール時間が短すぎる理由も調べた。
Codexは長いコマンドをバックグラウンドで走らせ、出力を確認する呼び出し（write_stdin）を繰り返している。
gpt-6-astraの子2体で集計したところ、出力を確認する呼び出しの前の時間は全体の1%未満だった。
思考の時間は、ほぼモデルが次の一手を出すまでの待ち時間だった。
1つのセッションの内訳
Codex（親はgpt-5.6-sol medium）で、業務リポジトリの未処理の課題をまとめて処理させたセッションを確認した。
現在タブでは、作業フォルダごとにエージェントを並べ、Codexの親の下に子を表示する。
親の行には子の状態（完了・中断）ごとの数や、中断のまま残っている子などの要確認項目をまとめた。
その下の帯グラフは起動からの時間の内訳（思考・ツール・子待ち・入力待ち）を示し、右端にトークン量を並べている。
スクリーンショットは公開用の表示に切り替え、フォルダ名、タイトル、子の名前、コマンドとファイル名、完了報告を伏せた。
取得時点のこのセッションの集計は次のとおり。
| 項目 | 値 |
|---|---|
| 総時間 | 6時間33分 |
| 実活動（思考＋ツール） | 1時間5分（17%） |
| 子待ち | 4時間28分（68%） |
| 入力待ち | 59分（15%） |
| 子 | 10体（完了8、中断2）、同時に動いた子は最大2体 |
| 入力トークン | 193.8M（キャッシュ98%） |
| 出力トークン | 668k（親129k、子538k） |
親は総時間（6時間33分）の約7割にあたる4時間28分を、子の完了待ちに費やしていた。
入力トークンは193.8M（約1.9億トークン）で、その98%はキャッシュヒットだった。出力トークンは全体で668k（約67万トークン）で、その8割を子が占めていた。
子の側をモデルごとに分けた内訳は次のようになった。
| 子のモデル | 子の数 | 呼び出し回数 | 思考1回 | 思考 | ツール | 出力トークン |
|---|---|---|---|---|---|---|
| gpt-5.6-luna max | 4 | 206 | 12秒 | 40分 | 1分 | 104k |
| gpt-5.6-sol high | 3 | 485 | 10秒 | 80分 | 11分 | 187k |
| gpt-6-astra high | 3 | 515 | 19秒 | 161分 | 12分 | 247k |
gpt-6-astra highの3体は、呼び出し回数がsol highとほぼ同じで、思考1回が約2倍だった。
子の思考合計281分のうち、161分をastraが占めていた。
30日分の履歴
履歴タブは、終わったセッションも含めてログから集計し、親の構成ごと、子のモデルごとにまとめる。
集計はログとは別に保存しているため、元データが消えたあとも残る。
セッション一覧には、セッションごとの時間の内訳、トークン、子の完了・中断、子のモデルの内訳を表示している。
親の構成ごと
直近30日の子のいるセッションのうち、同じ構成が2件以上あったもの。
割合は各セッションの割合の平均ではなく、時間の合計どうしの比で出している。
| 親の構成 | 件数 | 総時間（中央値） | 実活動 | 子待ち | 入力待ち | 子/件 | 子の完了率 | 入力/件（中央値） | キャッシュ | 出力/件（中央値） |
|---|---|---|---|---|---|---|---|---|---|---|
| codex gpt-5.6-sol xhigh | 73 | 1時間16分 | 31% | 19% | 50% | 11.9 | 95% | 33.5M | 97% | 151k |
| claude claude-fable-5-1 | 13 | 6時間18分 | 28% | 3% | 70% | 27.3 | 100% | 40.0M | 93% | 277k |
| claude claude-fable-5 | 11 | 6時間23分 | 24% | 6% | 70% | 17.0 | 99% | 54.2M | 96% | 627k |
| codex gpt-6-astra low | 8 | 1時間43分 | 39% | 33% | 24% | 15.0 | 97% | 30.9M | 98% | 164k |
| codex gpt-5.6-sol medium | 7 | 6時間33分 | 15% | 27% | 58% | 12.6 | 88% | 65.5M | 97% | 205k |
| claude claude-opus-5 | 6 | 23時間14分 | 5% | 3% | 91% | 27.5 | 99% | 42.5M | 97% | 258k |
| claude claude-sonnet-5 | 2 | 5分 | 30% | 70% | 0% | 1.0 | 100% | 809k | 78% | 27k |
| codex gpt-6-astra medium | 2 | 7時間5分 | 63% | 2% | 34% | 15.0 | 100% | 202.1M | 98% | 689k |
| codex gpt-5.6-sol high | 2 | 16時間43分 | 17% | 58% | 11% | 152.0 | 94% | 423.5M | 97% | 1.8M |
| codex gpt-6-astra xhigh | 2 | 12時間51分 | 8% | 25% | 68% | 29.5 | 98% | 189.7M | 96% | 1.0M |
入力待ちには、指示を投げたあとに人間が放置していた時間がそのまま含まれる。
この入力待ちを除いて計算すると、Codex（96件）の親は実活動53%・子待ち45%とほぼ半々を子の待機に費やしていた。
対してClaude Code（33件）は実活動85%・子待ち15%で、親自身が動いている時間が大半を占める。
子が3体以上いたセッションで同時に動いた子の最大数は、Codexが中央値4体（69件中25件は2体以下）、Claude Codeが中央値7体だった。
子のモデルごと
子が5体以上いたモデル。
表の列は次の意味で出している。
| 列 | 意味 |
|---|---|
| 実働 | 思考＋ツール。子1体ごとの中央値 |
| ツール比率 | 実働のうち、ツールの結果を待っていた時間 |
| 思考1回 | 思考の合計を呼び出し回数で割った値 |
| 入力/子 | 子1体あたりの入力トークン。キャッシュヒット分を含む |
| キャッシュ外の入力/子 | 入力からキャッシュヒット分を除いた分 |
| 出力/思考1分 | 思考1分あたりの出力トークン。推論の分を含む |
| 子のモデル | 子の数 | 完了 | 実働（中央値） | ツール比率 | 思考1回 | 入力/子 | キャッシュ | キャッシュ外の入力/子 | 出力/子 | 出力/思考1分 |
|---|---|---|---|---|---|---|---|---|---|---|
| claude claude-sonnet-5 | 690 | 100% | 5分 | 0% | 1分 | 389k | 79% | 81k | 17k | 3k |
| codex gpt-5.6-luna medium | 487 | 97% | 3分 | 10% | 10秒 | 1.7M | 95% | 76k | 9k | 2k |
| codex gpt-5.6-sol medium | 424 | 96% | 5分 | 4% | 13秒 | 4.4M | 97% | 119k | 18k | 2k |
| codex gpt-5.6-sol xhigh | 289 | 92% | 4分 | 5% | 13秒 | 2.8M | 96% | 113k | 15k | 2k |
| codex gpt-5.6-luna max | 90 | 91% | 9分 | 3% | 17秒 | 5.2M | 96% | 220k | 34k | 2k |
| codex gpt-5.6-terra medium | 72 | 99% | 5分 | 6% | 13秒 | 2.1M | 96% | 77k | 12k | 1k |
| codex gpt-5.6-sol high | 34 | 88% | 12分 | 5% | 14秒 | 9.0M | 97% | 232k | 36k | 2k |
| codex gpt-5.6-luna xhigh | 30 | 87% | 13分 | 4% | 13秒 | 10.9M | 97% | 304k | 55k | 3k |
| codex gpt-6-astra xhigh | 13 | 100% | 11分 | 1% | 34秒 | 2.3M | 95% | 111k | 22k | 1k |
| claude claude-opus-5 | 12 | 92% | 2分 | 1% | 36秒 | 365k | 79% | 76k | 2k | 678 |
| codex gpt-6-astra high | 9 | 78% | 8分 | 6% | 19秒 | 8.0M | 98% | 186k | 32k | 1k |
| codex gpt-6-astra medium | 8 | 100% | 2分 | 1% | 32秒 | 2.2M | 95% | 119k | 18k | 2k |
| claude claude-fable-5 | 7 | 100% | 10分 | 21% | 7秒 | 902k | 69% | 280k | 40k | 5k |
| codex gpt-5.6-luna low | 6 | 100% | 56秒 | 2% | 7秒 | 211k | 92% | 17k | 2k | 2k |
| claude claude-haiku-4-5-20251001 | 5 | 100% | 1分 | 32% | 3秒 | 515k | 89% | 55k | 5k | 6k |
| codex gpt-5.6-terra high | 5 | 80% | 3分 | 3% | 17秒 | 824k | 93% | 60k | 11k | 1k |
子の実働のうちツール実行は、Codexで5%、Claude Codeで1%だった。
残りの95%以上はモデルの応答待ちで、実際のコマンド実行やファイル操作に費やされた時間はごくわずかだった。
思考1回は、gpt-5.6のsolとlunaとterraが7〜17秒、gpt-6-astraが19〜34秒だった。
処理トークン
エージェントは呼び出しのたびに、それまでの会話を入力として送り直す。
そのため入力トークンは大きくなるが、大半はキャッシュヒットになる。
| 項目 | Codex（96件） | Claude Code（33件） |
|---|---|---|
| 入力トークンの合計 | 8,507.1M | 1,905.8M |
| うちキャッシュ | 97% | 95% |
| 出力トークンの合計 | 35.3M | 17.6M |
| 出力のうち子の分 | 68% | 67% |
30日分の入力トークンはCodexが8,507.1M（約85億トークン）、Claude Codeが1,905.8M（約19億トークン）で、どちらも95%以上がキャッシュだった。
出力トークンはCodexで35.3M（約3,530万トークン）、Claude Codeで17.6M（約1,760万トークン）で、その約3分の2（67〜68%）を子が占めていた。
Codexの子の入力は1体あたり0.2M〜10.9Mで、キャッシュ外の入力は17k〜304kだった。
出力は1体あたり2k〜55kで、思考1分あたりの出力はCodexのどのモデルも1k〜3kだった。
gpt-6-astraの思考1分あたりの出力は1k〜2kで、下限に近い水準だった。
トークン量の数え方はランタイムで違う。
| ランタイム | 数え方 |
|---|---|
| Codex | スレッドごとの累計（token_count の total_token_usage）の最後の値。コンテキスト圧縮（compact）を挟んでも減らず、1回ごとの使用量の合計と一致した。親の値に子の分は含まれない |
| Claude Code | 応答ごとの usage。入力にはキャッシュ作成とヒット分を含める |
この数字の限界
今回の集計値を見る上での前提と制約をまとめておく。
| 限界 | 内容 |
|---|---|
| 比較の条件 | 同じ作業を構成違いで流した比較ではない。作業内容も人が離れていた時間もセッションごとに違い、gpt-6-astraを親にしたセッションは構成ごとに2〜8件しかない |
| 思考の中身 | APIの待ち時間や順番待ちを含み、モデルの推論そのものとは分けられない |
| Codexのツール比率 | 子がツールの結果を待って止まっていた時間の割合で、バックグラウンドで走っていたコマンドの実行時間は含まない |
| ログの形式 | どちらも公開された仕様ではなく、手元のCodex CLI 0.154.0とClaude Code 2.1.274の記録で確かめただけ。2026年1月のCodex 0.78.0のログはターンの開始・終了を記録しておらず、内訳を出せなかった |
| トークン量 | ログ同士の整合までしか確かめておらず、請求額とは照合していない |