From ad4c37013a45e1496faf65c438b4c2f46965b27d Mon Sep 17 00:00:00 2001 From: Tianyi Cui <53024+tianyicui@users.noreply.github.com> Date: Wed, 22 Jul 2026 22:00:48 +0800 Subject: [PATCH] test(snapshot): await cancelled turn durability --- .../snapshots/cancel-tool-calls/input.json | 3 +- .../snapshots/cancel-tool-calls/session.jsonl | 2 +- .../tests/snapshots/cancel/input.json | 3 +- packages/support/acp-snapshot/src/harness.ts | 53 ++++++++++++++++++- .../tests/fixtures/fake-acp-agent.ts | 11 +++- .../acp-snapshot/tests/harness.spec.ts | 50 +++++++++++++++++ 6 files changed, 116 insertions(+), 6 deletions(-) diff --git a/examples/acp-agent/tests/snapshots/cancel-tool-calls/input.json b/examples/acp-agent/tests/snapshots/cancel-tool-calls/input.json index 0f40e9d8b6..d893a1a15b 100644 --- a/examples/acp-agent/tests/snapshots/cancel-tool-calls/input.json +++ b/examples/acp-agent/tests/snapshots/cancel-tool-calls/input.json @@ -7,6 +7,7 @@ "text": "Run two shell commands: wait for cancellation, then write skipped.txt.", "afterUpdate": "tool_call", "waitForToolCallUpdate": "call_skipped" - } + }, + { "op": "waitForTurnEnd" } ] } diff --git a/examples/acp-agent/tests/snapshots/cancel-tool-calls/session.jsonl b/examples/acp-agent/tests/snapshots/cancel-tool-calls/session.jsonl index 192c1e19cc..c52b9f2c5d 100644 --- a/examples/acp-agent/tests/snapshots/cancel-tool-calls/session.jsonl +++ b/examples/acp-agent/tests/snapshots/cancel-tool-calls/session.jsonl @@ -18,4 +18,4 @@ {"type":"tool/call","seq":16,"time":1784437195089,"data":{"turn":1,"step":1,"callId":"call_skipped","name":"bash","arguments":"{\"command\":\"printf skipped > skipped.txt\",\"description\":\"Write skipped marker\"}"}} {"type":"tool/result","seq":17,"time":1784437195089,"data":{"turn":1,"step":1,"callId":"call_skipped","content":[{"type":"text","text":"Error: tool call aborted before dispatch"}],"isError":true,"error":{"name":"AbortError","code":"ABORTED_BEFORE_DISPATCH"}},"sourceEventSeqs":[16],"surfaceOp":"append"} {"type":"step/end","seq":18,"time":1784437195090,"data":{"turn":1,"step":1}} -{"type":"turn/end","seq":19,"time":1784437195090,"data":{"turn":1,"reason":{"kind":"disposed"}}} +{"type":"turn/end","seq":19,"time":1784437195090,"data":{"turn":1,"reason":{"kind":"aborted"}}} diff --git a/examples/acp-agent/tests/snapshots/cancel/input.json b/examples/acp-agent/tests/snapshots/cancel/input.json index 0bc989ed10..a2e2fdc5f0 100644 --- a/examples/acp-agent/tests/snapshots/cancel/input.json +++ b/examples/acp-agent/tests/snapshots/cancel/input.json @@ -2,6 +2,7 @@ "steps": [ { "op": "initialize" }, { "op": "newSession" }, - { "op": "promptAndCancel", "text": "Start a long task; this turn will be cancelled mid-stream." } + { "op": "promptAndCancel", "text": "Start a long task; this turn will be cancelled mid-stream." }, + { "op": "waitForTurnEnd" } ] } diff --git a/packages/support/acp-snapshot/src/harness.ts b/packages/support/acp-snapshot/src/harness.ts index be4573aeb0..ebc3be88bb 100644 --- a/packages/support/acp-snapshot/src/harness.ts +++ b/packages/support/acp-snapshot/src/harness.ts @@ -21,6 +21,7 @@ import { existsSync } from 'node:fs' import { createHash } from 'node:crypto' import { tmpdir } from 'node:os' import { basename, dirname, join, delimiter } from 'node:path' +import { setTimeout as delay } from 'node:timers/promises' import { ClientSideConnection, PROTOCOL_VERSION, @@ -34,6 +35,9 @@ import { launchAcpTestAgent, type AgentUnderTest, type LaunchedAcpTestAgent } fr export type { AgentUnderTest } from './launcher.ts' +const DEFAULT_TURN_END_TIMEOUT_MS = 10_000 +const TURN_END_POLL_INTERVAL_MS = 10 + /** * One step of a scenario's deterministic input script (`input.json`). The * harness interprets these in order. `newSession` captures the server-issued @@ -46,6 +50,8 @@ export type { AgentUnderTest } from './launcher.ts' * step open for a terminal tool update that may follow the prompt response. * `promptAndWaitForAgentMessage` arms an exact text-chunk waiter before sending * the prompt, then keeps the application live until that later update arrives. + * `waitForTurnEnd` holds the subprocess open until the selected session's latest + * complete raw-JSONL turn boundary is `turn/end`; its timeout defaults to 10s. */ export type InputStep = | { op: 'initialize'; terminalOutput?: boolean } @@ -60,6 +66,7 @@ export type InputStep = afterUpdate?: 'agent_message_chunk' | 'tool_call' waitForToolCallUpdate?: string } + | { op: 'waitForTurnEnd'; timeoutMs?: number } | { op: 'cancel' } | { op: 'setMode'; modeId: string } | { op: 'setModeExpectError'; modeId: string } @@ -295,7 +302,15 @@ export async function runScenario(input: InputScript, opts: RunOptions): Promise const { client } = active for (const step of input.steps) { - await runStep(client, step, cwd, match => active.waitForUpdate(match), () => sessionId, (id) => { sessionId = id }) + await runStep( + client, + step, + cwd, + match => active.waitForUpdate(match), + () => sessionId, + (id) => { sessionId = id }, + (id, timeoutMs) => waitForPersistedTurnEnd(sessionsRoot, id, timeoutMs), + ) // A permission exchange happens while a step's request is in flight, so // by the time the step settles any script bug it exposed is captured — // fail the run HERE, as a harness error, rather than hoping the agent's @@ -365,6 +380,7 @@ async function runStep( waitForUpdate: (match: (u: SessionNotification['update']) => boolean) => Promise, getSessionId: () => string | undefined, setSessionId: (id: string) => void, + waitForTurnEnd: (sessionId: string, timeoutMs?: number) => Promise, ): Promise { switch (step.op) { case 'initialize': @@ -438,6 +454,12 @@ async function runStep( if (toolCallUpdateDone !== undefined) await toolCallUpdateDone return } + case 'waitForTurnEnd': { + const sessionId = getSessionId() + if (sessionId === undefined) throw new Error('snapshot-harness: waitForTurnEnd before newSession') + await waitForTurnEnd(sessionId, step.timeoutMs) + return + } case 'cancel': { const sessionId = getSessionId() if (sessionId === undefined) throw new Error('snapshot-harness: cancel before newSession') @@ -485,6 +507,35 @@ async function runStep( } } +/** + * Wait until the raw JSONL backend exposes one complete closing turn boundary. + * The ACP cancel notification settles its prompt before the agent necessarily + * reaches quiescence, so cancellation snapshots use this external boundary to + * keep subprocess disposal from changing an `aborted` turn into `disposed`. + */ +async function waitForPersistedTurnEnd( + root: string, + sessionId: string, + timeoutMs = DEFAULT_TURN_END_TIMEOUT_MS, +): Promise { + const deadline = Date.now() + timeoutMs + while (true) { + const log = (await harvestSessionLogs(root)).find(candidate => candidate.id === sessionId) + if (log !== undefined && latestTurnIsClosed(log.content)) return + if (Date.now() >= deadline) { + throw new Error(`snapshot-harness: session "${sessionId}" did not persist turn/end within ${timeoutMs}ms`) + } + await delay(TURN_END_POLL_INTERVAL_MS) + } +} + +/** Return whether the last complete raw-JSONL turn boundary closes its turn. */ +function latestTurnIsClosed(content: string): boolean { + const complete = content.slice(0, content.lastIndexOf('\n') + 1) + return complete.lastIndexOf('\n{"type":"turn/end",') + > complete.lastIndexOf('\n{"type":"turn/start",') +} + /** * Harvest EVERY persisted `.jsonl` session log under a sessions root, parse each * header line, and return them ordered primary-first: the top-level session (no diff --git a/packages/support/acp-snapshot/tests/fixtures/fake-acp-agent.ts b/packages/support/acp-snapshot/tests/fixtures/fake-acp-agent.ts index 26d2c41638..df3bb0b970 100644 --- a/packages/support/acp-snapshot/tests/fixtures/fake-acp-agent.ts +++ b/packages/support/acp-snapshot/tests/fixtures/fake-acp-agent.ts @@ -49,6 +49,8 @@ interface Behavior { cancelAtToolCall?: boolean /** Emit the parked tool call's terminal update after answering cancellation. */ cancelToolCallUpdate?: boolean + /** Persist the scripted logs while handling cancellation, before stdin EOF. */ + persistLogsOnCancel?: boolean /** Before responding to a prompt, send a `session/request_permission` request and echo its outcome as a chunk. */ permissionProbe?: boolean /** Before responding to a prompt, send an `elicitation/create` request and echo its response as a chunk. */ @@ -63,7 +65,7 @@ interface Behavior { stderrNote?: string /** Let a short-lived descendant retain stdio and emit one final ACP update plus stderr line after this parent exits. */ lateInheritedOutput?: boolean - /** Session logs to persist on stdin EOF. */ + /** Session logs to persist on stdin EOF and, when selected, on cancellation. */ logs?: ScriptedLog[] /** Leave a stray FILE directly under the sessions root (harvest must skip it). */ strayRootFile?: boolean @@ -304,6 +306,7 @@ function handleFrame(frame: Record): void { }, }) } + if (behavior.persistLogsOnCancel === true) writeLogs() } return default: @@ -313,12 +316,16 @@ function handleFrame(frame: Record): void { } } -function flushLogsAndExit(): void { +function writeLogs(): void { for (const log of behavior.logs ?? []) { const target = join(sessionsRoot, log.file) mkdirSync(dirname(target), { recursive: true }) writeFileSync(target, log.lines.map(l => JSON.stringify(instantiate(l))).join('\n') + '\n') } +} + +function flushLogsAndExit(): void { + writeLogs() if (behavior.strayRootFile === true) writeFileSync(join(sessionsRoot, 'stray.txt'), 'not a bucket\n') if (behavior.strayBucketFile === true) { mkdirSync(join(sessionsRoot, 'bucket-noise'), { recursive: true }) diff --git a/packages/support/acp-snapshot/tests/harness.spec.ts b/packages/support/acp-snapshot/tests/harness.spec.ts index ca88c51b46..b508742dd0 100644 --- a/packages/support/acp-snapshot/tests/harness.spec.ts +++ b/packages/support/acp-snapshot/tests/harness.spec.ts @@ -530,6 +530,55 @@ describe('runScenario', () => { expect(result.rawStdout.indexOf('cancelled')).toBeLessThan(result.rawStdout.indexOf('"sessionUpdate":"tool_call_update"')) }) + it('waitForTurnEnd holds cancellation open through the persisted closing boundary', { timeout: 20_000 }, async () => { + const { fixtureFile } = await scenario({ + prompt: 'hang-until-cancel', + persistLogsOnCancel: true, + logs: [{ + file: 'bucket/session.jsonl', + lines: [ + { type: 'session', version: 0, id: '{{SID}}', createdAt: 1, delegationDepth: 0 }, + { type: 'turn/end', seq: 1, time: 2, data: { turn: 1, reason: { kind: 'aborted' } } }, + ], + }], + }) + const result = await runScenario( + { steps: [...boot, { op: 'promptAndCancel', text: 'hang' }, { op: 'waitForTurnEnd' }] }, + { agent: AGENT, mode: 'replay', fixtureFile }, + ) + expect(result.sessionLogs[0]?.content).toContain('"type":"turn/end"') + }) + + it('waitForTurnEnd times out for a missing log and an open logged turn', { timeout: 20_000 }, async () => { + const missing = await scenario({}) + await expect(runScenario( + { steps: [...boot, { op: 'waitForTurnEnd', timeoutMs: 20 }] }, + { agent: AGENT, mode: 'replay', fixtureFile: missing.fixtureFile }, + )).rejects.toThrow(/did not persist turn\/end within 20ms/) + + const open = await scenario({ + prompt: 'hang-until-cancel', + persistLogsOnCancel: true, + logs: [{ + file: 'bucket/session.jsonl', + lines: [ + { type: 'session', version: 0, id: '{{SID}}', createdAt: 1, delegationDepth: 0 }, + { type: 'turn/start', seq: 0, time: 1, data: { turn: 1 } }, + ], + }], + }) + await expect(runScenario( + { + steps: [ + ...boot, + { op: 'promptAndCancel', text: 'hang' }, + { op: 'waitForTurnEnd', timeoutMs: 20 }, + ], + }, + { agent: AGENT, mode: 'replay', fixtureFile: open.fixtureFile }, + )).rejects.toThrow(/did not persist turn\/end within 20ms/) + }) + it('promptExpectError swallows a model-error response as the expected outcome', { timeout: 20_000 }, async () => { const { fixtureFile } = await scenario({ prompt: 'error' }) const result = await runScenario( @@ -620,6 +669,7 @@ describe('runScenario', () => { [{ op: 'promptAndWaitForAgentMessage', text: 'x', waitForText: 'later' }, /promptAndWaitForAgentMessage before newSession/], [{ op: 'promptExpectError', text: 'x' }, /promptExpectError before newSession/], [{ op: 'promptAndCancel', text: 'x' }, /promptAndCancel before newSession/], + [{ op: 'waitForTurnEnd' }, /waitForTurnEnd before newSession/], [{ op: 'cancel' }, /cancel before newSession/], [{ op: 'setConfigOption', configId: 'sandbox-mode', value: 'read-only' }, /setConfigOption before newSession/], [{ op: 'setConfigOptionExpectError', configId: 'sandbox-mode', value: 'yolo' }, /setConfigOptionExpectError before newSession/],