Round Number Delay When Starting Under WSL

[alex-courtis]

Multiple WSL users have reported issues with a freeze on startup, always a round number: 20s, 100s, 60s

Git enabled 20s: #1719

Git disabled 60s/100s: #549 (comment)

[alex-courtis]

Originally posted by @pedro2d10 in #549 (comment)

I've added some more profiling to hopefully narrow down on the issue. Please pull latest 95ed588 and enable profiling

Here the following logs:

[2022-12-16 08:57:24] [profile] START core init /home/pierre/.config/nvim
[2022-12-16 08:57:24] [watcher] Watcher:new '/home/pierre/.config/nvim' nil
[2022-12-16 08:57:24] [watcher] Event:new '/home/pierre/.config/nvim'
[2022-12-16 08:57:24] [watcher] Event:start '/home/pierre/.config/nvim'
[2022-12-16 08:57:24] [profile] START explore init /home/pierre/.config/nvim
[2022-12-16 08:58:24] [watcher] Watcher:new '/home/pierre/.config/nvim/lua' nil
[2022-12-16 08:58:24] [watcher] Event:new '/home/pierre/.config/nvim/lua'
[2022-12-16 08:58:24] [watcher] Event:start '/home/pierre/.config/nvim/lua'
[2022-12-16 08:58:24] [watcher] Watcher:new '/home/pierre/.config/nvim/plugin' nil
[2022-12-16 08:58:24] [watcher] Event:new '/home/pierre/.config/nvim/plugin'
[2022-12-16 08:58:24] [watcher] Event:start '/home/pierre/.config/nvim/plugin'
[2022-12-16 08:58:24] [profile] END   explore init /home/pierre/.config/nvim  60178ms
[2022-12-16 08:58:24] [profile] END   core init /home/pierre/.config/nvim  60179ms
[2022-12-16 08:58:24] [profile] START view open
[2022-12-16 08:58:24] [profile] END   view open  9ms
[2022-12-16 08:58:24] [profile] START draw
[2022-12-16 08:58:24] [profile] END   draw  0ms

As you can see, there 60s between profiling start and watcher.

I hope this will help

[alex-courtis]

vim.loop.fs_scandir_next may be an issue as that is called at least once before creating the watcher.

The round numbers hint at possible timeout from the OS.

There is no configurable timeout.

Wrapping and profiling could confirm.

[alex-courtis]

@pedro2d10 error handling has been improved and more profiling has been added. I would be most grateful if you could test again.

[pedro2d10]

Here the new logs:

