diff --git a/docs/CHANGELOG.md b/docs/CHANGELOG.md index a48e4d955..de03a69b5 100644 --- a/docs/CHANGELOG.md +++ b/docs/CHANGELOG.md @@ -18,6 +18,29 @@ entry. See `CONTRIBUTING.md` § Releases & changelog. ## [Unreleased] +### Fixed — the resume/reaper conformance test raced the wall clock + +- **`a RESUMED task survives the reaper` could fail for reasons unrelated to + the behaviour it guards.** It aged a parked task by `sleep(120)`, resumed it, + and then swept with `staleAfterMs: 60` using the reaper's *default real-time* + `now`. That left a 60ms budget between `provideInput` returning and the sweep + running: any stall longer than that — a GC pause, a loaded CI box, the serial + Postgres job sharing a runner — aged the freshly reset heartbeat past its own + window, so the reaper failed the task and the test went red while the code + was correct. Reproduced deterministically by inserting an 80ms stall before + the sweep. +- The sweep now takes an explicit `now` anchored on the resume's own + `updatedAt`. `provideInput` writes `updatedAt` and `lastHeartbeatAt` in one + statement, so that timestamp comes from the same clock that stamped the row — + the database's for the durable store, the process's for the in-memory one — + and the comparison no longer depends on how long the test itself takes. With + the fix the test survives even a 3s injected stall. +- `updatedAt` is the anchor precisely because it stays correct when the + behaviour regresses: dropping the `lastHeartbeatAt` reset still advances + `updatedAt`, so the frozen heartbeat lands outside the window and the test + goes red. Verified by mutation against **both** stores — in-memory and real + Postgres. + ### Fixed — the rest of the test servers now bind the port they dial (#707) - **The remaining 57 `listen(0)` sites are converted.** #703 fixed the diff --git a/middleware/test/tasks/taskStoreConformance.ts b/middleware/test/tasks/taskStoreConformance.ts index 4b1220cb5..d412dba6a 100644 --- a/middleware/test/tasks/taskStoreConformance.ts +++ b/middleware/test/tasks/taskStoreConformance.ts @@ -292,10 +292,27 @@ export function runTaskStoreConformance( 'provideInput advanced lastHeartbeatAt past creation', ); - // Reap immediately with a window (60ms) that sits BETWEEN the frozen - // pre-park heartbeat (~120ms old) and the just-reset one (~0ms old). Uses - // the reaper's default real-time `now`, so both stores' wall clocks agree. + // Reap with a window (60ms) that sits BETWEEN the frozen pre-park + // heartbeat (>=120ms before the resume) and the just-reset one. + // + // `now` is anchored on the resume's OWN timestamp rather than the wall + // clock. `provideInput` writes `updatedAt` and `lastHeartbeatAt` in one + // statement, so `updatedAt` marks the instant of the resume in whichever + // clock the store uses — the database's for the durable store, the + // process's for the in-memory one — which is the same clock the row's + // `lastHeartbeatAt` was stamped by. Reading the default real-time `now` + // instead left a 60ms budget between `provideInput` returning and the + // sweep running: a GC pause or a loaded CI box aged the freshly reset + // heartbeat past its own window and failed this test for reasons that had + // nothing to do with the behaviour under test. + // + // `updatedAt` is the right anchor precisely because it stays correct when + // the behaviour under test regresses: drop the `lastHeartbeatAt` reset and + // `updatedAt` still advances, so the frozen heartbeat lands outside the + // window and this test goes red — which is the whole point of it. + const resumeAt = Date.parse(afterResume.updatedAt); const result = await store.reapOrphans({ + now: new Date(resumeAt + 30), staleAfterMs: 60, purgeTerminalAfterMs: HOUR_MS, });