fix(log): set log settings immediately, fix no-op logic (#1881)

Author: pynappo

lua/neo-tree.lua

@@ -109,6 +109,10 @@ end
 M.setup = function(config)
   -- merging is deferred until ensure_config
   new_user_config = config
+  if new_user_config.log_level ~= nil then
+    M.set_log_level(new_user_config.log_level)
+  end
+  require("neo-tree.log").use_file(new_user_config.log_to_file, true)
   if vim.v.vim_did_enter == 0 then
     try_netrw_hijack(vim.fn.argv(0) --[[@as string]])
   end

lua/neo-tree/log.lua

@@ -80,9 +80,8 @@ local log_maker = {}
 
 ---@class (partial) neotree.Logger.PartialConfig : neotree.Logger.Config
 ---@param config neotree.Logger.PartialConfig|neotree.Logger.Config
----@param parent neotree.Logger?
 ---@return neotree.Logger
-log_maker.new = function(config, parent)
+log_maker.new = function(config)
   ---@class neotree.Logger
   local log = {}
   ---@diagnostic disable-next-line: cast-local-type
@@ -187,7 +186,7 @@ log_maker.new = function(config, parent)
   ---@param log_level vim.log.levels
   ---@param message_maker fun(...):string
   local logfunc = function(log_level, message_maker)
-    if log_level > log.minimum_level.file and log_level > log.minimum_level.console then
+    if log_level < log.minimum_level.file and log_level < log.minimum_level.console then
       return function() end
     end
     local level_config = config.level_configs[log_level]
@@ -220,15 +219,17 @@ log_maker.new = function(config, parent)
     ---@param lvl neotree.Log.Level
     ---@return vim.log.levels
     local to_loglevel = function(lvl)
+      if type(lvl) == "number" then
+        return lvl
+      end
+
       if type(lvl) == "string" then
         local levelupper = lvl:upper()
         for name, level_num in pairs(Levels) do
           if levelupper == name then
             return level_num
           end
         end
-      elseif type(lvl) == "number" then
-        return lvl
       end
       notify("Couldn't resolve log level " .. lvl .. "defaulting to log level INFO", Levels.WARN)
       return Levels.INFO
@@ -287,33 +288,37 @@ log_maker.new = function(config, parent)
   ---@return boolean using_file
   log.use_file = function(file, quiet)
     if file == false then
+      config.use_file = false
       if not quiet then
         log.info("Logging to file disabled")
       end
+      return config.use_file
+    end
+    log.outfile = type(file) == "string" and file or initial_filepath
+    local fp, err = io.open(log.outfile, "a+")
+
+    if not fp then
       config.use_file = false
-    else
-      if type(file) == "string" then
-        log.outfile = file
-      else
-        log.outfile = initial_filepath
-      end
-      local fp = io.open(log.outfile, "a+")
-      if fp then
-        local new_logfile_ino = assert(uv.fs_stat(log.outfile)).ino
-        if new_logfile_ino ~= current_logfile_inode then
-          -- the fp is pointing to a new/different file than previously
-          log.file = fp
-          log.file:setvbuf("line")
-          current_logfile_inode = new_logfile_ino
-        end
-        config.use_file = true
-        if not quiet then
-          log.info("Logging to file:", log.outfile)
-        end
-      else
-        config.use_file = false
-        log.warn("Could not open log file:", log.outfile)
-      end
+      log.warn("Could not open log file:", log.outfile, err)
+      return config.use_file
+    end
+
+    local stat, stat_err = uv.fs_stat(log.outfile)
+    if not stat then
+      config.use_file = false
+      log.warn("Could not stat log file:", log.outfile, stat_err)
+      return config.use_file
+    end
+
+    if stat.ino ~= current_logfile_inode then
+      -- the fp is pointing to a different file
+      log.file = fp
+      log.file:setvbuf("line")
+      current_logfile_inode = stat.ino
+    end
+    config.use_file = true
+    if not quiet then
+      log.info("Logging to file:", log.outfile)
     end
     return config.use_file
   end
@@ -353,8 +358,7 @@ log_maker.new = function(config, parent)
         "force",
         config,
         { context = vim.list_extend({ new_context }, { context }) }
-      ),
-      log
+      )
     )
   end
 

lua/neo-tree/setup/init.lua

@@ -428,10 +428,6 @@ M.merge_config = function(user_config)
     end, 50)
   end
 
-  if user_config.log_level ~= nil then
-    M.set_log_level(user_config.log_level)
-  end
-  log.use_file(user_config.log_to_file, true)
   log.debug("setup")
 
   if events_setup then

tests/neo-tree/log_spec.lua

@@ -0,0 +1,49 @@
+local log = require("neo-tree.log")
+local debug_locals = function(lvl)
+  local i = 1
+  local results = {}
+  while true do
+    local name, value = debug.getlocal(lvl, i)
+    if not name then
+      return results
+    end
+    results[#results + 1] = { name = name, value = value }
+    i = i + 1
+  end
+end
+describe("File logging", function()
+  it("should get correct debug info", function()
+    require("neo-tree").setup({
+      log_to_file = true,
+      log_level = {
+        console = vim.log.levels.OFF,
+        file = vim.log.levels.INFO,
+      },
+    })
+    local expected = debug.getinfo(1, "Sln")
+    local check_getinfo_at_format = false
+    local debug_getinfo_hook = function(...)
+      local running_func = debug.getinfo(2, "Sln")
+
+      if running_func.name == "getinfo" then
+        check_getinfo_at_format = true
+      elseif check_getinfo_at_format and running_func.name == "format" then
+        for _, localinfo in ipairs(debug_locals(4)) do
+          local actual = localinfo.value
+          if type(actual) == "table" then
+            if actual.lastlinedefined then
+              ---@cast actual debuginfo
+              assert(
+                actual.lastlinedefined == expected.lastlinedefined
+                  and actual.source == expected.source
+              )
+            end
+          end
+        end
+        debug.sethook()
+      end
+    end
+    debug.sethook(debug_getinfo_hook, "cl")
+    log.info("")
+  end)
+end)