Skip to content

fix(tracing): capture Codex MCP tool calls #105

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
jstar0 wants to merge 1 commit into
base: main
Choose a base branch
from
+417 −4
Open

fix(tracing): capture Codex MCP tool calls #105

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
111 changes: 108 additions & 3 deletions plugins/tracing/src/parse.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
import { skillsForPrompt } from "./skills.js";
import type {
EventMsgItem,
EventMsgPayload,
MessageContentPart,
ModelStep,
Expand Down Expand Up @@ -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"]);
Expand Down Expand Up @@ -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<string, number>();

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)) {
Expand Down Expand Up @@ -212,6 +311,7 @@ export function parseSession(lines: RolloutLine[]): {
}
turn = null;
toolCallsById = new Map();
mcpCallStartTimes.clear();
};

for (const line of lines) {
Expand Down Expand Up @@ -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") {
Expand Down
18 changes: 17 additions & 1 deletion plugins/tracing/src/types.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand Down
164 changes: 164 additions & 0 deletions plugins/tracing/test/parse.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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", () => {
Expand Down
Loading