From 37f06532bbdaeb8b80c90824b2f0b13ce94c6257 Mon Sep 17 00:00:00 2001
From: Robert <robert.hill@uphillsolutions.tech>
Date: Sun, 30 Aug 2026 08:43:31 -0400
Subject: [PATCH 1/4] feat: add configurable debug logging

---
 README.md                |   7 ++
 docs/debug-logging.md    |  27 ++++++++
 lua/sshfs/api.lua        |  35 ++++++++++
 lua/sshfs/config.lua     |   4 ++
 lua/sshfs/init.lua       |   3 +
 lua/sshfs/lib/logger.lua | 134 +++++++++++++++++++++++++++++++++++++++
 lua/sshfs/lib/ssh.lua    |  47 ++++++++++++--
 lua/sshfs/lib/sshfs.lua  |  53 +++++++++++++++-
 8 files changed, 305 insertions(+), 5 deletions(-)
 create mode 100644 docs/debug-logging.md
 create mode 100644 lua/sshfs/lib/logger.lua

diff --git a/README.md b/README.md
index ee346f6..2f6c7ee 100644
--- a/README.md
+++ b/README.md
@@ -261,6 +261,10 @@ require("sshfs").setup({
       preferred_picker = "auto",  -- one of: "auto", "snacks", "fzf-lua", "telescope", "mini"
     },
   },
