test(server): pin the Close-frame deadline delay and the wake threshold

lua/claudecode/server/README.md

@@ -78,7 +78,7 @@ Layers, top to bottom:
 - A message with a truthy `id` is a request. Any other message is a notification. A valid notification never gets a response. The -32700 and -32600 checks run before the `id` check, so a malformed notification gets an error reply [server/init.lua:M._handle_message]
 - A deferred response is keyed by `tostring(coroutine)` in `_G.claude_deferred_responses`. A result with neither `content` nor `error` becomes -32603 [server/init.lua:M._setup_deferred_response]
 - The ping timer closes a connected client when two ticks in a row find no pong within `interval * 2`. The first such tick pings again and sets `client.pong_overdue`, because a tick that Neovim runs late after a block can come before the loop has read the pong of the last ping. The next tick finds that pong, or drops the client. A tick that finds a pong clears `pong_overdue`. The Close frame of a dropped client carries 1011 "Keepalive timeout" (RFC 6455 reserves 1006, so no Close frame carries it), `on_disconnect` gets 1006 "Connection timeout", and the timer logs `Closed client_<n>: no reply for <s>s` at info level. A peer that stopped reading does not get that Close frame: once its receive window is full, every write to it (replies, pings, and the Close frame) waits in libuv's queue, and closing the socket drops the queue [server/tcp.lua:M.start_ping_timer] [server/tcp.lua:drop_client]
