fix(server): log Authenticated after the token check and run git once per lookup

.agents/skills/verify-diff-lifecycle/covered.lock

@@ -1,7 +1,7 @@
 == lua/claudecode/config.lua
 file lua/claudecode/config.lua 787fa0432d1d77d7
 == lua/claudecode/cwd.lua
-file lua/claudecode/cwd.lua 55d26ea362173afa
+file lua/claudecode/cwd.lua 35b7af3572d13018
 == lua/claudecode/diff.lua
 file lua/claudecode/diff.lua a21129cdc802e417
 block resolve_saved          46d5f3f732711fe1
@@ -146,7 +146,7 @@ file lua/claudecode/server/frame.lua 3c50766875878d56
 == lua/claudecode/server/handshake.lua
 file lua/claudecode/server/handshake.lua 3eca35d572094a55
 == lua/claudecode/server/init.lua
-file lua/claudecode/server/init.lua a9c0d153b61e3078
+file lua/claudecode/server/init.lua 8da8851fff781946
 block server_stop            4dae0bf675cf2cc1
 block on_disconnect          a0ce86cede4af786
 block handle_request         b74ff7dc2e55a2b8
@@ -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 0cfb4b3ed4c138a1
+file lua/claudecode/server/tcp.lua 8be1dd96671223ea
 == lua/claudecode/server/utils.lua
 file lua/claudecode/server/utils.lua 2915ae87b48f04ca
 == lua/claudecode/terminal.lua

lua/claudecode/README.md

@@ -206,7 +206,7 @@ Module map (direct files):
 - When a blocking diff resolves, `open_diff_blocking` sends the reply through the global `_G.claude_deferred_responses[tostring(co)]`, then sets that entry to nil. Without an entry, it logs an error [diff.lua:M.open_diff_blocking]
 - The native diff writes each temp file into its own session folder under `stdpath("cache")/claudecode_diffs`, or `claudecode_diffs_fallback` when it cannot create a directory in the first. The folder name includes the Neovim PID, so two running Neovim processes never share one. If both fail, `open_diff` returns `success = false` with an error that names both directories [diff.lua:create_temp_file]. A `BufDelete`/`BufWipeout` autocmd on the proposed buffer cleans up once, even when a wipe fires both events. It deletes the file and then its empty folder with `vim.fn.delete`, and warns once for each delete that fails. When the file delete fails, the folder is not empty, so its delete fails too and both warnings show [diff.lua:cleanup_temp_file]. `_cleanup_diff_state` does not [diff.lua:M._open_native_diff]
 - `diff_inline.lua` creates the `claudecode_inline_diff` namespace when the module loads. It defines the four `ClaudeCodeInlineDiff*` highlight groups (with `default = true`) [diff_inline.lua:setup_highlights] and sets extmarks [diff_inline.lua:M.render_diff_buffer]
-- The plugin runs `git rev-parse --show-toplevel` for the git root [cwd.lua:M.git_root], and `health.check` runs `<claude> --version` [health.lua:check_cli]
+- The plugin runs `git rev-parse --show-toplevel` at most once for each git root lookup [cwd.lua:M.git_root], and `health.check` runs `<claude> --version` [health.lua:check_cli]
 - `logger` defers each log line through `vim.schedule`. ERROR and WARN go to `vim.notify`. Other levels go to `nvim_echo` [logger.lua:log]. The level is INFO until `setup` runs. `logger.setup` warns at once, not deferred, when `log_level` is missing or invalid, and uses INFO [logger.lua:M.setup]. The plugin's `setup` never reaches that warning: `config.apply` fills in `info` and raises on an invalid `log_level` first [config.lua:M.validate]
 - `one_line` accepts only `error`, `warn`, and `info`, and asserts on any other level [logger.lua:M.one_line]
 - Below log_level debug, `one_line` replaces each run of whitespace with one space. A line wider than `v:echospace` cells drops its component tag and puts `ERROR:` or `WARN:` in place of its level tag (an info line gets none), so the level shows without colors. It drops the `[ClaudeCode]` name too when that would take more than half the width. Then it is cut to the width, ending in `...` when `v:echospace` is at least 3. Below debug, only that line reaches `:messages`: Neovim adds a line to the message history only by showing it, and showing a line wider than the command line stops at "Press ENTER" (always before Neovim 0.11, and from 0.11 on while `'messagesopt'` contains its default `hit-enter`), so the whole line shows only at log_level debug [logger.lua:M.one_line]

