diff --git a/plugins/tracing/src/parse.ts b/plugins/tracing/src/parse.ts index e4804f6..217a0f7 100644 --- a/plugins/tracing/src/parse.ts +++ b/plugins/tracing/src/parse.ts @@ -1,5 +1,6 @@ import { skillsForPrompt } from "./skills.js"; import type { + EventMsgItem, EventMsgPayload, MessageContentPart, ModelStep, @@ -92,6 +93,49 @@ function extractToolError(payload: EventMsgPayload): string | undefined { return undefined; } +type McpToolCallItem = EventMsgItem & { + type: "McpToolCall" | "mcpToolCall"; + id: string; + server: string; + tool: string; +}; + +function isMcpToolCallItem(item: EventMsgItem | null | undefined): item is McpToolCallItem { + return ( + (item?.type === "McpToolCall" || item?.type === "mcpToolCall") && + typeof item.id === "string" && + item.id.length > 0 && + typeof item.server === "string" && + item.server.length > 0 && + typeof item.tool === "string" && + item.tool.length > 0 + ); +} + +function mcpToolCallDurationMs(item: EventMsgItem): number | undefined { + const durationMs = item.durationMs ?? item.duration_ms; + if (typeof durationMs === "number" && Number.isFinite(durationMs) && durationMs >= 0) { + return durationMs; + } + + if (item.duration && typeof item.duration === "object") { + const duration = item.duration as { secs?: unknown; nanos?: unknown }; + if ( + typeof duration.secs === "number" && + typeof duration.nanos === "number" && + Number.isFinite(duration.secs) && + Number.isFinite(duration.nanos) && + duration.secs >= 0 && + duration.nanos >= 0 && + duration.nanos < 1_000_000_000 + ) { + return duration.secs * 1_000 + duration.nanos / 1_000_000; + } + } + + return undefined; +} + type MutableTurn = Turn & { lastAgentMessage?: string; userInputFallback?: string }; const TURN_OPENING_EVENTS = new Set(["user_message", "item_completed", "agent_message"]); @@ -174,6 +218,61 @@ export function parseSession(lines: RolloutLine[]): { const ensureTurn = (ts: number): MutableTurn => (turn ??= newTurn(ts)); const ensureStep = (ts: number) => (step ??= newStep(ts)); + const mcpCallStartTimes = new Map(); + + const recordMcpToolCallItem = ( + item: EventMsgItem | null | undefined, + ts: number, + completed: boolean, + ) => { + if (!isMcpToolCallItem(item)) return; + + let tc = toolCallsById.get(item.id); + if (!tc) { + tc = { + callId: item.id, + name: item.tool, + args: item.arguments, + startTime: ts, + mcp: { server: item.server, tool: item.tool }, + }; + ensureStep(ts).toolCalls.push(tc); + toolCallsById.set(tc.callId, tc); + } else { + tc.mcp = { server: item.server, tool: item.tool }; + if (item.arguments !== undefined) tc.args = item.arguments; + } + + if (!completed) { + const startedAt = Math.min(mcpCallStartTimes.get(item.id) ?? ts, ts); + mcpCallStartTimes.set(item.id, startedAt); + tc.startTime = startedAt; + return; + } + + const startedAt = mcpCallStartTimes.get(item.id); + const durationMs = mcpToolCallDurationMs(item); + if (startedAt !== undefined) tc.startTime = startedAt; + else if (durationMs !== undefined) tc.startTime = ts - durationMs; + tc.endTime = Math.max(tc.endTime ?? ts, ts); + if (item.result !== undefined) tc.output = item.result; + mcpCallStartTimes.delete(item.id); + + const error = + item.error != null + ? extractToolError({ type: "mcp_tool_call", error: item.error }) + : undefined; + if (error) { + tc.error = error; + } else if ( + !tc.error && + ["failed", "declined", "cancelled", "canceled", "interrupted", "error"].includes( + item.status ?? "", + ) + ) { + tc.error = item.status; + } + }; const recordSubagentThread = (threadId: string) => { if (!turn!.subagentThreadIds.includes(threadId)) { @@ -212,6 +311,7 @@ export function parseSession(lines: RolloutLine[]): { } turn = null; toolCallsById = new Map(); + mcpCallStartTimes.clear(); }; for (const line of lines) { @@ -367,14 +467,19 @@ export function parseSession(lines: RolloutLine[]): { continue; } - if (TURN_OPENING_EVENTS.has(et)) ensureTurn(ts); - else if (!turn) continue; + if (TURN_OPENING_EVENTS.has(et) || (et === "item_started" && isMcpToolCallItem(p.item))) { + ensureTurn(ts); + } else if (!turn) continue; - if (et === "user_message" && typeof p.message === "string") { + if (et === "item_started" && isMcpToolCallItem(p.item)) { + recordMcpToolCallItem(p.item, ts, false); + } else if (et === "user_message" && typeof p.message === "string") { if (!turn!.userInput) turn!.userInput = p.message; } else if (et === "item_completed" && p.item?.type === "UserMessage") { const text = extractMessageText(p.item.content); if (text && !turn!.userInput) turn!.userInput = text; + } else if (et === "item_completed" && isMcpToolCallItem(p.item)) { + recordMcpToolCallItem(p.item, ts, true); } else if (et === "agent_message" && typeof p.message === "string") { turn!.lastAgentMessage = p.message; } else if (et === "token_count") { diff --git a/plugins/tracing/src/types.ts b/plugins/tracing/src/types.ts index fbe10e8..8fa705c 100644 --- a/plugins/tracing/src/types.ts +++ b/plugins/tracing/src/types.ts @@ -118,6 +118,22 @@ export type TokenUsage = { reasoning_output_tokens?: number; }; +export type EventMsgItem = { + type?: string; + id?: string; + server?: string; + tool?: string; + status?: string; + duration?: unknown; + durationMs?: number; + duration_ms?: number; + arguments?: unknown; + result?: unknown; + error?: unknown; + content?: MessageContentPart[]; + [key: string]: unknown; +}; + export type EventMsgPayload = { type: string; turn_id?: string | null; @@ -127,7 +143,7 @@ export type EventMsgPayload = { last_token_usage?: TokenUsage; model_context_window?: number; } | null; - item?: { type?: string; content?: MessageContentPart[] } | null; + item?: EventMsgItem | null; new_thread_id?: string | null; kind?: string; agent_thread_id?: string | null; diff --git a/plugins/tracing/test/parse.test.ts b/plugins/tracing/test/parse.test.ts index 66e11df..da25478 100644 --- a/plugins/tracing/test/parse.test.ts +++ b/plugins/tracing/test/parse.test.ts @@ -613,6 +613,170 @@ describe("parseSession", () => { expect(tool.args).toBe("*** Begin Patch"); expect(tool.output).toBe("patched"); }); + + it("captures MCP tool-call items and merges direct model calls by id", () => { + const input = { organization_id: "demo" }; + const result = { projects: [{ id: "project-1", name: "Demo" }] }; + const lines: RolloutLine[] = [ + { timestamp: "2026-06-03T12:00:00.000Z", type: "session_meta", payload: { id: "s" } }, + { + timestamp: "2026-06-03T12:00:01.000Z", + type: "event_msg", + payload: { type: "task_started", turn_id: "t" }, + }, + { + timestamp: "2026-06-03T12:00:02.000Z", + type: "response_item", + payload: { + type: "function_call", + name: "mcp__codex_app__list_projects", + call_id: "direct-1", + arguments: JSON.stringify(input), + }, + }, + { + timestamp: "2026-06-03T12:00:02.100Z", + type: "event_msg", + payload: { + type: "item_started", + item: { + type: "McpToolCall", + id: "direct-1", + server: "codex_app", + tool: "list_projects", + status: "inProgress", + arguments: input, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:02.600Z", + type: "event_msg", + payload: { + type: "item_completed", + item: { + type: "McpToolCall", + id: "direct-1", + server: "codex_app", + tool: "list_projects", + status: "completed", + arguments: input, + result, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:03.000Z", + type: "event_msg", + payload: { + type: "item_started", + item: { + type: "McpToolCall", + id: "nested-1", + server: "codex_app", + tool: "list_projects", + status: "inProgress", + arguments: input, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:03.800Z", + type: "event_msg", + payload: { + type: "item_completed", + item: { + type: "McpToolCall", + id: "nested-1", + server: "codex_app", + tool: "list_projects", + status: "failed", + arguments: input, + error: { message: "access denied" }, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:03.900Z", + type: "event_msg", + payload: { + type: "item_completed", + item: { + type: "McpToolCall", + id: "completed-only-1", + server: "codex_app", + tool: "list_projects", + status: "completed", + duration: { secs: 0, nanos: 100_000_000 }, + arguments: input, + result, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:03.950Z", + type: "event_msg", + payload: { + type: "item_completed", + item: { + type: "McpToolCall", + id: "completed-only-ms", + server: "codex_app", + tool: "list_projects", + status: "completed", + durationMs: 100, + arguments: input, + result, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:04.000Z", + type: "event_msg", + payload: { type: "task_complete", turn_id: "t" }, + }, + ]; + + const { turns } = parseSession(lines); + const tools = turns[0].steps.flatMap((step) => step.toolCalls); + expect(tools).toHaveLength(4); + + const direct = tools.find((tool) => tool.callId === "direct-1"); + expect(direct).toMatchObject({ + name: "mcp__codex_app__list_projects", + args: input, + output: result, + mcp: { server: "codex_app", tool: "list_projects" }, + startTime: Date.parse("2026-06-03T12:00:02.100Z"), + endTime: Date.parse("2026-06-03T12:00:02.600Z"), + }); + + const nested = tools.find((tool) => tool.callId === "nested-1"); + expect(nested).toMatchObject({ + name: "list_projects", + args: input, + error: '{"message":"access denied"}', + mcp: { server: "codex_app", tool: "list_projects" }, + startTime: Date.parse("2026-06-03T12:00:03.000Z"), + endTime: Date.parse("2026-06-03T12:00:03.800Z"), + }); + + const completedOnly = tools.find((tool) => tool.callId === "completed-only-1"); + expect(completedOnly).toMatchObject({ + name: "list_projects", + args: input, + output: result, + mcp: { server: "codex_app", tool: "list_projects" }, + startTime: Date.parse("2026-06-03T12:00:03.800Z"), + endTime: Date.parse("2026-06-03T12:00:03.900Z"), + }); + + const completedWithDurationMs = tools.find((tool) => tool.callId === "completed-only-ms"); + expect(completedWithDurationMs).toMatchObject({ + startTime: Date.parse("2026-06-03T12:00:03.850Z"), + endTime: Date.parse("2026-06-03T12:00:03.950Z"), + }); + }); }); describe("user prompt extraction", () => { diff --git a/plugins/tracing/test/trace.test.ts b/plugins/tracing/test/trace.test.ts index aa28b51..962ca6c 100644 --- a/plugins/tracing/test/trace.test.ts +++ b/plugins/tracing/test/trace.test.ts @@ -709,6 +709,134 @@ describe("convertRollout", () => { expect(attr(shell, "langfuse.observation.output")).toContain("clean"); }); + it("emits nested Codex MCP items as named tool observations", async () => { + const dir = stageFixtures(); + const file = path.join(dir, "rollout-code-mode-mcp.jsonl"); + const input = { organization_id: "demo" }; + const lines = [ + { timestamp: "2026-06-03T12:00:00.000Z", type: "session_meta", payload: { id: "sess-mcp" } }, + { + timestamp: "2026-06-03T12:00:01.000Z", + type: "event_msg", + payload: { type: "task_started", turn_id: "turn-mcp" }, + }, + { + timestamp: "2026-06-03T12:00:01.200Z", + type: "turn_context", + payload: { model: "gpt-5.6" }, + }, + { + timestamp: "2026-06-03T12:00:01.300Z", + type: "event_msg", + payload: { type: "user_message", message: "List projects" }, + }, + { + timestamp: "2026-06-03T12:00:02.000Z", + type: "response_item", + payload: { + type: "custom_tool_call", + name: "exec", + call_id: "exec-1", + input: "await codex_app.list_projects({ organization_id: 'demo' });", + }, + }, + { + timestamp: "2026-06-03T12:00:02.100Z", + type: "event_msg", + payload: { + type: "item_started", + item: { + type: "McpToolCall", + id: "mcp-1", + server: "codex_app", + tool: "list_projects", + status: "inProgress", + arguments: input, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:02.900Z", + type: "event_msg", + payload: { + type: "item_completed", + item: { + type: "McpToolCall", + id: "mcp-1", + server: "codex_app", + tool: "list_projects", + status: "completed", + arguments: input, + result: { projects: [{ id: "project-1", name: "Demo" }] }, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:03.000Z", + type: "event_msg", + payload: { + type: "item_started", + item: { + type: "McpToolCall", + id: "mcp-2", + server: "codex_app", + tool: "get_project", + status: "inProgress", + arguments: { project_id: "project-1" }, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:03.400Z", + type: "event_msg", + payload: { + type: "item_completed", + item: { + type: "McpToolCall", + id: "mcp-2", + server: "codex_app", + tool: "get_project", + status: "failed", + arguments: { project_id: "project-1" }, + error: { message: "access denied" }, + }, + }, + }, + { + timestamp: "2026-06-03T12:00:03.500Z", + type: "response_item", + payload: { type: "custom_tool_call_output", call_id: "exec-1", output: "done" }, + }, + { + timestamp: "2026-06-03T12:00:03.600Z", + type: "event_msg", + payload: { type: "agent_message", message: "The project is Demo." }, + }, + { + timestamp: "2026-06-03T12:00:03.700Z", + type: "event_msg", + payload: { type: "task_complete", turn_id: "turn-mcp" }, + }, + ]; + fs.writeFileSync(file, `${lines.map((line) => JSON.stringify(line)).join("\n")}\n`); + + await convertRollout(file, { config: baseConfig }); + + const tools = exporter.getFinishedSpans().filter((span) => obsType(span) === "tool"); + const listProjects = tools.find((span) => span.name === "codex_app.list_projects"); + expect(listProjects).toBeDefined(); + expect(attr(listProjects!, "langfuse.observation.metadata.codex.call_id")).toBe("mcp-1"); + expect(attr(listProjects!, "langfuse.observation.input")).toContain('"organization_id":"demo"'); + expect(attr(listProjects!, "langfuse.observation.output")).toContain("Demo"); + expect(startMs(listProjects!)).toBe(Date.parse("2026-06-03T12:00:02.100Z")); + expect(endMs(listProjects!)).toBe(Date.parse("2026-06-03T12:00:02.900Z")); + + const failedProject = tools.find((span) => span.name === "codex_app.get_project"); + expect(failedProject).toBeDefined(); + expect(attr(failedProject!, "langfuse.observation.level")).toBe("ERROR"); + expect(attr(failedProject!, "langfuse.observation.status_message")).toContain("access denied"); + }); + it("does not re-export a settings event between turns on every invocation", async () => { const dir = stageFixtures(); const file = path.join(dir, "rollout-thread-settings-main.jsonl");