diff --git a/.agents/notes/implemented/testing/2026-10-28-acp-disconnect-fixture-clock.md b/.agents/notes/implemented/testing/2026-10-28-acp-disconnect-fixture-clock.md new file mode 100644 index 0000000000..ac153a8441 --- /dev/null +++ b/.agents/notes/implemented/testing/2026-10-28-acp-disconnect-fixture-clock.md @@ -0,0 +1,24 @@ +# Control ACP disconnect ordering without stranding repo persistence + +Status: implemented +Translation: current + +[中文](2026-10-28-acp-disconnect-fixture-clock.zh.md) + +## Abstract + +The disconnected-prompt regression could pass its assertions and still time out while closing its offline repository. Its fake timeout clock captured a persistence yield chosen using real elapsed time, and switching clocks at cleanup discarded that callback. These cases now retain real timers throughout the repository lifetime and use explicit prompt/disconnect gates plus an explicit flush boundary to test both buffered and persisted notifications. Production behavior, existing assertions and the 30-second timeout remain unchanged. + +## Decision and evidence + +This applies the [native repo fixture clock decision](2026-10-27-native-repo-epoch-fixture-clock.md) to the disconnected-prompt cases. In locked `loro-repo` 0.25.0, `DocManager.drainDirtyDocs` uses `performance.now()` for its 5ms work budget and awaits `setTimeout(0)` when more work remains. The fixture faked timeout timers while leaving that monotonic clock real. `destroyRepoOnRealTimers` uninstalled the clock before `repo.destroy()`, losing an outstanding yield while the repository still owned its persistence promise. + +A temporary, hoisted monotonic clock advancing 10ms on every read forced this branch before the SDK captured its clock. On the original tool-update case, timer stacks identified `DocManager.drainDirtyDocs`; cleanup reached repository destruction and then hit the unchanged 30-second timeout. [CI run 40630618794, first CLI attempt](https://github.com/LodyAI/Lody/actions/runs/40630618794/job/122625876973) records the same test timing out, but contains no stack proving which await stalled on that runner. The controlled reproduction proves the fixture defect, not that unobserved CI execution detail. + +The test does not assert elapsed time, so it keeps real timers instead of trying to guess how far to advance a fake clock. The synthetic provider emits its notification, cancels the scheduled batch flush synchronously, and signals prompt entry. The test either leaves the notification buffered or explicitly awaits `flushACPUpdatesNow`, then releases the provider's disconnection. It awaits the execution and resource cleanup receipts; no sleep, polling, retry or increased timeout is used. The existing no-replay, unknown outcome, inactive execution and cleared presence assertions cover both orders for all three notification types. Batch-window cases retain their fake clock. + +## Verification and limits + +The complete file passed 20 consecutive independent Vitest processes (74 cases each, 1,480 cases total). The six gated disconnect variants also passed five independent processes with the injected 10ms clock; timer stacks confirmed the forced persistence yield. Removing only the real-timer fix under that same clock reproduced the 30-second cleanup timeout after execution, drain and assertions had completed. The injected clock and diagnostic logging were temporary experiments, not shipped test hooks. + +The provider and Git boundary remain synthetic; lifecycle forwarding, history, execution finalization and offline repository cleanup remain real. Local repetitions and the injected-clock ablation validate this fixture path, not live providers or desktop packaging. No Effect ownership or migration boundary changes. diff --git a/.agents/notes/implemented/testing/2026-10-28-acp-disconnect-fixture-clock.zh.md b/.agents/notes/implemented/testing/2026-10-28-acp-disconnect-fixture-clock.zh.md new file mode 100644 index 0000000000..492bb908a1 --- /dev/null +++ b/.agents/notes/implemented/testing/2026-10-28-acp-disconnect-fixture-clock.zh.md @@ -0,0 +1,24 @@ +# 显式控制 ACP 断连顺序,保留仓库持久化回调 + +Status: implemented +Translation: current + +[English](2026-10-28-acp-disconnect-fixture-clock.md) + +## 摘要 + +断连提示词的回归测试可能已通过断言,却在关闭离线仓库时超时。原 fixture 根据真实耗时触发持久化让出,再用假 timeout 计时器接住回调;清理时切换时钟便丢掉了回调。这组用例现在让仓库整个生命周期保持真实计时器,并用显式的 prompt、断连信号和 flush 边界覆盖通知尚未写入与已经写入两种顺序。产品行为、原有断言和 30 秒超时保持不变。 + +## 决定与证据 + +本次将[原生仓库 fixture 时钟决定](2026-10-27-native-repo-epoch-fixture-clock.zh.md)应用到断连提示词用例。锁定版本 `loro-repo` 0.25.0 的 `DocManager.drainDirtyDocs` 使用 `performance.now()` 计算 5ms 工作预算,仍有工作时会等待 `setTimeout(0)`。fixture 替换了 timeout 计时器,却保留真实单调时钟。`destroyRepoOnRealTimers` 在调用 `repo.destroy()` 前卸载假时钟,丢掉尚未执行的让出回调,而仓库仍持有对应的持久化 Promise。 + +临时通过 hoisted 注入让单调时钟每次读取递增 10ms,在 SDK 捕获时钟前强制这条路径。原 tool-update 用例的计时器调用栈指向 `DocManager.drainDirtyDocs`;清理进入仓库销毁后触发原有 30 秒超时。[CI run 40630618794 的首次 CLI job](https://github.com/LodyAI/Lody/actions/runs/40630618794/job/122625876973)记录同一用例超时,但没有能证明当时具体阻塞点的调用栈。受控复现证明的是 fixture 缺陷,不能据此断言原 CI 未观测到的细节。 + +测试不检查耗时,因此保留真实计时器,而不猜测应推进假时钟多久。合成 provider 发出通知后同步取消已排队的批处理 flush,再发送 prompt 已进入信号。测试保留缓冲通知,或显式等待 `flushACPUpdatesNow`,然后才释放 provider 的断连。执行和资源清理均等待其完成 Promise,不使用 sleep、轮询、retry 或更长超时。原有的不重放、未知结果、执行结束、presence 清除断言覆盖三种通知的两种顺序。批处理窗口用例继续使用假时钟。 + +## 验证与限制 + +整个文件连续 20 个独立 Vitest 进程通过,每轮 74 项,共 1,480 项。六个显式控制顺序的断连变体在每次递增 10ms 的注入时钟下,另通过五个独立进程;计时器调用栈确认触发了持久化让出。同样条件下,仅去掉真实计时器修复,执行、排空和断言完成后再次触发 30 秒清理超时。注入时钟和诊断日志均为临时实验,不随测试提交。 + +provider 和 Git 边界仍为合成实现;生命周期事件转发、历史、执行收尾和离线仓库清理保持真实。本地循环与注入时钟的消融验证此 fixture 路径,不代表真实 provider 或桌面包验收。没有改变 Effect 资源归属或迁移边界。 diff --git a/apps/cli/tests/message-handler-acp-batching.test.ts b/apps/cli/tests/message-handler-acp-batching.test.ts index 90570947ad..c716484a3e 100644 --- a/apps/cli/tests/message-handler-acp-batching.test.ts +++ b/apps/cli/tests/message-handler-acp-batching.test.ts @@ -76,11 +76,10 @@ const jsonResponse = (body: unknown, status = 200): Response => headers: { 'Content-Type': 'application/json' }, }); -// loro-repo >= 0.16.11 resolves create()/initOffline()/destroy() on the real clock -// (native libuv async), NOT via the timers vitest fakes. Awaiting them while fake -// timers are installed leaves the resolution to real wall time, which on a loaded CI -// runner can be starved past the 30s test timeout. So run repo setup/teardown on real -// timers and only keep the fake clock for the batch-window assertions. +// Repo setup/teardown crosses native async work, so run it on real timers. +// Restoring real timers cannot settle yields already queued on a fake clock: +// persistence can await setTimeout(0). Tests without batch-window assertions +// should keep real timers for the whole repo lifetime. const destroyRepoOnRealTimers = async (repo: LoroRepo) => { if (vi.isFakeTimers()) { vi.useRealTimers(); @@ -237,6 +236,7 @@ const createRecoveryHarness = async ( store: SessionTransientStore; sessionActivePresence: SessionActivePresenceControllerLegacy; machineFlockCommandWatcher: { stop(): void }; + clearScheduledACPFlush(id: SessionId): void; flushACPUpdatesNow(id: SessionId): Promise; }; host.machineFlockCommandWatcher.stop(); @@ -937,26 +937,66 @@ describe('MessageHandler ACP batching', () => { } }); - it.each([ + const disconnectedPromptUpdates: AcpSessionNotification['update'][] = [ { sessionUpdate: 'current_mode_update', currentModeId: 'auto' }, { sessionUpdate: 'plan', entries: [] }, { sessionUpdate: 'tool_call_update', toolCallId: 'tool', status: 'completed' }, - ])('never replays a disconnected prompt after $sessionUpdate', async (update) => { - const h = await createRecoveryHarness({ updates: [update] }); - h.finishRetry.resolve(); - try { - await h.service.continueSession(h.message); - await h.service.drainInboxExecutions(); - expect(h.submissions).toEqual(['old']); - expect(h.outcomes.map((fact) => fact.outcome)).toEqual([ - { kind: 'unknown', code: 'agent_disconnected' }, - ]); - expect(h.service.getExecutionSnapshot(h.sessionId).hasActiveTurn).toBe(false); - expect(h.host.sessionActivePresence.has(h.sessionId)).toBe(false); - } finally { - await h.close(); + ]; + it.each( + disconnectedPromptUpdates.flatMap((update) => + [false, true].map((flushBeforeDisconnect) => ({ + update, + sessionUpdate: update.sessionUpdate, + flushBeforeDisconnect, + })) + ) + )( + 'never replays a disconnected prompt after $sessionUpdate (flushed=$flushBeforeDisconnect)', + async ({ update, flushBeforeDisconnect }) => { + // This tests event ownership, not time. A repo persistence yield must + // remain runnable through close instead of being discarded with fake timers. + vi.useRealTimers(); + const promptStarted = Promise.withResolvers(); + const disconnect = Promise.withResolvers(); + const h = await createRecoveryHarness({ + updates: [update], + onPrompt: async () => { + // Own the flush boundary so neither branch races the batch timer. + h.host.clearScheduledACPFlush(h.sessionId); + promptStarted.resolve(); + await disconnect.promise; + }, + }); + h.finishRetry.resolve(); + const running = h.service.continueSession(h.message); + try { + await Promise.race([ + promptStarted.promise, + running.then(() => { + throw new Error('Turn ended before the ACP update'); + }), + ]); + expect(h.host.store.get(h.sessionId).acpUpdateBuffer).toHaveLength(1); + if (flushBeforeDisconnect) { + await h.host.flushACPUpdatesNow(h.sessionId); + expect(h.host.store.get(h.sessionId).acpUpdateBuffer).toEqual([]); + } + disconnect.resolve(); + await running; + await h.service.drainInboxExecutions(); + expect(h.submissions).toEqual(['old']); + expect(h.outcomes.map((fact) => fact.outcome)).toEqual([ + { kind: 'unknown', code: 'agent_disconnected' }, + ]); + expect(h.service.getExecutionSnapshot(h.sessionId).hasActiveTurn).toBe(false); + expect(h.host.sessionActivePresence.has(h.sessionId)).toBe(false); + } finally { + disconnect.resolve(); + await running; + await h.close(); + } } - }); + ); it.each(['snapshot', 'progress', 'text', 'rich', 'tool'] as const)( 'subagent content observation distinguishes $0 from lifecycle status',