diff --git a/packages/test-support/session-snapshot/README.i18n.yaml b/packages/test-support/session-snapshot/README.i18n.yaml index 46d058dadf..7653583147 100644 --- a/packages/test-support/session-snapshot/README.i18n.yaml +++ b/packages/test-support/session-snapshot/README.i18n.yaml @@ -2,5 +2,5 @@ # side as of the last confirmed-consistent state. Both languages carry equal authority; # after editing either side, bring the other along and re-record with: # pnpm run verify-translation-pairing --write packages/test-support/session-snapshot/README.md -README.md: f1126920969cead7844712ad3b2c7213cce19ed9 -README.zh.md: 65e04f252a13c22351b450da2df44f244d484811 +README.md: 6e88270dc3be31b135534097d30fb2b67a37ebde +README.zh.md: 57cf86dcda198ac939c6e82c56cd3c9c3b473baa diff --git a/packages/test-support/session-snapshot/README.md b/packages/test-support/session-snapshot/README.md index f112692096..6e88270dc3 100644 --- a/packages/test-support/session-snapshot/README.md +++ b/packages/test-support/session-snapshot/README.md @@ -88,6 +88,7 @@ A scenario requiring a non-Windows host declares `posixOnly`, which skips its ru ### What can go wrong +- **A child turn wait fails** — `waitForSubagentTurnEnd` identifies the child, requested turn, and deadline even when the first log harvest exceeds that deadline, and retains the underlying failure as the error cause. - **A fixture guard rejects the committed files** — orphan scenario dirs, missing files, multiple pins for one header class, duplicate sidecar content, unscrubbed JSONL headers, and malformed pinning headers all fail the suite before comparisons run. - **The session harvest needs raw JSONL mode** — snapshot configs set the JSONL backend's `compression: 'none'`; compressed JSONL has no snapshot-harvest path. - **Built mode needs current artifacts** — run `pnpm run build` before selecting `DSH_EXAMPLE_MODE=lib`; source mode remains the zero-build path. diff --git a/packages/test-support/session-snapshot/README.zh.md b/packages/test-support/session-snapshot/README.zh.md index 65e04f252a..57cf86dcda 100644 --- a/packages/test-support/session-snapshot/README.zh.md +++ b/packages/test-support/session-snapshot/README.zh.md @@ -88,6 +88,7 @@ Spill 场景通过真实本地 provider 保存到私有临时根目录。夹具 ### 可能出什么问题 +- **子会话轮次等待失败**——即使首次日志收集就超过期限,`waitForSubagentTurnEnd` 也会指出子会话、目标轮次与等待期限,并通过错误的 cause 保留底层失败。 - **fixture 保护拒绝已提交文件**——遗留场景目录、缺失文件、一个 header 类别包含多个 pin、重复的伴随文件内容、未擦除的 JSONL header 与格式错误的 pin header 都会在比较运行前使套件失败。 - **会话收集需要原始 JSONL mode**——快照配置使用 JSONL 后端的 `compression: 'none'`;压缩 JSONL 没有快照收集路径。 - **构建 mode 需要当前产物**——选择 `DSH_EXAMPLE_MODE=lib` 前先运行 `pnpm run build`;源 mode 仍是零构建路径。 diff --git a/packages/test-support/session-snapshot/src/harness.ts b/packages/test-support/session-snapshot/src/harness.ts index cd54f516ae..691cb1dc8b 100644 --- a/packages/test-support/session-snapshot/src/harness.ts +++ b/packages/test-support/session-snapshot/src/harness.ts @@ -67,7 +67,8 @@ const WAIT_POLL_INTERVAL_MS = 10 * `waitForInboxMessage` waits for inserted inbox text containing a scenario marker. * `waitForSubagentTurnEnd` waits until one background child has persisted a * closed model-work turn after its own descriptor; child progress has no ACP - * update to wait on. + * update to wait on. Failures identify the child, turn, and deadline even if + * the first log read is still pending; the underlying failure is retained as cause. * `waitForTitleAfterTurnEnd` additionally waits for a later durable title. * `waitForEventAfterTurnEnd` waits until a complete record of the given event * type follows the latest closed turn — for scenarios whose asserted state @@ -608,16 +609,20 @@ async function waitForPersistedChildTurnEnd( timeoutMs = DEFAULT_WAIT_TIMEOUT_MS, minimumTurn = 1, ): Promise { - await vi.waitFor(async () => { - const log = (await harvestSessionLogs(root))[child] - if (log === undefined || !latestTurnIsClosed(log.content) - || !hasRequestHeaderAfterDescriptor(log.content) - || !hasClosedTurn(log.content, minimumTurn)) { - throw new Error( - `snapshot-harness: subagent child #${child} did not persist closed turn ${minimumTurn} within ${timeoutMs}ms`, - ) - } - }, { interval: WAIT_POLL_INTERVAL_MS, timeout: timeoutMs }) + const message = `snapshot-harness: subagent child #${child} did not persist closed turn ${minimumTurn} within ${timeoutMs}ms` + try { + await vi.waitFor(async () => { + const log = (await harvestSessionLogs(root))[child] + if (log === undefined || !latestTurnIsClosed(log.content) + || !hasRequestHeaderAfterDescriptor(log.content) + || !hasClosedTurn(log.content, minimumTurn)) { + throw new Error(message) + } + }, { interval: WAIT_POLL_INTERVAL_MS, timeout: timeoutMs }) + } catch (cause) { + // The deadline can precede the first harvest, before the callback names the missing turn. + throw new Error(message, { cause }) + } } /** Whether a raw session log contains the requested closed turn. */ diff --git a/packages/test-support/session-snapshot/tests/harness.spec.ts b/packages/test-support/session-snapshot/tests/harness.spec.ts index 089b68526c..0a23c326c6 100644 --- a/packages/test-support/session-snapshot/tests/harness.spec.ts +++ b/packages/test-support/session-snapshot/tests/harness.spec.ts @@ -1,4 +1,5 @@ import { mkdir, mkdtemp, readFile, readdir, realpath, rm, symlink, writeFile } from 'node:fs/promises' +import * as fsPromises from 'node:fs/promises' import { once } from 'node:events' import { tmpdir } from 'node:os' import { delimiter, join, relative, sep } from 'node:path' @@ -984,6 +985,37 @@ describe('runScenario', () => { )).rejects.toThrow(/did not persist goal phase "blocked" within 20ms/) }) + it('identifies the child wait when its first log harvest outlasts the deadline', async () => { + const { fixtureFile } = await scenario({}) + const reading = Promise.withResolvers() + const release = Promise.withResolvers() + let pendingRead: Promise | undefined + const originalReaddir = readdir + const spy = vi.spyOn(fsPromises, 'readdir').mockImplementation(async (...args) => { + if (pendingRead === undefined && String(args[0]).includes('acp-snap-sessions-')) { + const read = release.promise.then(() => originalReaddir(...args)) + pendingRead = read + reading.resolve(undefined) + return await read + } + return await originalReaddir(...args) + }) + const run = runScenario( + { steps: [...boot, { op: 'waitForSubagentTurnEnd', child: 2, timeoutMs: 20 }] }, + { agent: AGENT, mode: 'replay', fixtureFile }, + ) + const rejected = expect(run).rejects.toThrow(/subagent child #2 did not persist closed turn 1 within 20ms/) + try { + await Promise.race([reading.promise, rejected]) + expect(pendingRead).toBeDefined() + await rejected + } finally { + release.resolve(undefined) + await Promise.allSettled([pendingRead, run, rejected]) + spy.mockRestore() + } + }) + it('waitForSubagentTurnEnd requires a closed child work turn', { timeout: 20_000 }, async () => { const closed = await scenario({ prompt: 'hang-until-cancel',