fix: wrap ERROR and WARN logging in vim.schedule to prevent fast event context errors

Fixes issue where closing and reopening MacBook would trigger TCP connection
errors that call logger.error() from timer callbacks (fast event context),
causing "nvim_echo must not be called in a fast event context" errors.

Changes:
- Wrap vim.notify calls for ERROR and WARN levels in vim.schedule()
- Add comprehensive test suite for logger fast event context safety
- All logging levels now safely callable from any event context

Fixes #51

Change-Id: I9791d9e788745225aeac7c19c6c33562f95f086b
Signed-off-by: Thomas Kosiewski <[email protected]>

Author: ThomasK33

lua/claudecode/logger.lua

@@ -69,9 +69,13 @@ local function log(level, component, message_parts)
   end
 
   if level == M.levels.ERROR then
-    vim.notify(prefix .. " " .. message, vim.log.levels.ERROR, { title = "ClaudeCode Error" })
+    vim.schedule(function()
+      vim.notify(prefix .. " " .. message, vim.log.levels.ERROR, { title = "ClaudeCode Error" })
+    end)
   elseif level == M.levels.WARN then
-    vim.notify(prefix .. " " .. message, vim.log.levels.WARN, { title = "ClaudeCode Warning" })
+    vim.schedule(function()
+      vim.notify(prefix .. " " .. message, vim.log.levels.WARN, { title = "ClaudeCode Warning" })
+    end)
   else
     -- For INFO, DEBUG, TRACE, use nvim_echo to avoid flooding notifications,
     -- to make them appear in :messages, and wrap in vim.schedule

tests/unit/logger_spec.lua

@@ -0,0 +1,175 @@
+-- luacheck: globals expect
+require("tests.busted_setup")
+
+describe("Logger", function()
+  local logger
+  local original_vim_schedule
+  local original_vim_notify
+  local original_nvim_echo
+  local scheduled_calls = {}
+  local notify_calls = {}
+  local echo_calls = {}
+
+  local function setup()
+    package.loaded["claudecode.logger"] = nil
+
+    -- Mock vim.schedule to track calls
+    original_vim_schedule = vim.schedule
+    vim.schedule = function(fn)
+      table.insert(scheduled_calls, fn)
+      -- Immediately execute the function for testing
+      fn()
+    end
+
+    -- Mock vim.notify to track calls
+    original_vim_notify = vim.notify
+    vim.notify = function(msg, level, opts)
+      table.insert(notify_calls, { msg = msg, level = level, opts = opts })
+    end
+
+    -- Mock nvim_echo to track calls
+    original_nvim_echo = vim.api.nvim_echo
+    vim.api.nvim_echo = function(chunks, history, opts)
+      table.insert(echo_calls, { chunks = chunks, history = history, opts = opts })
+    end
+
+    logger = require("claudecode.logger")
+
+    -- Set log level to TRACE to enable all logging levels for testing
+    logger.setup({ log_level = "trace" })
+  end
+
+  local function teardown()
+    vim.schedule = original_vim_schedule
+    vim.notify = original_vim_notify
+    vim.api.nvim_echo = original_nvim_echo
+    scheduled_calls = {}
+    notify_calls = {}
+    echo_calls = {}
+  end
+
+  before_each(function()
+    setup()
+  end)
+
+  after_each(function()
+    teardown()
+  end)
+
+  describe("error logging", function()
+    it("should wrap error calls in vim.schedule", function()
+      logger.error("test", "error message")
+
+      -- Should have made one scheduled call
+      expect(#scheduled_calls).to_be(1)
+
+      -- Should have called vim.notify with error level
+      expect(#notify_calls).to_be(1)
+      expect(notify_calls[1].level).to_be(vim.log.levels.ERROR)
+      assert_contains(notify_calls[1].msg, "error message")
+    end)
+
+    it("should handle error calls without component", function()
+      logger.error("error message")
+
+      expect(#scheduled_calls).to_be(1)
+      expect(#notify_calls).to_be(1)
+      assert_contains(notify_calls[1].msg, "error message")
+    end)
+  end)
+
+  describe("warn logging", function()
+    it("should wrap warn calls in vim.schedule", function()
+      logger.warn("test", "warning message")
+
+      -- Should have made one scheduled call
+      expect(#scheduled_calls).to_be(1)
+
+      -- Should have called vim.notify with warn level
+      expect(#notify_calls).to_be(1)
+      expect(notify_calls[1].level).to_be(vim.log.levels.WARN)
+      assert_contains(notify_calls[1].msg, "warning message")
+    end)
+
+    it("should handle warn calls without component", function()
+      logger.warn("warning message")
+
+      expect(#scheduled_calls).to_be(1)
+      expect(#notify_calls).to_be(1)
+      assert_contains(notify_calls[1].msg, "warning message")
+    end)
+  end)
+
+  describe("info logging", function()
+    it("should wrap info calls in vim.schedule", function()
+      logger.info("test", "info message")
+
+      -- Should have made one scheduled call
+      expect(#scheduled_calls).to_be(1)
+
+      -- Should have called nvim_echo instead of notify
+      expect(#echo_calls).to_be(1)
+      expect(#notify_calls).to_be(0)
+      assert_contains(echo_calls[1].chunks[1][1], "info message")
+    end)
+  end)
+
+  describe("debug logging", function()
+    it("should wrap debug calls in vim.schedule", function()
+      logger.debug("test", "debug message")
+
+      -- Should have made one scheduled call
+      expect(#scheduled_calls).to_be(1)
+
+      -- Should have called nvim_echo instead of notify
+      expect(#echo_calls).to_be(1)
+      expect(#notify_calls).to_be(0)
+      assert_contains(echo_calls[1].chunks[1][1], "debug message")
+    end)
+  end)
+
+  describe("trace logging", function()
+    it("should wrap trace calls in vim.schedule", function()
+      logger.trace("test", "trace message")
+
+      -- Should have made one scheduled call
+      expect(#scheduled_calls).to_be(1)
+
+      -- Should have called nvim_echo instead of notify
+      expect(#echo_calls).to_be(1)
+      expect(#notify_calls).to_be(0)
+      assert_contains(echo_calls[1].chunks[1][1], "trace message")
+    end)
+  end)
+
+  describe("fast event context safety", function()
+    it("should not call vim API functions directly", function()
+      -- Simulate a fast event context by removing the mocked functions
+      -- and ensuring no direct calls are made
+      local direct_notify_called = false
+      local direct_echo_called = false
+
+      vim.notify = function()
+        direct_notify_called = true
+      end
+
+      vim.api.nvim_echo = function()
+        direct_echo_called = true
+      end
+
+      vim.schedule = function(fn)
+        -- Don't execute the function, just verify it was scheduled
+        table.insert(scheduled_calls, fn)
+      end
+
+      logger.error("test", "error in fast context")
+      logger.warn("test", "warn in fast context")
+      logger.info("test", "info in fast context")
+
+      -- All should be scheduled, none should be called directly
+      expect(#scheduled_calls).to_be(3)
+      expect(direct_notify_called).to_be_false()
+      expect(direct_echo_called).to_be_false()
+    end)
+  end)
+end)