Repository navigation
Fix six flaky or stale-reading follow-ups from the last reviews - #805
Merged
Merged
Conversation
…when a change notice arrives A click takes the read started on intent out of the table of reads and waits on it. A notice that its document was renamed, updated or deleted came to `forget`, which only looked in that table, so an opening already waiting on a slow read was given the record from before the change when it arrived. The reads an opening has been handed are now kept until it has them; `forget` marks those of the changed document, and the opening reads for itself instead of using the record. A read of another document is left as it was, and the read is dropped from the set once the opening has its answer, so nothing keeps it after it was used. Assistant-model: Claude Sonnet 5.5 Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e) Assistant-verification: bun test apps/web/src/document-intent.test.ts failed before the fix (the new test got the record from before the change) and passed after it, 25/25 Assistant-verification: bun run types (apps/web) passed Assistant-verification: dprint fmt, oxlint and scripts/check-design-contract.ts passed on the changed files Co-authored-by: Alex Lavaee <lavaman131@github.com>
… so it does not fail just after local midnight
The page words a machine's last-seen time as the time of day when it falls today and as a date and time on any other day, in the browser's time zone. The test marked the machine as seen an hour before the real clock and expected the time of day, so a run in the first hour after local midnight was shown "Nov 9, 11:40 PM" and failed, on a desktop and on a phone. The page's clock is now fixed at noon and its time zone at UTC, and the machine was seen an hour before that. What the test asserts is unchanged.
Assistant-model: Claude Sonnet 5.5
Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e)
Assistant-verification: playwright "says when it was last seen" (desktop and phone) failed before the fix with TZ=Etc/GMT-9 at 00:40 local ("Last seen Nov 9, 11:40 PM") and passed after it with the same zone, and 6/6 with --repeat-each=3 in the machine's own zone, on a disposable server and database of its own
Assistant-verification: tsgo --noEmit -p e2e, dprint fmt, oxlint and scripts/check-design-contract.ts passed
Co-authored-by: Alex Lavaee <lavaman131@github.com>
…han its short lease The expiring half of "shows a released or expired lease as free" took a lease with a 20 ms time and asserted it was not yet free after one more query. The lease's expiry is read from the database's clock when it is taken, and the commit and the next query come after it, so the assertion held only while the database answered within 20 ms. A runner with a slow disk or network found the lease already free: with a proxy holding each chunk to the database for 5 ms the test failed every time, "Expected: false, Received: true". It was never a fact about `peek`. Both leases are now read after the same wait: the short one, which is free, and one taken for a minute, which is still held. That keeps the claim, that only a lease whose time is up is free, and what separates the two is time alone, so no read has to land inside a window. Nothing was loosened and no wait was lengthened. Assistant-model: Claude Sonnet 5.5 Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e) Assistant-verification: the old contract failed 10 of 10 runs against PostgreSQL behind a proxy holding each chunk 5 ms in each direction (Expected false, Received true), and the new one passed 100 of 100 (--rerun-each 50, both tests) behind the same proxy, 100 of 100 with that proxy and busy loops sharing the two cores the test ran on, 100 of 100 directly, and 100 of 100 on the memory adapter Assistant-verification: bun run types (apps/server), dprint fmt and oxlint on the changed file passed Co-authored-by: Alex Lavaee <lavaman131@github.com>
The test registered its storage's cleanup after the world's own, and cleanups run last to first, so the database was closed first. A test that gave up while a turn was still saving, such as one that timed out, then had its Chat's turns fail on a closed connection: "[chat] could not save a finished turn" with "PostgresError: Connection closed", which is what the CI log of the flake showed beside the real error, a wait that timed out. The cleanup is now registered first, so the world closes its Chat and its turn ends before the database is closed. This does not change when these tests pass or fail. It stops a failure from burying its cause in errors its own cleanup caused. Assistant-model: Claude Sonnet 5.5 Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e) Assistant-verification: with PostgreSQL behind a proxy holding each chunk 2 ms in each direction, five runs of the file logged "PostgresError: Connection closed" five times before this change and none after it; the first test timed out in all five runs of each series, so the failures are the same timeouts Assistant-verification: bun run types (apps/server), dprint fmt and oxlint on the changed file passed Co-authored-by: Alex Lavaee <lavaman131@github.com>
… creation causes has finished
`document-navigation.e2e.ts:621` ("document switches preserve navigation state and avoid catalogue reloads") failed about one run in four alone with `--workers=1` on main, and was flaky on the main CI run too: `GET /api/repositories/octo-org/score/channels` was asked once in a window the test expects to be empty.
The request is not a duplicate in the product. The test makes its second document with New document, and a created document is announced on the sidebar socket to every sidebar watching the repository, its author's included (`Sidebar.Catalogue`: "Sent to every socket watching the repository, the change's author's included", tested in `sidebar-decision-counts.e2e.ts`). Each sidebar reads the catalogue once the burst has been quiet for 250 ms. A trace of one creation shows exactly one such read, 250 ms after the frame, and nothing else asking for the catalogue. The frame names the document and no revision, so a client cannot tell a change it has already applied from someone else's; the read is the design, and the page that made the document is meant to take it.
The test cleared its request log once it had seen the creation's visit, about 250 ms after the click, so whether the read fell before the clear or after it depended on how quickly the test's own steps ran. Landing after, it was counted as a switch's. The test now waits for the response to that read, and for the sidebar's "Loading more…" to go, before it clears the log and starts counting. The assertion that no catalogue was read during the switches is as it was: a read a switch caused would still fail it.
Assistant-model: Claude Sonnet 5.5
Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e)
Assistant-verification: Chromium e2e failed before the change: `--workers=1 --repeat-each=20` of document-navigation.e2e.ts:621 on a client built from 15dd6a87 failed 6 of 20 (five with one extra GET /channels, one with the header staying on the new document after the click on the first, which did not come back in the 70 runs after)
Assistant-verification: Chromium e2e passed after the change: the same command, same client and server, 20 of 20, then 25 of 25 and 25 of 25 on two fresh databases at once, 70 of 70 in all
Assistant-verification: tsgo -p e2e passed
Assistant-verification: dprint check, oxlint and scripts/check-design-contract.ts passed on the changed file
Co-authored-by: Alex Lavaee <lavaman131@github.com>
…pendent of how slow the runner is to start `restart.e2e.ts:242` asserted `outage < 4000` and measured 4.4 s on a CI runner. The outage it timed was made of three things, measured here with the server's own cut log and the page's socket timeline: - the old process's cut, from SIGTERM to exit: 0.37 to 0.43 s, of which 300 ms is the unready window (`HANDOVER_UNREADY_MS`), during which it still serves everything and the page still has its socket; - the test's own gap before the new process starts: 1.0 s, fixed; - the new process's start, from spawn to `/api/health/ready`: 1.3 to 1.4 s on a quick machine and 2.6 to 2.9 s on two cores shared with busy loops, where the same runs measured 4.03 to 4.28 s in all. It says ready 27 ms after it takes the lease; the rest is loading the server's module graph, most of a second of it in `(native)` in a CPU profile, by the command the image runs. Nothing about it was changed. The bound itself is the design's: the page is quiet for `RESTART_QUIET_MS` (5 s) from the 1012 and, once that has come, tries again within `RESTART_JITTER_MS` (1 s), so a server back within 4 s of the 1012 is found with the quiet still running. Two things made the test's use of it wrong. It counted from SIGTERM, though the page hears nothing until the release, which the design's own budget also counts from, so the cut's 0.4 s was charged to a window it is not in. And the sum of a fixed second and a start that varies by a factor of two cannot stay between the 1.5 s a blip is waited out in and that 4 s on every runner: in the loaded runs whose page timeline was complete the page reconnected 3.8 to 4.0 s after its 1012, inside the quiet, while the test failed on 4034 to 4284. The test now counts from the old process's exit (the 1012 is sent as it releases and exits), bounds the outage by `RESTART_QUIET_MS - RESTART_JITTER_MS` taken from the constants, keeps the 1.5 s blip as its lower bound, and sets the gap so that the restart takes about 2.5 s: what the first server took to start is subtracted from that, and the gap is none when it took longer. The next start takes about what the first did (1.32 to 1.37 s and 1.32 to 1.42 s in three idle runs, 2.1 to 2.4 s and 2.6 to 2.9 s under load), and the room between the aim and 4 s absorbs the difference. The same bound, copied into the cases that send a message as the server restarts, is the same and measured the same way. The bounds are not raised: the upper one is the 4 s it was, and the lower one is the 1.5 s it was, now counted from where the page's clock starts. Assistant-model: Claude Sonnet 5.5 Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e) Assistant-verification: Chromium e2e failed before the change: restart.e2e.ts's restart under an open tab, on a server of its own at HEAD with two cores shared with two busy loops, failed in 3 of 3 runs, and in 4 of 4 runs of an instrumented copy, with `Expected: < 4000`, received 4001 to 4304 Assistant-verification: Chromium e2e passed after the change: the three restart cases (a restart under an open tab, and a message sent as the server restarts, taken or never read) 15 of 15 on an idle machine, the restart under an open tab taking 2.48 to 2.58 s, and 12 of 12 under the same two shared cores, 2.78 to 3.34 s Assistant-verification: tsgo -p e2e passed Assistant-verification: dprint check and scripts/check-design-contract.ts passed on the changed file; oxlint reports only the warning it gave before for the page-side `at` helper Co-authored-by: Alex Lavaee <lavaman131@github.com>
…vent-loop turns
The saved-request tests waited for a prompt with `waitFor`, which looked 200 times with a `setTimeout(0)` between, about 0.2 s of an idle loop. Against the in-memory storage a turn finishes in turns of the loop, so that was ample. Against PostgreSQL each step of a turn is a round trip and a commit, and the loop turns idly meanwhile: after the restart the four queued requests need about a hundred of those turns on a fast machine, so a runner whose database answers half as fast ran out of them. CI failed this way on main ("timed out waiting for 5 prompts", run 42476309048), and the test that follows waits the same way before it queues its second message. The "Connection closed" lines beside the error were the cleanup closing the database under the turns that were still saving, which the earlier commit that closes the Chat first stops.
`waitFor` now gives its condition four seconds, as the remote Planner tests' `until` does (three or four), which ends before bun's five-second limit on a test, so a condition that never holds is still named. No assertion changed.
Assistant-model: Claude Sonnet 5.5
Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e)
Assistant-verification: with PostgreSQL behind a proxy that passes each chunk on 2 ms after it arrives, both ways, the old wait failed the "keep a message" test 10 of 10 runs with "timed out waiting for 5 prompts"; with 5 ms, that test and "mark a row a dead process had started as interrupted" both failed 5 of 5 ("timed out waiting for a condition"); each on a database made new for the run
Assistant-verification: the new wait passed all three tests of deferred-restart.test.ts 150 of 150 runs (--rerun-each 50) behind the 2 ms proxy, 150 of 150 directly, 150 of 150 with two busy loops sharing the two cores the test ran on, and 150 of 150 with both, each on a database made new for the run
Assistant-verification: bun test --rerun-each 20 apps/server/src/chat/deferred.test.ts passed 1100 of 1100 on the memory storage, which uses the same wait
Assistant-verification: bun run types (apps/server), dprint check and oxlint on the changed file passed
Co-authored-by: Alex Lavaee <lavaman131@github.com>
…begins, not before it is told to stop The test holds the lock every fenced write takes so that the old process stands at the commit of its cut, and took it 300 ms after the last message was answered, before SIGTERM. The old process settles first, still serving: it commits and checkpoints every document, and a commit's checkpoint is made 500 ms after it. When the last message's checkpoint was still owed (always, on a runner slow enough to space commits more than 500 ms apart; now and then on a quick one), that write stopped on the lock ahead of the listener, so the process never stopped listening and the test timed out waiting for it. The lock is now taken when readiness goes off, which is the cut's first step and comes after every write before it, with the unready window still to run; the connection is opened first so taking it is one round trip, and the test now also checks that the cut stood still until the lock was let go, so a lock taken late fails with that reason instead of passing without having held the cut. The product behaved as designed: a process whose storage will not take a write does not cut. What the test asserts of the page and the Planner is unchanged. Assistant-model: Claude Sonnet 5.5 Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e) Assistant-verification: playwright "messages sent without a pause while the old process is cutting" failed before the fix with "timed out waiting for the old process to stop listening": 2 of 12 runs alone with the old process's backend waiting on pg_advisory_xact_lock for the whole wait, 3 of 4 and 1 of 8 under CPU load (8 busy loops on 4 cores), on disposable servers and databases of its own Assistant-verification: playwright the same test passed 50 of 50 with --repeat-each=50 alone and 50 of 50 under the same CPU load after the fix Assistant-verification: tsgo --noEmit --skipLibCheck -p e2e, dprint check and oxlint passed on the changed file Co-authored-by: Alex Lavaee <lavaman131@github.com>
…ment changes `forget` only marked the read an opening was handed as stale. The opening still waited for that read to settle before it made its own, so a read that was slow, or never answered, held the opening back though the page had already been told its record was out of date. Each opening waiting on a handed-out read now registers a drop signal in `used`, and `read` races the hover read against it. `forget` for the document of such an opening fires the signal, the race ends at once and the opening makes its own read, exactly once: what the dropped read answers or fails with afterwards is ignored, a second change notice does nothing more, and the entry leaves `used` as soon as the race ends. An opening of another document, or one that already has its record, is unchanged. Assistant-model: Claude Sonnet 5.5 Assistant-workflow: goal (run 9218171a-973c-468a-a0e6-2528103ba79f) Assistant-verification: bun test src/document-intent.test.ts in apps/web failed before the change on the new held-read test (Expected: "Own", Received: "still waiting"; 26 pass, 1 fail) with the fix reverted and the tests kept Assistant-verification: the same command passed after the change, 27 of 27, and bun test in apps/web passed (1118 pass, 2 skip, 0 fail) Assistant-verification: bun run types and bun run ci passed Co-authored-by: Alex Lavaee <lavaman131@github.com>
… process's exit The restart cases timed the outage with `Date.now()` taken when `stop()` returned, which is when the test saw the old process exit. The design's window is the page's: it is quiet for `RESTART_QUIET_MS` from the 1012 and, once that has come, tries again within `RESTART_JITTER_MS`, so a server back within `RESTART_QUIET_MS - RESTART_JITTER_MS` of the 1012 is found while the quiet is still running. The page's 1012 and the test's sight of the exit are two events: the 1012 is sent as the process releases and exits, but the test learns of the exit through the child's `close` event, which a runner that is slow to reap and report it delivers late. Whatever it takes the test to notice is subtracted from an outage the page has already been in, so the bound could pass while the page was past its quiet. The page's probe now also stamps the first 1012 with `Date.now()` (`lostAtWall`; the existing `lostAt` is `performance.now()` of the page and cannot be compared with the test's clock, which on one machine `Date.now()` can). The main case and both message-retry cases take the time the new server is ready and read the probe afterwards, counting the outage from `lostAtWall` through one helper, `outageFrom1012`, which fails the test if the page saw no 1012 rather than falling back to the exit. The bounds are the ones they were: `SILENT_OUTAGE_MS` is still `RESTART_QUIET_MS - RESTART_JITTER_MS` from the constants and the main case's lower bound is still the 1.5 s blip. The 1012 comes with the exit, so the aim of 2.5 s and the gap sized from the first server's start are unchanged; only the comments that counted from the old process's exit now count from the 1012. Assistant-model: Claude Sonnet 5.5 Assistant-workflow: goal (run 9218171a-973c-468a-a0e6-2528103ba79f) Assistant-verification: Chromium e2e of the restart cases on a scratch copy of the spec (port 9461, a fresh database on chopin-stage1-pg, copy of HEAD with the test seeing the exit 2 s late, which is the only instrumentation): the exit-based head passed the restart under an open tab at 2492 ms and both message-retry cases at 2458 and 2501 ms; the same lateness against this change failed all three with `Expected: < 4000`, received 4506 for the main case (the exit-based figure measured in the same run: 2455 ms) and 4553 and 4520 for the retry cases Assistant-verification: Chromium e2e passed after the change with no lateness: the whole file 8 of 8 idle, the restart under an open tab 2498 ms from the 1012 (2446 ms from the exit); the main case and both message-retry cases 9 of 9 (three repeats each) under two busy loops pinned with the test to two cores, 3122 to 3465 ms for the main case and 2454 to 3098 ms for the retry cases, all under 4000 Assistant-verification: tsgo --noEmit --skipLibCheck -p e2e, dprint check and scripts/check-design-contract.ts passed on the changed file; oxlint reports only the warning it gave before for the page-side `at` helper Co-authored-by: Alex Lavaee <lavaman131@github.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fix six flaky or stale-reading follow-ups from the last reviews
Six items the last reviews left open (commit hashes are those of the branch rebased onto
origin/main): a stale record a click could still open, three tests that failed now and then in CI (the PostgreSQL saved Planner requests, the lease peek, the hand-over test), two browser specs that broke on the clock (the planner picker across midnight, the restart test's 4 s bound), and a catalogue read thatdocument-navigationcounted as a switch's. Each is fixed at its cause, in its own signed commit, with a run that failed before and one that passes after. Only one is a product change (document-intent.ts); the other five are test faults, and the commit messages say what in the product was checked and left alone.Nothing was widened to pass: no assertion was loosened, no wait lengthened without a reason from the design or from what is measured below, and every changed test keeps what it asserted (the hand-over test gained one assertion).
The six, with the cause of each
1. A change notice after the click (
2d0ad2b8andf38dc40c, product)Cause. A click takes the read started on hover out of the table of reads (
reads) and waits on it. A notice that the document was renamed, updated or deleted came toforget, which only searched that table, so an opening already waiting on a slow hover read was given the record from before the change.Fix.
apps/web/src/document-intent.tskeeps the openings that wait on a handed-out read in ausedset, each with a drop signal.forgetfires the signal of every opening of the changed document, andreadraces the hover read against that signal, so the opening makes its own read at once instead of waiting for the stale read to settle (2d0ad2b8marked the read stale, which still left the opening waiting for it; a read that was slow, or never answered, held it back). The opening makes its own read exactly once: what the dropped read answers or fails with afterwards is ignored, a second notice does nothing more, and the entry leavesusedas soon as the race ends. A read of another document is left as it was. The prefetched read itself is dropped fromreadsat use, as the brief also asked.Evidence.
bun test src/document-intent.test.tsinapps/web: with the old module restored the new held-read test (a read that never resolves;forgetafter the click) fails withExpected: "Own" Received: "still waiting"(26 pass, 1 fail); with the fix 27 of 27, and the wholeapps/websuite 1118 pass, 2 skip, 0 fail. Three of the new tests are guards that pass either way (a change to another document; a change after the opening has its record; a second notice, or the dropped read failing afterwards, does not make the opening read twice). Browser: with a client built from the fix,e2e/document-intent.e2e.tsanddocument-navigation.e2e.tsran 43 of 44; the one failure, "a pointer-dismissed navigation dialog releases focus while it exits", fails the same way on a client built from the commit before the fix (on a machine another project's browser tests were loading), so it is not this change's. A second run, with two workers, also lost "a long description card stays inside the window beside a bottom row" (a tooltip that stayed hidden), another motion check; it is not in what this change touches and was not re-run alone.2. The flaky PostgreSQL saved Planner requests and lease peek tests (
f9e50f9d,8cafbe45,598fa152, tests only)Cause: not a product race. Three separate faults:
waitForlooked 200 times with asetTimeout(0)between, about 0.2 s of an idle event loop. Against the memory storage a turn finishes in loop turns, so that was ample. Against PostgreSQL every step of a turn is a round trip and a commit: after the kill the four queued requests need about a hundred loop turns on a quick machine, so a runner whose database answers about half as fast runs out. CI failed exactly this way on main (run 42476309048, atdeferred-restart.test.ts:71), and "mark a row a dead process had started as interrupted" waits the same way before it queues its second message.[chat] could not save a finished turn ... Connection closedbeside the real timeout.peek.Fixes.
f9e50f9d(lease-peek-contract.ts): a 20 ms lease and a 60 s lease are read after the same 60 ms wait; the short one must be free and the long one still held. The claim (only a lease whose time is up is free) is kept, and what separates the two is time alone, so no read has to land inside a window. Nothing loosened, no wait lengthened.8cafbe45(deferred-restart.test.ts): the storage cleanup is registered first, so the Chat closes before its database. It changes when the tests pass or fail by nothing; it stops a failure from burying its cause.598fa152(deferred.test-fixtures.ts):waitForgives its condition four seconds of wall clock, as the remote Planner tests'untildoes (three or four), which ends before bun's five-second limit on a test, so a condition that never holds is still named. No assertion changed.Evidence. A TCP proxy in front of the disposable PostgreSQL (
chopin-stage1-pg, port 5442) passes each chunk on N ms after it arrived, in both directions and in order, as a database further away than this machine's would; every series ran on a fresh database.--rerun-each 10timed out waiting for 5 prompts(CI's message)--rerun-each 50, three tests)Expected: false, Received: true--rerun-each 50, both tests)apps/server/src/chat/deferred.test.ts(memory storage, samewaitFor)--rerun-each 20)Connection closedlogged 5 timesAlso checked, not part of this change.
bun test apps/server/src/storage/postgres: 178 of 178 directly and behind a +1 ms proxy; under load 177 of 178, the one failurestartup.test.ts"recovers one missed terminal Chat notice across repeated server starts", which takes 3.6 s idle and hits bun's 5 s limit under load. It is not in the brief and was not touched. There is no in-repo regression test for this item: reproducing it needs injected database latency and the repository has no such harness; the proxy runs above are the repeatable check.3. The planner-picker "Last seen" tests across midnight (
02d7738d, test only)Cause. The page words a machine's last-seen time as a time of day when it falls today and as a date and time on another day, in the browser's time zone. The test marked the machine as seen an hour before the real clock and expected a time of day, so a run in the first hour after local midnight read "Nov 9, 11:40 PM" and failed, on a desktop and on a phone.
Fix. The test's context sets
timezoneId: "UTC"and installspage.clockat noon, and the machine was seen an hour before that. What the test asserts is unchanged.Evidence. The real spec on a disposable server with
TZ=Etc/GMT-9at 00:40 local failed for both desktop and phone ("Runs on studio. studio is offline. Last seen Nov 9, 11:40 PM."); the same run after the fix passes 2 of 2; in the machine's own zone 6 of 6 (--repeat-each=3). Re-run on the final tree withTZ=Etc/GMT-9: 2 of 2, and the whole file 41 of 41.4.
document-navigation.e2e.ts:621(an extraGET /channels) (b5cce96c, test only)Cause: the request is not a duplicate in the product. The test makes its second document with New document, and a created document is announced on the sidebar socket to every sidebar watching the repository, its author's included (
Sidebar.Catalogueinpackages/protocol/index.d.ts: "Sent to every socket watching the repository, the change's author's included"; tested insidebar-decision-counts.e2e.ts). Each sidebar reads the catalogue once the burst has been quiet for 250 ms. A trace of one creation shows exactly one such read, 250 ms after the frame, and nothing else asking for the catalogue. The frame names the document and no revision, so a client cannot tell a change it already applied from someone else's: removing the read would be a protocol change, so the product is left as it is. The test cleared its request log about when that read fired, so it was counted as a switch's roughly one run in four. The main CI run 42596408116 failed the same way (expected 0, received 1) and passed on retry.Fix. The test registers
waitForResponsefor that read before clicking New document and, once it has seen the creation's visit, awaits the response and waits for "Loading more…" to go, then clears the log and counts. The zero-reads assertion is unchanged: a read a switch caused still fails it.Evidence.
--workers=1 --repeat-each=20on a client built before the change: 6 of 20 failed (5 with one extraGET /channels, 1 with the header staying on the new document after the click on the first). After: 20 of 20, then 25 of 25 and 25 of 25 on two fresh databases at once, 70 of 70 in all. On the final head the whole file passes (44 of 44 withdocument-intent).5. The restart test's 4 s bound (
b1aafa3aand5b38e9c2, test only)What the outage is made of (the server's own cut log and the page's socket timeline):
HANDOVER_UNREADY_MS; the page still has its socket)/api/health/readyThe new server says ready 27 ms after it takes the lease; the rest is loading its module graph (most of a second of it in a CPU profile), by the command the image runs. That is not changed here.
The bound is the design's, and the test applied it wrongly. The page is quiet for
RESTART_QUIET_MS(5 s) from the 1012 and, once that has come, tries again withinRESTART_JITTER_MS(1 s), so a server back within 4 s of the 1012 is found with the quiet still running. The test counted from SIGTERM, though the page hears nothing until the release, so the cut's 0.4 s was charged to a window it is not in. It also added a fixed second to a start time that varies by about 2x across runners, which cannot stay between the 1.5 s a blip is waited out in and 4 s everywhere. In the loaded runs whose page timeline was complete, the page reconnected 3.8 to 4.0 s after its 1012, inside the quiet, while the test failed on 4034 to 4284.Fix.
b1aafa3abounded the outage byRESTART_QUIET_MS - RESTART_JITTER_MStaken from the constants, kept the 1.5 s blip as its lower bound, and sized the gap to aim at about 2.5 s (max(0, 2500 - the first server's measured start); the next start takes about what the first did). It counted from the old process's exit, which the test learns of through the child'scloseevent, later than the page saw its 1012 on a slow runner.5b38e9c2counts from the 1012 the page sees: the page's probe stamps the first 1012 withDate.now()(lostAtWall), and the main case and both message-retry cases take the time the new server is ready and compute the outage through one helper,outageFrom1012, which fails the test if the page saw no 1012. The bounds are not changed: the upper one is the design'sRESTART_QUIET_MS - RESTART_JITTER_MS(4 s) and the lower one the 1.5 s it was; only the comments that counted from the exit now count from the 1012. The 1012 comes as the process exits, so the 2.5 s aim is unchanged.Evidence. Under two shared cores with two busy loops, at the commit before: the restart under an open tab failed 3 of 3 (
Expected: < 4000, received 4001 to 4304), and 4 of 4 in an instrumented copy (4034 to 4284). After: the three restart cases passed 15 of 15 idle (outage 2.48 to 2.58 s) and 12 of 12 under the same load (2.78 to 3.34 s). On the final tree the whole file passes, 8 of 8. For5b38e9c2: on a scratch copy of the spec in which the test sees the old process's exit 2 s late (a slow runner reaping the child), the exit-based timing passed the main case at 2492 ms and the two message-retry cases at 2458 and 2501 ms, while counting from the 1012 failed all three (Expected: < 4000, received 4506, 4553 and 4520; the exit-based figure in the same run was 2455 ms); with no lateness the two agree (2486 and 2498 ms). After it, the whole file passes 8 of 8 idle (main case 2498 ms from the 1012, 2446 ms from the exit), and the main case and both message-retry cases 9 of 9 (three repeats each) under two busy loops pinned to the test's two cores: 3122 to 3465 ms and 2454 to 3098 ms, all under 4000. The late-exit instrumentation is on a scratch copy, not in the suite. The sandboxed "two cores plus busy loops" load is a stand-in for a CI runner; no CI log with the 4.4 s figure could be recovered.6.
handover.e2e.ts:1337"never marked Couldn't send" (8b408c04, test only)Cause: not a listener-stop bug, not a wait that is too short. The test held the lock every fenced write takes (a PostgreSQL advisory lock), so the old process would stand at the commit of its cut, and took it 300 ms after the last message was answered, before SIGTERM. After SIGTERM the old process first settles while still serving: it commits and checkpoints every document, and a commit's checkpoint is scheduled 500 ms after it (
scheduleCheckpointinapps/server/src/plan/service.ts). Whenever the last message's checkpoint was still owed at SIGTERM, that write stopped on the held lock ahead of the listener, so the process never stopped listening, and no longer wait could help because the lock is only let go after that wait ends. On a runner that spaces commits more than 500 ms apart a checkpoint is always owed when the test locks; the CI timing itself could not be observed, so that part is inferred from the shape of the failure (the same error on three attempts in one shard on #803, and on #796, #798). The product behaved as designed: a process whose storage will not take a write does not cut.Fix. The lock is taken when
GET /api/health/readyon the old process answersdraining, which is the cut's first step: it comes after every write made before the cut, with the 300 ms unready window still to run, so the next write the process makes is the cut's own.holdWritesopens its connection first, so taking the lock is one round trip, and theBun.sleep(300)it replaces is gone. One assertion was added: before the lock is let go, the lease must not have been released, so a lock taken too late fails with that reason instead of passing without having held the cut. What the test asserts of the page and the Planner is unchanged.Evidence. The test is non-deterministic, so the red evidence is a failure rate on the unmodified spec on a disposable server and database: 2 of 12 alone (in each, a commit landed just after a checkpoint, and the old process's backend waited on
pg_advisory_xact_lockfor the whole 5 s wait), 3 of 4 in a first load run that was stopped early and 1 of 8 in a second (8 busy loops on 4 cores), withtimed out waiting for the old process to stop listening; setting the old 300 ms idle wait to zero made the same wait time out. After: 50 of 50 alone (--repeat-each=50) and 50 of 50 under the same load. On the final tree, 10 of 10 more (--repeat-each=10) and the whole file 13 of 13.Commits
2d0ad2b8Give an opening that already waits on a read the document's own read when a change notice arrivesf38dc40cMake an opening that waits on a hover read stop waiting when its document changes02d7738dFix the clock and time zone of the planner picker's "last seen" test, so it does not fail just after local midnightf9e50f9dStop the lease peek test from racing the clock of a database slower than its short lease8cafbe45Close a saved-request test's Chat before the database it saves tob5cce96cCount a document switch's catalogue reads only after the read its own creation causes has finishedb1aafa3aMeasure a restart's outage from the release, and make its length independent of how slow the runner is to start5b38e9c2Time a restart's outage from the 1012 the page sees, not from the old process's exit598fa152Wait for a saved Planner request's turns by time, not by a count of event-loop turns8b408c04Take the write lock of the hand-over test when the old process's cut begins, not before it is told to stopFiles:
apps/web/src/document-intent.tsand its test;apps/server/src/chat/deferred.test-fixtures.ts,apps/server/src/storage/lease-peek-contract.ts,apps/server/src/storage/postgres/deferred-restart.test.ts;e2e/planner-picker.e2e.ts,e2e/document-navigation.e2e.ts,e2e/restart.e2e.ts,e2e/handover.e2e.ts(157 insertions, 35 deletions). All eight are signed. Two commit messages (f9e50f9d,8cafbe45) were reworded after a first proxy build was found to delay chunks one after another; their figures were re-measured with the corrected proxy. A third (598fa152) was reworded to name the earlier commit it refers to. The trees were checked identical before and after each rewrite.Verification on the final head
Base
341a2b33. Head8b408c04. The commands below ran on the tree of521925d0, which has the same tree as8b408c04(verified withgit log --format=%T: the commit rewrites changed only messages). PostgreSQL was thechopin-stage1-pgcontainer on 5442 with a fresh database for each run, dropped afterwards (5432 andbun run db:upwere not used). Browser runs hadGIT_CONFIG_COUNT=1 GIT_CONFIG_KEY_0=commit.gpgsign GIT_CONFIG_VALUE_0=falsein their own environment only, and used ports 9300 and up with their own databases.bun run fix: no change to any file.bun run types: passed (connector, editor, server and web, thentsgo -p e2e).bun run ci: passed (dprint, oxlint 74 warnings and 0 errors, tokens, design contract 1158 sources and 331 exact reviewed exceptions, design record, Impeccable no new findings).bun testwithTEST_DATABASE_URLon a fresh database: 7957 pass, 17 skip, 2 fail. Both failures are environmental: the two tests commit in a throwaway repository with the developer's globalcommit.gpgsign=trueand no signing key there (fatal: either user.signingkey or gpg.ssh.defaultKeyCommand needs to be configured): the connector's "a spike's agent cannot push ..." and the server's "a waiting connector registers again ...". Re-run with the browser runs'GIT_CONFIG_*override: both files pass, 58 of 58.bun test apps/server/src/storage/postgres(whatbun run test:postgresruns, pointed at 5442 instead of its hard-wired 5432) on a fresh database: 178 of 178.VITE_CHILD_MOTION_TOGGLE=on VITE_MESSAGE_ANALYSIS=on),--retries=0:document-navigation.e2e.tsanddocument-intent.e2e.tstogether 44 of 44 (plain project, a configuration of its own on port 9300);planner-picker.e2e.ts41 of 41;restart.e2e.ts8 of 8;handover.e2e.ts13 of 13;handover"never marked Couldn't send" alone--repeat-each=1010 of 10;planner-picker"last seen" underTZ=Etc/GMT-92 of 2.planner-picker,restartandhandoverhard-wire ports 8794, 8796 and 8801 to 8803, so they ran as copies (under a git-ignored scratch directory, since removed) with only the import paths, the ports (9394, 9396, 9401 to 9403) and the database names changed, checked bydiff.Review follow-up
Two findings from the last review are fixed in
f38dc40c(item 1: an opening waiting on a hover read no longer waits for it once its document has changed, even if that read never answers) and5b38e9c2(item 5: the outage is counted from the 1012 the page sees, with the design's bound unchanged). On this head,bun run fixchanged nothing,bun run typesandbun run cipass (oxlint 74 warnings, 0 errors), and theapps/websuite passes (1118 pass, 2 skip, 0 fail).restart.e2e.tspasses 8 of 8; the browser evidence is in items 1 and 5. Browser runs hadGIT_CONFIG_COUNT=1 GIT_CONFIG_KEY_0=commit.gpgsign GIT_CONFIG_VALUE_0=falsein their own environment only, PostgreSQLchopin-stage1-pgon 5442 with a fresh database each, and ports 9000 and up (the specs hard-wire lower ones, so they ran as copies under a git-ignored scratch directory, since removed, with only the imports, ports and databases changed).Open points
#reserveSluginapps/server/src/storage/postgres/adapter.tsprobes slug candidates one at a time, so creating a document with the same title as N earlier ones in a repository costs about 2N round trips. It made repeated runs on one database slow; each series above used a fresh one.document-navigation. One of the 6 failures before the fix was the header staying on the new document after the click on the first; it did not recur in the 70 runs after the fix, its cause was not established, and the commit does not claim one.startup.test.tsunder load. "recovers one missed terminal Chat notice across repeated server starts" takes 3.6 s idle and hit bun's 5 s limit once under heavy CPU load. Not in the brief, not touched; it passed in the full run above.Assistant-model: Claude Sonnet 5.5
Assistant-workflow: goal (run faf72526-b6af-4985-b325-7ebb55272d7e)
Assistant-duration: unmeasured converged (the run's clock readings were about 07:36 to 09:30 PST on 2026-11-09; no time was recorded as a measurement)
Assistant-verification: bun run fix made no change, and bun run types and bun run ci passed on the tree of 521925d0, which is the tree of 8b408c0 (oxlint 74 warnings, 0 errors; design contract 1158 sources and 331 exact reviewed exceptions)
Assistant-verification: full bun test with TEST_DATABASE_URL on a fresh PostgreSQL database on 5442: 7957 pass, 17 skip, 2 fail, both failures from the developer's global commit.gpgsign=true with no signing key in a throwaway repository, and both files passing 58 of 58 with the GIT_CONFIG_* override
Assistant-verification: bun test apps/server/src/storage/postgres on a fresh database on 5442 passed 178 of 178
Assistant-verification: playwright through a configuration of my own on ports 9300 and up, with their own databases, --retries=0: document-navigation and document-intent 44 of 44, planner-picker 41 of 41, restart 8 of 8, handover 13 of 13, handover "never marked Couldn't send" alone 10 of 10, planner-picker "last seen" under TZ=Etc/GMT-9 2 of 2
Assistant-verification: bun test --rerun-each 50 apps/server/src/storage/memory/adapter.test.ts -t "lease peek" passed 100 of 100, and the saved-requests teardown order, re-measured behind a 2 ms proxy for five runs on a fresh database each, logged "Connection closed" 5 times before and 0 times after
Assistant-verification: the eight commits are signed (git log %G? shows G for each), and git log --format=%T shows the same trees before and after rewording three commit messages
Assistant-workflow: goal (run 9218171a-973c-468a-a0e6-2528103ba79f)
Assistant-verification: after the last review's two P2s were fixed (an opening stops waiting on a hover read its document's change invalidated; the restart outage is timed from the 1012 the page sees), the held-read unit test failed on the module before the fix (26 pass, 1 fail, "still waiting") and passed after (27 of 27); bun run types, bun run ci and apps/web bun test (1118 pass, 0 fail) passed on 5b38e9c
Assistant-verification: e2e/restart.e2e.ts passed 8 of 8 on a fresh database, outage from the 1012 of 2473 ms (main case) and 2494 and 2584 ms (the two retry cases) against 4000; a scratch probe that delayed the old process's exit by 2 s passed the old measurement (2407 ms from exit) and failed the new one (4511 ms from the 1012), showing the new measurement counts the time the old one left out; that probe was not kept in the suite
Assistant-verification: document-intent and document-navigation passed 44 of 44 with one worker on a fresh database, the client built as scripts/e2e.ts builds it
Co-authored-by: Alex Lavaee lavaman131@github.com