Slowdown on save

[Shatur]

I noticing slowdown when neo-tree is open. I assume it caused by updating the tree on save?
Log: neo-tree.nvim.txt
I use default settings.

[cseickel]

Deja vu! Looking at those logs, it's not really doing anything. It is tracking your movements opening and closing buffers and switching windows, but none of those events actually caused a refresh. Nothing that happened in these logs could have had a noticeable impact on performance.

Are you sure that these logs cover the period where there is a slowdown?

[Shatur]

Hm... I tried to check it, but :lua require("neo-tree").show_logs() results in empty file for me on the latest master. My configuration:

local config = {
  log_level = 'trace', -- "trace", "debug", "info", "warn", "error", "fatal"
  log_to_file = true, -- true, false, "/path/to/file.log", use :NeoTreeLogs to show the file
}

require("neo-tree").setup(config)

[cseickel]

I accidentally broke logging in the prior commit. It is fixed now.

[Shatur]

Okay, here we go: neo-tree.nvim.txt

Config:

local config = {
  enable_diagnostics = false,
  enable_git_status = false,
  enable_modified_markers = false, -- Show markers for files with unsaved changes.
  log_level = 'trace', -- "trace", "debug", "info", "warn", "error", "fatal"
  log_to_file = true, -- true, false, "/path/to/file.log", use :NeoTreeLogs to show the file
}

require('neo-tree').setup(config)

[cseickel]

The core problem here is that the "buffer_changed" event is firing continuously. This is triggered by the BufWritePost and BufFilePost autocmd events. I would say that something is wrong in your setup for these events to be firing continuously like that. You might want to try a minimal setup without any other plugins.

As a workaround, you can avoid the problem within neo-tree by using the libuv file watcher instead of relying on those buffer changed events:

local config = {
  enable_diagnostics = false,
  enable_git_status = false,
  enable_modified_markers = false, -- Show markers for files with unsaved changes.
  
  log_level = 'trace', -- "trace", "debug", "info", "warn", "error", "fatal"
  log_to_file = true, -- true, false, "/path/to/file.log", use :NeoTreeLogs to show the file
  filesystem = {
    use_libuv_file_watcher = true, -- This will use the OS level file watchers to detect changes
  }

}

require('neo-tree').setup(config)

[cseickel]

It just occurred to me that maybe you were spamming a save file mapping on purpose to illustrate the save slowdown. If that's the case, then I'd say everything looks fine as far as I can see. If you were not intentionally saving every second, then see my prior comment.

[Shatur]

It just occurred to me that maybe you were spamming a save file mapping on purpose to illustrate the save slowdown.

That's what I did :D

As a workaround, you can avoid the problem within neo-tree by using the libuv file watcher instead of relying on those buffer changed events:

Still have the same slowdown... Log: neo-tree.nvim.txt
(this time I saved only once)

[cseickel]

From the logs, that looks like neotree is working correctly. There does seem to be an unusual number of buffers (133?) opened in this session, and a lot of movement between windows.

The strangest things I notice are that there is a file named 4913, which keeps getting renamed. Also, tree.lua keeps getting renamed to tree.lua~ and back again. If you only saved once, then something else is going on here because there was a rapid fire of this file being saved and renamed many times in a second. Neo-tree did properly debounce that so many of the events were skipped, but that still means several refreshes for one save action.

[Shatur]

That's strange... Here is the log without plugins (only necessary to run neo-tree): neo-tree.nvim.txt. The same slowdown still happens

[cseickel]

Still the same behavior, here is the relevant part of the logs without the extra noise of event calls that do nothing:

[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  file_open_requested  with args:  {
  open_cmd = "e",
  path = "/home/gena/.config/nvim/init.lua",
  state = {
    async_directory_scan = "auto",
    bind_to_cwd = true,
    bufnr = 2,
    commands = {
      add = <function 1>,
      ...
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  vim_win_enter  with args:  {
  afile = "README.md"
}
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:132: Handler  neo-tree-win-enter  for vim_win_enter called successfully.
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  vim_buffer_enter  with args:  {
  afile = "README.md"
}.
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  vim_buffer_added  with args:  {
  afile = "init.lua"
}
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  vim_buffer_enter  with args:  {
  afile = "init.lua"
}
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  vim_buffer_enter  with args:  {
  afile = "init.lua"
}
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  file_opened  with args:  /home/gena/.config/nvim/init.lua
[TRACE Sun May  1 12:23:59 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:132: Handler  buffers.vim_buffer_added  for vim_buffer_added called successfully.
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  vim_buffer_changed  with args:  {
  afile = "init.lua"
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "4913",
  status = {
    rename = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "4913",
  status = {
    change = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "4913",
  status = {
    rename = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "init.lua",
  status = {
    rename = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "init.lua~",
  status = {
    rename = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "init.lua",
  status = {
    rename = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "init.lua",
  status = {
    change = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "init.lua",
  status = {
    change = true
  }
}
[TRACE Sun May  1 12:24:02 2022] ...lugins/start/neo-tree.nvim/lua/neo-tree/events/queue.lua:158: Firing event:  fs_event  with args:  {
  path = "init.lua~",
  status = {
    rename = true
  }
}

You had README open, then you opened init.lua, then there was a flurry of changes and renames, and some strange file called 4913 was also saved.

Maybe you should try it with the minimal init that is in the neo-tree repo:

nvim --noplugin -u tests/mininit.lua

[Shatur]

Still the same behavior, here is the relevant part of the logs without the extra noise of event calls that do nothing:
You had README open, then you opened init.lua, then there was a flurry of changes and renames, and some strange file called 4913 was also saved.

That strange, I disabled all plugins and configuration expect a few mappings in my init.lua.
Okay, here is the log where I disabled everything except <C-s> mapping to save the file and still have a slowdown on save:
neo-tree.nvim.txt
And here is the branch with my configuration where you can see that I disabled everything: Shatur/neovim-config#2
(I use submodules)

[cseickel]

That is definitely a clean log without any of the extra events from the prior logs. I don't see anything wrong with this log though. It looks like a single "write" action happened at the very end and the corresponding refresh started and ended within the same second.

I should have asked earlier, what do you mean by slowdown? Can you demonstrate it in a video?

[Shatur]

Then maybe it's not an issue. When I use ui client I spinning cursor for a moment and on cli cursor blinks for a moment. It usually happens on some sync action. And it doesn't happen when neotree is hidden.

[Shatur]

Log with my regular init.lua, looks clean too: neo-tree.nvim.txt

[cseickel]

Definitely looks fine. Strange that it is so different from earlier logs.

As far as I can see, there's nothing to do here. 🤷‍♂️