-- A Claude that answers each ping but never reads would keep that queue, which is Neovim's memory, without limit, so the server also closes a connected client that answers and whose write queue made no progress at two ticks in a row. Each tick calls `is_client_reading` for each connected client, which calls `sample_write_progress`: it compares `queued_bytes - get_write_queue_size()` with its value at the last progress, and an empty queue counts as progress. A tick that finds progress clears `client.write_stalled`. The first tick that finds none sets it. The second asks for a confirmation, and a confirmation that still finds no progress drops the client: the Close frame carries 1011 "Not reading", `on_disconnect` gets 1006 "Write queue stalled", and the server logs `Closed client_<n>: not reading for <s>s, <n> KB queued` at info level. The confirmation runs right after the next poll. libuv reports that a socket is writable again only in a poll phase, so a tick that Neovim runs after a main-loop block inside an I/O callback can find no progress although Claude read during the block, whether the tick is late or on time. `after_next_poll` arms a check handle, which libuv runs right after each poll phase in every version, and an idle handle, which keeps that poll from waiting for a timer or a socket. The check callback closes both handles, removes them from `server.pending_polls`, and judges the queue once more: progress clears `write_stalled`, and no progress drops the client. A client that left or started to leave in the meantime, because the poll read its EOF, its Close frame or a protocol error, is skipped without a log line. `stop_server` closes the handles of a confirmation that has not run, which `server.pending_polls` lists. If libuv cannot create a handle, the tick leaves the client for the next tick. The look is a sample at one moment, not proof. libuv takes its snapshot of the ready sockets when a poll starts, so a callback that blocks inside that poll, after the snapshot, hides what Claude reads during the block from the check callback that follows. A client that was stalled for the whole window and resumes during such a block is dropped. That is a deadline race, as with any timeout: the client was stalled when the window ended, and what it read afterwards is not reported yet. Verifier probes closed a reader that resumed 0.1 s into a 0.5 s to 1.5 s block inside the confirming poll, on Neovim 0.12.3 and 0.8.0, at 3 s, 5 s and 30 s intervals. A block after the tick and before that poll, or in a scheduled callback, keeps the reader. The bound is two to three ticks after the last progress, which is 60 s to 90 s at the default interval, plus the delay of ticks that Neovim runs late by less than 1.5 intervals. A tick gap above `interval * 1.5` counts as a wake from sleep. A wake tick starts a fresh stall window: it clears the count and judges nothing, so it delays the drop by one tick when the count was clear, and by two ticks when the wake tick takes the place of the confirming tick. The next two ticks always count, wake ticks or not, because wake ticks that come again and again are a loop that stays blocked, not sleeps. So whatever the pattern of late ticks, a stalled client is closed at the second tick after a fresh window started. A wake tick three or more ticks after the last fresh start starts a new window. The bound is never the size of the queue, so a Claude that reads slowly, or is sent one message of tens of MB, stays connected while libuv writes any of it. libuv writes more only after the kernel reports the socket writable again, which took 1.2 to 1.5 MB of reading on a Linux loopback socket with default buffers (measured), so a Claude that reads less than about 1.4 MB per window counts as stalled while a backlog exists, and one that reads just faster than that still lets the queue grow as long as Neovim queues more than it reads. `write` queues a frame of more than 1 MiB in pieces of 1 MiB, because libuv on Windows lowers the queue only when a whole write request is done, so a large frame shows its progress per piece there too, and the callback of the last piece reports the frame. [server/tcp.lua:M.start_ping_timer] [server/tcp.lua:confirm_stall] [server/tcp.lua:after_next_poll] [server/tcp.lua:M.stop_server] [server/client.lua:M.is_client_reading] [server/client.lua:M.sample_write_progress] [server/client.lua:write]
+- A Claude that answers each ping but never reads would keep that queue, which is Neovim's memory, without limit, so the server also closes a connected client that answers and whose write queue made no progress at two ticks in a row. Each tick calls `is_client_reading` for each connected client, which calls `sample_write_progress`: it compares `queued_bytes - get_write_queue_size()` with its value at the last progress, and an empty queue counts as progress. A tick that finds progress clears `client.write_stalled`. The first tick that finds none sets it. The second asks for a confirmation, and a confirmation that still finds no progress drops the client: the Close frame carries 1011 "Not reading", `on_disconnect` gets 1006 "Write queue stalled", and the server logs `Closed client_<n>: not reading for <s>s, <n> KB queued` at info level. The confirmation runs right after the next poll. libuv reports that a socket is writable again only in a poll phase, so a tick that Neovim runs after a main-loop block inside an I/O callback can find no progress although Claude read during the block, whether the tick is late or on time. `after_next_poll` arms a check handle, which libuv runs right after each poll phase in every version, and an idle handle, which keeps that poll from waiting for a timer or a socket. The check callback closes both handles, removes them from `server.pending_polls`, and judges the queue once more: progress clears `write_stalled`, and no progress drops the client. A client that left or started to leave in the meantime, because the poll read its EOF, a read error, its Close frame or a protocol error, is skipped without a log line. `stop_server` closes the handles of a confirmation that has not run, which `server.pending_polls` lists. If libuv cannot create a handle, the tick leaves the client for the next tick. The look is a sample at one moment, not proof. libuv takes its snapshot of the ready sockets when a poll starts, so a callback that blocks inside that poll, after the snapshot, hides what Claude reads during the block from the check callback that follows. A client that was stalled for the whole window and resumes during such a block is dropped. That is a deadline race, as with any timeout: the client was stalled when the window ended, and what it read afterwards is not reported yet. Verifier probes closed a reader that resumed 0.1 s into a 0.5 s to 1.5 s block inside the confirming poll, on Neovim 0.12.3 and 0.8.0, at 3 s, 5 s and 30 s intervals. A block after the tick and before that poll, or in a scheduled callback, keeps the reader. The bound is two to three ticks after the last progress, which is 60 s to 90 s at the default interval, plus the delay of late ticks, each of which comes at most `interval * 1.5` after the tick before it. A tick that comes more than `interval * 1.5` after the tick before it counts as a wake from sleep. A wake tick starts a fresh stall window: it clears the count and judges nothing, so it delays the drop by one tick when the count was clear, and by two ticks when the wake tick takes the place of the confirming tick. The next two ticks always count, wake ticks or not, because wake ticks that come again and again are a loop that stays blocked, not sleeps. So whatever the pattern of late ticks, a stalled client is closed at the second tick after a fresh window started. A wake tick three or more ticks after the last fresh start starts a new window. The bound is never the size of the queue, so a Claude that reads slowly, or is sent one message of tens of MB, stays connected while libuv writes any of it. libuv writes more only after the kernel reports the socket writable again, which took 1.2 to 1.5 MB of reading on a Linux loopback socket with default buffers (measured), so a Claude that reads less than about 1.4 MB per window counts as stalled while a backlog exists, and one that reads just faster than that still lets the queue grow as long as Neovim queues more than it reads. `write` queues a frame of more than 1 MiB in pieces of 1 MiB, because libuv on Windows lowers the queue only when a whole write request is done, so a large frame shows its progress per piece there too, and the callback of the last piece reports the frame. [server/tcp.lua:M.start_ping_timer] [server/tcp.lua:confirm_stall] [server/tcp.lua:after_next_poll] [server/tcp.lua:M.stop_server] [server/client.lua:M.is_client_reading] [server/client.lua:M.sample_write_progress] [server/client.lua:write]
 - On one tick the pong rule runs first. A client without a pong gets the second chance or the keepalive drop whatever its write queue shows, and only a client that answered is confirmed for a stall. A pong that arrives while the queue is stalled does not save the client: the next tick clears `pong_overdue`, and then asks for the confirmation. Every connected client is sampled on every tick except one that starts a fresh stall window, answering or not, so "two ticks in a row" means consecutive ticks. A tick gap above `interval * 1.5` counts as a wake from sleep and resets `last_pong` of each connected client, and its own alive check finds the fresh pong and clears `pong_overdue`. A wake tick that starts a fresh stall window also resets `last_drain`, clears `write_stalled`, and does not sample the queue. `last_drain` feeds only the `not reading for <s>s` of the log line, so the reset keeps the sleep out of it. A wake tick within two ticks after the start of a fresh window resets `last_pong` only, and counts like any tick. The 101 write callback sets `last_pong` again, so the keepalive window starts when the client is connected, not at the accept. A main loop that blocks during the handshake then does not count against the client [server/tcp.lua:M.start_ping_timer] [server/client.lua:M.process_data]
 - `_disconnect_client` is idempotent: `on_disconnect` fires once per client id. A client that already left the server (it stopped before a scheduled `on_close` or an EOF ran) gets its socket closed there, unless the write callback of its Close frame will close it [server/tcp.lua:M._disconnect_client]
 - A client's read error or protocol error reaches the server only as its `on_disconnect` reason (`Client read error: …` or `Client error: …`), which `init.lua` logs at debug level. `on_error` carries only the server's own failures (listen, accept, and creating a client handle or the ping timer), which `init.lua` logs at error level [server/tcp.lua:M._handle_new_connection] [server/init.lua:M.start]

