test(server): wait for complete background work settlement

Co-Authored-By: Paperclip <noreply@paperclip.ing>
This commit is contained in:
DottaandPaperclip committed 2026-10-25 17:28:56 -05:00
1 parent c0d91f5539
commit 59f8c8b3e5
4 files changed
+56 -5

No files matched your search

@@ -1971,3 +1971,12 @@ existing maintenance/startup cases. Workspace typecheck/build, migration/replay,
and candidate-index evidence passed. Full local acceptance and remote PR gates
remain required. See `2026-10-25-github-review-check-sleep-audit.md` for the failed
attempts, repairs, exact boundary, and external reconciliation limitation.
Slice 36 is draft [#17662](https://github.com/paperclipai/paperclip/pull/17662).
Its initial full local run had 13 failures and 1,569 passes, and CI failed an
inherited login-cleanup fixture. The quiet observation and fake-clock settlement
repairs are documented in its owner audit. The corrected selections passed 23
chat cases and all 16 login-cleanup tests; full/new-head verification is required.
The earlier cancellation browser failures were not reproduced in six local
replays. #17490 and #17572 remain unresolved gates, not inferred green from that
negative result. The next untouched duty remains late stale-head projection repair.
@@ -119,3 +119,32 @@ The earlier source checkpoint is `219061a159`. No full local acceptance or remot
CI success is claimed for this slice until the running checks finish. Open parent
stack failures and review findings remain independent obligations; this slice does
not make the whole stack ready or authorize merging it.
## Full acceptance and CI repairs
Draft [#17662](https://github.com/paperclipai/paperclip/pull/17662) was published at
`c0d91f553994ba898edc2701c6879c10a46b8b50`. Its first full local run completed with
1,569 passes and 13 failures in 541.25 seconds. The first failure observed a final
terminal-response state read after the scheduler removed its deadline but before
the in-flight pass finished. `nextWakeAt() === null` does not prove quiescence.
That assertion also skipped restoring its SQL spies, causing cascading failures.
The affected quiet checks now require both zero tracked active work and no next
wake. Their spies also restore on test completion if an assertion fails. All 23
affected chat cases passed in a fresh database after this repair.
The same head's CI had 51 successes and the server 1/12 plus aggregate failure.
Server 1/12 failed the inherited setup-token consume fixture while it waited for
an idle hold. Cleanup can signal another generation during a sweep, leaving a
coalesced deadline beyond the fixture's single fake-clock jump. The fixture now
advances to actual registered deadlines while tracked work remains. It keeps the
existing observation timeout and all production intervals. All 16 login-cleanup
cases passed in a separate disposable database. Fresh full acceptance and new-
head CI/review remain required; the old head is not reported green.
An independent diagnostic replayed the earlier stack's two failing cancellation
browser cases three times each: all six passed on this head in 33.6 seconds.
Scoped lock observation did not capture a deadlock. A second minimal FK/row-lock
hypothesis also did not reproduce a cycle. These are negative diagnostic results,
not a fix for #17490 or #17572. An initial database-name collision stopped setup;
the existing database was preserved and a newly named disposable database was
used instead. No blind CI rerun was consumed.
@@ -3777,15 +3777,18 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => {
const baseline = f.responseWrites.length;
sending = githubChatReviewService(db, f.providerFetch).execute(f.session, "comment", { body: "Authored final response", idempotencyKey: "terminal-owner-race" });
await ready;
await expect.poll(() => coordinator.nextWakeAt(), { timeout: 5000 }).toBeNull();
await expect.poll(() => ({ active: idleWorkSnapshot().active, next: coordinator.nextWakeAt() }),
{ timeout: 5000 }).toEqual({ active: 0, next: null });
expect(f.responseWrites).toHaveLength(baseline);
release(); await sending;
expect((await action()).status).toBe("cancelled");
if (!uncertain) await expect.poll(() => [...f.responseComments.values()][0]?.body, { timeout: 5000 }).toContain("stopped before completing");
await expect.poll(() => coordinator.nextWakeAt(), { timeout: 5000 }).toBeNull();
await expect.poll(() => ({ active: idleWorkSnapshot().active, next: coordinator.nextWakeAt() }),
{ timeout: 5000 }).toEqual({ active: 0, next: null });
if (uncertain) expect(f.responseWrites).toHaveLength(baseline);
vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"], shouldAdvanceTime: true });
const reads = vi.spyOn(db, "select"), writes = vi.spyOn(db, "transaction");
onTestFinished(() => { reads.mockRestore(); writes.mockRestore(); });
await vi.advanceTimersByTimeAsync(120_000);
expect(reads).not.toHaveBeenCalled(); expect(writes).not.toHaveBeenCalled();
reads.mockRestore(); writes.mockRestore(); expect(errors).toEqual([]);
@@ -6652,10 +6655,12 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => {
expect(coordinator.nextWakeAt()).toBeNull();
await f.enqueue();
await expect.poll(async () => (await f.action())?.status, { timeout: 5000 }).toBe("processed");
await expect.poll(() => coordinator.nextWakeAt(), { timeout: 5000 }).toBeNull();
await expect.poll(() => ({ active: idleWorkSnapshot().active, next: coordinator.nextWakeAt() }),
{ timeout: 5000 }).toEqual({ active: 0, next: null });
expect(f.writes).toEqual([expect.objectContaining({ status: "completed" })]);
vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"], shouldAdvanceTime: true });
const reads = vi.spyOn(db, "select"), transactions = vi.spyOn(db, "transaction");
onTestFinished(() => { reads.mockRestore(); transactions.mockRestore(); });
const count = f.requests.length;
await vi.advanceTimersByTimeAsync(120_000);
expect(reads).not.toHaveBeenCalled(); expect(transactions).not.toHaveBeenCalled();
@@ -6698,9 +6703,11 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => {
f.setRemoteHead("c".repeat(40));
await vi.advanceTimersByTimeAsync(6000);
await expect.poll(async () => (await f.action()).status, { timeout: 5000 }).toBe("cancelled");
await expect.poll(() => coordinator.nextWakeAt(), { timeout: 5000 }).toBeNull();
await expect.poll(() => ({ active: idleWorkSnapshot().active, next: coordinator.nextWakeAt() }),
{ timeout: 5000 }).toEqual({ active: 0, next: null });
expect((await db.select().from(chatGitHubReviews).where(eq(chatGitHubReviews.id, f.review.id)))[0].state).toBe("superseded");
const reads = vi.spyOn(db, "select"), count = f.requests.length;
onTestFinished(() => reads.mockRestore());
await vi.advanceTimersByTimeAsync(120_000);
expect(reads).not.toHaveBeenCalled(); expect(f.requests).toHaveLength(count); reads.mockRestore();
expect(f.writes).toHaveLength(1); expect(errors).toEqual([]);
@@ -116,7 +116,13 @@ describe.skipIf(!support.supported)("durable login cleanup", () => {
});
async function settle(ms = 30_000) {
await vi.advanceTimersByTimeAsync(ms);
await vi.waitFor(() => expect(idleWorkSnapshot().active).toBe(0), { timeout: 5000 });
await vi.waitFor(async () => {
if (idleWorkSnapshot().active > 0) {
const deadlines = coordinators.flatMap(c => c.nextWakeAt() === null ? [] : [c.nextWakeAt()!]);
if (deadlines.length) await vi.advanceTimersByTimeAsync(Math.max(0, Math.min(...deadlines) - Date.now()));
}
expect(idleWorkSnapshot().active).toBe(0);
}, { timeout: 5000 });
await vi.advanceTimersByTimeAsync(1);
await vi.waitFor(() => expect(idleWorkSnapshot().active).toBe(0), { timeout: 5000 });
expect(errors).toEqual([]);