From 5aa76a5bb6ab6ec417e244e39192c800ba22a922 Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 5 Feb 2023 13:55:10 +1100 Subject: [PATCH 1/8] fix(#1970): additional log function gating for efficiency when not logging --- lua/nvim-tree.lua | 6 +++-- lua/nvim-tree/actions/init.lua | 6 +++-- lua/nvim-tree/git/runner.lua | 2 +- lua/nvim-tree/git/utils.lua | 8 +++++-- lua/nvim-tree/log.lua | 42 +++++++++++++++++++++++----------- 5 files changed, 44 insertions(+), 20 deletions(-) diff --git a/lua/nvim-tree.lua b/lua/nvim-tree.lua index 22a9446c7df..507855b77cc 100644 --- a/lua/nvim-tree.lua +++ b/lua/nvim-tree.lua @@ -880,8 +880,10 @@ function M.setup(conf) require("nvim-tree.notify").setup(opts) require("nvim-tree.log").setup(opts) - log.line("config", "default config + user") - log.raw("config", "%s\n", vim.inspect(opts)) + if log.enabled "config" then + log.line("config", "default config + user") + log.raw("config", "%s\n", vim.inspect(opts)) + end require("nvim-tree.actions").setup(opts) require("nvim-tree.keymap").setup(opts) diff --git a/lua/nvim-tree/actions/init.lua b/lua/nvim-tree/actions/init.lua index 7a9fad21e79..868ee0a502c 100644 --- a/lua/nvim-tree/actions/init.lua +++ b/lua/nvim-tree/actions/init.lua @@ -437,8 +437,10 @@ function M.setup(opts) require("nvim-tree.actions.dispatch").setup(M.custom_keypress_funcs) - log.line("config", "active mappings") - log.raw("config", "%s\n", vim.inspect(M.mappings)) + if log.enabled "config" then + log.line("config", "active mappings") + log.raw("config", "%s\n", vim.inspect(M.mappings)) + end end return M diff --git a/lua/nvim-tree/git/runner.lua b/lua/nvim-tree/git/runner.lua index 7a12894d009..ee9328301e8 100644 --- a/lua/nvim-tree/git/runner.lua +++ b/lua/nvim-tree/git/runner.lua @@ -59,7 +59,7 @@ function Runner:_getopts(stdout_handle, stderr_handle) end function Runner:_log_raw_output(output) - if output and type(output) == "string" then + if log.enabled "git" and output and type(output) == "string" then log.raw("git", "%s", output) log.line("git", "done") end diff --git a/lua/nvim-tree/git/utils.lua b/lua/nvim-tree/git/utils.lua index e14cdafca40..b4cc6cc4bbb 100644 --- a/lua/nvim-tree/git/utils.lua +++ b/lua/nvim-tree/git/utils.lua @@ -11,7 +11,9 @@ function M.get_toplevel(cwd) local toplevel = vim.fn.system(cmd) - log.raw("git", toplevel) + if log.enabled "git" then + log.raw("git", toplevel) + end log.profile_end(ps, "git toplevel %s", cwd) if vim.v.shell_error ~= 0 or not toplevel or #toplevel == 0 or toplevel:match "fatal" then @@ -48,7 +50,9 @@ function M.should_show_untracked(cwd) local has_untracked = vim.fn.system(cmd) - log.raw("git", has_untracked) + if log.enabled "git" then + log.raw("git", has_untracked) + end log.profile_end(ps, "git untracked %s", cwd) untracked[cwd] = vim.trim(has_untracked) ~= "no" diff --git a/lua/nvim-tree/log.lua b/lua/nvim-tree/log.lua index 9f035bad810..2a17168fac3 100644 --- a/lua/nvim-tree/log.lua +++ b/lua/nvim-tree/log.lua @@ -8,7 +8,7 @@ local M = { --- @param fmt string for string.format --- @vararg any arguments for string.format function M.raw(typ, fmt, ...) - if not M.path or not M.config.types[typ] and not M.config.types.all then + if not M.enabled(typ) then return end @@ -21,32 +21,48 @@ function M.raw(typ, fmt, ...) end end ---- Write to log file via M.line +--- Write profile start to log file --- START is prefixed +--- @param fmt string for string.format +--- @vararg any arguments for string.format --- @return number nanos to pass to profile_end function M.profile_start(fmt, ...) - if not M.path or not M.config.types.profile and not M.config.types.all then + if M.enabled "profile" then + M.line("profile", "START " .. (fmt or "???"), ...) + return vim.loop.hrtime() + else return 0 end - M.line("profile", "START " .. (fmt or "???"), ...) - return vim.loop.hrtime() end ---- Write to log file via M.line +--- Write profile end to log file --- END is prefixed and duration in seconds is suffixed --- @param start number nanos returned from profile_start +--- @param fmt string for string.format +--- @vararg any arguments for string.format function M.profile_end(start, fmt, ...) - if not M.path or not M.config.types.profile and not M.config.types.all then - return + if M.enabled "profile" then + local millis = start and math.modf((vim.loop.hrtime() - start) / 1000000) or -1 + M.line("profile", "END " .. (fmt or "???") .. " " .. millis .. "ms", ...) end - local millis = start and math.modf((vim.loop.hrtime() - start) / 1000000) or -1 - M.line("profile", "END " .. (fmt or "???") .. " " .. millis .. "ms", ...) end --- Write to log file via M.raw --- time and typ are prefixed and a trailing newline is added +--- Write to log file +--- time and typ are prefixed and a trailing newline is added +--- @param typ string as per log.types config +--- @param fmt string for string.format +--- @vararg any arguments for string.format function M.line(typ, fmt, ...) - M.raw(typ, string.format("[%s] [%s] %s\n", os.date "%Y-%m-%d %H:%M:%S", typ, fmt), ...) + if M.enabled(typ) then + M.raw(typ, string.format("[%s] [%s] %s\n", os.date "%Y-%m-%d %H:%M:%S", typ, fmt), ...) + end +end + +--- Logging is enabled for typ or all +--- @param typ string as per log.types config +--- @return boolean +function M.enabled(typ) + return M.path ~= nil and (M.config.types[typ] or M.config.types.all) end function M.setup(opts) From bb296c6e86eea327813034699af931e403858504 Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 5 Feb 2023 13:56:48 +1100 Subject: [PATCH 2/8] fix(#1970): additional log function gating for efficiency when not logging --- lua/nvim-tree/git/utils.lua | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/lua/nvim-tree/git/utils.lua b/lua/nvim-tree/git/utils.lua index b4cc6cc4bbb..e14cdafca40 100644 --- a/lua/nvim-tree/git/utils.lua +++ b/lua/nvim-tree/git/utils.lua @@ -11,9 +11,7 @@ function M.get_toplevel(cwd) local toplevel = vim.fn.system(cmd) - if log.enabled "git" then - log.raw("git", toplevel) - end + log.raw("git", toplevel) log.profile_end(ps, "git toplevel %s", cwd) if vim.v.shell_error ~= 0 or not toplevel or #toplevel == 0 or toplevel:match "fatal" then @@ -50,9 +48,7 @@ function M.should_show_untracked(cwd) local has_untracked = vim.fn.system(cmd) - if log.enabled "git" then - log.raw("git", has_untracked) - end + log.raw("git", has_untracked) log.profile_end(ps, "git untracked %s", cwd) untracked[cwd] = vim.trim(has_untracked) ~= "no" From b485698cbf7c57350ed3df999efde4bf311228eb Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 5 Feb 2023 14:26:33 +1100 Subject: [PATCH 3/8] fix(#1970): disable git integration after 10 timeouts --- doc/nvim-tree-lua.txt | 1 + lua/nvim-tree/git/init.lua | 7 +++++++ lua/nvim-tree/git/runner.lua | 4 ++++ 3 files changed, 12 insertions(+) diff --git a/doc/nvim-tree-lua.txt b/doc/nvim-tree-lua.txt index 5cdaad72bd1..e2c894d10bc 100644 --- a/doc/nvim-tree-lua.txt +++ b/doc/nvim-tree-lua.txt @@ -626,6 +626,7 @@ Git integration with icons and colors. *nvim-tree.git.timeout* Kills the git process after some time if it takes too long. + Git integration will be disabled after 10 git jobs exceed this timeout. Type: `number`, Default: `400` (ms) You will still need to set |renderer.icons.show.git| `= true` or diff --git a/lua/nvim-tree/git/init.lua b/lua/nvim-tree/git/init.lua index 7bf7f542d85..c5be4ef02f1 100644 --- a/lua/nvim-tree/git/init.lua +++ b/lua/nvim-tree/git/init.lua @@ -176,6 +176,13 @@ function M.purge_state() M.cwd_to_project_root = {} end +--- Disable git integration permanently +function M.disable_git_integration() + log.line("git", "disabling git integration") + M.purge_state() + M.config.git.enable = false +end + function M.setup(opts) M.config.git = opts.git M.config.filesystem_watchers = opts.filesystem_watchers diff --git a/lua/nvim-tree/git/runner.lua b/lua/nvim-tree/git/runner.lua index ee9328301e8..58e4902d8f2 100644 --- a/lua/nvim-tree/git/runner.lua +++ b/lua/nvim-tree/git/runner.lua @@ -1,9 +1,13 @@ local log = require "nvim-tree.log" local utils = require "nvim-tree.utils" +local notify = require "nvim-tree.notify" local Runner = {} Runner.__index = Runner +local timeouts = 0 +local MAX_TIMEOUTS = 5 + function Runner:_parse_status_output(status, path) -- replacing slashes if on windows if vim.fn.has "win32" == 1 then From 7cce0ed76f0aa9ce3148bc202695dca931a397d3 Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 5 Feb 2023 14:27:19 +1100 Subject: [PATCH 4/8] fix(#1970): disable git integration after 10 timeouts --- lua/nvim-tree/git/runner.lua | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/lua/nvim-tree/git/runner.lua b/lua/nvim-tree/git/runner.lua index 58e4902d8f2..75b07261a40 100644 --- a/lua/nvim-tree/git/runner.lua +++ b/lua/nvim-tree/git/runner.lua @@ -163,6 +163,11 @@ function Runner.run(opts) if self.rc == -1 then log.line("git", "job timed out %s %s", opts.project_root, opts.path) + timeouts = timeouts + 1 + if timeouts == MAX_TIMEOUTS then + notify.warn(string.format("%d git jobs have timed out after %dms, disabling git integration. Please consider increasing git.timeout", timeouts, opts.timeout)) + require "nvim-tree.git".disable_git_integration() + end elseif self.rc ~= 0 then log.line("git", "job fail rc %d %s %s", self.rc, opts.project_root, opts.path) else From 98407eef1c989400231ef5a095a45dc243898b83 Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 5 Feb 2023 14:45:44 +1100 Subject: [PATCH 5/8] fix(#1970): disable git integration after 10 timeouts --- lua/nvim-tree/git/runner.lua | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/lua/nvim-tree/git/runner.lua b/lua/nvim-tree/git/runner.lua index 75b07261a40..2774b9a41c6 100644 --- a/lua/nvim-tree/git/runner.lua +++ b/lua/nvim-tree/git/runner.lua @@ -165,8 +165,14 @@ function Runner.run(opts) log.line("git", "job timed out %s %s", opts.project_root, opts.path) timeouts = timeouts + 1 if timeouts == MAX_TIMEOUTS then - notify.warn(string.format("%d git jobs have timed out after %dms, disabling git integration. Please consider increasing git.timeout", timeouts, opts.timeout)) - require "nvim-tree.git".disable_git_integration() + notify.warn( + string.format( + "%d git jobs have timed out after %dms, disabling git integration. Please consider increasing git.timeout", + timeouts, + opts.timeout + ) + ) + require("nvim-tree.git").disable_git_integration() end elseif self.rc ~= 0 then log.line("git", "job fail rc %d %s %s", self.rc, opts.project_root, opts.path) From 4e1321d589f57b3df9effef49c038d47aa96b95c Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 5 Feb 2023 16:57:43 +1100 Subject: [PATCH 6/8] fix(#1970): cleanly kill timed out git processes --- lua/nvim-tree/git/runner.lua | 48 +++++++++++++++++++++--------------- 1 file changed, 28 insertions(+), 20 deletions(-) diff --git a/lua/nvim-tree/git/runner.lua b/lua/nvim-tree/git/runner.lua index 2774b9a41c6..4aed814c53b 100644 --- a/lua/nvim-tree/git/runner.lua +++ b/lua/nvim-tree/git/runner.lua @@ -70,38 +70,41 @@ function Runner:_log_raw_output(output) end function Runner:_run_git_job() - local handle, pid + local handle local stdout = vim.loop.new_pipe(false) local stderr = vim.loop.new_pipe(false) local timer = vim.loop.new_timer() - local function on_finish(rc) + local function on_finish(rc, signal) + log.line("git", "rc=%d, signal=%s", tostring(rc), tostring(signal)) self.rc = rc or 0 - if timer:is_closing() or stdout:is_closing() or stderr:is_closing() or (handle and handle:is_closing()) then - return + + if timer and not timer:is_closing() then + timer:stop() + timer:close() + end + if stdout and not stdout:is_closing() then + stdout:read_stop() + stdout:close() end - timer:stop() - timer:close() - stdout:read_stop() - stderr:read_stop() - stdout:close() - stderr:close() - if handle then + if stderr and not stderr:is_closing() then + stderr:read_stop() + stderr:close() + end + if handle and not handle:is_closing() then handle:close() end - - pcall(vim.loop.kill, pid) end local opts = self:_getopts(stdout, stderr) log.line("git", "running job with timeout %dms", self.timeout) log.line("git", "git %s", table.concat(utils.array_remove_nils(opts.args), " ")) - handle, pid = vim.loop.spawn( + handle = vim.loop.spawn( "git", opts, - vim.schedule_wrap(function(rc) - on_finish(rc) + vim.schedule_wrap(function(rc, signal) + on_finish(rc, signal) end) ) @@ -109,7 +112,11 @@ function Runner:_run_git_job() self.timeout, 0, vim.schedule_wrap(function() - on_finish(-1) + log.line("git", "timed out, killing") + self.timed_out = true + if handle then + handle:kill "sigkill" + end end) ) @@ -135,7 +142,7 @@ end function Runner:_wait() local function is_done() - return self.rc ~= nil + return self.rc ~= nil or self.timed_out end while not vim.wait(30, is_done) do @@ -153,7 +160,8 @@ function Runner.run(opts) list_ignored = opts.list_ignored, timeout = opts.timeout or 400, output = {}, - rc = nil, -- -1 indicates timeout + rc = nil, + timed_out = false, }, Runner) self:_run_git_job() @@ -161,7 +169,7 @@ function Runner.run(opts) log.profile_end(ps, "git job %s %s", opts.project_root, opts.path) - if self.rc == -1 then + if self.timed_out then log.line("git", "job timed out %s %s", opts.project_root, opts.path) timeouts = timeouts + 1 if timeouts == MAX_TIMEOUTS then From 1d194dfe2e9c7db46f363bf534da5e8c7c23c9a1 Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 12 Feb 2023 14:18:44 +1100 Subject: [PATCH 7/8] fix(#1970): revert git kill, to be completed via #1974 experiment --- lua/nvim-tree/explorer/explore.lua | 10 +++---- lua/nvim-tree/git/runner.lua | 48 +++++++++++++----------------- 2 files changed, 25 insertions(+), 33 deletions(-) diff --git a/lua/nvim-tree/explorer/explore.lua b/lua/nvim-tree/explorer/explore.lua index f3b0ea2b7b2..f14406fef9d 100644 --- a/lua/nvim-tree/explorer/explore.lua +++ b/lua/nvim-tree/explorer/explore.lua @@ -26,7 +26,7 @@ local function populate_children(handle, cwd, node, git_status) local abs = utils.path_join { cwd, name } - local profile = log.profile_start("explore populate_children %s", abs) + -- local profile = log.profile_start("explore populate_children %s", abs) t = get_type_from(t, abs) if @@ -52,7 +52,7 @@ local function populate_children(handle, cwd, node, git_status) end end - log.profile_end(profile) + -- log.profile_end(profile) end end @@ -63,7 +63,7 @@ function M.explore(node, status) return end - local profile = log.profile_start("explore init %s", node.absolute_path) + -- local profile = log.profile_start("explore init %s", node.absolute_path) populate_children(handle, cwd, node, status) @@ -74,14 +74,14 @@ function M.explore(node, status) local ns = M.explore(child_folder_only, status) node.nodes = ns or {} - log.profile_end(profile) + -- log.profile_end(profile) return ns end sorters.merge_sort(node.nodes, sorters.node_comparator) live_filter.apply_filter(node) - log.profile_end(profile) + -- log.profile_end(profile) return node.nodes end diff --git a/lua/nvim-tree/git/runner.lua b/lua/nvim-tree/git/runner.lua index 664b8c73553..549a75f213c 100644 --- a/lua/nvim-tree/git/runner.lua +++ b/lua/nvim-tree/git/runner.lua @@ -70,41 +70,38 @@ function Runner:_log_raw_output(output) end function Runner:_run_git_job() - local handle + local handle, pid local stdout = vim.loop.new_pipe(false) local stderr = vim.loop.new_pipe(false) local timer = vim.loop.new_timer() - local function on_finish(rc, signal) - log.line("git", "rc=%d, signal=%s", tostring(rc), tostring(signal)) + local function on_finish(rc) self.rc = rc or 0 - - if timer and not timer:is_closing() then - timer:stop() - timer:close() - end - if stdout and not stdout:is_closing() then - stdout:read_stop() - stdout:close() - end - if stderr and not stderr:is_closing() then - stderr:read_stop() - stderr:close() + if timer:is_closing() or stdout:is_closing() or stderr:is_closing() or (handle and handle:is_closing()) then + return end - if handle and not handle:is_closing() then + timer:stop() + timer:close() + stdout:read_stop() + stderr:read_stop() + stdout:close() + stderr:close() + if handle then handle:close() end + + pcall(vim.loop.kill, pid) end local opts = self:_getopts(stdout, stderr) log.line("git", "running job with timeout %dms", self.timeout) log.line("git", "git %s", table.concat(utils.array_remove_nils(opts.args), " ")) - handle = vim.loop.spawn( + handle, pid = vim.loop.spawn( "git", opts, - vim.schedule_wrap(function(rc, signal) - on_finish(rc, signal) + vim.schedule_wrap(function(rc) + on_finish(rc) end) ) @@ -112,11 +109,7 @@ function Runner:_run_git_job() self.timeout, 0, vim.schedule_wrap(function() - log.line("git", "timed out, killing") - self.timed_out = true - if handle then - handle:kill "sigkill" - end + on_finish(-1) end) ) @@ -142,7 +135,7 @@ end function Runner:_wait() local function is_done() - return self.rc ~= nil or self.timed_out + return self.rc ~= nil end while not vim.wait(30, is_done) do @@ -160,8 +153,7 @@ function Runner.run(opts) list_ignored = opts.list_ignored, timeout = opts.timeout or 400, output = {}, - rc = nil, - timed_out = false, + rc = nil, -- -1 indicates timeout }, Runner) self:_run_git_job() @@ -169,7 +161,7 @@ function Runner.run(opts) log.profile_end(profile) - if self.timed_out then + if self.rc == -1 then log.line("git", "job timed out %s %s", opts.project_root, opts.path) timeouts = timeouts + 1 if timeouts == MAX_TIMEOUTS then From f486178bec60cda7b33d34eec2b420bddd6bfb07 Mon Sep 17 00:00:00 2001 From: Alexander Courtis Date: Sun, 12 Feb 2023 14:21:58 +1100 Subject: [PATCH 8/8] fix(#1970): revert git kill, to be completed via #1974 experiment --- lua/nvim-tree/explorer/explore.lua | 10 +++++----- lua/nvim-tree/git/runner.lua | 2 +- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/lua/nvim-tree/explorer/explore.lua b/lua/nvim-tree/explorer/explore.lua index f14406fef9d..f3b0ea2b7b2 100644 --- a/lua/nvim-tree/explorer/explore.lua +++ b/lua/nvim-tree/explorer/explore.lua @@ -26,7 +26,7 @@ local function populate_children(handle, cwd, node, git_status) local abs = utils.path_join { cwd, name } - -- local profile = log.profile_start("explore populate_children %s", abs) + local profile = log.profile_start("explore populate_children %s", abs) t = get_type_from(t, abs) if @@ -52,7 +52,7 @@ local function populate_children(handle, cwd, node, git_status) end end - -- log.profile_end(profile) + log.profile_end(profile) end end @@ -63,7 +63,7 @@ function M.explore(node, status) return end - -- local profile = log.profile_start("explore init %s", node.absolute_path) + local profile = log.profile_start("explore init %s", node.absolute_path) populate_children(handle, cwd, node, status) @@ -74,14 +74,14 @@ function M.explore(node, status) local ns = M.explore(child_folder_only, status) node.nodes = ns or {} - -- log.profile_end(profile) + log.profile_end(profile) return ns end sorters.merge_sort(node.nodes, sorters.node_comparator) live_filter.apply_filter(node) - -- log.profile_end(profile) + log.profile_end(profile) return node.nodes end diff --git a/lua/nvim-tree/git/runner.lua b/lua/nvim-tree/git/runner.lua index 549a75f213c..6c31995b3ee 100644 --- a/lua/nvim-tree/git/runner.lua +++ b/lua/nvim-tree/git/runner.lua @@ -167,7 +167,7 @@ function Runner.run(opts) if timeouts == MAX_TIMEOUTS then notify.warn( string.format( - "%d git jobs have timed out after %dms, disabling git integration. Please consider increasing git.timeout", + "%d git jobs have timed out after %dms, disabling git integration. Try increasing git.timeout", timeouts, opts.timeout )