lua/claudecode/cwd.lua

@@ -34,11 +34,9 @@ function M.git_root(start_dir)
   -- Prefer running without shell by passing a list
   local result
   if vim.fn.systemlist then
-    local ok, _ = pcall(function()
-      local _ = vim.fn.systemlist({ "git", "-C", start_dir, "rev-parse", "--show-toplevel" })
-    end)
+    local ok, output = pcall(vim.fn.systemlist, { "git", "-C", start_dir, "rev-parse", "--show-toplevel" })
     if ok then
-      result = vim.fn.systemlist({ "git", "-C", start_dir, "rev-parse", "--show-toplevel" })
+      result = output
     else
       -- Fallback to string command if needed
       local cmd = "git -C " .. vim.fn.shellescape(start_dir) .. " rev-parse --show-toplevel"

lua/claudecode/server/README.md

@@ -112,7 +112,7 @@ Layers, top to bottom:
 ## Side Effects
 
 - `M.start` changes the global tool registry (`tools.setup`), opens a listening TCP handle, and starts a `vim.loop` ping timer [server/init.lua:M.start]
-- When a client completed its WebSocket handshake (`on_open`, called from the 101 write callback in `client.lua`), the server schedules `claudecode.process_mention_queue(true)`. `on_connect` runs at the TCP accept, before the handshake, and only logs [server/init.lua:M.start] [server/client.lua:M.process_data]
+- When a client completed its WebSocket handshake (`on_open`, called from the 101 write callback in `client.lua`), the server schedules `claudecode.process_mention_queue(true)`. With an auth token it first logs `Authenticated WebSocket client connected` at debug level, because the handshake has checked the token by then. `on_connect` runs at the TCP accept, before the handshake and the token check, and only logs `WebSocket client connected, awaiting authentication` (`WebSocket client connected (no auth)` without a token) [server/init.lua:M.start] [server/client.lua:M.process_data]
 - On disconnect, the server schedules `diff.close_diffs_for_client(client.id, "client disconnected")`, only when `package.loaded["claudecode.diff"]` is set and the client completed its handshake. A client without a completed handshake ran no tool, so it owns no diff. The cleanup runs through `utils.when_windows_allowed`: in the command-line window or under textlock it waits, and it runs once Neovim allows window changes again. One 50 ms timer checks for every waiting cleanup [server/init.lua:M.start] [lua/claudecode/utils.lua:M.when_windows_allowed]
 - `M.stop` calls `diff.close_pending_diffs("server stopping")` when `package.loaded["claudecode.diff"]` is set, resets `_G.claude_deferred_responses`, and clears `M.state.auth_token` [server/init.lua:M.stop]
 - `M.start` logs only the auth token length, not the token [server/init.lua:M.start]

lua/claudecode/server/init.lua

@@ -55,14 +55,19 @@ function M.start(config, auth_token)
       M._handle_message(client, message)
     end,
     on_connect = function(client)
-      -- Log connection with auth status
+      -- This runs at the TCP accept, before the handshake, so the token has not been checked yet.
       if M.state.auth_token then
-        logger.debug("server", "Authenticated WebSocket client connected:", client.id)
+        logger.debug("server", "WebSocket client connected, awaiting authentication:", client.id)
       else
         logger.debug("server", "WebSocket client connected (no auth):", client.id)
       end
     end,
     on_open = function(client)
+      -- With a token, the handshake has passed the token check by now, so the client is authenticated.
+      if M.state.auth_token then
+        logger.debug("server", "Authenticated WebSocket client connected:", client.id)
+      end
+
       -- The client completed its WebSocket handshake, so it can take the queued @ mentions now.
       local main_module = require("claudecode")
       if main_module.process_mention_queue then

lua/claudecode/server/tcp.lua

@@ -16,7 +16,8 @@ local M = {}
 ---@field keepalive_timeout number|nil The window in milliseconds for a pong and for write progress: twice the ping interval, set by `start_ping_timer`
 ---@field pending_polls table<table, boolean>|nil The check and idle handles of each stall judgement that waits for the next poll: closed by `stop_server`
 