+  debug = {
+    enabled = false,              -- write SSH/SSHFS diagnostics to a log file
+    log_file = vim.fn.stdpath("log") .. "/sshfs.nvim.log",
+  },
   lead_prefix = "<leader>m",      -- change keymap prefix (default: <leader>m)
   keymaps = {
     mount = "<leader>mm",         -- creates an ssh connection and mounts via sshfs
@@ -294,6 +298,7 @@ require("sshfs").setup({
 - `:SSHDisconnectAll` - Unmount all hosts
 - `:SSHConfig` - Edit SSH config files
 - `:SSHReload` - Reload SSH configuration
+- `:SSHDebug [on|off]` - Toggle debug logging for the current Neovim session
 - `:SSHFiles` - Find files with auto-detected picker
 - `:SSHGrep [pattern]` - Search files with auto-detected tool
 - `:SSHLiveFind [pattern]` - Stream remote `find`/`fd` results over SSH (snacks/fzf-lua/telescope/mini)
@@ -303,6 +308,8 @@ require("sshfs").setup({
 - `:SSHCommand [cmd]` - Run custom command (e.g. `Oil`, `Telescope`)
 - `:SSHTerminal` - Open terminal session (reuses auth)
 
+Debug logging records SSH authentication, ControlMaster, remote-home resolution, and SSHFS subprocess diagnostics. See [`docs/debug-logging.md`](docs/debug-logging.md) for details.
+
 ## 🎹 Key Mapping
 
 Default keybindings under `<leader>m` (fully customizable):
diff --git a/docs/debug-logging.md b/docs/debug-logging.md
new file mode 100644
index 0000000..b9ad828
--- /dev/null
+++ b/docs/debug-logging.md
@@ -0,0 +1,27 @@
+# Debug logging
+
+Debug logging is disabled by default. Enable it in setup:
+
+```lua
+require("sshfs").setup({
+  debug = {
+    enabled = true,
+    log_file = vim.fn.stdpath("log") .. "/sshfs.nvim.log",
+  },
+})
+```
+
+You can also change debug logging for the current Neovim session without changing configuration:
+
+```vim
+:SSHDebug
+:SSHDebug on
+:SSHDebug off
+```
+
+With no argument, `:SSHDebug` toggles logging. The command reports the active log path.
+
+When enabled, sshfs.nvim records timestamped diagnostics for SSH authentication, ControlMaster setup/cleanup, remote home resolution, and SSHFS mount subprocesses, including exit codes, stdout, and stderr. No log file writes are performed while debug logging is disabled.
+
+> [!WARNING]
+> Debug logs may contain hostnames, usernames, filesystem paths, SSH/SSHFS output, or authentication-related messages. Review logs before sharing them publicly.
diff --git a/lua/sshfs/api.lua b/lua/sshfs/api.lua
index 1e5d562..a88cbb6 100644
--- a/lua/sshfs/api.lua
+++ b/lua/sshfs/api.lua
@@ -100,6 +100,31 @@ Api.reload = function()
   Session.reload()
 end
 
+--- Toggle debug logging for the current Neovim session
+--- @param mode string|nil Optional explicit mode: "on" or "off"
+Api.debug = function(mode)
+  local Logger = require("sshfs.lib.logger")
+  local enabled
+
+  if mode == nil or mode == "" then
+    enabled = Logger.toggle()
+  elseif mode == "on" then
+    Logger.enable()
+    enabled = true
+  elseif mode == "off" then
+    Logger.disable()
+    enabled = false
+  else
+    vim.notify("Usage: :SSHDebug [on|off]", vim.log.levels.ERROR)
+    return
+  end
+
+  vim.notify(
+    string.format("sshfs.nvim debug logging %s: %s", enabled and "enabled" or "disabled", Logger.path()),
+    vim.log.levels.INFO
+  )
+end
+
 --- Browse remote files using native file browser
 --- @param opts table|nil Picker options
 Api.find_files = function(opts)
@@ -333,6 +358,16 @@ Api.setup = function()
     Api.reload()
   end, { desc = "Reload SSH configuration" })
 
+  vim.api.nvim_create_user_command("SSHDebug", function(opts)
+    Api.debug(opts.args)
+  end, {
+    nargs = "?",
+    complete = function()
+      return { "on", "off" }
+    end,
+    desc = "Toggle sshfs.nvim debug logging",
+  })
+
   vim.api.nvim_create_user_command("SSHDisconnect", function()
     Api.unmount()
   end, { desc = "Disconnect from current SSH host" })
diff --git a/lua/sshfs/config.lua b/lua/sshfs/config.lua
index 74f9b22..d762136 100644
--- a/lua/sshfs/config.lua
+++ b/lua/sshfs/config.lua
@@ -82,6 +82,10 @@ local DEFAULT_CONFIG = {
 			preferred_picker = "auto",      -- "auto", "telescope", "fzf-lua", "snacks", "mini"
 		},
 	},
+	debug = {
+		enabled = false,                   -- Enable debug logging
+		log_file = vim.fn.stdpath("log") .. "/sshfs.nvim.log", -- Debug log destination
+	},
 	keymaps = nil,                      -- Override individual keymaps (e.g., {mount = "<leader>mm", unmount = "<leader>mu"})
 	lead_prefix = "<leader>m",          -- Prefix for default keymaps
 }
diff --git a/lua/sshfs/init.lua b/lua/sshfs/init.lua
index f31434f..6243d51 100644
--- a/lua/sshfs/init.lua
+++ b/lua/sshfs/init.lua
@@ -10,6 +10,9 @@ function App.setup(user_opts)
   Config.setup(user_opts)
   local opts = Config.get()
 
+  local Logger = require("sshfs.lib.logger")
+  Logger.debug("sshfs.nvim initialized", { log_file = Logger.path() })
+
   -- Initialize other modules
   local MountPoint = require("sshfs.lib.mount_point")
   MountPoint.get_or_create()
diff --git a/lua/sshfs/lib/logger.lua b/lua/sshfs/lib/logger.lua
new file mode 100644
index 0000000..97fea85
--- /dev/null
+++ b/lua/sshfs/lib/logger.lua
@@ -0,0 +1,134 @@
+-- lua/sshfs/lib/logger.lua
+-- Centralized debug logging for sshfs.nvim
+
+local Logger = {}
+local runtime_enabled = nil
+local last_write_error = nil
+
+local function get_config()
+  local config = require("sshfs.config").get()
+  return config.debug or {}
+end
+
+local function escape_log_value(value)
+  return tostring(value):gsub("\r", "\\r"):gsub("\n", "\\n"):gsub("\t", "\\t")
+end
+
+local function ensure_parent_dir(path)
+  local parent = vim.fn.fnamemodify(path, ":h")
+  if parent ~= "" and vim.fn.isdirectory(parent) == 0 then
+    local result = vim.fn.mkdir(parent, "p", "0700")
+    if result == 0 and vim.fn.isdirectory(parent) == 0 then error("could not create log directory: " .. parent) end
+  end
+end
+
+local function write_log_line(path, line)
+  local uv = vim.uv or vim.loop
+  local fd, open_err = uv.fs_open(path, "a", 384)
+  if not fd then error("could not open log file: " .. tostring(open_err)) end
+
+  local chmod_ok, chmod_err = uv.fs_fchmod(fd, 384)
+  if not chmod_ok then
+    uv.fs_close(fd)
+    error("could not set log file permissions: " .. tostring(chmod_err))
+  end
+
+  local written, write_err = uv.fs_write(fd, line .. "\n", -1)
+  uv.fs_close(fd)
+  if not written then error("could not write log file: " .. tostring(write_err)) end
+end
+
+local function serialize_context(context)
+  if not context then return "" end
+  if type(context) ~= "table" then return " " .. escape_log_value(context) end
+
+  local parts = {}
+  for key, value in pairs(context) do
+    if value ~= nil then
+      local rendered = type(value) == "table" and vim.inspect(value) or tostring(value)
+      table.insert(parts, string.format("%s=%s", key, escape_log_value(rendered)))
+    end
+  end
+  table.sort(parts)
+
+  return #parts > 0 and (" " .. table.concat(parts, " ")) or ""
+end
+
+local function notify_write_failure(err)
+  local message = tostring(err)
+  if message == last_write_error then return end
+  last_write_error = message
+
+  vim.schedule(function()
+    vim.notify("sshfs.nvim: failed to write debug log: " .. message, vim.log.levels.ERROR)
+  end)
+end
+
+function Logger.is_enabled()
+  if runtime_enabled ~= nil then return runtime_enabled end
+  return get_config().enabled == true
+end
+
+function Logger.set_enabled(enabled)
+  runtime_enabled = enabled == true
+end
+
+function Logger.enable()
+  Logger.set_enabled(true)
+end
+
+function Logger.disable()
+  Logger.set_enabled(false)
+end
+
+function Logger.toggle()
+  Logger.set_enabled(not Logger.is_enabled())
+  return Logger.is_enabled()
+end
+
+function Logger.path()
+  local config = get_config()
+  return vim.fn.expand(config.log_file or (vim.fn.stdpath("log") .. "/sshfs.nvim.log"))
+end
+
+function Logger.log(level, message, context)
+  if not Logger.is_enabled() then return end
+
+  local path = Logger.path()
+  local line = string.format(
+    "%s [%s] %s%s",
+    os.date("%Y-%m-%d %H:%M:%S"),
+    string.upper(level or "debug"),
+    escape_log_value(message),
+    serialize_context(context)
+  )
+
+  local ok, result = pcall(function()
+    ensure_parent_dir(path)
+    write_log_line(path, line)
+  end)
+
+  if not ok then
+    notify_write_failure(result)
+  else
+    last_write_error = nil
+  end
+end
+
+function Logger.debug(message, context)
+  Logger.log("debug", message, context)
+end
+
+function Logger.info(message, context)
+  Logger.log("info", message, context)
+end
+
+function Logger.warn(message, context)
+  Logger.log("warn", message, context)
+end
+
+function Logger.error(message, context)
+  Logger.log("error", message, context)
+end
+
+return Logger
diff --git a/lua/sshfs/lib/ssh.lua b/lua/sshfs/lib/ssh.lua
index f31a8b7..f61c2ab 100644
--- a/lua/sshfs/lib/ssh.lua
+++ b/lua/sshfs/lib/ssh.lua
@@ -2,6 +2,7 @@
 -- SSH operations: terminal sessions, command execution, and connection utilities
 
 local Ssh = {}
+local Logger = require("sshfs.lib.logger")
 
 --- Get SSH socket directory, creating it if it doesn't exist
 --- @return string|nil socket_dir The socket directory path, or nil if creation failed
@@ -10,13 +11,19 @@ local function get_or_create_socket_dir()
   local Config = require("sshfs.config")
   local socket_dir = Config.get_socket_dir()
 
-  if vim.fn.isdirectory(socket_dir) == 1 then return socket_dir, nil end
+  if vim.fn.isdirectory(socket_dir) == 1 then
+    Logger.debug("SSH socket directory available", { socket_dir = socket_dir })
+    return socket_dir, nil
+  end
 
   local ok, err = pcall(vim.fn.mkdir, socket_dir, "p", "0700")
   if ok then
+    Logger.debug("Created SSH socket directory", { socket_dir = socket_dir })
     return socket_dir, nil
   else
-    return nil, "Failed to create socket directory: " .. socket_dir .. " (" .. tostring(err) .. ")"
+    local error_msg = "Failed to create socket directory: " .. socket_dir .. " (" .. tostring(err) .. ")"
+    Logger.error(error_msg)
+    return nil, error_msg
   end
 end
 
@@ -126,6 +133,7 @@ end
 ---@param remote_path string|nil Optional remote path to cd into
 function Ssh.open_terminal(host, remote_path)
   local ssh_cmd = Ssh.build_command(host, remote_path)
+  Logger.debug("Opening SSH terminal", { host = host, remote_path = remote_path })
   vim.cmd("enew")
   vim.fn.jobstart(ssh_cmd, { term = true })
   vim.cmd("startinsert")
@@ -149,10 +157,18 @@ function Ssh.get_remote_home(host, callback)
   table.insert(cmd, host)
   -- Use readlink -f to resolve symlinks and get the canonical path with fallback if no readlink
   table.insert(cmd, "readlink -f $HOME 2>/dev/null || echo $HOME")
+  Logger.debug("Resolving remote home", { host = host, command = table.concat(cmd, " ") })
 
   -- Execute asynchronously
   vim.system(cmd, { text = true }, function(obj)
     vim.schedule(function()
+      Logger.debug("Remote home command completed", {
+        host = host,
+        exit_code = obj.code,
+        stdout = vim.trim(obj.stdout or ""),
+        stderr = vim.trim(obj.stderr or ""),
+      })
+
       if obj.code == 0 then
         local home_path = vim.trim(obj.stdout or "")
         if home_path ~= "" and home_path:sub(1, 1) == "/" then
@@ -187,7 +203,13 @@ function Ssh.cleanup_control_master(host)
   table.insert(cmd, host)
 
   -- Execute synchronously (must complete before nvim exit)
-  vim.fn.system(cmd)
+  Logger.debug("Closing SSH ControlMaster", { host = host, command = table.concat(cmd, " ") })
+  local output = vim.fn.system(cmd)
+  Logger.debug("SSH ControlMaster cleanup completed", {
+    host = host,
+    exit_code = vim.v.shell_error,
+    output = vim.trim(output or ""),
+  })
   -- Ignore exit code - socket may already be closed/expired
   return true
 end
@@ -218,12 +240,20 @@ function Ssh.try_batch_connect(host, callback)
   -- Add host and exit command (just test connection, don't start shell)
   table.insert(cmd, host)
   table.insert(cmd, "exit")
+  Logger.debug("Starting batch SSH authentication", { host = host, command = table.concat(cmd, " ") })
 
   -- Execute asynchronously
   vim.system(cmd, { text = true }, function(obj)
     vim.schedule(function()
       local success = obj.code == 0
       local error_msg = success and nil or (obj.stderr or obj.stdout or "Unknown error")
+      Logger.debug("Batch SSH authentication completed", {
+        host = host,
+        success = success,
+        exit_code = obj.code,
+        stdout = vim.trim(obj.stdout or ""),
+        stderr = vim.trim(obj.stderr or ""),
+      })
       callback(success, obj.code, error_msg)
     end)
   end)
@@ -238,6 +268,7 @@ function Ssh.open_auth_terminal(host, callback)
   -- Ensure socket directory exists before attempting connection
   local socket_dir, err = get_or_create_socket_dir()
   if not socket_dir then
+    Logger.error("Unable to start interactive SSH authentication", { host = host, error = err })
     vim.notify("sshfs.nvim: " .. err, vim.log.levels.ERROR)
     vim.schedule(function()
       callback(false, 1)
@@ -266,8 +297,16 @@ function Ssh.open_auth_terminal(host, callback)
   table.insert(cmd, "exit")
 
   -- Open authentication terminal window
+  Logger.debug("Opening interactive SSH authentication", { host = host, command = table.concat(cmd, " ") })
   local Terminal = require("sshfs.ui.terminal")
-  Terminal.open_auth_floating(cmd, host, callback)
+  Terminal.open_auth_floating(cmd, host, function(success, exit_code)
+    Logger.debug("Interactive SSH authentication completed", {
+      host = host,
+      success = success,
+      exit_code = exit_code,
+    })
+    callback(success, exit_code)
+  end)
 end
 
 return Ssh
diff --git a/lua/sshfs/lib/sshfs.lua b/lua/sshfs/lib/sshfs.lua
index 9e5131d..e543f04 100644
--- a/lua/sshfs/lib/sshfs.lua
+++ b/lua/sshfs/lib/sshfs.lua
@@ -2,6 +2,7 @@
 -- SSHFS wrapper with authentication workflows
 
 local Sshfs = {}
+local Logger = require("sshfs.lib.logger")
 
 --- Convert sshfs_options table to array format for sshfs -o
 --- @param options_table table Table of options (e.g., {reconnect = true, ConnectTimeout = 5})
@@ -67,9 +68,27 @@ local function mount_with_path(host, mount_point, remote_path_suffix, callback)
     table.insert(cmd, host.port)
   end
 
+  Logger.debug("Starting SSHFS mount", {
+    host = host.name,
+    user = host.user,
+    remote_path = remote_path_suffix,
+    mount_point = mount_point,
+    command = table.concat(cmd, " "),
+  })
+
   -- Execute mount command asynchronously
   vim.system(cmd, { text = true }, function(obj)
     vim.schedule(function()
+      local stdout = vim.trim(obj.stdout or "")
+      local stderr = vim.trim(obj.stderr or "")
+      Logger.debug("SSHFS mount completed", {
+        host = host.name,
+        mount_point = mount_point,
+        exit_code = obj.code,
+        stdout = stdout,
+        stderr = stderr,
+      })
+
       if obj.code == 0 then
         callback({
           success = true,
@@ -77,7 +96,13 @@ local function mount_with_path(host, mount_point, remote_path_suffix, callback)
           resolved_path = remote_path_suffix,
         })
       else
-        local error_msg = obj.stderr or obj.stdout or "Unknown error"
+        local error_msg = stderr ~= "" and stderr or (stdout ~= "" and stdout or "Unknown error")
+        Logger.error("SSHFS mount failed", {
+          host = host.name,
+          mount_point = mount_point,
+          exit_code = obj.code,
+          error = error_msg,
+        })
         callback({
           success = false,
           message = "Mount failed: " .. error_msg,
@@ -104,9 +129,19 @@ local function mount_via_socket(host, mount_point, remote_path_suffix, callback)
       if actual_home then
         -- Replace ~ with the actual home path and mount
         local resolved_path = remote_path_suffix:gsub("^~", actual_home)
+        Logger.debug("Resolved remote home path", {
+          host = host.name,
+          requested_path = remote_path_suffix,
+          resolved_path = resolved_path,
+        })
         mount_with_path(host, mount_point, resolved_path, callback)
       else
         -- Fall back to letting SSHFS try to handle it (may fail for symlinks)
+        Logger.warn("Could not resolve remote home path", {
+          host = host.name,
+          requested_path = remote_path_suffix,
+          error = error or "unknown error",
+        })
         vim.notify(
           "Could not resolve home directory, attempting mount anyway: " .. (error or "unknown error"),
           vim.log.levels.WARN
@@ -127,20 +162,36 @@ end
 --- @param callback function Callback function(result: table) - result has fields: success, message, resolved_path
 function Sshfs.authenticate_and_mount(host, mount_point, remote_path_suffix, callback)
   local Ssh = require("sshfs.lib.ssh")
+  Logger.debug("Starting SSH authentication and mount", {
+    host = host.name,
+    user = host.user,
+    port = host.port,
+    remote_path = remote_path_suffix,
+    mount_point = mount_point,
+  })
   vim.notify("Connecting to " .. host.name .. "...", vim.log.levels.INFO)
 
   -- Try batch connection (non-interactive)
   Ssh.try_batch_connect(host.name, function(success, exit_code, error)
     if success then
+      Logger.debug("Batch authentication succeeded; mounting via socket", { host = host.name })
       mount_via_socket(host, mount_point, remote_path_suffix, callback)
       return
     end
 
     -- Batch failed, try interactive terminal
+    Logger.debug("Batch authentication failed; falling back to interactive authentication", {
+      host = host.name,
+      exit_code = exit_code,
+      error = error,
+    })
+
     Ssh.open_auth_terminal(host.name, function(term_success, term_exit_code)
       if term_success then
+        Logger.debug("Interactive authentication succeeded; mounting via socket", { host = host.name })
         mount_via_socket(host, mount_point, remote_path_suffix, callback)
       else
+        Logger.error("SSH authentication failed", { host = host.name, exit_code = term_exit_code })
         callback({
           success = false,
           message = string.format("SSH authentication failed for %s (exit code: %d)", host.name, term_exit_code),

From 7beb69214fea48b24f784ce8419a710c821525aa Mon Sep 17 00:00:00 2001
From: Robert Hill <robert.hill@uphillsolutions.tech>
Date: Sun, 30 Aug 2026 23:51:02 -0400
Subject: [PATCH 2/4] fix: make the logger safe before setup and normalize
 escaping

Logger.is_enabled and Logger.path could be reached before Config.setup
had populated Config.options, which would index a nil config. Tolerate a
missing configuration, parenthesize escape_log_value so the gsub match
count is not returned to callers, and export App.debug alongside the
other API entry points.
---
 lua/sshfs/init.lua       | 1 +
 lua/sshfs/lib/logger.lua | 9 +++++++--
 2 files changed, 8 insertions(+), 2 deletions(-)

diff --git a/lua/sshfs/init.lua b/lua/sshfs/init.lua
index 6243d51..d05de47 100644
--- a/lua/sshfs/init.lua
+++ b/lua/sshfs/init.lua
@@ -87,5 +87,6 @@ App.explore = Api.explore
 App.change_dir = Api.change_dir
 App.ssh_terminal = Api.ssh_terminal
 App.command = Api.command
+App.debug = Api.debug
 
 return App
diff --git a/lua/sshfs/lib/logger.lua b/lua/sshfs/lib/logger.lua
index 97fea85..04294cb 100644
--- a/lua/sshfs/lib/logger.lua
+++ b/lua/sshfs/lib/logger.lua
@@ -6,12 +6,17 @@ local runtime_enabled = nil
 local last_write_error = nil
 
 local function get_config()
-  local config = require("sshfs.config").get()
+  -- Logging can be reached before Config.setup() has run, so tolerate no config.
+  local ok, config = pcall(function()
+    return require("sshfs.config").get()
+  end)
+  if not ok or type(config) ~= "table" then return {} end
   return config.debug or {}
 end
 
 local function escape_log_value(value)
-  return tostring(value):gsub("\r", "\\r"):gsub("\n", "\\n"):gsub("\t", "\\t")
+  -- Parenthesized so the gsub match count is not returned to callers.
+  return (tostring(value):gsub("\r", "\\r"):gsub("\n", "\\n"):gsub("\t", "\\t"))
 end
 
 local function ensure_parent_dir(path)

From ee0f4194cbcbfe70bc73b29d5abbd58570708a87 Mon Sep 17 00:00:00 2001
From: Robert Hill <robert.hill@uphillsolutions.tech>
Date: Mon, 31 Aug 2026 00:22:32 -0400
Subject: [PATCH 3/4] test: add debug logging regression coverage

Adds regression coverage for the logging introduced here, on top of the
shared harness.

Covers the gate: nothing is written while logging is off, not even the
file, and the logger tolerates being reached before setup has run.
Covers runtime toggling through :SSHDebug in all four argument forms,
including that an unknown argument changes nothing and that toggling
never rewrites user configuration.

Covers the record format: timestamp, level, message, context rendered
in a stable order, multi-line subprocess output escaped onto a single
line, appending across calls, log directory creation, and owner-only
file permissions, since logs can carry hostnames and SSH output.
Covers write failures being reported once rather than on every call and
never raising out of the caller.

Covers what a connection attempt actually records: the mount attempt,
the exit code and stderr of a failed mount, the fallback from batch to
interactive authentication with its SSH reason, and an authentication
failure, plus that none of it is written when logging is off.

Refs #24
---
 tests/debug_instrumentation_spec.lua | 114 ++++++++++++
 tests/logger_spec.lua                | 249 +++++++++++++++++++++++++++
 2 files changed, 363 insertions(+)
 create mode 100644 tests/debug_instrumentation_spec.lua
 create mode 100644 tests/logger_spec.lua

diff --git a/tests/debug_instrumentation_spec.lua b/tests/debug_instrumentation_spec.lua
new file mode 100644
index 0000000..6438c88
--- /dev/null
+++ b/tests/debug_instrumentation_spec.lua
@@ -0,0 +1,114 @@
+-- tests/debug_instrumentation_spec.lua
+-- What debug logging actually records for a connection attempt
+--
+-- Issue #9 was hard to diagnose because subprocess details were discarded.
+-- These cover that the details survive when logging is on, and that nothing is
+-- recorded when it is off.
+
+--- Run a connection attempt with logging configured, returning the log lines
+--- @param opts table {enabled, batch_success, mount_code, mount_stderr}
+--- @return table lines
+local function connect_and_read_log(opts)
+  stub.reload()
+  local log_path = vim.fn.tempname() .. "/sshfs.nvim.log"
+  require("sshfs.config").setup({ debug = { enabled = opts.enabled, log_file = log_path } })
+
+  package.loaded["sshfs.lib.ssh"] = {
+    try_batch_connect = function(_, callback)
+      callback(opts.batch_success or false, opts.batch_success and 0 or 255, "Permission denied (publickey).")
+    end,
+    open_auth_terminal = function(_, callback)
+      callback(false, 1)
+    end,
+    build_command_string = function()
+      return "ssh"
+    end,
+  }
+
+  stub.notifications()
+  stub.set("schedule", function(fn)
+    fn()
+  end)
+  stub.set("system", function(_, _, callback)
+    local result = { code = opts.mount_code or 0, stdout = "", stderr = opts.mount_stderr or "" }
+    if callback then callback(result) end
+    return {
+      wait = function()
+        return result
+      end,
+    }
+  end)
+
+  require("sshfs.lib.sshfs").authenticate_and_mount(
+    { name = "example.com", user = "deploy" },
+    "/home/tester/mnt/example",
+    "/srv/app",
+    function() end
+  )
+  stub.restore_all()
+
+  local lines = vim.fn.filereadable(log_path) == 1 and vim.fn.readfile(log_path) or {}
+  vim.fn.delete(vim.fn.fnamemodify(log_path, ":h"), "rf")
+  return lines
+end
+
+--- Find the first log line containing a substring
+local function line_with(lines, needle)
+  for _, line in ipairs(lines) do
+    if line:find(needle, 1, true) then return line end
+  end
+  return nil
+end
+
+describe("connection diagnostics with logging enabled", function()
+  it("records the mount attempt with its host and target", function()
+    local lines = connect_and_read_log({ enabled = true, batch_success = true })
+    local line = line_with(lines, "Starting SSHFS mount")
+
+    expect.truthy(line, "the mount attempt must be recorded")
+    expect.contains(line, "host=example.com")
+    expect.contains(line, "mount_point=/home/tester/mnt/example")
+  end)
+
+  it("records the exit code and stderr of a failed mount", function()
+    local lines = connect_and_read_log({
+      enabled = true,
+      batch_success = true,
+      mount_code = 1,
+      mount_stderr = "read: Connection reset by peer",
+    })
+    local line = line_with(lines, "SSHFS mount failed")
+
+    expect.truthy(line)
+    expect.contains(line, "exit_code=1")
+    expect.contains(line, "Connection reset by peer")
+  end)
+
+  it("records the fallback from batch to interactive authentication", function()
+    local lines = connect_and_read_log({ enabled = true, batch_success = false })
+
+    expect.truthy(line_with(lines, "falling back to interactive authentication"))
+    expect.truthy(line_with(lines, "Permission denied"), "the SSH reason must be preserved")
+  end)
+
+  it("records an authentication failure", function()
+    local lines = connect_and_read_log({ enabled = true, batch_success = false })
+    local line = line_with(lines, "SSH authentication failed")
+
+    expect.truthy(line)
+    expect.contains(line, "[ERROR]")
+  end)
+end)
+
+describe("connection diagnostics with logging disabled", function()
+  it("records nothing at all", function()
+    local lines = connect_and_read_log({
+      enabled = false,
+      batch_success = true,
+      mount_code = 1,
+      mount_stderr = "read: Connection reset by peer",
+    })
+
+    expect.eq(lines, {}, "normal usage must not write a log file")
+  end)
+end)
diff --git a/tests/logger_spec.lua b/tests/logger_spec.lua
new file mode 100644
index 0000000..6cc75dd
--- /dev/null
+++ b/tests/logger_spec.lua
@@ -0,0 +1,249 @@
+-- tests/logger_spec.lua
+-- Opt-in debug logging: gating, formatting, and runtime toggling
+
+--- Load the logger against a temporary log file
+--- @param debug_config table|nil Value for the `debug` configuration table
+--- @return table Logger, string log_path
+local function load_logger(debug_config)
+  stub.reload()
+  local log_path = vim.fn.tempname() .. "/sshfs.nvim.log"
+  if debug_config then debug_config.log_file = debug_config.log_file or log_path end
+  require("sshfs.config").setup({ debug = debug_config })
+  return require("sshfs.lib.logger"), log_path
+end
+
+--- Read a log file, returning an empty list when it was never created
+local function read_log(path)
+  if vim.fn.filereadable(path) == 0 then return {} end
+  return vim.fn.readfile(path)
+end
+
+local function cleanup(path)
+  vim.fn.delete(vim.fn.fnamemodify(path, ":h"), "rf")
+end
+
+describe("debug logging gate", function()
+  it("writes nothing at all while disabled", function()
+    local Logger, log_path = load_logger({ enabled = false })
+
+    Logger.debug("a message")
+    Logger.error("another message")
+
+    expect.eq(vim.fn.filereadable(log_path), 0, "a disabled logger must not even create the file")
+    cleanup(log_path)
+  end)
+
+  it("writes when enabled through configuration", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.debug("a message")
+
+    expect.eq(#read_log(log_path), 1)
+    cleanup(log_path)
+  end)
+
+  it("is disabled by default", function()
+    stub.reload()
+    require("sshfs.config").setup({})
+
+    expect.falsy(require("sshfs.lib.logger").is_enabled())
+  end)
+
+  it("does not raise when used before setup has run", function()
+    stub.reload()
+    local Logger = require("sshfs.lib.logger")
+
+    expect.no_error(function()
+      Logger.is_enabled()
+    end, "configuration may not exist yet")
+    expect.no_error(function()
+      Logger.path()
+    end)
+  end)
+end)
+
+describe("runtime toggling", function()
+  it("enables logging without rewriting configuration", function()
+    local Logger, log_path = load_logger({ enabled = false })
+
+    expect.truthy(Logger.toggle())
+    Logger.debug("now recorded")
+
+    expect.eq(#read_log(log_path), 1)
+    expect.falsy(require("sshfs.config").get().debug.enabled, "user configuration stays untouched")
+    cleanup(log_path)
+  end)
+
+  it("disables logging that configuration had enabled", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.disable()
+    Logger.debug("not recorded")
+
+    expect.eq(read_log(log_path), {})
+    cleanup(log_path)
+  end)
+
+  it("toggles back and forth", function()
+    local Logger, log_path = load_logger({ enabled = false })
+
+    expect.truthy(Logger.toggle())
+    expect.falsy(Logger.toggle())
+    expect.truthy(Logger.toggle())
+    cleanup(log_path)
+  end)
+
+  it("reports the active log path", function()
+    local Logger, log_path = load_logger({ enabled = true })
+    expect.eq(Logger.path(), log_path)
+    cleanup(log_path)
+  end)
+end)
+
+describe("log formatting", function()
+  it("records a timestamp, level, and message", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.warn("something happened")
+    local line = read_log(log_path)[1]
+
+    expect.truthy(line:match("^%d%d%d%d%-%d%d%-%d%d %d%d:%d%d:%d%d %[WARN%] something happened$"), line)
+    cleanup(log_path)
+  end)
+
+  it("renders context in a stable order", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.debug("mount", { host = "example.com", exit_code = 1, mount_point = "/mnt/x" })
+    local line = read_log(log_path)[1]
+
+    expect.contains(line, "exit_code=1 host=example.com mount_point=/mnt/x")
+    cleanup(log_path)
+  end)
+
+  it("keeps multi-line subprocess output on one line", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.error("mount failed", { stderr = "first line\nsecond line\twith a tab" })
+    local log = read_log(log_path)
+
+    expect.eq(#log, 1, "an embedded newline must not split the record")
+    expect.contains(log[1], "stderr=first line\\nsecond line\\twith a tab")
+    cleanup(log_path)
+  end)
+
+  it("appends rather than truncating", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.debug("first")
+    Logger.debug("second")
+
+    expect.eq(#read_log(log_path), 2)
+    cleanup(log_path)
+  end)
+
+  it("creates the log directory when it does not exist", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.debug("first")
+
+    expect.eq(vim.fn.isdirectory(vim.fn.fnamemodify(log_path, ":h")), 1)
+    cleanup(log_path)
+  end)
+
+  it("writes the log file readable only by its owner", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.debug("sensitive output")
+    local mode = vim.fn.getfperm(log_path)
+
+    expect.eq(mode, "rw-------", "logs can contain hostnames and SSH output")
+    cleanup(log_path)
+  end)
+end)
+
+describe("log write failures", function()
+  it("reports a write failure once rather than on every call", function()
+    local Logger = load_logger({ enabled = true, log_file = "/proc/definitely-not-writable/sshfs.log" })
+    local notifications = stub.notifications()
+    -- The failure notice is scheduled onto the event loop; run it inline.
+    stub.set("schedule", function(fn)
+      fn()
+    end)
+
+    Logger.debug("first")
+    Logger.debug("second")
+    Logger.debug("third")
+    stub.restore_all()
+
+    expect.eq(#notifications, 1, "a broken log path must not spam the user")
+    expect.contains(notifications[1].message, "failed to write debug log")
+  end)
+
+  it("does not raise out of the caller", function()
+    local Logger = load_logger({ enabled = true, log_file = "/proc/definitely-not-writable/sshfs.log" })
+    stub.notifications()
+    stub.set("schedule", function(fn)
+      fn()
+    end)
+
+    expect.no_error(function()
+      Logger.debug("a message")
+    end, "logging is diagnostic and must never break the operation it describes")
+    stub.restore_all()
+  end)
+end)
+
+describe(":SSHDebug", function()
+  local function run_debug(mode)
+    stub.reload()
+    local log_path = vim.fn.tempname() .. "/sshfs.nvim.log"
+    require("sshfs.config").setup({ debug = { enabled = false, log_file = log_path } })
+    local notifications = stub.notifications()
+
+    require("sshfs.api").debug(mode)
+    local enabled = require("sshfs.lib.logger").is_enabled()
+    stub.restore_all()
+    cleanup(log_path)
+
+    return enabled, notifications
+  end
+
+  it("toggles when given no argument", function()
+    local enabled, notifications = run_debug(nil)
+
+    expect.truthy(enabled)
+    expect.contains(notifications[1].message, "enabled")
+  end)
+
+  it("treats an empty argument as a toggle", function()
+    expect.truthy(run_debug(""))
+  end)
+
+  it("enables explicitly with on", function()
+    local enabled, notifications = run_debug("on")
+
+    expect.truthy(enabled)
+    expect.contains(notifications[1].message, "enabled")
+  end)
+
+  it("disables explicitly with off", function()
+    local enabled, notifications = run_debug("off")
+
+    expect.falsy(enabled)
+    expect.contains(notifications[1].message, "disabled")
+  end)
+
+  it("reports the log path so the user can find it", function()
+    local _, notifications = run_debug("on")
+    expect.contains(notifications[1].message, "sshfs.nvim.log")
+  end)
+
+  it("rejects an unknown argument without changing state", function()
+    local enabled, notifications = run_debug("maybe")
+
+    expect.falsy(enabled)
+    expect.contains(notifications[1].message, "Usage: :SSHDebug [on|off]")
+    expect.eq(notifications[1].level, vim.log.levels.ERROR)
+  end)
+end)

From 74ba38d6207d43e39d5b1a4bac3e06e421202161 Mon Sep 17 00:00:00 2001
From: Robert Hill <robert.hill@uphillsolutions.tech>
Date: Thu, 10 Sep 2026 21:40:59 -0400
Subject: [PATCH 4/4] fix(logger): escape control bytes and cap log growth

Remote stderr was written to the log verbatim, so a hostile server could
plant terminal escape sequences that fire when the file is read. The log
also grew without limit, and the four command-line call sites paid for
their context string even with logging off.
---
 README.md                |  1 +
 docs/debug-logging.md    |  3 ++
 lua/sshfs/config.lua     |  1 +
 lua/sshfs/lib/logger.lua | 23 ++++++++++-
 lua/sshfs/lib/ssh.lua    | 16 ++++++--
 tests/logger_spec.lua    | 87 ++++++++++++++++++++++++++++++++++++++++
 6 files changed, 125 insertions(+), 6 deletions(-)

diff --git a/README.md b/README.md
index 20d50df..92f0906 100644
--- a/README.md
+++ b/README.md
@@ -264,6 +264,7 @@ require("sshfs").setup({
   debug = {
     enabled = false,              -- write SSH/SSHFS diagnostics to a log file
     log_file = vim.fn.stdpath("log") .. "/sshfs.nvim.log",
+    max_size = 1048576,           -- rotate to <log_file>.1 past this size (0 disables)
   },
   lead_prefix = "<leader>m",      -- change keymap prefix (default: <leader>m)
   keymaps = {
diff --git a/docs/debug-logging.md b/docs/debug-logging.md
index b9ad828..a5b6589 100644
--- a/docs/debug-logging.md
+++ b/docs/debug-logging.md
@@ -7,10 +7,13 @@ require("sshfs").setup({
   debug = {
     enabled = true,
     log_file = vim.fn.stdpath("log") .. "/sshfs.nvim.log",
+    max_size = 1048576,
   },
 })
 ```
 
+Once the log passes `max_size` bytes it is moved to `<log_file>.1` and a fresh file is started, so only the last two generations are kept. Set `max_size = 0` to disable rotation and let the file grow.
+
 You can also change debug logging for the current Neovim session without changing configuration:
 
 ```vim
diff --git a/lua/sshfs/config.lua b/lua/sshfs/config.lua
index d762136..7debd64 100644
--- a/lua/sshfs/config.lua
+++ b/lua/sshfs/config.lua
@@ -85,6 +85,7 @@ local DEFAULT_CONFIG = {
 	debug = {
 		enabled = false,                   -- Enable debug logging
 		log_file = vim.fn.stdpath("log") .. "/sshfs.nvim.log", -- Debug log destination
+		max_size = 1048576,                 -- Rotate the log to .1 once it passes this many bytes
 	},
 	keymaps = nil,                      -- Override individual keymaps (e.g., {mount = "<leader>mm", unmount = "<leader>mu"})
 	lead_prefix = "<leader>m",          -- Prefix for default keymaps
diff --git a/lua/sshfs/lib/logger.lua b/lua/sshfs/lib/logger.lua
index 04294cb..e56752c 100644
--- a/lua/sshfs/lib/logger.lua
+++ b/lua/sshfs/lib/logger.lua
@@ -14,9 +14,15 @@ local function get_config()
   return config.debug or {}
 end
 
+local NAMED_ESCAPES = { ["\r"] = "\\r", ["\n"] = "\\n", ["\t"] = "\\t" }
+
 local function escape_log_value(value)
-  -- Parenthesized so the gsub match count is not returned to callers.
-  return (tostring(value):gsub("\r", "\\r"):gsub("\n", "\\n"):gsub("\t", "\\t"))
+  -- Remote output reaches this file, so no control byte may survive to a terminal.
+  return (
+    tostring(value):gsub("%c", function(char)
+      return NAMED_ESCAPES[char] or string.format("\\x%02x", char:byte())
+    end)
+  )
 end
 
 local function ensure_parent_dir(path)
@@ -27,6 +33,15 @@ local function ensure_parent_dir(path)
   end
 end
 
+--- Move the log aside once it passes max_size, keeping a single previous generation
+local function rotate_if_needed(path, max_size)
+  if not max_size or max_size <= 0 then return end
+
+  local uv = vim.uv or vim.loop
+  local stat = uv.fs_stat(path)
+  if stat and stat.size >= max_size then uv.fs_rename(path, path .. ".1") end
+end
+
 local function write_log_line(path, line)
   local uv = vim.uv or vim.loop
   local fd, open_err = uv.fs_open(path, "a", 384)
@@ -99,6 +114,9 @@ end
 function Logger.log(level, message, context)
   if not Logger.is_enabled() then return end
 
+  -- Callers pass a builder when the context costs something to assemble.
+  if type(context) == "function" then context = context() end
+
   local path = Logger.path()
   local line = string.format(
     "%s [%s] %s%s",
@@ -110,6 +128,7 @@ function Logger.log(level, message, context)
 
   local ok, result = pcall(function()
     ensure_parent_dir(path)
+    rotate_if_needed(path, get_config().max_size)
     write_log_line(path, line)
   end)
 
diff --git a/lua/sshfs/lib/ssh.lua b/lua/sshfs/lib/ssh.lua
index f1e2829..9913112 100644
--- a/lua/sshfs/lib/ssh.lua
+++ b/lua/sshfs/lib/ssh.lua
@@ -226,7 +226,9 @@ end
 ---@param callback function Callback(home_path: string|nil, error: string|nil)
 function Ssh.get_remote_home(host, callback)
   local cmd = Ssh.build_home_command(host)
-  Logger.debug("Resolving remote home", { host = host_label(host), command = table.concat(cmd, " ") })
+  Logger.debug("Resolving remote home", function()
+    return { host = host_label(host), command = table.concat(cmd, " ") }
+  end)
 
   -- Execute asynchronously
   vim.system(cmd, { text = true }, function(obj)
@@ -260,7 +262,9 @@ end
 function Ssh.cleanup_control_master(host)
   -- Execute synchronously (must complete before nvim exit)
   local cmd = Ssh.build_control_command(host, "exit")
-  Logger.debug("Closing SSH ControlMaster", { host = host_label(host), command = table.concat(cmd, " ") })
+  Logger.debug("Closing SSH ControlMaster", function()
+    return { host = host_label(host), command = table.concat(cmd, " ") }
+  end)
   local output = vim.fn.system(cmd)
   Logger.debug("SSH ControlMaster cleanup completed", {
     host = host_label(host),
@@ -287,7 +291,9 @@ function Ssh.try_batch_connect(host, callback)
 
   -- Build and execute the batch command asynchronously
   local cmd = Ssh.build_batch_command(host)
-  Logger.debug("Starting batch SSH authentication", { host = host_label(host), command = table.concat(cmd, " ") })
+  Logger.debug("Starting batch SSH authentication", function()
+    return { host = host_label(host), command = table.concat(cmd, " ") }
+  end)
   vim.system(cmd, { text = true }, function(obj)
     vim.schedule(function()
       local success = obj.code == 0
@@ -326,7 +332,9 @@ function Ssh.open_auth_terminal(host, callback)
   local cmd = Ssh.build_auth_command(host_obj)
 
   -- Open authentication terminal window
-  Logger.debug("Opening interactive SSH authentication", { host = host_label(host), command = table.concat(cmd, " ") })
+  Logger.debug("Opening interactive SSH authentication", function()
+    return { host = host_label(host), command = table.concat(cmd, " ") }
+  end)
   local Terminal = require("sshfs.ui.terminal")
   Terminal.open_auth_floating(cmd, host_obj.name, function(success, exit_code)
     Logger.debug("Interactive SSH authentication completed", {
diff --git a/tests/logger_spec.lua b/tests/logger_spec.lua
index 6cc75dd..80a1cd2 100644
--- a/tests/logger_spec.lua
+++ b/tests/logger_spec.lua
@@ -247,3 +247,90 @@ describe(":SSHDebug", function()
     expect.eq(notifications[1].level, vim.log.levels.ERROR)
   end)
 end)
+
+describe("control byte escaping", function()
+  it("escapes an ANSI escape sequence from remote output", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.debug("remote said", { stderr = "\27[2Jcleared\7" })
+    local line = read_log(log_path)[1]
+    cleanup(log_path)
+
+    expect.truthy(line, "the line must be written")
+    expect.is_nil(line:find("\27", 1, true), "no raw escape byte may reach the log")
+    expect.is_nil(line:find("\7", 1, true), "no raw bell byte may reach the log")
+    expect.contains(line, "\\x1b[2Jcleared\\x07")
+  end)
+
+  it("keeps the readable names for the common whitespace bytes", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    Logger.debug("whitespace", { value = "a\r\nb\tc" })
+    local line = read_log(log_path)[1]
+    cleanup(log_path)
+
+    expect.contains(line, "a\\r\\nb\\tc")
+  end)
+end)
+
+describe("log rotation", function()
+  it("moves the log aside once it passes max_size", function()
+    local Logger, log_path = load_logger({ enabled = true, max_size = 200 })
+
+    for index = 1, 40 do
+      Logger.debug("filling the log", { index = index })
+    end
+    local rotated = log_path .. ".1"
+    local current_lines = #read_log(log_path)
+    local rotated_lines = #read_log(rotated)
+    cleanup(log_path)
+
+    expect.truthy(rotated_lines > 0, "the previous generation must be kept")
+    expect.truthy(current_lines > 0, "logging must continue after a rotation")
+    expect.truthy(current_lines < 40, "the current log must not still hold every line")
+  end)
+
+  it("never rotates when max_size is unset", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    for index = 1, 20 do
+      Logger.debug("filling the log", { index = index })
+    end
+    local current_lines = #read_log(log_path)
+    local rotated_exists = vim.fn.filereadable(log_path .. ".1")
+    cleanup(log_path)
+
+    expect.eq(current_lines, 20)
+    expect.eq(rotated_exists, 0)
+  end)
+end)
+
+describe("lazy context", function()
+  it("skips the builder entirely while disabled", function()
+    local Logger, log_path = load_logger({ enabled = false })
+
+    local built = 0
+    Logger.debug("expensive", function()
+      built = built + 1
+      return { value = "assembled" }
+    end)
+    cleanup(log_path)
+
+    expect.eq(built, 0, "a disabled logger must not pay for its context")
+  end)
+
+  it("calls the builder and logs its table while enabled", function()
+    local Logger, log_path = load_logger({ enabled = true })
+
+    local built = 0
+    Logger.debug("expensive", function()
+      built = built + 1
+      return { value = "assembled" }
+    end)
+    local line = read_log(log_path)[1]
+    cleanup(log_path)
+
+    expect.eq(built, 1)
+    expect.contains(line, "value=assembled")
+  end)
+end)