Repository navigation
test(server): pin the Close-frame deadline delay and the wake threshold - #495
Conversation
The fake timers of the lifecycle spec run only when a test calls their callback, so no test read the delay of the deadline that waits for a Close frame. A first delay of 0 closed a still-reading client at once, and a first delay of three windows kept the queue three times as long as the bound says. Both survived the whole suite. Assert the delay of the deadline.
A tick that comes more than interval * 1.5 after the tick before it counts as a wake from sleep and starts a fresh stall window. Existing tests used gaps of 1.4 intervals and 20 intervals only, so a change from > to >=, or of the factor to 1.4 or 2, kept every test green. Add a test at exactly 1.5 intervals, which is not a wake, and one 1 ms above, which is.
The stall confirmation skips a client that left in the poll, and a read error removes the client as an EOF does. Name it next to EOF, and pin it with a test. The README said ticks run "late by less than 1.5 intervals". The code counts the gap to the tick before, and a gap above 1.5 intervals is a wake, so a late tick is late by up to half an interval. Say what the code compares.
|
@codex review |
|
@codex security review |
Codex Review Summary: ✅ CompletedThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
|
Codex Review: Didn't find any major issues. What shall we delve into next? Reviewed commit: ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
If Codex has suggestions, it will comment; otherwise it will react with 👍. Codex can also answer questions or update the PR. Try commenting "@codex address that feedback". |
🛡️ Codex Security ReviewSecurity review completed. No security issues were found in this pull request. Reviewed commit: Only the user who started this review can view the report in Codex. ℹ️ About Codex security reviews in GitHubThis is an experimental Codex feature. Security reviews are triggered when:
Once complete, Codex will leave suggestions, or a comment if no findings are found. |
A tick that pinged a client always arms the check and idle pair, so the wake-threshold test from #495 can no longer expect no handle. It now runs the poll and checks that the client is kept.
…er#488) ## Result Neovim 0.8 no longer drops a Claude that answers every ping. A block of the main loop, of any length and in any callback, does not close a Claude that writes something within 75 s (`interval * 2.5`) of each ping. A Claude that sends nothing is still closed 3 intervals (90 s by default) after its first unanswered ping, when no block longer than 1.5 intervals gets in the way. **This push also merges main with coder#467** (a client that answers pings but never reads), which rewrote the same ping tick. Its stall rule stays, and both rules hold (see "With coder#467"). ## Problem coder#479 made the ping timer drop a client only at the second tick that finds no pong. On Neovim 0.8 (libuv 1.44.2) that is still a race. `uv_run(UV_RUN_ONCE)` runs timers at the start of a pass and again at the end, after the check handles. Neovim runs `vim.schedule` callbacks between two `uv_run` calls. So a tick at the end of a pass, a block in `vim.schedule`, and a tick at the start of the next pass run with no socket read between them. Claude's pong waits in the socket for both ticks. Trace on main, Neovim 0.8.3, a separate-process Claude that answers every ping at once (interval 200 ms): ``` TICK since_pong=191 overdue=nil ping sent B1: 260 ms block in a check callback TICK since_pong=453 overdue=true timers run again at the end of the pass, pong still unread B2: 260 ms block in vim.schedule on_disconnect(client_1, 1006, "Connection timeout") dropped at the next tick ``` A counter cannot fix this. Any number of ticks can run before a read, so the tick must not judge at all. ## Change - A tick pings each connected client and never drops one. It stamps `client.ping_unanswered_since` with the oldest ping sent since bytes were last read from the client. It calls `vim.loop.update_time()` before it reads the clock for the wake test, the stamp and the gap: libuv caches the loop time when a pass starts and runs the timers of the pass with it, and a timer callback that ran before the tick in the pass can have blocked since, or the machine can have slept in it. A stale time hid a wake in the earlier pushes of this PR (Codex round 3). - Each tick that pinged a client starts a one-shot libuv check handle. libuv runs it after the poll phase that reads the sockets, so every byte that reached a socket before the loop time of the check was read. The check drops a client whose oldest ping is `interval * 2.5` old. - **Any bytes clear the stamp.** The read callback clears it, not only a PONG. A pong can wait behind more unread data than the socket holds (Claude writes while Neovim is blocked, and one poll reads only the first part), so the poll after a block does not always reach the pong. Claude shows it is alive by writing anything. - **The check judges only if its loop time is at most `interval * 1.5` after its tick.** A machine that sleeps between a tick and its poll stops Neovim and Claude together: no bytes arrive, and the ping looks as old as the sleep. A tick treats a gap above 1.5 intervals as a wake. The check now does too, and the next tick starts the count over. A block longer than 1.5 intervals therefore restarts the count. - A wake from sleep (a tick gap above `interval * 1.5`) clears the stamps. - Removed: `client.pong_overdue`, `client.is_client_alive` (its only caller was the old tick), and the reset of `last_pong` in the 101 write callback (a client that no tick pinged has no stamp, so the main loop cannot time it out). - `vim.schedule` is not a safe place to judge: Neovim can run it before the read. The check handle is. ## With coder#467 coder#467 landed on main while this PR was in review. It rewrote the ping tick (a pong rule with a second chance, `pong_overdue`, `is_client_alive`) and added a write-queue stall rule with its own check and idle handles. This branch keeps that rule and puts the keepalive of this PR next to it: - The stall rule is unchanged: a client that answered and whose write queue made no progress at two ticks in a row is closed after the next poll ("Write queue stalled", Close 1011 "Not reading"). The 61 tests of main's lifecycle spec: 56 pass under their names, and 5 were rewritten for the stamp and renamed (the `pong_overdue` second chance, the late-tick tests, and the wake and drain tests that spoke of flags). - "Answered" now means that no ping of the client waited for `interval * 2` (it was "a pong within `interval * 2`"). Only an answered client is judged for a stall. A silent client is closed by the keepalive judgement ("Connection timeout", Close 1011 "Keepalive timeout") at the same tick as before, whatever its write queue shows. - A tick that pinged a client arms **one** check and idle pair (`after_next_poll`, from coder#467) that runs both judgements after the poll. It was one pair for each stalled client. `stop_server` closes it as before. - `pong_overdue` and `is_client_alive` are gone, because the stamp replaces them. The tests that named them are rewritten for the stamp (a silent client with a stalled queue is closed by the keepalive, a late pong does not save a stalled queue, a wake restarts both windows). Three confirmation tests no longer expect "no handle" at a tick without a stall, because a tick that pinged always arms the pair. The wake-threshold test from coder#495 ("a tick 1 ms above the wake threshold") expected no handle after a wake tick for the same reason: it now runs the poll after the tick and checks that the client is kept and `on_disconnect` did not run. Two helper counts changed (`forget_handles`). - A real-socket probe of the stall rule (Claude sends unprompted pongs and never reads, 8 MB queued, interval 300 ms): main and this branch both close it with "Write queue stalled" 2.6 intervals after the message, on Neovim 0.8.3 and 0.12.3. - A client that writes data and reads what the plugin writes, but never answers a ping, is kept. Main closes it 3 intervals after its first ping. ## Behavior - A block of the main loop, of any length and in any callback, does not close a Claude that writes something within `interval * 2.5` of each ping. A tick never closes a client, a check judges only after a poll within `interval * 1.5` of its tick, and any bytes clear the stamp. - **A client that writes data and reads what the plugin writes, but never answers a ping, is no longer closed by the keepalive.** It is alive, and the plugin does not judge what it writes. Main closes it 3 intervals after its first ping. The stall rule of coder#467 still closes it if it stops reading, but only once the kernel's socket buffers are full and libuv's write queue backs up: until then every write completes, and an empty queue counts as progress. So a client that stops reading and keeps sending is closed later than main closed it when it also never answered a ping. The README says so. - A Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping (90 s by default). Main closes it at 2 to 3 intervals after its first ping in the verifier's runs and at 3.0 in mine. - A block delays the close of a silent Claude to the first read after the block ends. A block longer than 1.5 intervals also restarts the count, so a run of such blocks can postpone the close. - The info line `Closed client_<n>: no reply for <s>s` counts from the oldest ping sent since bytes were last read. ## Tests `tests/unit/server/connection_lifecycle_spec.lua` models the loop as libuv runs it: a loop time cached at the start of a pass, a poll that reads the sockets, and check handles that run after it. These fail on the code of coder#479 (main): two late ticks with no read between them (the trace above), 20 late ticks in a row, a silent Claude is dropped only at the first read after its tick, the time counts from the first unanswered ping, and a client that hung up or is closing is not judged. These three fail on the first push of this PR (f3576ea) and pass now: a block of 3 intervals between a tick and its poll judges nothing, a Claude that sends a large message before its pong is not dropped (the poll reads only the first 64 KB, the ping is 2.8 intervals old, and the poll is within the gap), and a client that writes data but never answers a ping is kept. The last two also fail on the gap skip alone. The other new tests guard: a client that writes data and never answers a ping is kept, a pong that waits in the socket when its ping is 3 intervals old, a late tick that finds a silent Claude's ping 2.5 intervals old, a poll 1.4 intervals after its tick that still judges, the stamp aged from the time the ping was sent, a block that restarts the count, a stale cached loop time, and a wake from sleep. `tcp_spec.lua` and `log_lines_spec.lua` follow the new tick/check split. Added after the verifier's mutation run on `68b0b13`: the check judges with the loop time of the poll and not with a time read after a younger callback blocked (a Claude whose pong arrives during that block is kept), a tick takes a wake for a wake although the cached loop time is old (a timer callback before it in the pass blocked for 2 intervals, so the clock shows 3 since the last tick and the cache shows 1), the gap skip at exactly 1.5 intervals (judges) and at 1 ms above it (does not), a drop at exactly 2.5 intervals, the stall judgement does not sit under the gap skip (a stalled client is dropped although every poll comes 1.6 intervals after its tick), and a client whose ping is still inside the window is judged for a stall. **Mutants.** My 16 are each caught by at least one test: no `update_time`; bytes do not clear the stamp; a wake does not clear it; no listed-client guard; no connected guard; limit x2 and /2; stamp overwritten each tick; pinged list empty; the check reads the real time; no gap skip; gap x3 and /3; the stall rule judges a silent client; the stall rule never runs; the dropped client keeps its Close-frame deadline. Of the verifier's 33 mutants of `68b0b13`, nine survived. Six are now killed: `update_time` inside `judge_silence`, the stall judgement under the gap skip, the gap skip at 2.0 intervals, the gap skip with `<` for `<=`, the limit with `>` for `>=`, and `answered` true only for a client with no stamp. Each has a test that fails on it. The seventh, a `tick_time` taken from the cached loop time, is equivalent since the round-3 fix (the tick time is the fresh time of the tick), and I dropped it. Two new mutants of the tick clock are killed: no `update_time`, and `update_time` after the wake test. The two that still survive are the stall judgement running before the keepalive one in the check, and the any-bytes clear after `process_data` instead of before it. The verifier classed both as equivalent. As far as I can tell, the first changes only which reason (`Not reading` or `Connection timeout`) a client gets when both rules apply to it in one poll, and the second matters only if `process_data` raises. **Random order.** The full suite passes with `--shuffle` for seeds 1 to 60 (1439 successes, 16 pending, 0 failures in each of the 60 runs). Before the fix, seeds 9, 15, 40, 57 and 59 failed (the verifier found them on `68b0b13`): the pong of the late-tick tests was built when the file loaded, from a `frame` module that only the outer `before_each` sets (`attempt to index upvalue 'frame'`). It is built in a `before_each` now. ## Replays on real Neovim A separate-process Claude (Python) answers every ping at once. Interval 300 ms. **Block matrix.** Blocks of 0.9, 1.3, 1.45 and 2.2 intervals run one after the other: the first right after a ping, in each of four contexts (a check callback, `vim.schedule`, a timer callback, an I/O read callback on a UDP socket), then the second in each of the four. 64 cases. 12 more cases run 6 blocks that cycle through all four contexts. | | Neovim 0.8.3 (libuv 1.44.2) | Neovim 0.12.3 (libuv 1.52.1) | |---|---|---| | main, 76 block cases | **6 dropped**, 70 kept | 0 dropped, 76 kept | | this PR, 76 block cases | 0 dropped, 76 kept | 0 dropped, 76 kept | | main, random blocks, 16 seeds of 20 s | **2 dropped** (seeds 10, 11) | not run | | this PR, random blocks, 24 seeds of 20 s | 0 dropped | 0 dropped | **The three paths of the verifier's finding, each with the mechanism that covers it.** 4 runs each (idle and prepare callbacks, 2 each), dropped / total: | Probe | first push (f3576ea) | gap skip only | any bytes only | both (this PR) | |---|---|---|---|---| | A block of 2.7 intervals before the poll, Claude writes 300 KB and then its pong during it | 4/4 on 0.8.3 and 0.12.3 | 0/4 | 0/4 | 0/4 | | Claude sleeps with Neovim: it answers the ping 2.7 intervals late | 3/4 | 0/4 | **4/4** | 0/4 | | Two blocks of 1.4 intervals (under the gap) with an older stamp, Claude writes 300 KB and then its pong | 4/4 | **4/4** | 0/4 | 0/4 | Each mechanism is needed: the gap skip alone drops the third row, and any bytes alone drops the second. **A client that writes every 100 ms and never answers a ping:** main drops it 3.0 intervals after its first ping. This PR keeps it (2 of 2 versions), and the stall rule of coder#467 still closes a client that never reads. **A Claude that reads pings and never answers:** dropped 3.0 intervals after its first ping on main and on this PR, on both versions. With 2 blocks of 2 intervals in the way: 8.0 intervals on both. **Re-run after the tick reads a fresh clock (Codex round 3), on the `lua/` code of this push.** Block matrix: 76 kept and 0 dropped on Neovim 0.8.3 and on 0.12.3. Random blocks: 24 seeds of 20 s, 0 dropped on both. The three F1 probes and the residual probe (300 KB and a pong behind a block, a Claude that answers 2.7 intervals late, two blocks of 1.4 intervals): kept on both. A client that writes every 100 ms and never answers: kept on both. A Claude that sends nothing: dropped 3.0 intervals after its first ping on both, and 8.0 with two blocks of 2 intervals. With six blocks of 1.3 intervals through four contexts it is dropped at 11.8 (0.8.3) and 11.9 (0.12.3) intervals, 3 later than before the change: the tick now sees the real gap, takes it for a wake, and restarts the count, as the README says. The scripts are my scratch probes, not repo files. They move into the `verify-ws-connection` replays in coder#474. ## Not in this PR - The TLA+ model in coder#474 follows this change in a separate update. ## Checks `luacheck` (with `--no-unused-args --no-max-line-length`, as CI runs it), `stylua --check`, `prettier --check` on the README, a `luajit` load of every file under `lua/`, the full busted suite (1439 successes, 16 pending, seed 424242 and seeds 1 to 60) on the code of the merge with main at `e5c5ddb` (the newer main commit `b477362` changes only `scripts/`), `verify-diff-lifecycle/check.sh` PASS (full run) and its `covered.lock` re-recorded. --- _Generated with [`xum`](https://github.com/coder/xum) • Model: `anthropic:claude-sonnet-5-5` • Thinking: `xhigh`_
Why
The goal is a test suite that fails when someone changes the first delay of the Close-frame deadline or the wake threshold of the ping timer. Both came out of the two verification lanes of #467 (merged as edcbe3c). One lane found mutants of the deadline line that passed every test. The other found a mutant of the wake line that did the same. The lanes also asked for two wording fixes in the server README.
What goes wrong if the lines regress:
start_close_timerinclient.lua) waits one keepalive window for a Close frame that sits in a queue. If its first delay becomes 0, it closes a client that still reads, in the next loop iteration. The verifier measured a reader at 1 MB/s that got 7.85 MB of the 23 to 25 MB queued, then EOF and no Close frame. If its first delay becomes three windows, a client that never reads keeps its queue for 18.0 s instead of 6.0 s at a 3 s ping interval.elapsed > interval * 1.5instart_ping_timer) counts a tick as a wake when it comes more than 1.5 intervals after the tick before it. A wake tick starts a fresh stall window only when it comes three or more ticks after the last fresh start. If>becomes>=, a tick at exactly 1.5 intervals restarts the window, and a stalled client that answers pings stays up to two ticks longer (60 s at the default interval). If the factor grows, a real wake is counted as a late tick.No runtime behavior is wrong today. Only the tests were missing.
What changed
test(server): pin the first delay of the Close-frame deadline. One test asserts that the deadline timer first runs after2 * interval. The fake timers of the lifecycle spec run a callback only when a test calls it, so no earlier test readdelay.test(server): pin the wake threshold to the millisecond. Two tests in the stall-confirmation block. A tick at exactly 1.5 intervals is not a wake, so the stalled client is dropped. A tick 1 ms above 1.5 intervals is a wake, so the count clears and no confirmation is armed.The message of commit 4ccbab1 is imprecise. It says existing tests "used gaps of 1.4 intervals and 20 intervals only". Main's spec also uses gaps of 1, 1.06 and 1.3 intervals and a first tick of 3.33 intervals. No existing gap lay between 1.4 and 3.33 intervals, so the conclusion holds. I do not amend the commit.
docs(server): name a read error and state the wake gap exactly.tcp.lua,read_startcallback). A new test pins the claim.interval * 1.5is a wake. The sentence now says "late ticks, each of which comes at mostinterval * 1.5after the tick before it", and "a tick that comes more thaninterval * 1.5after the tick before it counts as a wake from sleep".Scope
Changed:
tests/unit/server/connection_lifecycle_spec.lua(4 tests) and one line oflua/claudecode/server/README.md.Not changed, with the reason:
lua/file changes andcovered.lockstays valid.new_checkreturns nil).luvraises on out-of-memory anduv_check_initalways returns 0 on the pinned luv 1.52.1 and libuv 1.52.1. The branch cannot run on a real runtime, so a test would pin only an injected failure. The existing test pins the documented outcome for an idle handle that libuv cannot create: the tick leaves the client for the next tick.Blast Radius
Tests and one documentation line. No runtime code runs differently.
check.sh --hash-onlyreports thatcovered.lockmatches the code.Verification
Each mutant below is one edit to a line of
lua/claudecode/server/. "main spec" is the lifecycle spec fromorigin/main(61 tests). "new spec" is the spec of this branch (65 tests). The edit is reverted after each run.timer:start(0, timeout, ...)inclient.luatimer:start(timeout * 3, timeout, ...)elapsed >= (interval * 1.5)interval * 1.5 + 1On the branch, the lifecycle spec passes 65 of 65 and no test is red.
Gates at head
5411fe16a94e41811ff2448eff004558be3a0183:mise run all(BUSTED_SEED=46731) exits 0. 1397 successes, 0 failures, 0 errors, 16 pending. luacheck: 0 warnings, 0 errors in 163 files. treefmt: 329 files, 0 changed. The 16 pending tests need a real Neovim. The verifiers of fix(server): drop a client that answers pings but never reads #467 counted 1393 successes at the fix(server): drop a client that answers pings but never reads #467 head, so this branch adds 4.mise run format-checkexits 0. 329 files, 0 changed.busted -o TAP tests/unit/server tests/unit/server_spec.lua) exit 0. 195 ok, 0 not ok. The verifiers of fix(server): drop a client that answers pings but never reads #467 counted 191 at the fix(server): drop a client that answers pings but never reads #467 head, so this branch adds 4.check.sh --hash-onlyexits 0: "covered.lock matches the code".I did not run
scripts/run_integration_tests_individually.sh. The change touches no code that the integration specs reach.Generated with
xum• Model:anthropic:claude-sonnet-5-5• Thinking:xhigh