--- Seed Lua's PRNG exactly once per process. #282 removed the implicit seeding
+-- Seed Lua's PRNG once per load of this module: `rng_seeded` is a module local, so a reload seeds again. Neovim loads
+-- the module once, so a fresh Neovim seeds once. #282 removed the implicit seeding
 -- that used to happen via utils.shuffle_array (math.randomseed(os.time())), which
 -- left LuaJIT's fixed default seed in place -- so every fresh Neovim picked the
 -- *same* starting port and parallel instances always collided (#283). Mixing in a

tests/unit/cwd_spec.lua

@@ -0,0 +1,93 @@
+require("tests.busted_setup")
+
+describe("The git root lookup", function()
+  local cwd, temp_dir, dir
+  local saved = {}
+  local git_calls, git_runs
+
+  -- Stands in for vim.fn.systemlist. `outcome` is what git printed and how it ended. A run is a call that did not raise:
+  -- the real function starts the process only then.
+  local function stub_git(outcome)
+    vim.fn.systemlist = function(command)
+      git_calls[#git_calls + 1] = command
+      git_runs = git_runs + 1
+      vim.v.shell_error = outcome.exit_code
+      return outcome.lines
+    end
+  end
+
+  before_each(function()
+    package.loaded["claudecode.cwd"] = nil
+    cwd = require("claudecode.cwd")
+    temp_dir = require("tests.helpers.temp_dir")
+    dir = temp_dir.new()
+    git_calls, git_runs = {}, 0
+    saved.systemlist, saved.shell_error, saved.finddir = vim.fn.systemlist, vim.v.shell_error, vim.fn.finddir
+    saved.shellescape = vim.fn.shellescape
+  end)
+
+  after_each(function()
+    vim.fn.systemlist, vim.v.shell_error, vim.fn.finddir = saved.systemlist, saved.shell_error, saved.finddir
+    vim.fn.shellescape = saved.shellescape
+    temp_dir.remove(dir)
+  end)
+
+  it("runs git rev-parse once and returns the root it printed", function()
+    stub_git({ lines = { dir }, exit_code = 0 })
+
+    assert.equals(dir, cwd.git_root(dir))
+
+    assert.equals(1, git_runs, vim.inspect(git_calls))
+    assert.same({ "git", "-C", dir, "rev-parse", "--show-toplevel" }, git_calls[1])
+  end)
+
+  it("runs git rev-parse once for a folder that is not in a repository, then searches for .git", function()
+    stub_git({ lines = { "fatal: not a git repository" }, exit_code = 128 })
+    local searched
+    vim.fn.finddir = function(name, path)
+      searched = { name = name, path = path }
+      return ""
+    end
+
+    assert.is_nil(cwd.git_root(dir))
+
+    assert.equals(1, git_runs, vim.inspect(git_calls))
+    assert.same({ name = ".git", path = dir .. ";" }, searched)
+  end)
+
+  it("runs git rev-parse as a shell string, once, when systemlist refuses a list", function()
+    vim.fn.shellescape = function(text)
+      return "'" .. text .. "'"
+    end
+    vim.fn.systemlist = function(command)
+      git_calls[#git_calls + 1] = command
+      if type(command) == "table" then
+        error("E475: Invalid argument: expected String")
+      end
+      git_runs = git_runs + 1
+      vim.v.shell_error = 0
+      return { dir }
+    end
+
+    assert.equals(dir, cwd.git_root(dir))
+
+    assert.equals(1, git_runs, vim.inspect(git_calls))
+    assert.equals("string", type(git_calls[#git_calls]))
+  end)
+
+  it("does not run git for a folder that does not exist", function()
+    stub_git({ lines = { dir }, exit_code = 0 })
+
+    assert.is_nil(cwd.git_root(dir .. "/missing"))
+
+    assert.equals(0, #git_calls)
+  end)
+
+  it("runs git rev-parse once for each lookup that resolve makes with git_repo_cwd", function()
+    stub_git({ lines = { dir }, exit_code = 0 })
+
+    assert.equals(dir, cwd.resolve({ git_repo_cwd = true }, { file_dir = dir, cwd = dir }))
+
+    assert.equals(1, git_runs, vim.inspect(git_calls))
+  end)
+end)

tests/unit/server/connect_log_spec.lua

@@ -0,0 +1,122 @@
+--- The server says "Authenticated" about a client only after its handshake passed the token check. A TCP connection
+--- carries no proof yet: any process on the machine can open one, and its handshake can still fail.
+require("tests.busted_setup")
+
+describe("The server's log of a connecting client", function()
+  local server, tcp, logged
+  local token = "test-token-0123456789"
+
+  before_each(function()
+    logged = {}
+    -- A logger that keeps every line in order, so the tests can read what the server said and when.
+    package.loaded["claudecode.logger"] = setmetatable({}, {
+      __index = function(_, level)
+        return function(component, ...)
+          local words = {}
+          for _, word in ipairs({ ... }) do
+            words[#words + 1] = tostring(word)
+          end
+          logged[#logged + 1] = { level = level, component = component, text = table.concat(words, " ") }
+        end
+      end,
+    })
+    for _, name in ipairs({
+      "claudecode.server.handshake",
+      "claudecode.server.client",
+      "claudecode.server.tcp",
+      "claudecode.server.init",
+    }) do
+      package.loaded[name] = nil
+    end
+    tcp = require("claudecode.server.tcp")
+    server = require("claudecode.server.init")
+  end)
+
+  after_each(function()
+    if server.state.server then
+      server.stop()
+    end
+    -- Later specs load the real logger, and the server modules that hold this one.
+    for _, name in ipairs({
+      "claudecode.logger",
+      "claudecode.server.handshake",
+      "claudecode.server.client",
+      "claudecode.server.tcp",
+      "claudecode.server.init",
+    }) do
+      package.loaded[name] = nil
+    end
+  end)
+
+  local function start(auth_token)
+    assert(server.start({ port_range = { min = 10000, max = 65535 } }, auth_token))
+    return server.state.server
+  end
+
+  -- What the listen callback does for each new connection. Returns the client the server made for it.
+  local function connect(tcp_server)
+    tcp._handle_new_connection(tcp_server)
+    return assert(tcp_server.clients["client_" .. _G.claudecode_clients_created])
+  end
+
+  local function upgrade(auth)
+    return "GET / HTTP/1.1\r\nHost: 127.0.0.1\r\nUpgrade: websocket\r\nConnection: Upgrade\r\n"
+      .. "Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==\r\nSec-WebSocket-Version: 13\r\n"
+      .. "x-claude-code-ide-authorization: "
+      .. auth
+      .. "\r\n\r\n"
+  end
+
+  ---@param pattern string A Lua pattern, matched against the text of each line the server logged
+  ---@return integer[] indexes The position of each match in the log
+  local function lines_matching(pattern)
+    local indexes = {}
+    for index, line in ipairs(logged) do
+      if line.text:find(pattern) then
+        indexes[#indexes + 1] = index
+      end
+    end
+    return indexes
+  end
+
+  it("does not say Authenticated when a client only connects over TCP", function()
+    local client = connect(start(token))
+
+    assert.same({}, lines_matching("Authenticated"), vim.inspect(logged))
+    assert.equals(1, #lines_matching("client connected, awaiting authentication: " .. client.id))
+  end)
+
+  it("never says Authenticated about a client whose token is wrong", function()
+    local tcp_server = start(token)
+    local client = connect(tcp_server)
+
+    client.tcp_handle._read_cb(nil, upgrade("wrong-token-0123456789"))
+
+    assert.same({}, lines_matching("Authenticated"), vim.inspect(logged))
+    assert.equals(1, #lines_matching("Rejected " .. client.id), vim.inspect(logged))
+    assert.is_nil(tcp_server.clients[client.id], "the rejected client is gone")
+  end)
+
+  it("says Authenticated once, after the handshake accepted the token", function()
+    local client = connect(start(token))
+
+    client.tcp_handle._read_cb(nil, upgrade(token))
+
+    local authenticated = lines_matching("Authenticated WebSocket client connected: " .. client.id)
+    assert.equals(1, #authenticated, vim.inspect(logged))
+    local accepted = lines_matching("Client authenticated successfully: " .. client.id)
+    assert.equals(1, #accepted, vim.inspect(logged))
+    assert.is_true(accepted[1] < authenticated[1], "the token check logs first: " .. vim.inspect(logged))
+    assert.is_true(client.handshake_complete)
+  end)
+
+  it("keeps its no-auth line, and never says Authenticated, when the server has no token", function()
+    local client = connect(start(nil))
+
+    client.tcp_handle._read_cb(nil, upgrade("any-value"))
+
+    assert.equals(1, #lines_matching("client connected %(no auth%): " .. client.id), vim.inspect(logged))
+    assert.same({}, lines_matching("Authenticated"), vim.inspect(logged))
+    assert.is_true(client.handshake_complete)
+  end)
+end)