From 223687bbb9d71a27365eadd6ce7488ba4638fb0b Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Thu, 5 Nov 2026 22:40:13 -0600 Subject: [PATCH] test(server): size heavy chat-channel tests to their workload to stop timeout cascades (#19404) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - Chat channels connect GitHub, Slack, and other providers to tasks, and `chat-channels.integration.test.ts` covers them against a real embedded Postgres > - Two parameterized tests do much more database work than the other tests in the file, but they use the global 15s `testTimeout` > - On a slow CI runner they time out. Vitest then keeps the timed-out test body running, and that body breaks later, unrelated tests in the same file > - This failure blocks PRs that do not touch chat code > - This pull request gives the two heavy tests a time budget that fits their workload > - The benefit is that a slow runner no longer turns one heavy test into a cascade of 2–7 failures ## Linked Issues or Issue Description **What happened?** In run 42098299218 (job 127495756270, shard `General tests (chat (3/3))`), 7 chat tests failed in two Vitest processes on a PR that changed only unrelated test files: - Process 1: `reactivates denied retry notices when authority is restored during bounded pass` timed out at 15000ms. Then `… during requester merge` failed with `A function to advance timers was called but the timers APIs are not mocked`. - Process 2: `preserves one current GitHub Retry across backlog_51` and `… consumed_backlog_52` timed out at 15000ms. About 110 tests later, three pre-run FIFO tests failed: `advances pre-run FIFO selection past a suppressed page with microsecond timestamps (manual)` (`expected +0 to be 1`), `retires an already-visible pre-run FIFO notice once without publishing scheduler failures` (`expected [] to have a length of 1`), and `retries a contended pre-run FIFO receipt before I/O and observes cancellation after the lock releases` (`expected undefined to match object { state: 'retry' }`). **Expected behavior** These tests pass on a slower runner. A timeout in one test does not change the result of a different test. **Steps to reproduce** 1. On `master`, in `server/`, run: `pnpm exec vitest run src/__tests__/chat-channels.integration.test.ts -t "GitHub Retry across (backlog_51|consumed_backlog_52)|advances pre-run FIFO selection past a suppressed page|retires an already-visible pre-run FIFO notice once|retries a contended pre-run FIFO receipt before I/O" --testTimeout=1200` 2. The lower timeout simulates a slow runner. The two backlog tests time out, and then the same three FIFO tests fail with the same assertions as in CI. The `scoped` FIFO case passes, as it did in CI. 3. Run the same command without `--testTimeout`. All 6 tests pass. **Root cause** - The workload is large. `backlog_51` and `consumed_backlog_52` deliver 51–52 real inbound GitHub messages through the full delivery path. `bounded pass` inserts and authorizes 100 rejected retry notices. - CI timing data supports this. On passing runs these tests take 5.4–7.7s (backlog) and 3.6–5.3s (bounded pass), and lighter tests in the same file take 0.5–1s. On the failing runner, the lighter tests were 2–3x slower (for example, `idle` took 1856ms instead of 500–680ms). This put the heavy tests over 15s. - When Vitest times out a test, it does not stop the test body. The body keeps running while the next tests start: - The unfinished backlog tests left 51+ `deferred_issue_execution` inbound wakeups. The pre-run FIFO tests use unscoped, bounded passes (`enqueueInboundWakeupPublications`, `processPendingPublications`). The leftover rows filled those pages, so the new test's row was not reached. - The unfinished `bounded pass` body later ran its `finally` block, which calls `vi.useRealTimers()`. This disabled the fake timers that `requester merge` had just installed. ## What Changed - `preserves one current GitHub Retry across %s`: set an explicit 60s timeout. - `reactivates denied retry notices when authority is restored during %s`: set an explicit 60s timeout. Increase the `bounded pass` wait for its held 100-row reconciliation from 10s to 30s, so that the inner wait does not become the new limit. - The same file already uses explicit 20s, 25s, 30s, 40s, 60s, and 90s budgets for other heavy tests. No product code changed. ## Verification - Red: the reproduction command above fails on `master` with the CI cascade. A tighter `--testTimeout=1600` on `reactivates denied retry notices` also shows that later modes fail after `bounded pass` times out. - Green: the same reproduction command with this change (still `--testTimeout=1200` for all other tests) passes 10/10 selected tests, including the three FIFO tests. - `pnpm exec vitest run src/__tests__/chat-channels.integration.test.ts -t "GitHub Retry across|reactivates denied retry notices|pre-run FIFO"`: 46 passed. ## Risks - Low risk. This is a test-only change. A real hang in these two tests now fails after 60s instead of 15s. This is well inside the job limit. - The cascade can still occur if one of these tests needs more than 60s. That would mean a runner about 10x slower than a normal one. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, used through Claude Code with tool use (shell, file edits, GitHub CLI). Default context window. No extended thinking mode. ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes #` / `Refs #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [ ] All Paperclip CI gates are green - [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-authored-by: Claude Opus 5.5 --- server/src/__tests__/chat-channels.integration.test.ts | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/server/src/__tests__/chat-channels.integration.test.ts b/server/src/__tests__/chat-channels.integration.test.ts index 9ff1ae6b8eb..644e2696c00 100644 --- a/server/src/__tests__/chat-channels.integration.test.ts +++ b/server/src/__tests__/chat-channels.integration.test.ts @@ -65751,7 +65751,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { }); } } finally { await f.service.shutdown(); } - }, + }, 60_000, ); it("leaves saved GitHub input pending when a persisted Retry wait loses board authority", async () => { @@ -68767,7 +68767,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { } vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"], shouldAdvanceTime: true }); ready = chatFailedRetryNoticeWork(context.service).register(coordinator, () => true).ready; - if (mode === "bounded pass") await vi.waitFor(() => expect(held).toBe(true), { timeout: 10_000 }); + if (mode === "bounded pass") await vi.waitFor(() => expect(held).toBe(true), { timeout: 30_000 }); else { await ready; await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(10); @@ -68814,7 +68814,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { [...rejectedIds, context.retry.requestId!, context.retry.chatActionId!])); if (rejectedIds.length) await db.delete(chatActions).where(inArray(chatActions.id, rejectedIds)); } - }); + }, 60_000); it("wakes a not-started retry notice after resumed admission is denied", async () => { const context = await deferredFailedRetryNoticeFixture();