From f3576ea21423763ec25c9762484c25b3a7ab75da Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Tue, 10 Nov 2026 23:50:54 +0000 Subject: [PATCH 1/9] fix(server): judge a silent Claude only after reading its socket A ping timer tick cannot tell a silent Claude from a pong that is still in the socket: libuv can run a tick before it reads the socket, after a block of the main loop in any callback. Neovim 0.8 (libuv 1.44) runs the timers again at the end of a pass, so two late ticks can run with no read between them, and #479's second-tick rule then dropped a Claude that answered every ping. A tick now pings and stamps the oldest unanswered ping (`ping_unanswered_since`, with `vim.loop.update_time()` first), and never drops. It starts a one-shot libuv check handle, which libuv runs after the poll that reads the sockets. The check drops a client whose oldest ping is `interval * 2.5` old. A pong clears the stamp, and so does a wake from sleep. A Claude that answers within `interval * 2.5` is never dropped. A Claude that never answers is dropped at the first read after the third tick that follows its first unanswered ping, as before. Removes `pong_overdue`, `is_client_alive` and the 101-callback reset of `last_pong`, which only served the old tick-side check. --- .../skills/verify-diff-lifecycle/covered.lock | 4 +- lua/claudecode/server/README.md | 6 +- lua/claudecode/server/client.lua | 21 +- lua/claudecode/server/tcp.lua | 92 ++++-- .../unit/server/connection_lifecycle_spec.lua | 286 ++++++++++++++++-- tests/unit/server/log_lines_spec.lua | 31 +- tests/unit/server/tcp_spec.lua | 47 ++- 7 files changed, 388 insertions(+), 99 deletions(-) diff --git a/.agents/skills/verify-diff-lifecycle/covered.lock b/.agents/skills/verify-diff-lifecycle/covered.lock index 8829c1786..05c5c1a35 100644 --- a/.agents/skills/verify-diff-lifecycle/covered.lock +++ b/.agents/skills/verify-diff-lifecycle/covered.lock @@ -138,7 +138,7 @@ file lua/claudecode/logger.lua 17b404dda41c3591 == lua/claudecode/selection.lua file lua/claudecode/selection.lua 0fa651cc95e0af0d == lua/claudecode/server/client.lua -file lua/claudecode/server/client.lua 5789c6ff18045f9f +file lua/claudecode/server/client.lua 4218e4fd15f51b3a block create_client 647b7523dea26af6 == lua/claudecode/server/frame.lua file lua/claudecode/server/frame.lua 3c50766875878d56 @@ -160,7 +160,7 @@ site lua/claudecode/server/init.lua: if not _G.claude_deferred_responses then @ == lua/claudecode/server/mock.lua file lua/claudecode/server/mock.lua def1248d2793d559 == lua/claudecode/server/tcp.lua -file lua/claudecode/server/tcp.lua f1f9833b4322b1ae +file lua/claudecode/server/tcp.lua 99fe003ea1a3c494 == lua/claudecode/server/utils.lua file lua/claudecode/server/utils.lua 2915ae87b48f04ca == lua/claudecode/terminal.lua diff --git a/lua/claudecode/server/README.md b/lua/claudecode/server/README.md index 8622c5aa4..0cceff141 100644 --- a/lua/claudecode/server/README.md +++ b/lua/claudecode/server/README.md @@ -41,7 +41,7 @@ Layers, top to bottom: ### Connection, handshake, and frames -- `client.create_client(tcp_handle)`, `process_data(...)`, `send_message`, `send_ping`, `close_client`, `is_client_alive(client, timeout=30000)`, and `get_client_info` [server/client.lua:M.process_data] +- `client.create_client(tcp_handle)`, `process_data(...)`, `send_message`, `send_ping`, `close_client`, and `get_client_info` [server/client.lua:M.process_data] - `handshake.process_handshake(request, expected_auth_token) -> ok, response, headers?` [server/handshake.lua:M.process_handshake] - `handshake.validate_upgrade_request`, `create_handshake_response`, `parse_request_line`, `is_websocket_endpoint`, `create_error_response`, and `extract_http_request` [server/handshake.lua:M.validate_upgrade_request] - `frame.OPCODE`: `CONTINUATION 0x0`, `TEXT 0x1`, `BINARY 0x2`, `CLOSE 0x8`, `PING 0x9`, `PONG 0xA` [server/frame.lua:M.OPCODE] @@ -77,7 +77,7 @@ Layers, top to bottom: - When the JSON decodes to a non-table value (for example a number or a boolean), `_handle_message` replies -32600 with `"id": null`. It does not raise [server/init.lua:M._handle_message] - 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 libuv runs timers before it reads sockets, so a tick that Neovim runs late after a block finds the pong of the last ping still unread. The next tick finds that pong, or drops the client. A pong clears `pong_overdue` at the next tick. 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_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and resets `last_pong` of each connected client. 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] +- A ping timer tick pings every connected client and never closes one. `client.ping_unanswered_since` holds the loop time of the oldest ping that no pong has answered. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. A pong clears it. Each tick 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent, after a block of the main loop in any callback, and Neovim 0.8 (libuv 1.44) runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim can run it before the read. Drop bound: a Claude that answers each ping within `interval * 2.5` (75 s by default) is never closed, whatever blocks the main loop. A Claude that never answers is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping, or when a block of the main loop ends if the block delays that tick. 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 check logs `Closed client_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and clears `ping_unanswered_since` of each connected client. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [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] - A rejected handshake logs `Rejected client_: ` at warn level, with the reason from the body of the error response. Once the error response is written, `on_error` removes the client from the server and closes its socket [server/client.lua:M.process_data] @@ -99,7 +99,7 @@ Layers, top to bottom: - `client.create_client` increments `_G.claudecode_clients_created` [server/client.lua:M.create_client] - `tcp.lua` seeds `math.randomseed` once per process. `init.lua` calls `math.random` at load. Both change the global PRNG [server/tcp.lua:ensure_rng_seeded] - `client.process_data` writes handshake, PONG, and Close frames to the socket. It runs `on_message` and `on_close` through `vim.schedule`. It calls `on_error` directly after a failed handshake write, and after it queues the Close frame for a protocol error [server/client.lua:M.process_data] [server/client.lua:M.close_client] -- The ping timer writes ping frames and closes timed-out clients [server/tcp.lua:M.start_ping_timer] +- The ping timer writes ping frames, and the check handle that each tick starts closes the clients that did not answer [server/tcp.lua:M.start_ping_timer] - `handshake.lua`, `frame.lua`, and `utils.lua` do no I/O [server/handshake.lua:M] - `mock.lua` opens no sockets and keeps its clients and messages in its own `M.state` tables. Its `mcp.tool.invoke` handler calls the real `tools.handle_invoke`, so a simulated tool call has that tool's real side effects (for example `saveDocument` writes the file) [server/mock.lua:M.register_handlers] [server/mock.lua:M.state] diff --git a/lua/claudecode/server/client.lua b/lua/claudecode/server/client.lua index 742612882..03448c1e6 100644 --- a/lua/claudecode/server/client.lua +++ b/lua/claudecode/server/client.lua @@ -30,7 +30,7 @@ local CLOSE_REASONS = { ---@field close_pending boolean|nil True while a Close frame waits to be written: its write callback closes the socket ---@field last_ping number Timestamp of last ping sent ---@field last_pong number Timestamp of last pong received ----@field pong_overdue boolean|nil True after a ping timer tick found no pong for two intervals. The next such tick drops the client +---@field ping_unanswered_since number|nil Loop time of the oldest ping that no pong has answered. nil when none waits ---Create a new WebSocket client ---@param tcp_handle table The vim.loop TCP handle @@ -193,9 +193,6 @@ function M.process_data(client, data, on_message, on_close, on_error, auth_token end client.handshake_complete = true client.state = "connected" - -- The keepalive window starts now. The ping timer ignores a client that is not connected, so the main loop can - -- block between the accept and this point for longer than the timeout, and no ping reached this client yet. - client.last_pong = vim.loop.now() logger.debug("client", "WebSocket connection established for client:", client.id) if on_open then on_open(client) @@ -286,6 +283,7 @@ function M.process_data(client, data, on_message, on_close, on_error, auth_token client.tcp_handle:write(pong_frame) elseif opcode == frame.OPCODE.PONG then client.last_pong = vim.loop.now() + client.ping_unanswered_since = nil end end client.buffer = client.buffer:sub(offset) @@ -373,21 +371,6 @@ function M.close_client(client, code, reason) end end ----Check if a client connection is alive ----@param client WebSocketClient The client object ----@param timeout number Timeout in milliseconds (default: 30000) ----@return boolean alive True if the client is considered alive -function M.is_client_alive(client, timeout) - timeout = timeout or 30000 -- 30 seconds default - - if client.state ~= "connected" then - return false - end - - local now = vim.loop.now() - return (now - client.last_pong) < timeout -end - ---Get client info for debugging ---@param client WebSocketClient The client object ---@return table info Client information diff --git a/lua/claudecode/server/tcp.lua b/lua/claudecode/server/tcp.lua index c4fc11573..7afdbe736 100644 --- a/lua/claudecode/server/tcp.lua +++ b/lua/claudecode/server/tcp.lua @@ -381,7 +381,53 @@ function M.stop_server(server) end end ----Start a periodic ping task to keep connections alive +---Drop each of `clients` whose oldest ping has gone unanswered for `limit` ms, once Neovim has read their sockets. The +---judgment runs in a libuv check handle, which libuv runs after the poll phase that reads the sockets, so every byte +---that reached a socket before the loop time of the check has been read. A timer tick cannot judge: libuv can run it +---before it reads the pong that Claude sent, after a block of the main loop in any callback, and Neovim 0.8 (libuv +---1.44) runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` is +---no help either: Neovim can run it before the read. +---@param server TCPServer The server object +---@param clients WebSocketClient[] The clients that the ping timer pinged in one tick +---@param limit number Age in milliseconds of the oldest unanswered ping at which a client is dropped +local function drop_unanswered_after_read(server, clients, limit) + local check = vim.loop.new_check() + if not check then + server.on_error("Failed to create keepalive check") + return + end + + check:start(function() + check:stop() + check:close() + local now = vim.loop.now() + + for _, client in ipairs(clients) do + local since = client.ping_unanswered_since + if server.clients[client.id] == client and client.state == "connected" and since and now - since >= limit then + -- Client connection timed out - log at INFO level (this is expected behavior) + require("claudecode.logger").one_line( + "info", + "server", + string.format("Closed %s: no reply for %ds", client.id, math.floor((now - since) / 1000)) + ) + -- RFC 6455 reserves 1006, so the Close frame says 1011, as other servers do for a keepalive timeout. The + -- connection still ends without the client's Close frame, which is what 1006 means here. + client_manager.close_client(client, 1011, "Keepalive timeout") + -- The socket does not wait for the Close frame: a Claude that stopped answering may never read it. Closing + -- now drops the frame when Claude's window is full. + client.close_pending = nil + M._disconnect_client(server, client, 1006, "Connection timeout") + end + end + end) +end + +---Start a periodic ping task to keep connections alive. +---A tick pings every connected client and never drops one. A client whose oldest ping is `interval * 2.5` old is +---dropped at the first read of its socket after a tick [drop_unanswered_after_read]. A Claude that answers each ping +---within that time is never dropped, however the main loop blocks. A Claude that never answers is dropped after the +---third tick that follows its first unanswered ping: the half interval keeps timer jitter from moving the drop. ---@param server TCPServer The server object ---@param interval number Ping interval in milliseconds (default: 30000) ---@return table? timer The timer handle, or nil if creation failed @@ -404,7 +450,7 @@ function M.start_ping_timer(server, interval) local is_wake_from_sleep = elapsed > (interval * 1.5) if is_wake_from_sleep then - -- After system sleep/wake, reset all client pong timestamps to prevent false timeouts + -- After system sleep/wake, forget the pings that went unanswered to prevent false timeouts -- This gives clients a fresh keepalive window since the time jump isn't their fault require("claudecode.logger").debug( "server", @@ -414,44 +460,28 @@ function M.start_ping_timer(server, interval) ) ) for _, client in pairs(server.clients) do - if client.state == "connected" then - client.last_pong = now - end + client.ping_unanswered_since = nil end end + local pinged = {} for _, client in pairs(server.clients) do if client.state == "connected" then - -- Check if client is alive (local connections, so use standard timeout) - if client_manager.is_client_alive(client, interval * 2) then - client.pong_overdue = nil - client_manager.send_ping(client, "ping") - elseif not client.pong_overdue then - -- libuv runs timers before it reads sockets, so a tick that Neovim runs late after a block finds the pong of - -- the last ping still unread. The first tick that finds no pong for two intervals pings again. The next one - -- finds the pong that was read in between, or drops the client. - client.pong_overdue = true - client_manager.send_ping(client, "ping") - else - -- Client connection timed out - log at INFO level (this is expected behavior) - local time_since_pong = math.floor((now - client.last_pong) / 1000) - require("claudecode.logger").one_line( - "info", - "server", - string.format("Closed %s: no reply for %ds", client.id, time_since_pong) - ) - -- RFC 6455 reserves 1006, so the Close frame says 1011, as other servers do for a keepalive timeout. The - -- connection still ends without the client's Close frame, which is what 1006 means here. - client_manager.close_client(client, 1011, "Keepalive timeout") - -- The socket does not wait for the Close frame: a Claude that stopped answering may never read it. Closing - -- now drops the frame when Claude's window is full. - client.close_pending = nil - M._disconnect_client(server, client, 1006, "Connection timeout") - end + client_manager.send_ping(client, "ping") + -- libuv caches the loop time when a pass starts, and a callback that ran before this tick in the pass can have + -- blocked since. A ping stamped with that old time would look older than it is, and the check could drop a + -- Claude that had no time to answer it. + vim.loop.update_time() + client.ping_unanswered_since = client.ping_unanswered_since or vim.loop.now() + table.insert(pinged, client) end end last_run = now + + if #pinged > 0 then + drop_unanswered_after_read(server, pinged, interval * 2.5) + end end) return timer diff --git a/tests/unit/server/connection_lifecycle_spec.lua b/tests/unit/server/connection_lifecycle_spec.lua index 33f59cd9f..cda3d6b35 100644 --- a/tests/unit/server/connection_lifecycle_spec.lua +++ b/tests/unit/server/connection_lifecycle_spec.lua @@ -1,12 +1,13 @@ --- A client that the plugin is done with must leave the server promptly, be reported once and have its socket closed, --- and a Claude that answers pings must never be dropped. These tests run the real tcp.lua and client.lua against a --- socket that works like libuv's: a write callback runs only when the test calls `done` (a Claude that does not read ---- never completes a write), and a second close of a handle is an error. +--- never completes a write), and a second close of a handle is an error. The loop time is cached at the start of a pass +--- of the main loop, and a check handle runs after the pass has read the sockets, as in libuv. require("tests.busted_setup") describe("The lifecycle of a WebSocket connection", function() local tcp, frame, server, callbacks, scheduled - local clock, saved + local clock, cached, checks, saved local token = "test-token-0123456789" local interval = 30000 @@ -22,8 +23,15 @@ describe("The lifecycle of a WebSocket connection", function() end tcp = require("claudecode.server.tcp") frame = require("claudecode.server.frame") - scheduled, clock = nil, 1000000 - saved = { schedule = vim.schedule, now = vim.loop.now, new_timer = vim.loop.new_timer } + scheduled, clock, checks = nil, 1000000, {} + cached = clock + saved = { + schedule = vim.schedule, + now = vim.loop.now, + new_timer = vim.loop.new_timer, + new_check = vim.loop.new_check, + update_time = vim.loop.update_time, + } -- While `scheduled` is a list, scheduled callbacks wait in it, as they wait for the main loop in Neovim. vim.schedule = function(fn) if scheduled then @@ -32,8 +40,27 @@ describe("The lifecycle of a WebSocket connection", function() fn() end end + -- `clock` is the time of the world. `cached` is the loop time: libuv sets it from `clock` when a pass of the main loop + -- starts, and after the poll that reads the sockets. A callback that blocks does not move it. vim.loop.now = function() - return clock + return cached + end + vim.loop.update_time = function() + cached = clock + end + vim.loop.new_check = function() + local handle = {} + function handle:start(callback) + self.callback = callback + table.insert(checks, self) + end + function handle:stop() + self.callback, self.stopped = nil, true + end + function handle:close() + self.closed = true + end + return handle end callbacks = { on_message = spy.new(function() end), @@ -48,6 +75,7 @@ describe("The lifecycle of a WebSocket connection", function() after_each(function() vim.schedule, vim.loop.now, vim.loop.new_timer = saved.schedule, saved.now, saved.new_timer + vim.loop.new_check, vim.loop.update_time = saved.new_check, saved.update_time end) ---Accept a connection whose socket works like libuv's. @@ -90,13 +118,17 @@ describe("The lifecycle of a WebSocket connection", function() end end - ---Start the ping timer on the server, and return the function that runs on each tick. + ---Start the ping timer on the server, and return the function that runs on each tick. A tick runs at the start of a + ---pass of the main loop, or at its end (libuv 1.44 runs the timers again after the check handles): the loop time is + ---the time of the world, unless `after_block` of the pass is set. + ---@return function tick Runs the timer callback. `tick(block)`: a callback that ran before it in its pass blocked for + ---`block` ms, so the loop time is that old local function start_ping_timer() - local tick + local callback vim.loop.new_timer = function() return { - start = function(_, _, _, callback) - tick = callback + start = function(_, _, _, timer_callback) + callback = timer_callback end, stop = function() end, close = function() end, @@ -104,7 +136,32 @@ describe("The lifecycle of a WebSocket connection", function() end tcp.start_ping_timer(server, interval) vim.loop.new_timer = saved.new_timer - return tick + return function(block) + cached = clock + clock = clock + (block or 0) + callback() + end + end + + ---The poll of a pass of the main loop, with the read of Claude's socket that the test makes, then the check handles + ---that the ticks since the last poll started. + ---@param handle table|nil The socket of the client that Claude wrote to + ---@param data string|nil What Claude wrote + local function poll(handle, data) + cached = clock + if handle then + handle._read_cb(nil, data) + end + local pending = checks + checks = {} + for _, check in ipairs(pending) do + check.callback() + assert.is_true(check.stopped and check.closed, "a check handle stayed running or open after it ran") + end + end + + local function pong() + return frame.create_frame(frame.OPCODE.PONG, "ping", true, true) end local function parse(write) @@ -139,55 +196,219 @@ describe("The lifecycle of a WebSocket connection", function() assert.equals(2, #writes, "the 101 reply and a ping") assert.equals(frame.OPCODE.PING, parse(writes[2]).opcode) end) + end) - it("still drops a client that never answers, at the second tick that finds no pong", function() + describe("when a Claude never answers a ping", function() + it("drops it at the first read of its socket after the fourth tick, and not at the tick", function() local tick = start_ping_timer() local client, writes, handle = connect_and_upgrade() clock = clock + interval - tick() -- the client is 1 interval old: a ping - clock = clock + interval - tick() -- no pong for 2 intervals: the first such tick pings again and does not drop - assert.is_not_nil(server.clients[client.id], "the client was dropped at the first tick that found no pong") - assert.equals(frame.OPCODE.PING, parse(writes[#writes]).opcode) + tick() -- the first ping + poll() + for _ = 1, 2 do + clock = clock + interval + tick() -- the first ping is 1, then 2 intervals old + poll() + end + assert.is_not_nil(server.clients[client.id], "the client was dropped before its ping was 2.5 intervals old") clock = clock + interval - tick() -- still no pong: the second such tick drops the client + tick() -- the first ping is 3 intervals old, and Neovim did not read the socket since this tick + assert.is_not_nil(server.clients[client.id], "a tick dropped the client before the socket was read") + assert.spy(callbacks.on_disconnect).was_not_called() + poll() assert.is_nil(server.clients[client.id]) assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "Connection timeout") assert.equals(1011, close_status(writes[#writes])) assert.is_true(handle:is_closing()) end) + + it("drops it at the first read after a late tick that finds its ping 2.5 intervals old", function() + local tick = start_ping_timer() + local client = connect_and_upgrade() + + clock = clock + interval + tick() + poll() + clock = clock + 1.3 * interval + tick() + poll() -- the first ping is 1.3 intervals old + assert.is_not_nil(server.clients[client.id]) + clock = clock + 1.3 * interval + tick() + poll() -- the first ping is 2.6 intervals old: the third tick is not needed + + assert.is_nil(server.clients[client.id]) + end) + + it("counts the time from the first ping that went unanswered, after Claude answered before", function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + + clock = clock + interval + tick() + poll(handle, pong()) -- Claude answers the first ping + for _ = 1, 4 do + clock = clock + interval + tick() + assert.is_not_nil(server.clients[client.id]) + poll() + end + + assert.is_nil(server.clients[client.id], "the ping of the second tick was unanswered for 3 intervals") + end) + + it("does not drop a Claude whose pong waits in the socket when its ping is 3 intervals old", function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + + clock = clock + interval + tick() + poll() -- Claude answers after this poll + for _ = 1, 2 do + clock = clock + interval + tick() + poll() + end + clock = clock + interval + tick() -- the ping of the first tick is 3 intervals old, and its pong was not read yet + poll(handle, pong()) + + assert.is_not_nil(server.clients[client.id], "the check ran before the pong was read") + assert.spy(callbacks.on_disconnect).was_not_called() + end) end) - describe("when the ping timer runs late, below the wake threshold, with Claude's pong still unread", function() - -- libuv runs timers before it reads sockets. A tick that Neovim runs late after a block finds the pong of the last ping - -- still in the socket, so its last_pong is a whole interval older than the tick before it. A block of up to 1.5 - -- intervals is not a wake, so last_pong is not reset. - it("does not drop a Claude that answers every ping, and forgets the late tick once Claude answers", function() + describe("when the main loop blocks before the pongs of a Claude that answers every ping are read", function() + -- libuv runs timers before it reads sockets, and Neovim 0.8 (libuv 1.44) runs the timers a second time at the end + -- of a pass, after the check handles. A tick that Neovim runs late after a block finds the pongs of the last pings + -- unread, and two late ticks can run with no read between them. + it("does not drop it when two late ticks run with no read between them", function() local tick = start_ping_timer() - local client, writes, handle = connect_and_upgrade() - local pong = frame.create_frame(frame.OPCODE.PONG, "ping", true, true) + local client, _, handle = connect_and_upgrade() clock = clock + interval tick() - handle._read_cb(nil, pong) + poll() -- Claude answers after this poll + clock = clock + interval + tick() + poll(handle, pong()) clock = clock + interval - tick() -- Neovim blocks right after this ping, before it reads the pong, for 1.3 intervals + tick() -- ping 3 + poll() + -- A check callback blocks for 1.3 intervals right after the ping. The timers run again at the end of the pass, and + -- a vim.schedule callback blocks for 1.3 intervals before the next pass reads the socket. clock = clock + 1.3 * interval tick() + clock = clock + 1.3 * interval + tick() + assert.is_not_nil(server.clients[client.id], "a late tick dropped the client") + + poll(handle, pong() .. pong() .. pong()) + + assert.is_not_nil(server.clients[client.id], "the check of a late tick dropped the client") + assert.spy(callbacks.on_disconnect).was_not_called() + end) + + it("does not drop it however many late ticks run with no read between them", function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + + for _ = 1, 20 do + clock = clock + 1.3 * interval + tick() + end + assert.is_not_nil(server.clients[client.id], "a late tick dropped the client") + poll(handle, pong() .. pong() .. pong()) - assert.is_not_nil(server.clients[client.id], "the client was dropped by a late tick") + assert.is_not_nil(server.clients[client.id], "the check of a late tick dropped the client") assert.spy(callbacks.on_disconnect).was_not_called() - handle._read_cb(nil, pong) -- the loop reads the pong after the late tick + end) + + it( + "stamps a ping with the time of the world, not the loop time cached before an earlier callback blocked", + function() + local tick = start_ping_timer() + local client = connect_and_upgrade() + + clock = clock + interval + tick(100000) -- a timer that ran before the ping timer in this pass blocked for 100 s + poll() -- Claude had no time to answer yet + + assert.is_not_nil(server.clients[client.id], "the ping was dropped for the age of the loop time") + end + ) + + it("forgets the pings that went unanswered when Neovim wakes from sleep", function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + + clock = clock + interval + tick() + poll() clock = clock + interval tick() - clock = clock + 1.3 * interval -- a second late tick, again with the pong unread + poll() + clock = clock + 10 * interval -- the machine slept: Claude slept too, and answers once it is awake tick() + poll() + assert.is_not_nil(server.clients[client.id], "the wake was not forgiven") + poll(handle, pong()) + + assert.is_not_nil(server.clients[client.id]) + end) + end) + + describe("when a client leaves between a tick and the check that follows it", function() + local one_line + + before_each(function() + one_line = spy.on(require("claudecode.logger"), "one_line") + end) + + after_each(function() + one_line:revert() + end) + + ---Four ticks, with a poll after each but the last. Claude never answered: at the fourth tick its oldest ping is 3 + ---intervals old, and the check of that tick is the next to run. + local function tick_four_times(tick) + for round = 1, 4 do + clock = clock + interval + tick() + if round < 4 then + poll() + end + end + end + + it("does not report a client that hung up, and logs nothing about it", function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + tick_four_times(tick) + + handle._read_cb(nil, nil) -- Claude hangs up before the pass reads anything else + assert.spy(callbacks.on_disconnect).was_called(1) + assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "EOF") + poll() + + assert.spy(callbacks.on_disconnect).was_called(1) + assert.spy(one_line).was_not_called() + end) + + it("does not drop a client that is closing", function() + local tick = start_ping_timer() + local client, writes, handle = connect_and_upgrade() + tick_four_times(tick) + scheduled = {} -- on_close waits for the loop + handle._read_cb(nil, frame.create_frame(frame.OPCODE.CLOSE, "\3\232", true, true)) + assert.equals("closing", client.state) + local written = #writes + poll() - assert.is_not_nil(server.clients[client.id], "the first late tick counted against the second one") + assert.equals(written, #writes, "a Close frame followed the reply to Claude's Close frame") assert.spy(callbacks.on_disconnect).was_not_called() - assert.equals(frame.OPCODE.PING, parse(writes[#writes]).opcode) end) end) @@ -282,9 +503,10 @@ describe("The lifecycle of a WebSocket connection", function() local client, writes, handle = connect_and_upgrade() tcp.send_to_client(server, client.id, string.rep("x", 262144)) - for _ = 1, 3 do + for _ = 1, 4 do clock = clock + interval tick() + poll() end assert.is_nil(server.clients[client.id]) diff --git a/tests/unit/server/log_lines_spec.lua b/tests/unit/server/log_lines_spec.lua index 0feaf2300..7223cca7f 100644 --- a/tests/unit/server/log_lines_spec.lua +++ b/tests/unit/server/log_lines_spec.lua @@ -21,6 +21,7 @@ describe("Server lines on the command line", function() lines = {} saved.notify, saved.echo, saved.new_timer, saved.new_tcp = vim.notify, vim.api.nvim_echo, vim.loop.new_timer, vim.loop.new_tcp + saved.new_check, saved.update_time, saved.now = vim.loop.new_check, vim.loop.update_time, vim.loop.now vim.notify = function(msg, level) table.insert(lines, { text = msg, level = level }) end @@ -37,6 +38,7 @@ describe("Server lines on the command line", function() end vim.notify, vim.api.nvim_echo, vim.loop.new_timer, vim.loop.new_tcp = saved.notify, saved.echo, saved.new_timer, saved.new_tcp + vim.loop.new_check, vim.loop.update_time, vim.loop.now = saved.new_check, saved.update_time, saved.now end) local function start() @@ -220,6 +222,7 @@ describe("Server lines on the command line", function() it("shows a keepalive timeout as one info line", function() local tick + local checks, clock = {}, 1000000 vim.loop.new_timer = function() return { start = function(_, _, _, callback) @@ -229,18 +232,38 @@ describe("Server lines on the command line", function() close = function() end, } end + vim.loop.new_check = function() + return { + start = function(_, callback) + table.insert(checks, callback) + end, + stop = function() end, + close = function() end, + } + end + vim.loop.update_time = function() end + vim.loop.now = function() + return clock + end local client = connect(start()) client.tcp_handle._read_cb(nil, upgrade(token)) assert.equals("connected", client.state) lines = {} - client.last_pong = vim.loop.now() - 61000 - tick() -- the first tick that finds no pong pings again and logs nothing - assert.same({}, lines) - tick() + for round = 1, 4 do + clock = clock + 30000 + tick() -- a tick pings and logs nothing: the timeout is decided at the check, after libuv read the socket + assert.same({}, lines) + if round < 4 then + table.remove(checks)() + assert.same({}, lines) + end + end + table.remove(checks)() local line = only_line() assert.equals(vim.log.levels.INFO, line.level) assert_contains(line.text, client.id) + assert_contains(line.text, "no reply for 90s") end) end) diff --git a/tests/unit/server/tcp_spec.lua b/tests/unit/server/tcp_spec.lua index 8141106a2..2fbfdfe28 100644 --- a/tests/unit/server/tcp_spec.lua +++ b/tests/unit/server/tcp_spec.lua @@ -5,15 +5,23 @@ local client_manager = require("claudecode.server.client") describe("TCP server disconnect handling", function() local tcp local original_process_data + local original_loop before_each(function() package.loaded["claudecode.server.tcp"] = nil tcp = require("claudecode.server.tcp") original_process_data = client_manager.process_data + original_loop = {} + for _, name in ipairs({ "new_timer", "new_check", "update_time", "now" }) do + original_loop[name] = vim.loop[name] + end end) after_each(function() client_manager.process_data = original_process_data + for name, fn in pairs(original_loop) do + vim.loop[name] = fn + end end) describe("find_available_port", function() @@ -313,7 +321,8 @@ describe("TCP server disconnect handling", function() it("closes a client that stopped answering pings with 1011, and reports 1006 to on_disconnect", function() local frame = require("claudecode.server.frame") local tick - local new_timer = vim.loop.new_timer + local checks = {} + local clock = 1000000 vim.loop.new_timer = function() return { start = function(_, _, _, callback) @@ -323,6 +332,20 @@ describe("TCP server disconnect handling", function() close = function() end, } end + -- A check handle runs after the poll that reads the sockets. Neovim runs the callback of the ping timer's check once. + vim.loop.new_check = function() + return { + start = function(self, callback) + table.insert(checks, callback) + end, + stop = function() end, + close = function() end, + } + end + vim.loop.update_time = function() end + vim.loop.now = function() + return clock + end local writes = {} local handle = { closed = false } function handle:write(data, callback) @@ -338,17 +361,25 @@ describe("TCP server disconnect handling", function() return self.closed end local client = client_manager.create_client(handle) - client.state, client.handshake_complete, client.last_pong = "connected", true, vim.loop.now() - 61000 + client.state, client.handshake_complete = "connected", true local server = { clients = { [client.id] = client }, on_disconnect = spy.new(function() end) } tcp.start_ping_timer(server, 30000) - vim.loop.new_timer = new_timer - tick() -- the first tick that finds no pong pings again: a late tick finds the pong of the last ping unread - assert.equals(frame.OPCODE.PING, assert(frame.parse_frame(writes[1])).opcode) - assert.is_not_nil(server.clients[client.id]) - tick() + for round = 1, 4 do + clock = clock + 30000 + tick() -- a tick pings and never drops: it can run before libuv reads the pong of the last ping + assert.is_not_nil(server.clients[client.id]) + assert.equals(frame.OPCODE.PING, assert(frame.parse_frame(writes[#writes])).opcode) + assert.equals(1, #checks) + if round < 4 then + table.remove(checks)() -- libuv read the socket, and Claude did not answer + assert.is_not_nil(server.clients[client.id]) + end + end + -- The oldest ping is 3 intervals old, and libuv read the socket: Claude did not answer. + table.remove(checks)() - local close = assert(frame.parse_frame(writes[2])) + local close = assert(frame.parse_frame(writes[#writes])) assert.equals(frame.OPCODE.CLOSE, close.opcode) assert.equals(1011, close.payload:byte(1) * 256 + close.payload:byte(2)) assert.spy(server.on_disconnect).was_called_with(client, 1006, "Connection timeout") From 360b53d816800fe5e21f19ba7cd3a99c73670034 Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 00:29:38 +0000 Subject: [PATCH 2/9] docs(server): say which blocks let a tick run before the socket read With libuv 1.44 (bundled in Neovim 0.8) a tick can run before the read after a block in any callback. With newer libuv it can after a block in a check callback or an I/O read callback, and not after a block in vim.schedule or a timer callback. Say so in the comment of drop_unanswered_after_read and in server/README.md, and re-record covered.lock. --- .agents/skills/verify-diff-lifecycle/covered.lock | 2 +- lua/claudecode/server/README.md | 2 +- lua/claudecode/server/tcp.lua | 7 ++++--- 3 files changed, 6 insertions(+), 5 deletions(-) diff --git a/.agents/skills/verify-diff-lifecycle/covered.lock b/.agents/skills/verify-diff-lifecycle/covered.lock index 05c5c1a35..f7a691c08 100644 --- a/.agents/skills/verify-diff-lifecycle/covered.lock +++ b/.agents/skills/verify-diff-lifecycle/covered.lock @@ -160,7 +160,7 @@ site lua/claudecode/server/init.lua: if not _G.claude_deferred_responses then @ == lua/claudecode/server/mock.lua file lua/claudecode/server/mock.lua def1248d2793d559 == lua/claudecode/server/tcp.lua -file lua/claudecode/server/tcp.lua 99fe003ea1a3c494 +file lua/claudecode/server/tcp.lua 1f16e6e541239f3d == lua/claudecode/server/utils.lua file lua/claudecode/server/utils.lua 2915ae87b48f04ca == lua/claudecode/terminal.lua diff --git a/lua/claudecode/server/README.md b/lua/claudecode/server/README.md index 0cceff141..6074dfac5 100644 --- a/lua/claudecode/server/README.md +++ b/lua/claudecode/server/README.md @@ -77,7 +77,7 @@ Layers, top to bottom: - When the JSON decodes to a non-table value (for example a number or a boolean), `_handle_message` replies -32600 with `"id": null`. It does not raise [server/init.lua:M._handle_message] - 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] -- A ping timer tick pings every connected client and never closes one. `client.ping_unanswered_since` holds the loop time of the oldest ping that no pong has answered. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. A pong clears it. Each tick 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent, after a block of the main loop in any callback, and Neovim 0.8 (libuv 1.44) runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim can run it before the read. Drop bound: a Claude that answers each ping within `interval * 2.5` (75 s by default) is never closed, whatever blocks the main loop. A Claude that never answers is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping, or when a block of the main loop ends if the block delays that tick. 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 check logs `Closed client_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and clears `ping_unanswered_since` of each connected client. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [server/tcp.lua:M.start_ping_timer] [server/client.lua:M.process_data] +- A ping timer tick pings every connected client and never closes one. `client.ping_unanswered_since` holds the loop time of the oldest ping that no pong has answered. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. A pong clears it. Each tick 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: a Claude that answers each ping within `interval * 2.5` (75 s by default) is never closed, whatever blocks the main loop. A Claude that never answers is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping, or when a block of the main loop ends if the block delays that tick. 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 check logs `Closed client_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and clears `ping_unanswered_since` of each connected client. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [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] - A rejected handshake logs `Rejected client_: ` at warn level, with the reason from the body of the error response. Once the error response is written, `on_error` removes the client from the server and closes its socket [server/client.lua:M.process_data] diff --git a/lua/claudecode/server/tcp.lua b/lua/claudecode/server/tcp.lua index 7afdbe736..ecd3dc147 100644 --- a/lua/claudecode/server/tcp.lua +++ b/lua/claudecode/server/tcp.lua @@ -384,9 +384,10 @@ end ---Drop each of `clients` whose oldest ping has gone unanswered for `limit` ms, once Neovim has read their sockets. The ---judgment runs in a libuv check handle, which libuv runs after the poll phase that reads the sockets, so every byte ---that reached a socket before the loop time of the check has been read. A timer tick cannot judge: libuv can run it ----before it reads the pong that Claude sent, after a block of the main loop in any callback, and Neovim 0.8 (libuv ----1.44) runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` is ----no help either: Neovim can run it before the read. +---before it reads the pong that Claude sent. That happens after a block in a check callback or an I/O read callback, +---and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at +---the end of a pass, so two ticks can run with no read between them. `vim.schedule` is no help either: Neovim runs its +---callbacks between two passes, so it can run one before the read. ---@param server TCPServer The server object ---@param clients WebSocketClient[] The clients that the ping timer pinged in one tick ---@param limit number Age in milliseconds of the oldest unanswered ping at which a client is dropped From f2826c07ddf7978226fb1776ac754fe175eff511 Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 01:08:08 +0000 Subject: [PATCH 3/9] fix(server): skip the keepalive judgment after a long block before the poll A check that runs after the loop blocked between its tick and the poll judges a ping that the block made look old. Claude kept writing during the block, so a pong that it sent can wait behind more unread data than the socket holds, and the one poll after the block does not reach it. The check now judges only if its loop time is at most `interval * 1.5` after its tick. After a longer block the next tick sees the gap, takes it for a wake and clears the stamps, so such a block restarts the count. Also say in the README and the field doc that the stamp is the oldest ping sent since the last pong was read, and that only a tick that pinged a client starts a check. Add tests for the block before the poll, for the check judging with the loop time of the poll, for the stamp aged from the time of the ping, for a poll 1.4 intervals after the tick, and for the restart of the count. --- .../skills/verify-diff-lifecycle/covered.lock | 4 +- lua/claudecode/server/README.md | 2 +- lua/claudecode/server/client.lua | 2 +- lua/claudecode/server/tcp.lua | 19 +++- .../unit/server/connection_lifecycle_spec.lua | 105 ++++++++++++++++++ 5 files changed, 123 insertions(+), 9 deletions(-) diff --git a/.agents/skills/verify-diff-lifecycle/covered.lock b/.agents/skills/verify-diff-lifecycle/covered.lock index f7a691c08..3cf912633 100644 --- a/.agents/skills/verify-diff-lifecycle/covered.lock +++ b/.agents/skills/verify-diff-lifecycle/covered.lock @@ -138,7 +138,7 @@ file lua/claudecode/logger.lua 17b404dda41c3591 == lua/claudecode/selection.lua file lua/claudecode/selection.lua 0fa651cc95e0af0d == lua/claudecode/server/client.lua -file lua/claudecode/server/client.lua 4218e4fd15f51b3a +file lua/claudecode/server/client.lua 689e06cd093358b4 block create_client 647b7523dea26af6 == lua/claudecode/server/frame.lua file lua/claudecode/server/frame.lua 3c50766875878d56 @@ -160,7 +160,7 @@ site lua/claudecode/server/init.lua: if not _G.claude_deferred_responses then @ == lua/claudecode/server/mock.lua file lua/claudecode/server/mock.lua def1248d2793d559 == lua/claudecode/server/tcp.lua -file lua/claudecode/server/tcp.lua 1f16e6e541239f3d +file lua/claudecode/server/tcp.lua 0752d9f5a4fd9312 == lua/claudecode/server/utils.lua file lua/claudecode/server/utils.lua 2915ae87b48f04ca == lua/claudecode/terminal.lua diff --git a/lua/claudecode/server/README.md b/lua/claudecode/server/README.md index 6074dfac5..e5223b7ad 100644 --- a/lua/claudecode/server/README.md +++ b/lua/claudecode/server/README.md @@ -77,7 +77,7 @@ Layers, top to bottom: - When the JSON decodes to a non-table value (for example a number or a boolean), `_handle_message` replies -32600 with `"id": null`. It does not raise [server/init.lua:M._handle_message] - 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] -- A ping timer tick pings every connected client and never closes one. `client.ping_unanswered_since` holds the loop time of the oldest ping that no pong has answered. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. A pong clears it. Each tick 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: a Claude that answers each ping within `interval * 2.5` (75 s by default) is never closed, whatever blocks the main loop. A Claude that never answers is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping, or when a block of the main loop ends if the block delays that tick. 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 check logs `Closed client_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and clears `ping_unanswered_since` of each connected client. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [server/tcp.lua:M.start_ping_timer] [server/client.lua:M.process_data] +- A ping timer tick pings every connected client and never closes one. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since the last pong was read. Any pong clears it, also one that answers an older ping. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block, a pong that Claude sent can still wait behind more unread data than the socket holds, and one poll does not reach it. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: a block of the main loop, of any length and in any callback, does not close a Claude that answers each ping within `interval * 2.5` (75 s by default). A tick never closes a client, and a check judges only after a poll within `interval * 1.5` of its tick. A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that never answers is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and clears `ping_unanswered_since` of each connected client. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [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] - A rejected handshake logs `Rejected client_: ` at warn level, with the reason from the body of the error response. Once the error response is written, `on_error` removes the client from the server and closes its socket [server/client.lua:M.process_data] diff --git a/lua/claudecode/server/client.lua b/lua/claudecode/server/client.lua index 03448c1e6..6d16f97ca 100644 --- a/lua/claudecode/server/client.lua +++ b/lua/claudecode/server/client.lua @@ -30,7 +30,7 @@ local CLOSE_REASONS = { ---@field close_pending boolean|nil True while a Close frame waits to be written: its write callback closes the socket ---@field last_ping number Timestamp of last ping sent ---@field last_pong number Timestamp of last pong received ----@field ping_unanswered_since number|nil Loop time of the oldest ping that no pong has answered. nil when none waits +---@field ping_unanswered_since number|nil Loop time of the oldest ping sent since the last pong was read. nil when none ---Create a new WebSocket client ---@param tcp_handle table The vim.loop TCP handle diff --git a/lua/claudecode/server/tcp.lua b/lua/claudecode/server/tcp.lua index ecd3dc147..62909e1b2 100644 --- a/lua/claudecode/server/tcp.lua +++ b/lua/claudecode/server/tcp.lua @@ -388,10 +388,15 @@ end ---and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at ---the end of a pass, so two ticks can run with no read between them. `vim.schedule` is no help either: Neovim runs its ---callbacks between two passes, so it can run one before the read. +---The check judges only if its loop time is at most `gap` after the tick. After a longer block, a pong that Claude sent +---can wait behind more unread data than the socket holds, and one poll does not reach it. The next tick finds the same +---gap, takes it for a wake and starts over. ---@param server TCPServer The server object ---@param clients WebSocketClient[] The clients that the ping timer pinged in one tick ---@param limit number Age in milliseconds of the oldest unanswered ping at which a client is dropped -local function drop_unanswered_after_read(server, clients, limit) +---@param tick_time number Loop time in milliseconds at which the tick pinged them +---@param gap number Time in milliseconds after the tick, above which the check judges nothing +local function drop_unanswered_after_read(server, clients, limit, tick_time, gap) local check = vim.loop.new_check() if not check then server.on_error("Failed to create keepalive check") @@ -402,6 +407,9 @@ local function drop_unanswered_after_read(server, clients, limit) check:stop() check:close() local now = vim.loop.now() + if now - tick_time > gap then + return + end for _, client in ipairs(clients) do local since = client.ping_unanswered_since @@ -426,9 +434,10 @@ end ---Start a periodic ping task to keep connections alive. ---A tick pings every connected client and never drops one. A client whose oldest ping is `interval * 2.5` old is ----dropped at the first read of its socket after a tick [drop_unanswered_after_read]. A Claude that answers each ping ----within that time is never dropped, however the main loop blocks. A Claude that never answers is dropped after the ----third tick that follows its first unanswered ping: the half interval keeps timer jitter from moving the drop. +---dropped at the first read of its socket after a tick [drop_unanswered_after_read], if the loop ran that read within +---`interval * 1.5` of the tick. A block longer than that restarts the count (the next tick is a wake). A Claude that +---never answers is dropped after the third tick that follows its first unanswered ping: the half interval keeps timer +---jitter from moving the drop. ---@param server TCPServer The server object ---@param interval number Ping interval in milliseconds (default: 30000) ---@return table? timer The timer handle, or nil if creation failed @@ -481,7 +490,7 @@ function M.start_ping_timer(server, interval) last_run = now if #pinged > 0 then - drop_unanswered_after_read(server, pinged, interval * 2.5) + drop_unanswered_after_read(server, pinged, interval * 2.5, vim.loop.now(), interval * 1.5) end end) diff --git a/tests/unit/server/connection_lifecycle_spec.lua b/tests/unit/server/connection_lifecycle_spec.lua index cda3d6b35..d9892282a 100644 --- a/tests/unit/server/connection_lifecycle_spec.lua +++ b/tests/unit/server/connection_lifecycle_spec.lua @@ -340,6 +340,111 @@ describe("The lifecycle of a WebSocket connection", function() end ) + -- libuv reads at most what the socket holds in one poll. When the loop blocked, Claude kept writing, and a pong that + -- Claude sent can wait behind more unread data than the socket holds: the poll that follows the block does not + -- reach it, and the ping looks as old as the block. + it("judges nothing when the loop blocked for longer than 1.5 intervals between the tick and its poll", function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + + clock = clock + interval + tick() + clock = clock + 3 * interval -- an idle or prepare callback blocks before the poll + poll() -- Claude's pong waits behind 300 KB that the poll does not finish reading + + assert.is_not_nil(server.clients[client.id], "the check judged a ping that the block made look old") + poll(handle, pong()) + assert.is_not_nil(server.clients[client.id]) + assert.spy(callbacks.on_disconnect).was_not_called() + end) + + it( + "judges a silent Claude with the loop time of the poll, not with a time read after a callback blocked", + function() + local tick = start_ping_timer() + local client = connect_and_upgrade() + + for round = 1, 4 do + clock = clock + interval + tick() + if round < 4 then + poll() + end + end + cached = clock -- the poll returned + clock = clock + 3 * interval -- a callback that runs before the check handles blocks after the poll + local pending = checks + checks = {} + for _, check in ipairs(pending) do + check.callback() + end + + assert.is_nil(server.clients[client.id], "the check took the time after the block for the time of the poll") + end + ) + + it("still judges a silent Claude when the loop blocked for 1.4 intervals between the tick and its poll", function() + local tick = start_ping_timer() + local client = connect_and_upgrade() + + for round = 1, 4 do + clock = clock + interval + tick() + if round < 4 then + poll() + end + end + clock = clock + 1.4 * interval + poll() + + assert.is_nil(server.clients[client.id], "the check skipped a poll that came within 1.5 intervals of its tick") + end) + + it( + "ages a ping from when it was sent, though a callback of the pass blocked for half an interval before", + function() + local tick = start_ping_timer() + local client = connect_and_upgrade() + + clock = clock + interval + tick(0.5 * interval) -- a timer that ran before the ping timer in this pass blocked: the loop time is that old + poll() + for _ = 1, 2 do + clock = clock + interval + tick() + poll() + end + assert.is_not_nil(server.clients[client.id], "the ping was aged from the loop time that the block left behind") + + clock = clock + interval + tick() + poll() + assert.is_nil(server.clients[client.id]) + end + ) + + it("restarts the count of a silent Claude when a block makes the next tick a wake", function() + local tick = start_ping_timer() + local client = connect_and_upgrade() + + for _ = 1, 2 do + clock = clock + interval + tick() + poll() + end + clock = clock + 2 * interval -- a block of 2 intervals: the next tick sees a gap above 1.5 intervals + for round = 1, 3 do + tick() -- the first of these is the wake and stamps afresh, the others age that stamp + assert.is_not_nil(server.clients[client.id], "the count did not restart") + poll() + clock = clock + interval + end + tick() + poll() + + assert.is_nil(server.clients[client.id], "a silent Claude was not dropped 3 ticks after the wake") + end) + it("forgets the pings that went unanswered when Neovim wakes from sleep", function() local tick = start_ping_timer() local client, _, handle = connect_and_upgrade() From 7df108d4ef9f44fe3ad63133121da36bdf916a76 Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 01:28:20 +0000 Subject: [PATCH 4/9] fix(server): any bytes from a client clear its keepalive stamp The check judged a ping unanswered if no pong was read, but 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 of a large message. A block of less than 1.5 intervals before such a poll, on top of an older stamp, still made the ping look 2.5 intervals old. The read callback now clears the stamp on any bytes from the client: Claude shows it is alive by writing anything. A client that writes data but never answers a ping is no longer closed. The gap skip stays: a machine that sleeps between a tick and its poll stops Claude too, so no bytes arrive, and only the skip keeps it. --- .../skills/verify-diff-lifecycle/covered.lock | 4 +- lua/claudecode/server/README.md | 2 +- lua/claudecode/server/client.lua | 3 +- lua/claudecode/server/tcp.lua | 19 ++++--- .../unit/server/connection_lifecycle_spec.lua | 53 +++++++++++++++---- 5 files changed, 60 insertions(+), 21 deletions(-) diff --git a/.agents/skills/verify-diff-lifecycle/covered.lock b/.agents/skills/verify-diff-lifecycle/covered.lock index 3cf912633..ccee57af8 100644 --- a/.agents/skills/verify-diff-lifecycle/covered.lock +++ b/.agents/skills/verify-diff-lifecycle/covered.lock @@ -138,7 +138,7 @@ file lua/claudecode/logger.lua 17b404dda41c3591 == lua/claudecode/selection.lua file lua/claudecode/selection.lua 0fa651cc95e0af0d == lua/claudecode/server/client.lua -file lua/claudecode/server/client.lua 689e06cd093358b4 +file lua/claudecode/server/client.lua d0141ad6aea1b9b9 block create_client 647b7523dea26af6 == lua/claudecode/server/frame.lua file lua/claudecode/server/frame.lua 3c50766875878d56 @@ -160,7 +160,7 @@ site lua/claudecode/server/init.lua: if not _G.claude_deferred_responses then @ == lua/claudecode/server/mock.lua file lua/claudecode/server/mock.lua def1248d2793d559 == lua/claudecode/server/tcp.lua -file lua/claudecode/server/tcp.lua 0752d9f5a4fd9312 +file lua/claudecode/server/tcp.lua 3744919a85e71492 == lua/claudecode/server/utils.lua file lua/claudecode/server/utils.lua 2915ae87b48f04ca == lua/claudecode/terminal.lua diff --git a/lua/claudecode/server/README.md b/lua/claudecode/server/README.md index e5223b7ad..1aecccec4 100644 --- a/lua/claudecode/server/README.md +++ b/lua/claudecode/server/README.md @@ -77,7 +77,7 @@ Layers, top to bottom: - When the JSON decodes to a non-table value (for example a number or a boolean), `_handle_message` replies -32600 with `"id": null`. It does not raise [server/init.lua:M._handle_message] - 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] -- A ping timer tick pings every connected client and never closes one. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since the last pong was read. Any pong clears it, also one that answers an older ping. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block, a pong that Claude sent can still wait behind more unread data than the socket holds, and one poll does not reach it. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: a block of the main loop, of any length and in any callback, does not close a Claude that answers each ping within `interval * 2.5` (75 s by default). A tick never closes a client, and a check judges only after a poll within `interval * 1.5` of its tick. A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that never answers is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and clears `ping_unanswered_since` of each connected client. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [server/tcp.lua:M.start_ping_timer] [server/client.lua:M.process_data] +- A ping timer tick pings every connected client and never closes one. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since bytes were last read from the client. The read callback clears it on any bytes, not only a pong: Claude shows it is alive by writing anything, and a pong that waits behind more unread data than the socket holds is not in the first poll after a block. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block Neovim and Claude can have slept together (a suspended machine), and Claude has had no time to answer. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: 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` (75 s by default) 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 but never answers a ping is not closed: it is alive, and the plugin does not judge what it writes. A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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. Until the timeout, the queued replies stay in memory. A tick gap above `interval * 1.5` counts as a wake from sleep and clears `ping_unanswered_since` of each connected client. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [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] - A rejected handshake logs `Rejected client_: ` at warn level, with the reason from the body of the error response. Once the error response is written, `on_error` removes the client from the server and closes its socket [server/client.lua:M.process_data] diff --git a/lua/claudecode/server/client.lua b/lua/claudecode/server/client.lua index 6d16f97ca..398720ea1 100644 --- a/lua/claudecode/server/client.lua +++ b/lua/claudecode/server/client.lua @@ -30,7 +30,7 @@ local CLOSE_REASONS = { ---@field close_pending boolean|nil True while a Close frame waits to be written: its write callback closes the socket ---@field last_ping number Timestamp of last ping sent ---@field last_pong number Timestamp of last pong received ----@field ping_unanswered_since number|nil Loop time of the oldest ping sent since the last pong was read. nil when none +---@field ping_unanswered_since number|nil Loop time of the oldest ping sent since bytes were last read from the client ---Create a new WebSocket client ---@param tcp_handle table The vim.loop TCP handle @@ -283,7 +283,6 @@ function M.process_data(client, data, on_message, on_close, on_error, auth_token client.tcp_handle:write(pong_frame) elseif opcode == frame.OPCODE.PONG then client.last_pong = vim.loop.now() - client.ping_unanswered_since = nil end end client.buffer = client.buffer:sub(offset) diff --git a/lua/claudecode/server/tcp.lua b/lua/claudecode/server/tcp.lua index 62909e1b2..8b709f60b 100644 --- a/lua/claudecode/server/tcp.lua +++ b/lua/claudecode/server/tcp.lua @@ -215,6 +215,10 @@ function M._handle_new_connection(server) return end + -- Any bytes show that Claude is alive and writing. A pong can wait behind more unread data than the socket holds, + -- and one poll does not reach it, so the keepalive does not wait for the pong itself. + client.ping_unanswered_since = nil + -- Process incoming data client_manager.process_data(client, data, function(cl, message) server.on_message(cl, message) @@ -381,16 +385,16 @@ function M.stop_server(server) end end ----Drop each of `clients` whose oldest ping has gone unanswered for `limit` ms, once Neovim has read their sockets. The +---Drop each of `clients` that sent nothing since its oldest ping, for `limit` ms, once Neovim has read their sockets. The ---judgment runs in a libuv check handle, which libuv runs after the poll phase that reads the sockets, so every byte ---that reached a socket before the loop time of the check has been read. A timer tick cannot judge: libuv can run it ---before it reads the pong that Claude sent. That happens after a block in a check callback or an I/O read callback, ---and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at ---the end of a pass, so two ticks can run with no read between them. `vim.schedule` is no help either: Neovim runs its ---callbacks between two passes, so it can run one before the read. ----The check judges only if its loop time is at most `gap` after the tick. After a longer block, a pong that Claude sent ----can wait behind more unread data than the socket holds, and one poll does not reach it. The next tick finds the same ----gap, takes it for a wake and starts over. +---The check judges only if its loop time is at most `gap` after the tick. After a longer block Neovim and Claude can +---have slept together, and Claude has had no time to answer: the next tick finds the same gap, takes it for a wake and +---starts over. ---@param server TCPServer The server object ---@param clients WebSocketClient[] The clients that the ping timer pinged in one tick ---@param limit number Age in milliseconds of the oldest unanswered ping at which a client is dropped @@ -435,9 +439,10 @@ end ---Start a periodic ping task to keep connections alive. ---A tick pings every connected client and never drops one. A client whose oldest ping is `interval * 2.5` old is ---dropped at the first read of its socket after a tick [drop_unanswered_after_read], if the loop ran that read within ----`interval * 1.5` of the tick. A block longer than that restarts the count (the next tick is a wake). A Claude that ----never answers is dropped after the third tick that follows its first unanswered ping: the half interval keeps timer ----jitter from moving the drop. +---`interval * 1.5` of the tick. A block longer than that restarts the count (the next tick is a wake). Any bytes read +---from a client clear its stamp, so a Claude that sends anything, also a large message before its pong, is not dropped. +---A Claude that sends nothing is dropped after the third tick that follows its first unanswered ping: the half +---interval keeps timer jitter from moving the drop. ---@param server TCPServer The server object ---@param interval number Ping interval in milliseconds (default: 30000) ---@return table? timer The timer handle, or nil if creation failed diff --git a/tests/unit/server/connection_lifecycle_spec.lua b/tests/unit/server/connection_lifecycle_spec.lua index d9892282a..76686ca25 100644 --- a/tests/unit/server/connection_lifecycle_spec.lua +++ b/tests/unit/server/connection_lifecycle_spec.lua @@ -340,17 +340,16 @@ describe("The lifecycle of a WebSocket connection", function() end ) - -- libuv reads at most what the socket holds in one poll. When the loop blocked, Claude kept writing, and a pong that - -- Claude sent can wait behind more unread data than the socket holds: the poll that follows the block does not - -- reach it, and the ping looks as old as the block. + -- A machine that sleeps between a tick and its poll stops Neovim and Claude together. When they wake, the loop polls + -- before Claude answers, and the ping looks as old as the sleep. A block that long is a wake, as it is for a tick. it("judges nothing when the loop blocked for longer than 1.5 intervals between the tick and its poll", function() local tick = start_ping_timer() local client, _, handle = connect_and_upgrade() clock = clock + interval tick() - clock = clock + 3 * interval -- an idle or prepare callback blocks before the poll - poll() -- Claude's pong waits behind 300 KB that the poll does not finish reading + clock = clock + 3 * interval -- a callback blocks before the poll, or the machine sleeps + poll() -- Claude has not answered yet assert.is_not_nil(server.clients[client.id], "the check judged a ping that the block made look old") poll(handle, pong()) @@ -358,6 +357,43 @@ describe("The lifecycle of a WebSocket connection", function() assert.spy(callbacks.on_disconnect).was_not_called() end) + it( + "does not drop a Claude that sends a large message before its pong, whichever block comes before the poll", + function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + local big = frame.create_frame(frame.OPCODE.TEXT, string.rep("x", 300000), true, true) + + clock = clock + interval + tick() + poll() + clock = clock + 1.4 * interval + tick() -- the ping of the first tick is 1.4 intervals old, and its pong waits behind the large message + clock = clock + 1.4 * interval + poll(handle, big:sub(1, 65536)) -- the poll reads the first part: the ping is 2.8 intervals old, within the gap of the tick + + assert.is_not_nil(server.clients[client.id], "the check dropped a Claude that was sending") + poll(handle, big:sub(65537) .. pong()) + assert.is_not_nil(server.clients[client.id]) + assert.spy(callbacks.on_disconnect).was_not_called() + end + ) + + it("does not drop a client that writes data but never answers a ping", function() + local tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + local request = frame.create_frame(frame.OPCODE.TEXT, "{}", true, true) + + for _ = 1, 8 do + clock = clock + interval + tick() + poll(handle, request) + end + + assert.is_not_nil(server.clients[client.id], "a client that writes is alive") + assert.spy(callbacks.on_disconnect).was_not_called() + end) + it( "judges a silent Claude with the loop time of the poll, not with a time read after a callback blocked", function() @@ -504,15 +540,14 @@ describe("The lifecycle of a WebSocket connection", function() it("does not drop a client that is closing", function() local tick = start_ping_timer() - local client, writes, handle = connect_and_upgrade() + local client, writes = connect_and_upgrade() tick_four_times(tick) - scheduled = {} -- on_close waits for the loop - handle._read_cb(nil, frame.create_frame(frame.OPCODE.CLOSE, "\3\232", true, true)) + require("claudecode.server.client").close_client(client, 1001, "going away") -- the Close frame waits to be written assert.equals("closing", client.state) local written = #writes poll() - assert.equals(written, #writes, "a Close frame followed the reply to Claude's Close frame") + assert.equals(written, #writes, "a Close frame followed the Close frame that was queued") assert.spy(callbacks.on_disconnect).was_not_called() end) end) From 68b0b13e5ae0e811daf58bb3bb1109a6f0ba4789 Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 07:50:36 +0000 Subject: [PATCH 5/9] test(server): run the poll after a wake tick instead of counting handles 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. --- tests/unit/server/connection_lifecycle_spec.lua | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/tests/unit/server/connection_lifecycle_spec.lua b/tests/unit/server/connection_lifecycle_spec.lua index 25b19f537..85bab341e 100644 --- a/tests/unit/server/connection_lifecycle_spec.lua +++ b/tests/unit/server/connection_lifecycle_spec.lua @@ -1126,12 +1126,14 @@ describe("The lifecycle of a WebSocket connection", function() assert.is_true(client.write_stalled) handle._read_cb(nil, pong) + forget_handles() clock = clock + 1.5 * interval + 1 tick() + poll() -- the poll after the tick: a confirmation would find no progress and drop the client 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") + assert.spy(callbacks.on_disconnect).was_not_called() end) it("judges only the clients that answered at the tick", function() From 7fac82874ec1e65248cb3c9d28ab9cc1dc104ea8 Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 08:12:19 +0000 Subject: [PATCH 6/9] docs(server): name the real judge helpers and the one shared poll-handle pair The README linked drop_unanswered_after_read and confirm_stall, which do not exist (the code has judge_silence and judge_stall), and said a stalled client adds a check and idle pair. A tick that pinged arms one pair that judges every client of that tick. --- lua/claudecode/server/README.md | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lua/claudecode/server/README.md b/lua/claudecode/server/README.md index 1a0cdfc5b..cb97c4ac7 100644 --- a/lua/claudecode/server/README.md +++ b/lua/claudecode/server/README.md @@ -77,8 +77,8 @@ Layers, top to bottom: - When the JSON decodes to a non-table value (for example a number or a boolean), `_handle_message` replies -32600 with `"id": null`. It does not raise [server/init.lua:M._handle_message] - 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] -- A ping timer tick pings every connected client and never closes one for a missing answer. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since bytes were last read from the client. The read callback clears it on any bytes, not only a pong: Claude shows it is alive by writing anything, and a pong that waits behind more unread data than the socket holds is not in the first poll after a block. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. Each tick that pinged a client calls `drop_unanswered_after_read`, which runs after the next poll through `after_next_poll` (below). libuv runs the check handle right 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block Neovim and Claude can have slept together (a suspended machine), and Claude has had no time to answer. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: 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` (75 s by default) 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 but never answers a ping is not closed by this rule: it is alive, and the plugin does not judge what it writes (the stall rule below still closes it when it does not read). A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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_unanswered_after_read] [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_: not reading for s, 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] +- A ping timer tick pings every connected client and never closes one for a missing answer. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since bytes were last read from the client. The read callback clears it on any bytes, not only a pong: Claude shows it is alive by writing anything, and a pong that waits behind more unread data than the socket holds is not in the first poll after a block. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. Each tick that pinged a client arms `after_next_poll` (below), and its callback runs `judge_silence` after the next poll. libuv runs the check handle right 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block Neovim and Claude can have slept together (a suspended machine), and Claude has had no time to answer. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: 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` (75 s by default) 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 but never answers a ping is not closed by this rule: it is alive, and the plugin does not judge what it writes (the stall rule below still closes it when it does not read). A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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:judge_silence] [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_: not reading for s, 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:judge_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 a client counts as answered when no ping of it waited for `interval * 2`. Only a client that answered is confirmed for a stall. A client that did not answer is dropped by the keepalive check above, whatever its write queue shows. A client that answers while its queue is stalled is not saved: its bytes clear the stamp, the next tick finds it answered, 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 clears `ping_unanswered_since` of each connected client. 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` 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 clears the stamps only, and counts like any tick. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [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] @@ -102,7 +102,7 @@ Layers, top to bottom: - `tcp.lua` seeds `math.randomseed` once per process. `init.lua` calls `math.random` at load. Both change the global PRNG [server/tcp.lua:ensure_rng_seeded] - `client.process_data` writes handshake, PONG, and Close frames to the socket. It runs `on_message` and `on_close` through `vim.schedule`. It calls `on_error` directly after a failed handshake write, and after it queues the Close frame for a protocol error [server/client.lua:M.process_data] [server/client.lua:M.close_client] - The ping timer writes ping frames and closes clients that timed out or stopped reading [server/tcp.lua:M.start_ping_timer] -- Each tick that pinged a client creates a `vim.loop` check handle and an idle handle for the keepalive judgement, and one more pair for each client whose stall it asks to confirm. The check callback closes them, and `stop_server` closes those that did not run [server/tcp.lua:after_next_poll] [server/tcp.lua:M.stop_server] +- Each tick that pinged a client creates one `vim.loop` check handle and one idle handle, and the judgement of every client of that tick, keepalive and stall, shares that pair. The check callback closes them, and `stop_server` closes those that did not run [server/tcp.lua:after_next_poll] [server/tcp.lua:M.stop_server] - `close_client` starts a repeating `vim.loop` timer for the Close frame of a client that has `keepalive_timeout`. It runs until the frame is written, the socket closes, or the deadline closes the socket [server/client.lua:M.close_client] [server/client.lua:start_close_timer] - `handshake.lua`, `frame.lua`, and `utils.lua` do no I/O [server/handshake.lua:M] - `mock.lua` opens no sockets and keeps its clients and messages in its own `M.state` tables. Its `mcp.tool.invoke` handler calls the real `tools.handle_invoke`, so a simulated tool call has that tool's real side effects (for example `saveDocument` writes the file) [server/mock.lua:M.register_handlers] [server/mock.lua:M.state] From a11d5e1defd48069b8f68c84380a48e245a213f4 Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 09:10:19 +0000 Subject: [PATCH 7/9] test(server): build the pong in before_each and pin the keepalive boundaries The pong of the late-tick describe was built at describe time from `frame`, which only the outer before_each sets, so seeds 9, 15, 40, 57 and 59 failed with 'attempt to index upvalue frame'. New tests kill mutants that survived: update_time inside judge_silence, a tick_time taken from the cached loop time, the stall judgement under the gap skip, the gap skip at 1.5 intervals and 1 ms above it, the drop at exactly 2.5 intervals, and the stall check for a client whose ping is still inside its window. --- .../unit/server/connection_lifecycle_spec.lua | 126 +++++++++++++++++- 1 file changed, 125 insertions(+), 1 deletion(-) diff --git a/tests/unit/server/connection_lifecycle_spec.lua b/tests/unit/server/connection_lifecycle_spec.lua index 85bab341e..15814e69c 100644 --- a/tests/unit/server/connection_lifecycle_spec.lua +++ b/tests/unit/server/connection_lifecycle_spec.lua @@ -358,6 +358,56 @@ describe("The lifecycle of a WebSocket connection", function() assert.is_nil(server.clients[client.id], "the check skipped a poll that came within 1.5 intervals of its tick") end) + -- The gap skip is pinned to the millisecond from both sides, as the wake threshold of a tick is: a poll exactly 1.5 + -- intervals after its tick judges, and one 1 ms later does not. + it("judges at a poll exactly 1.5 intervals after its tick", function() + local tick, raw_tick = start_ping_timer() + local client = connect_and_upgrade() + + for _ = 1, 3 do + clock = clock + interval + tick() + end + clock = clock + interval + raw_tick() + clock = clock + 1.5 * interval + poll() + + assert.is_nil(server.clients[client.id], "the check skipped a poll at exactly 1.5 intervals after its tick") + end) + + it("judges nothing at a poll 1 ms above 1.5 intervals after its tick", function() + local tick, raw_tick = start_ping_timer() + local client = connect_and_upgrade() + + for _ = 1, 3 do + clock = clock + interval + tick() + end + clock = clock + interval + raw_tick() + clock = clock + 1.5 * interval + 1 + poll() + + assert.is_not_nil(server.clients[client.id], "the check judged a poll more than 1.5 intervals after its tick") + end) + + it("drops a client whose oldest ping is exactly 2.5 intervals old at its poll", function() + local tick, raw_tick = start_ping_timer() + local client = connect_and_upgrade() + + for _ = 1, 2 do + clock = clock + interval + tick() + end + clock = clock + interval + raw_tick() -- the third tick: the first ping is 2 intervals old + clock = clock + 0.5 * interval -- the poll comes within 1.5 intervals of its tick + poll() + + assert.is_nil(server.clients[client.id], "a ping exactly 2.5 intervals old was not judged") + end) + it("restarts the count when a block makes the next tick a wake", function() local tick = start_ping_timer() local client = connect_and_upgrade() @@ -397,7 +447,11 @@ describe("The lifecycle of a WebSocket connection", function() -- libuv runs timers before it reads sockets, and Neovim 0.8 (libuv 1.44) runs the timers a second time at the end -- of a pass, after the check handles. A tick that Neovim runs late after a block finds the pongs of the last pings -- unread, and two late ticks can run with no read between them. - local pong = frame.create_frame(frame.OPCODE.PONG, "", true, true) + local pong + + before_each(function() + pong = frame.create_frame(frame.OPCODE.PONG, "", true, true) + end) ---Claude read the pings queued for it, answered, and the poll reads its answers. local function claude_answers(handle, data) @@ -562,6 +616,45 @@ describe("The lifecycle of a WebSocket connection", function() end ) + it("keeps a Claude whose pong reaches the socket while a callback blocks between the poll and the check", function() + local refresh = cache_loop_time() + local _, raw_tick = start_ping_timer() + local client, _, handle = connect_and_upgrade() + + clock = clock + interval + refresh() + raw_tick() + poll(function() + refresh() -- the poll returned before Claude's pong arrived, and read nothing + clock = clock + 3 * interval -- a younger check callback or an I/O callback blocks; the pong arrives meanwhile + end) + assert.is_not_nil(server.clients[client.id], "the check judged with a time read after the block") + poll(claude_answers(handle)) + + assert.is_not_nil(server.clients[client.id]) + assert.spy(callbacks.on_disconnect).was_not_called() + end) + + it("measures the gap to the poll from the ping, not from the loop time that a block left behind", function() + local refresh = cache_loop_time() + local tick, raw_tick = start_ping_timer() + local client = connect_and_upgrade() + + for _ = 1, 3 do + clock = clock + interval + refresh() + tick() + end + clock = clock + interval + refresh() + clock = clock + 1.2 * interval -- a callback that runs before the timers of this pass blocks: the loop time is old + raw_tick() + clock = clock + 0.5 * interval -- the poll comes 0.5 intervals after the ping, but 1.7 after the old loop time + poll(refresh) + + assert.is_nil(server.clients[client.id], "the gap was measured from the loop time of the start of the pass") + end) + it( "ages a ping from when it was sent, though a callback of the pass blocked for half an interval before", function() @@ -1069,6 +1162,37 @@ describe("The lifecycle of a WebSocket connection", function() assert.equals("Not reading", parse(writes[#writes]).payload:sub(3)) end) + it("drops a stalled client although every poll comes 1.6 intervals after its tick", function() + local _, raw_tick, client, handle = stalled_client() + + clock = clock + 1.6 * interval + for _ = 1, 9 do + handle._read_cb(nil, pong) -- Claude answers, and does not read + raw_tick() + clock = clock + 1.6 * interval -- a callback blocks between the tick and its poll + poll() + if not server.clients[client.id] then + break + end + end + + assert.is_nil(server.clients[client.id], "a stalled client stayed while every poll came late") + assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "Write queue stalled") + end) + + it("judges a stall for a client whose last ping is inside the window and not answered yet", function() + local tick, raw_tick, client, handle = stalled_client() + answer_and(tick, 1)(handle) -- the first tick that counts + assert.is_true(client.write_stalled) + + clock = clock + interval + raw_tick() -- the ping of the last tick waits for Claude: it is one interval old, inside the window of two + poll() + + assert.is_nil(server.clients[client.id], "a client that has two intervals to answer was not judged for a stall") + assert.spy(callbacks.on_disconnect).was_called_with(client, 1006, "Write queue stalled") + end) + it("does not ask for a confirmation at the first tick without progress", function() local tick, _, client, handle = stalled_client() From 8dda9337204525bd214e5cb7186bd095b0aa7b03 Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 09:10:19 +0000 Subject: [PATCH 8/9] docs(server): fix a stray backtick, say when the stall rule closes a client that still sends, and name the check as the closer --- lua/claudecode/server/README.md | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lua/claudecode/server/README.md b/lua/claudecode/server/README.md index cb97c4ac7..0fc6fd30c 100644 --- a/lua/claudecode/server/README.md +++ b/lua/claudecode/server/README.md @@ -41,7 +41,7 @@ Layers, top to bottom: ### Connection, handshake, and frames -- `client.create_client(tcp_handle, keepalive_timeout?)`, `process_data(...)`, `send_message`, `send_ping`, `close_client`, `abandon_close_frame`, ``sample_write_progress(client)`, `is_client_reading(client)`, and `get_client_info` [server/client.lua:M.process_data] +- `client.create_client(tcp_handle, keepalive_timeout?)`, `process_data(...)`, `send_message`, `send_ping`, `close_client`, `abandon_close_frame`, `sample_write_progress(client)`, `is_client_reading(client)`, and `get_client_info` [server/client.lua:M.process_data] - `handshake.process_handshake(request, expected_auth_token) -> ok, response, headers?` [server/handshake.lua:M.process_handshake] - `handshake.validate_upgrade_request`, `create_handshake_response`, `parse_request_line`, `is_websocket_endpoint`, `create_error_response`, and `extract_http_request` [server/handshake.lua:M.validate_upgrade_request] - `frame.OPCODE`: `CONTINUATION 0x0`, `TEXT 0x1`, `BINARY 0x2`, `CLOSE 0x8`, `PING 0x9`, `PONG 0xA` [server/frame.lua:M.OPCODE] @@ -77,7 +77,7 @@ Layers, top to bottom: - When the JSON decodes to a non-table value (for example a number or a boolean), `_handle_message` replies -32600 with `"id": null`. It does not raise [server/init.lua:M._handle_message] - 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] -- A ping timer tick pings every connected client and never closes one for a missing answer. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since bytes were last read from the client. The read callback clears it on any bytes, not only a pong: Claude shows it is alive by writing anything, and a pong that waits behind more unread data than the socket holds is not in the first poll after a block. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. Each tick that pinged a client arms `after_next_poll` (below), and its callback runs `judge_silence` after the next poll. libuv runs the check handle right 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block Neovim and Claude can have slept together (a suspended machine), and Claude has had no time to answer. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: 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` (75 s by default) 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 but never answers a ping is not closed by this rule: it is alive, and the plugin does not judge what it writes (the stall rule below still closes it when it does not read). A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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:judge_silence] [server/tcp.lua:drop_client] +- A ping timer tick pings every connected client and never closes one for a missing answer. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since bytes were last read from the client. The read callback clears it on any bytes, not only a pong: Claude shows it is alive by writing anything, and a pong that waits behind more unread data than the socket holds is not in the first poll after a block. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. Each tick that pinged a client arms `after_next_poll` (below), and its callback runs `judge_silence` after the next poll. libuv runs the check handle right 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block Neovim and Claude can have slept together (a suspended machine), and Claude has had no time to answer. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: 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` (75 s by default) 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 but never answers a ping is not closed by this rule: it is alive, and the plugin does not judge what it writes (the stall rule below closes it when it stops reading, but only once the kernel's socket buffers are full and libuv's write queue backs up, because a queue that is empty counts as progress). A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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:judge_silence] [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_: not reading for s, 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:judge_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 a client counts as answered when no ping of it waited for `interval * 2`. Only a client that answered is confirmed for a stall. A client that did not answer is dropped by the keepalive check above, whatever its write queue shows. A client that answers while its queue is stalled is not saved: its bytes clear the stamp, the next tick finds it answered, 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 clears `ping_unanswered_since` of each connected client. 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` 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 clears the stamps only, and counts like any tick. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [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] @@ -101,7 +101,7 @@ Layers, top to bottom: - `client.create_client` increments `_G.claudecode_clients_created` [server/client.lua:M.create_client] - `tcp.lua` seeds `math.randomseed` once per process. `init.lua` calls `math.random` at load. Both change the global PRNG [server/tcp.lua:ensure_rng_seeded] - `client.process_data` writes handshake, PONG, and Close frames to the socket. It runs `on_message` and `on_close` through `vim.schedule`. It calls `on_error` directly after a failed handshake write, and after it queues the Close frame for a protocol error [server/client.lua:M.process_data] [server/client.lua:M.close_client] -- The ping timer writes ping frames and closes clients that timed out or stopped reading [server/tcp.lua:M.start_ping_timer] +- The ping timer writes ping frames. The check handle that each tick arms closes clients that timed out or stopped reading [server/tcp.lua:M.start_ping_timer] [server/tcp.lua:after_next_poll] - Each tick that pinged a client creates one `vim.loop` check handle and one idle handle, and the judgement of every client of that tick, keepalive and stall, shares that pair. The check callback closes them, and `stop_server` closes those that did not run [server/tcp.lua:after_next_poll] [server/tcp.lua:M.stop_server] - `close_client` starts a repeating `vim.loop` timer for the Close frame of a client that has `keepalive_timeout`. It runs until the frame is written, the socket closes, or the deadline closes the socket [server/client.lua:M.close_client] [server/client.lua:start_close_timer] - `handshake.lua`, `frame.lua`, and `utils.lua` do no I/O [server/handshake.lua:M] From 67374f07fea8272b126152504bd8a4cdbb63c4ab Mon Sep 17 00:00:00 2001 From: Thomas Kosiewski Date: Wed, 11 Nov 2026 10:22:35 +0000 Subject: [PATCH 9/9] fix(server): update the loop time before the tick reads the clock libuv runs the timers of a pass with the loop time of the start of the pass. A timer callback that ran before the ping timer can block for longer than 1.5 intervals, or the machine can sleep in it. The tick then read a stale time: it did not see the wake, kept the stamps of pings from before it, and the check, whose poll is within the gap of the tick, dropped a live Claude that had no time to answer. The tick now calls update_time first and uses that time for the wake test, the stamp and the gap. Found by Codex round 3. --- .../skills/verify-diff-lifecycle/covered.lock | 2 +- lua/claudecode/server/README.md | 2 +- lua/claudecode/server/tcp.lua | 12 ++++++------ tests/unit/server/connection_lifecycle_spec.lua | 16 +++++++++------- 4 files changed, 17 insertions(+), 15 deletions(-) diff --git a/.agents/skills/verify-diff-lifecycle/covered.lock b/.agents/skills/verify-diff-lifecycle/covered.lock index ad6aecb23..a8215d5f0 100644 --- a/.agents/skills/verify-diff-lifecycle/covered.lock +++ b/.agents/skills/verify-diff-lifecycle/covered.lock @@ -161,7 +161,7 @@ site lua/claudecode/server/init.lua: if not _G.claude_deferred_responses then @ == lua/claudecode/server/mock.lua file lua/claudecode/server/mock.lua def1248d2793d559 == lua/claudecode/server/tcp.lua -file lua/claudecode/server/tcp.lua c0ab3eabbe30b1c4 +file lua/claudecode/server/tcp.lua 0cfb4b3ed4c138a1 == lua/claudecode/server/utils.lua file lua/claudecode/server/utils.lua 2915ae87b48f04ca == lua/claudecode/terminal.lua diff --git a/lua/claudecode/server/README.md b/lua/claudecode/server/README.md index 0fc6fd30c..5868a67bc 100644 --- a/lua/claudecode/server/README.md +++ b/lua/claudecode/server/README.md @@ -77,7 +77,7 @@ Layers, top to bottom: - When the JSON decodes to a non-table value (for example a number or a boolean), `_handle_message` replies -32600 with `"id": null`. It does not raise [server/init.lua:M._handle_message] - 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] -- A ping timer tick pings every connected client and never closes one for a missing answer. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since bytes were last read from the client. The read callback clears it on any bytes, not only a pong: Claude shows it is alive by writing anything, and a pong that waits behind more unread data than the socket holds is not in the first poll after a block. The tick stamps it after `vim.loop.update_time()`, because libuv caches the loop time when a pass of the main loop starts, and a callback that ran before the tick in the pass can have blocked since. Each tick that pinged a client arms `after_next_poll` (below), and its callback runs `judge_silence` after the next poll. libuv runs the check handle right 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block Neovim and Claude can have slept together (a suspended machine), and Claude has had no time to answer. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: 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` (75 s by default) 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 but never answers a ping is not closed by this rule: it is alive, and the plugin does not judge what it writes (the stall rule below closes it when it stops reading, but only once the kernel's socket buffers are full and libuv's write queue backs up, because a queue that is empty counts as progress). A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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:judge_silence] [server/tcp.lua:drop_client] +- A ping timer tick pings every connected client and never closes one for a missing answer. `client.ping_unanswered_since` holds the loop time of the oldest ping sent since bytes were last read from the client. The read callback clears it on any bytes, not only a pong: Claude shows it is alive by writing anything, and a pong that waits behind more unread data than the socket holds is not in the first poll after a block. The tick calls `vim.loop.update_time()` before it reads the clock, because libuv caches the loop time when a pass of the main loop starts and runs the timers of the pass with it, and a callback that ran before the tick in the pass can have blocked since, or the machine can have slept in it. A stale time would hide a wake and would stamp a ping older than it is. Each tick that pinged a client arms `after_next_poll` (below), and its callback runs `judge_silence` after the next poll. libuv runs the check handle right 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 closes each client that the tick pinged when its oldest ping is `interval * 2.5` old, but only if its loop time is at most `interval * 1.5` after the tick. After a longer block Neovim and Claude can have slept together (a suspended machine), and Claude has had no time to answer. A tick cannot decide this, because libuv can run a tick before it reads the pong that Claude sent: after a block in a check callback or an I/O read callback, and, with libuv 1.44 (bundled in Neovim 0.8), after a block in any callback. libuv 1.44 also runs the timers again at the end of a pass, so two ticks can run with no read between them. `vim.schedule` cannot decide it either, because Neovim runs its callbacks between two passes, so it can run one before the read. Drop bound: 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` (75 s by default) 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 but never answers a ping is not closed by this rule: it is alive, and the plugin does not judge what it writes (the stall rule below closes it when it stops reading, but only once the kernel's socket buffers are full and libuv's write queue backs up, because a queue that is empty counts as progress). A block longer than `interval * 1.5` restarts the count: the next tick sees the gap, takes it for a wake and clears every stamp. So a block delays the close of a silent Claude, and a run of such blocks can postpone it. Without a long block, a Claude that sends nothing is closed at the first read of its socket after the third tick that follows its first unanswered ping, which is 90 s by default after that ping. 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 check logs `Closed client_: no reply for 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:judge_silence] [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_: not reading for s, 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:judge_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 a client counts as answered when no ping of it waited for `interval * 2`. Only a client that answered is confirmed for a stall. A client that did not answer is dropped by the keepalive check above, whatever its write queue shows. A client that answers while its queue is stalled is not saved: its bytes clear the stamp, the next tick finds it answered, 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 clears `ping_unanswered_since` of each connected client. 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` 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 clears the stamps only, and counts like any tick. A client that is not connected is not pinged, so a main loop that blocks during the handshake does not count against it [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] diff --git a/lua/claudecode/server/tcp.lua b/lua/claudecode/server/tcp.lua index 1c94ec7e1..cd1b8756b 100644 --- a/lua/claudecode/server/tcp.lua +++ b/lua/claudecode/server/tcp.lua @@ -531,6 +531,10 @@ function M.start_ping_timer(server, interval) server.keepalive_timeout = timeout timer:start(interval, interval, function() + -- libuv caches the loop time when a pass starts and runs the timers of the pass with it. A callback that ran before + -- this tick in the pass can have blocked since, or the machine can have slept in it. Read the clock again: a stale + -- `now` hides a wake, and a ping stamped with it looks older than it is. + vim.loop.update_time() local now = vim.loop.now() local elapsed = now - last_run @@ -578,11 +582,7 @@ function M.start_ping_timer(server, interval) local since = client.ping_unanswered_since local answered = since == nil or now - since < timeout client_manager.send_ping(client, "ping") - -- libuv caches the loop time when a pass starts, and a callback that ran before this tick in the pass can have - -- blocked since. A ping stamped with that old time would look older than it is, and the check could drop a - -- Claude that had no time to answer it. - vim.loop.update_time() - client.ping_unanswered_since = since or vim.loop.now() + client.ping_unanswered_since = since or now table.insert(pinged, client) -- Only a client that answered is dropped for a stall, and only after the next poll confirms it. A client that -- did not answer is dropped by the keepalive judgement, whatever its write queue shows. @@ -595,7 +595,7 @@ function M.start_ping_timer(server, interval) last_run = now if #pinged > 0 then - local tick_time = vim.loop.now() + local tick_time = now -- Neither judgement happens at the tick: see `judge_silence` and `judge_stall`. If libuv cannot create the handles, -- the clients wait for the next tick. after_next_poll(server, function() diff --git a/tests/unit/server/connection_lifecycle_spec.lua b/tests/unit/server/connection_lifecycle_spec.lua index 15814e69c..67f2c0c0c 100644 --- a/tests/unit/server/connection_lifecycle_spec.lua +++ b/tests/unit/server/connection_lifecycle_spec.lua @@ -635,24 +635,26 @@ describe("The lifecycle of a WebSocket connection", function() assert.spy(callbacks.on_disconnect).was_not_called() end) - it("measures the gap to the poll from the ping, not from the loop time that a block left behind", function() + -- libuv runs the timers of a pass with the loop time of the start of the pass. A timer callback that runs before the + -- ping timer can block for longer than 1.5 intervals, or the machine can sleep in it. The cached time then hides the + -- wake, and the pings that went unanswered before it would look old at the check, which has no gap to skip. + it("takes a tick for a wake when a callback before it in the pass blocked, though the loop time is old", function() local refresh = cache_loop_time() local tick, raw_tick = start_ping_timer() local client = connect_and_upgrade() - for _ = 1, 3 do + for _ = 1, 2 do clock = clock + interval refresh() tick() end clock = clock + interval refresh() - clock = clock + 1.2 * interval -- a callback that runs before the timers of this pass blocks: the loop time is old - raw_tick() - clock = clock + 0.5 * interval -- the poll comes 0.5 intervals after the ping, but 1.7 after the old loop time - poll(refresh) + clock = clock + 2 * interval -- a timer callback that runs before the ping timer blocks, or the machine sleeps + raw_tick() -- the cached loop time shows one interval since the last tick, the clock three + poll() -- Claude has had no time to answer - assert.is_nil(server.clients[client.id], "the gap was measured from the loop time of the start of the pass") + assert.is_not_nil(server.clients[client.id], "the tick did not see the wake, and the check judged an old ping") end) it(