From d37c03c236fb240878649256f2dd76620cd1e23e Mon Sep 17 00:00:00 2001 From: Paperclip Date: Mon, 12 Oct 2026 12:51:37 +0000 Subject: [PATCH] fix(acpx): snapshot pending tools when the stop fires A cancel can close the stalled tool with a tool_call update before finalization, which dropped it from the stop-time pending set and erased acpOldestPendingToolAgeAtStopMs and its kind. Snapshot the pending tools in the abort listener and summarize that snapshot for stopped turns. Co-Authored-By: Claude Opus 5.5 --- doc/observability.md | 6 ++- .../src/acpx-engine/execute.test.ts | 41 +++++++++++++++++++ .../adapter-utils/src/acpx-engine/execute.ts | 20 ++++++--- 3 files changed, 59 insertions(+), 8 deletions(-) diff --git a/doc/observability.md b/doc/observability.md index 9bcbf83993c..807ad61c80a 100644 --- a/doc/observability.md +++ b/doc/observability.md @@ -642,8 +642,10 @@ A stopped turn (wall-clock timeout or operator stop) also records `acpLastEventAgeAtStopMs` and `acpOldestPendingToolAgeAtStopMs`, measured at the moment the stop fired. A cancel can make the agent emit closing events, so the finalization age alone cannot separate a turn that went silent long before its -deadline from one that was still working. When tools are pending, -`acpPendingToolKinds` lists their ACP tool kinds as a sorted, comma-separated +deadline from one that was still working. For a stopped turn, pending tools +means the tools pending when the stop fired, so a tool the cancel closes still +counts; `acpPendingToolCount` keeps its finalization-time meaning. When tools are +pending, `acpPendingToolKinds` lists their ACP tool kinds as a sorted, comma-separated string drawn only from the closed ACP `ToolKind` enum plus `unknown`; the server drops the field if any other value appears. diff --git a/packages/adapter-utils/src/acpx-engine/execute.test.ts b/packages/adapter-utils/src/acpx-engine/execute.test.ts index ca6dfe688d5..847dcfab7c9 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.test.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.test.ts @@ -3393,6 +3393,47 @@ describe("ACP activity diagnostics", () => { const diagnostics = Object.fromEntries(Object.entries(result.resultJson ?? {}).filter(([key]) => key.startsWith("acp"))); expect(JSON.stringify(diagnostics)).not.toContain("private"); }, 15_000); + + it("keeps the stalled tool's stop-time age when the cancel closes that tool", async () => { + const root = await makeTempRoot(); + const cwd = path.join(root, "worktree"); + await fs.mkdir(cwd, { recursive: true }); + let currentNow = 1000; + let releaseTurn: (() => void) | null = null; + const turnCancelled = new Promise((resolve) => { releaseTurn = resolve; }); + const execute = createAcpxEngineExecutor({ + now: () => currentNow, + createRuntime: () => ({ + ...buildRuntime(), + startTurn: () => ({ + events: (async function* () { + yield { type: "tool_call", toolCallId: "private-id", title: "private command", kind: "execute", status: "in_progress" }; + currentNow = 9000; + await turnCancelled; + // The cancel closes the stalled tool before finalization runs. + currentNow = 9500; + yield { type: "tool_call", tag: "tool_call_update", toolCallId: "private-id", status: "cancelled" }; + })(), + result: turnCancelled.then(() => ({ status: "cancelled", stopReason: "cancelled" })), + cancel: async () => { releaseTurn?.(); }, + }), + }) as never, + }); + const result = await execute({ + runId: "cancel-closes-tool", agent: { id: "agent-1", companyId: "company-1" }, runtime: {}, + config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir: path.join(root, "state"), cwd, timeoutSec: 1 }, + context: {}, onMeta: async () => {}, onLog: async () => {}, + } as never); + expect(result.timedOut).toBe(true); + expect(result.resultJson).toMatchObject({ + acpPendingToolCount: 0, + acpLastEventAgeAtStopMs: 8000, + acpOldestPendingToolAgeAtStopMs: 8000, + acpPendingToolKinds: "execute", + }); + const diagnostics = Object.fromEntries(Object.entries(result.resultJson ?? {}).filter(([key]) => key.startsWith("acp"))); + expect(JSON.stringify(diagnostics)).not.toContain("private"); + }, 15_000); }); describe("summarizeAcpStopActivity", () => { diff --git a/packages/adapter-utils/src/acpx-engine/execute.ts b/packages/adapter-utils/src/acpx-engine/execute.ts index 02b394dcc10..01ae1020b8d 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.ts @@ -3250,6 +3250,10 @@ async function emitRuntimeEvent( } } +function isPendingAcpTool(tool: { status?: string }): boolean { + return tool.status !== "completed" && tool.status !== "failed" && tool.status !== "cancelled"; +} + /** * Activity as of the moment the turn's stop fired, for a stopped turn only. * Separates a turn that went silent long before its deadline from one that @@ -4798,10 +4802,12 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { let observedRuntimeEvents = 0; // Activity as of the moment the turn's stop (wall-clock timeout or // operator stop) fired. The cancel can make the agent emit closing - // events, so the finalize-time age alone cannot tell a silent stall + // events (including updates that close the stalled tool), so the + // finalize-time age and pending set alone cannot tell a silent stall // from live work. let turnStopRequestedAt: number | null = null; let lastRuntimeEventBeforeStopAt: number | null = null; + let pendingToolsAtStop: Array<{ kind?: string; firstSeenAt?: number }> | null = null; let turnDispatchAttempted = false; // The turn-local state the sequence steps share. `promptBuild` sets the // prompt, `preTurnUsage` sets the pre-turn status, `turnStart` sets the @@ -4889,7 +4895,11 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { }; const stepTurnStart = (signal: AbortSignal, startTimeoutMs: number | undefined): StartedTurn => { ctx.signal?.throwIfAborted(); - signal.addEventListener("abort", () => { turnStopRequestedAt ??= now(); }, { once: true }); + signal.addEventListener("abort", () => { + if (turnStopRequestedAt !== null) return; + turnStopRequestedAt = now(); + pendingToolsAtStop = [...interruptionTools.values()].filter(isPendingAcpTool); + }, { once: true }); // After entering startTurn, a thrown error cannot prove the provider // received no work. Only failures before this boundary are free to settle. turnDispatchAttempted = true; @@ -5050,16 +5060,14 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { // Capture runtime activity before usage reads, error logs, or cleanup // make an otherwise silent turn look active at its execution deadline. const lastEventAgeMs = lastRuntimeEventAt === null ? undefined : now() - lastRuntimeEventAt; - const pendingTools = [...interruptionTools.values()].filter( - (tool) => tool.status !== "completed" && tool.status !== "failed" && tool.status !== "cancelled", - ); + const pendingTools = [...interruptionTools.values()].filter(isPendingAcpTool); const activityDiagnostics = { acpObservedEventCount: observedRuntimeEvents, ...(lastEventAgeMs !== undefined && Number.isSafeInteger(lastEventAgeMs) && lastEventAgeMs >= 0 ? { acpLastEventAgeMs: lastEventAgeMs } : {}), acpPendingToolCount: pendingTools.length, acpToolInventoryComplete: !incompleteToolInventory, - ...summarizeAcpStopActivity(turnStopRequestedAt, lastRuntimeEventBeforeStopAt, pendingTools), + ...summarizeAcpStopActivity(turnStopRequestedAt, lastRuntimeEventBeforeStopAt, pendingToolsAtStop ?? pendingTools), }; if (input.kind === "terminal") { const terminal = input.terminal;