tests/unit/server/connection_lifecycle_spec.lua

@@ -782,6 +782,36 @@ describe("The lifecycle of a WebSocket connection", function()
       assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "Write queue stalled")
     end)
 
+    -- The two tests below pin the wake threshold from both sides, to the millisecond. A gap of exactly 1.5 intervals is
+    -- not a wake, and a gap 1 ms above it is.
+    it(
+      "counts a tick at exactly the wake threshold, so that it is not a wake and a stalled client is dropped",
+      function()
+        local tick, _, client, handle = stalled_client()
+        answer_and(tick, 1)(handle)
+        assert.is_true(client.write_stalled)
+
+        answer_and(tick, 1.5)(handle)
+
+        assert.is_nil(server.clients[client.id], "a gap of exactly 1.5 intervals restarted the stall window")
+        assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "Write queue stalled")
+      end
+    )
+
+    it("starts a fresh stall window at a tick 1 ms above the wake threshold", function()
+      local tick, _, client, handle = stalled_client()
+      answer_and(tick, 1)(handle)
+      assert.is_true(client.write_stalled)
+
+      handle._read_cb(nil, pong)
+      clock = clock + 1.5 * interval + 1
+      tick()
+
+      assert.is_nil(client.write_stalled, "a gap above 1.5 intervals kept the count")
+      assert.is_not_nil(server.clients[client.id], "a gap above 1.5 intervals counted against the client")
+      assert.equals(0, #checks, "a wake tick asked for a confirmation")
+    end)
+
     it("judges only the clients that answered at the tick", function()
       local tick, _, client, handle = stalled_client()
       answer_and(tick, 1)(handle)
@@ -996,6 +1026,21 @@ describe("The lifecycle of a WebSocket connection", function()
         assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "EOF")
       end)
 
+      it("skips a client whose socket failed to read in the poll of its confirmation, and logs no stall", function()
+        local client, handle = pending_confirmation()
+
+        local lines = logged_info_during(function()
+          poll(function()
+            handle._read_cb("ECONNRESET", nil) -- the poll reads the error of a reset connection
+          end)
+        end)
+
+        assert.same({}, lines, "a client that already left was logged as not reading")
+        assert.spy(callbacks.on_disconnect).was_called(1)
+        assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "Client read error: ECONNRESET")
+        assert.is_nil(server.clients[client.id])
+      end)
+
       it("closes the handles of a confirmation in stop_server, and the confirmation never runs", function()
         local client = pending_confirmation()
 
@@ -1270,6 +1315,20 @@ describe("The lifecycle of a WebSocket connection", function()
       end
     )
 
+    -- The fake timers run only when a test calls their callback, so no other test reads `delay`. A deadline that first
+    -- runs at once cuts off a Claude that is still reading, and one that first runs after three windows keeps the queue
+    -- three times as long as the bound says. Real sockets showed both (verifier probes at a 3 s interval).
+    it("first runs the deadline one window after the frame, not at once and not later", function()
+      start_ping_timer()
+      local client, _, handle = connect_and_upgrade()
+      tcp.send_to_client(server, client.id, reply)
+      handle._read_cb(nil, binary())
+
+      local deadline = close_deadline()
+
+      assert.equals(2 * interval, deadline.delay, "the deadline does not first run one window after the frame")
+    end)
+
     it("waits while Claude reads, and the write callback then closes the socket and ends the deadline", function()
       start_ping_timer()
       local client, writes, handle = connect_and_upgrade()