[2022-12-17 08:51:16] [profile] START core init /home/pierre/.config/nvim
[2022-12-17 08:51:16] [watcher] Watcher:new '/home/pierre/.config/nvim' nil
[2022-12-17 08:51:16] [watcher] Event:new '/home/pierre/.config/nvim'
[2022-12-17 08:51:16] [watcher] Event:start '/home/pierre/.config/nvim'
[2022-12-17 08:51:16] [profile] START fs_scandir /home/pierre/.config/nvim
[2022-12-17 08:51:16] [profile] END   fs_scandir /home/pierre/.config/nvim  0ms
[2022-12-17 08:51:16] [profile] START explore init /home/pierre/.config/nvim
[2022-12-17 08:51:16] [profile] START fs_scandir_next /home/pierre/.config/nvim
[2022-12-17 08:51:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim  0ms
[2022-12-17 08:51:16] [profile] START fs_scandir /home/pierre/.config/nvim/.git
[2022-12-17 08:51:16] [profile] END   fs_scandir /home/pierre/.config/nvim/.git  0ms
[2022-12-17 08:51:16] [profile] START fs_scandir_next /home/pierre/.config/nvim/.git
[2022-12-17 08:51:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim/.git  0ms
[2022-12-17 08:51:16] [profile] START fs_scandir_next /home/pierre/.config/nvim
[2022-12-17 08:51:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim  0ms
[2022-12-17 08:52:16] [profile] START fs_scandir_next /home/pierre/.config/nvim
[2022-12-17 08:52:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim  0ms
[2022-12-17 08:52:16] [profile] START fs_scandir_next /home/pierre/.config/nvim
[2022-12-17 08:52:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim  0ms
[2022-12-17 08:52:16] [profile] START fs_scandir_next /home/pierre/.config/nvim
[2022-12-17 08:52:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim  0ms
[2022-12-17 08:52:16] [profile] START fs_scandir /home/pierre/.config/nvim/lua
[2022-12-17 08:52:16] [profile] END   fs_scandir /home/pierre/.config/nvim/lua  0ms
[2022-12-17 08:52:16] [profile] START fs_scandir_next /home/pierre/.config/nvim/lua
[2022-12-17 08:52:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim/lua  0ms
[2022-12-17 08:52:16] [watcher] Watcher:new '/home/pierre/.config/nvim/lua' nil
[2022-12-17 08:52:16] [watcher] Event:new '/home/pierre/.config/nvim/lua'
[2022-12-17 08:52:16] [watcher] Event:start '/home/pierre/.config/nvim/lua'
[2022-12-17 08:52:16] [profile] START fs_scandir_next /home/pierre/.config/nvim
[2022-12-17 08:52:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim  0ms
[2022-12-17 08:52:16] [profile] START fs_scandir /home/pierre/.config/nvim/plugin
[2022-12-17 08:52:16] [profile] END   fs_scandir /home/pierre/.config/nvim/plugin  0ms
[2022-12-17 08:52:16] [profile] START fs_scandir_next /home/pierre/.config/nvim/plugin
[2022-12-17 08:52:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim/plugin  0ms
[2022-12-17 08:52:16] [watcher] Watcher:new '/home/pierre/.config/nvim/plugin' nil
[2022-12-17 08:52:16] [watcher] Event:new '/home/pierre/.config/nvim/plugin'
[2022-12-17 08:52:16] [watcher] Event:start '/home/pierre/.config/nvim/plugin'
[2022-12-17 08:52:16] [profile] START fs_scandir_next /home/pierre/.config/nvim
[2022-12-17 08:52:16] [profile] END   fs_scandir_next /home/pierre/.config/nvim  0ms
[2022-12-17 08:52:16] [profile] END   explore init /home/pierre/.config/nvim  60288ms
[2022-12-17 08:52:16] [profile] END   core init /home/pierre/.config/nvim  60289ms
[2022-12-17 08:52:16] [profile] START view open
[2022-12-17 08:52:16] [profile] END   view open  11ms
[2022-12-17 08:52:16] [profile] START draw
[2022-12-17 08:52:16] [profile] END   draw  0ms

On line 15, there is exactly a 60s delay befaore it goes to the next step.

[alex-courtis]

Thanks @pedro2d10

I've attempted replication with a dummy directory populated after git init: 1831.tar.gz

After cleaning:

40,41c40,41
< [profile] END   explore init /path/to/nvim  60288ms
< [profile] END   core init /path/to/nvim  60289ms
---
> [profile] END   explore init /path/to/nvim  1ms
> [profile] END   core init /path/to/nvim  1ms
43c43
< [profile] END   view open  11ms
---
> [profile] END   view open  2ms

[alex-courtis]

There's a lot of file system operations taking place to detect whether a file is executable:

nvim-tree.lua/lua/nvim-tree/explorer/node-builders.lua

Line 33 in 89c79cb

elseif M.is_wsl then

@pedro2d10 I would be most grateful if you could test with a branch that removes this check:

cd /path/to/nvim-tree.lua
git pull
git checkout 1831-test-skipping-executable-check

Possible actions:

• Disable executable checks on windows by default
• Diagnose and fix performance issue
• Remove executable functionality on windows

[pedro2d10]

@alex-courtis you're a genius! It work great now. There's no delay when nvim-tree open.

Let me now if you want me to send you come log or change parameters.