From 4b1ee028ff18e524b902bf39f6813b90c9461d97 Mon Sep 17 00:00:00 2001 From: yunhungo Date: Fri, 7 Aug 2026 11:36:56 +0800 Subject: [PATCH] fix: trace current Codex subagent activity --- plugins/tracing/dist/index.mjs | 7 +++- plugins/tracing/src/parse.ts | 17 ++++++--- plugins/tracing/src/types.ts | 3 ++ .../rollout-child-thread-child-current.jsonl | 12 +++++++ .../rollout-parent-sub-agent-activity.jsonl | 13 +++++++ plugins/tracing/test/parse.test.ts | 7 ++++ plugins/tracing/test/trace.test.ts | 36 +++++++++++++++++++ 7 files changed, 90 insertions(+), 5 deletions(-) create mode 100644 plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-child-thread-child-current.jsonl create mode 100644 plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-parent-sub-agent-activity.jsonl diff --git a/plugins/tracing/dist/index.mjs b/plugins/tracing/dist/index.mjs index f96eb74..39673f3 100644 --- a/plugins/tracing/dist/index.mjs +++ b/plugins/tracing/dist/index.mjs @@ -46661,6 +46661,10 @@ function newTurn(startTime) { aborted: false }; } +/** Record a spawned subagent once across Codex rollout schema versions. */ +function addSubagentThreadId(turn, threadId) { + if (typeof threadId === "string" && !turn.subagentThreadIds.includes(threadId)) turn.subagentThreadIds.push(threadId); +} /** * Parse a Codex rollout into session metadata and a list of fully assembled * turns. @@ -46835,7 +46839,8 @@ function parseSession(lines) { aborted: true }); else { - if (et === "collab_agent_spawn_end" && typeof p.new_thread_id === "string") turn.subagentThreadIds.push(p.new_thread_id); + if (et === "collab_agent_spawn_end") addSubagentThreadId(turn, p.new_thread_id); + else if (et === "sub_agent_activity" && p.kind === "started") addSubagentThreadId(turn, p.agent_thread_id); if ((et === "mcp_tool_call_begin" || et === "mcp_tool_call_end") && typeof p.call_id === "string") { const tc = toolCallsById.get(p.call_id); const inv = p.invocation; diff --git a/plugins/tracing/src/parse.ts b/plugins/tracing/src/parse.ts index 877ad96..1683d31 100644 --- a/plugins/tracing/src/parse.ts +++ b/plugins/tracing/src/parse.ts @@ -96,6 +96,13 @@ function newTurn(startTime: number): MutableTurn { }; } +/** Record a spawned subagent once across Codex rollout schema versions. */ +function addSubagentThreadId(turn: MutableTurn, threadId: unknown): void { + if (typeof threadId === "string" && !turn.subagentThreadIds.includes(threadId)) { + turn.subagentThreadIds.push(threadId); + } +} + /** * Parse a Codex rollout into session metadata and a list of fully assembled * turns. @@ -305,10 +312,12 @@ export function parseSession(lines: RolloutLine[]): { } else if (et === "turn_aborted") { finishTurn(ts, { completed: true, aborted: true }); } else { - // A subagent spawn records the child thread *and* (since it carries a - // call_id ending in "_end") enriches the spawning tool call below. - if (et === "collab_agent_spawn_end" && typeof p.new_thread_id === "string") { - turn!.subagentThreadIds.push(p.new_thread_id); + // Codex has used two lifecycle schemas for successful subagent spawns. + // Accept both and deduplicate in case a rollout contains both forms. + if (et === "collab_agent_spawn_end") { + addSubagentThreadId(turn!, p.new_thread_id); + } else if (et === "sub_agent_activity" && p.kind === "started") { + addSubagentThreadId(turn!, p.agent_thread_id); } // MCP tool calls are function calls with a mangled name // (`server__tool`); the begin/end events carry the clean server/tool diff --git a/plugins/tracing/src/types.ts b/plugins/tracing/src/types.ts index 36abc2c..511e732 100644 --- a/plugins/tracing/src/types.ts +++ b/plugins/tracing/src/types.ts @@ -131,6 +131,9 @@ export type EventMsgPayload = { } | null; /** collab_agent_spawn_end */ new_thread_id?: string | null; + /** sub_agent_activity */ + agent_thread_id?: string | null; + kind?: string | null; /** mcp_tool_call_begin / mcp_tool_call_end */ invocation?: { server?: string; tool?: string; arguments?: unknown } | null; /** web_search_end */ diff --git a/plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-child-thread-child-current.jsonl b/plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-child-thread-child-current.jsonl new file mode 100644 index 0000000..56bc2ac --- /dev/null +++ b/plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-child-thread-child-current.jsonl @@ -0,0 +1,12 @@ +{"timestamp":"2026-06-03T13:00:03.000Z","type":"session_meta","payload":{"id":"thread-child-current","cli_version":"0.147.0","model_provider":"openai","parent_thread_id":"sess-parent-current","thread_source":"subagent"}} +{"timestamp":"2026-06-03T13:00:03.100Z","type":"event_msg","payload":{"type":"task_started","turn_id":"turn-child-current"}} +{"timestamp":"2026-06-03T13:00:03.200Z","type":"turn_context","payload":{"model":"gpt-5.4"}} +{"timestamp":"2026-06-03T13:00:03.300Z","type":"event_msg","payload":{"type":"user_message","message":"run a command"}} +{"timestamp":"2026-06-03T13:00:03.400Z","type":"response_item","payload":{"type":"function_call","name":"exec_command","call_id":"call-child-exec","arguments":"{\"command\":[\"echo\",\"child action\"]}"}} +{"timestamp":"2026-06-03T13:00:03.600Z","type":"event_msg","payload":{"type":"exec_command_end","call_id":"call-child-exec","status":"completed","exit_code":0,"stdout":"child action\n","stderr":"","aggregated_output":"child action\n"}} +{"timestamp":"2026-06-03T13:00:03.700Z","type":"response_item","payload":{"type":"function_call_output","call_id":"call-child-exec","output":"child action\n"}} +{"timestamp":"2026-06-03T13:00:03.800Z","type":"event_msg","payload":{"type":"token_count","info":{"last_token_usage":{"input_tokens":40,"output_tokens":8,"total_tokens":48,"cached_input_tokens":0,"reasoning_output_tokens":0},"total_token_usage":{"input_tokens":40,"output_tokens":8,"total_tokens":48,"cached_input_tokens":0,"reasoning_output_tokens":0}}}} +{"timestamp":"2026-06-03T13:00:04.000Z","type":"response_item","payload":{"type":"message","role":"assistant","content":[{"type":"output_text","text":"The child command completed."}]}} +{"timestamp":"2026-06-03T13:00:04.100Z","type":"event_msg","payload":{"type":"agent_message","message":"The child command completed."}} +{"timestamp":"2026-06-03T13:00:04.200Z","type":"event_msg","payload":{"type":"token_count","info":{"last_token_usage":{"input_tokens":50,"output_tokens":10,"total_tokens":60,"cached_input_tokens":0,"reasoning_output_tokens":0},"total_token_usage":{"input_tokens":90,"output_tokens":18,"total_tokens":108,"cached_input_tokens":0,"reasoning_output_tokens":0}}}} +{"timestamp":"2026-06-03T13:00:04.300Z","type":"event_msg","payload":{"type":"task_complete","turn_id":"turn-child-current"}} diff --git a/plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-parent-sub-agent-activity.jsonl b/plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-parent-sub-agent-activity.jsonl new file mode 100644 index 0000000..bb9d7b3 --- /dev/null +++ b/plugins/tracing/test/fixtures/sessions/2026/06/03/rollout-parent-sub-agent-activity.jsonl @@ -0,0 +1,13 @@ +{"timestamp":"2026-06-03T13:00:00.000Z","type":"session_meta","payload":{"id":"sess-parent-current","cli_version":"0.147.0","model_provider":"openai"}} +{"timestamp":"2026-06-03T13:00:01.000Z","type":"event_msg","payload":{"type":"task_started","turn_id":"turn-parent-current"}} +{"timestamp":"2026-06-03T13:00:01.200Z","type":"turn_context","payload":{"model":"gpt-5.4"}} +{"timestamp":"2026-06-03T13:00:01.300Z","type":"event_msg","payload":{"type":"user_message","message":"Spawn a subagent to run a command"}} +{"timestamp":"2026-06-03T13:00:02.000Z","type":"response_item","payload":{"type":"function_call","name":"spawn_agent","call_id":"call-spawn-current","arguments":"{\"message\":\"run a command\"}"}} +{"timestamp":"2026-06-03T13:00:02.500Z","type":"event_msg","payload":{"type":"sub_agent_activity","event_id":"call-spawn-current","agent_thread_id":"thread-child-current","agent_path":"/root/current-child","kind":"started"}} +{"timestamp":"2026-06-03T13:00:02.600Z","type":"event_msg","payload":{"type":"sub_agent_activity","event_id":"call-spawn-current","agent_thread_id":"thread-child-current","agent_path":"/root/current-child","kind":"started"}} +{"timestamp":"2026-06-03T13:00:02.700Z","type":"response_item","payload":{"type":"function_call_output","call_id":"call-spawn-current","output":"started"}} +{"timestamp":"2026-06-03T13:00:02.800Z","type":"event_msg","payload":{"type":"token_count","info":{"last_token_usage":{"input_tokens":80,"output_tokens":10,"total_tokens":90,"cached_input_tokens":0,"reasoning_output_tokens":0},"total_token_usage":{"input_tokens":80,"output_tokens":10,"total_tokens":90,"cached_input_tokens":0,"reasoning_output_tokens":0}}}} +{"timestamp":"2026-06-03T13:00:05.000Z","type":"response_item","payload":{"type":"message","role":"assistant","content":[{"type":"output_text","text":"Subagent completed."}]}} +{"timestamp":"2026-06-03T13:00:05.100Z","type":"event_msg","payload":{"type":"agent_message","message":"Subagent completed."}} +{"timestamp":"2026-06-03T13:00:05.200Z","type":"event_msg","payload":{"type":"token_count","info":{"last_token_usage":{"input_tokens":90,"output_tokens":12,"total_tokens":102,"cached_input_tokens":0,"reasoning_output_tokens":0},"total_token_usage":{"input_tokens":170,"output_tokens":22,"total_tokens":192,"cached_input_tokens":0,"reasoning_output_tokens":0}}}} +{"timestamp":"2026-06-03T13:00:05.300Z","type":"event_msg","payload":{"type":"task_complete","turn_id":"turn-parent-current"}} diff --git a/plugins/tracing/test/parse.test.ts b/plugins/tracing/test/parse.test.ts index 9dbbc90..d3cb453 100644 --- a/plugins/tracing/test/parse.test.ts +++ b/plugins/tracing/test/parse.test.ts @@ -81,6 +81,13 @@ describe("parseSession", () => { expect(turn.endTime).toBe(Date.parse("2026-06-03T11:00:05.000Z")); }); + it("captures and deduplicates current sub_agent_activity thread ids", () => { + const { turns } = parseSession(loadFixture("rollout-parent-sub-agent-activity.jsonl")); + + expect(turns).toHaveLength(1); + expect(turns[0].subagentThreadIds).toEqual(["thread-child-current"]); + }); + it("treats a trailing, never-completed turn as not completed", () => { const lines: RolloutLine[] = [ { timestamp: "2026-06-03T12:00:00.000Z", type: "session_meta", payload: { id: "s" } }, diff --git a/plugins/tracing/test/trace.test.ts b/plugins/tracing/test/trace.test.ts index ca9890a..4c22321 100644 --- a/plugins/tracing/test/trace.test.ts +++ b/plugins/tracing/test/trace.test.ts @@ -159,6 +159,42 @@ describe("convertRollout", () => { expect(attr(failedTool!, "langfuse.observation.status_message")).toContain("command failed"); }); + it("nests current sub_agent_activity rollouts with their execution actions", async () => { + const dir = stageFixtures(); + await convertRollout(path.join(dir, "rollout-parent-sub-agent-activity.jsonl"), { + config: baseConfig, + }); + + const spans = exporter.getFinishedSpans(); + const parent = spans.find((s) => s.name === "Codex Turn" && obsType(s) === "agent"); + const childAgents = spans.filter( + (s) => s.name === "Codex Subagent Turn" && obsType(s) === "agent", + ); + + expect(parent).toBeDefined(); + expect(childAgents).toHaveLength(1); + const child = childAgents[0]; + expect(parentId(child)).toBe(parent!.spanContext().spanId); + expect(child.spanContext().traceId).toBe(parent!.spanContext().traceId); + + const childGeneration = spans.find( + (s) => + s.name === "LLM Subagent" && + obsType(s) === "generation" && + parentId(s) === child.spanContext().spanId, + ); + expect(childGeneration).toBeDefined(); + + const childTool = spans.find( + (s) => + s.name === "exec_command" && + obsType(s) === "tool" && + parentId(s) === childGeneration!.spanContext().spanId, + ); + expect(childTool).toBeDefined(); + expect(attr(childTool!, "langfuse.observation.output")).toContain("child action"); + }); + it("captures web search, local shell, and MCP tool calls with specific names", async () => { const dir = stageFixtures(); await convertRollout(path.join(dir, "rollout-tools-main.jsonl"), { config: baseConfig });