Round Number Delay When Starting Under WSL #1831

alex-courtis · 2022-12-17T04:11:46Z

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 · 2022-12-17T04:15:10Z

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 · 2022-12-17T04:24:37Z

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 · 2022-12-17T05:59:58Z

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

pedro2d10 · 2022-12-17T07:57:43Z

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 · 2022-12-19T00:22:11Z

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 · 2022-12-19T00:45:47Z

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

…d add no value

pedro2d10 · 2022-12-19T12:18:51Z

@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.

alex-courtis · 2022-12-19T21:04:15Z

@doanamo I would be grateful if you could take a look at this one: node-builders.is_executable is experiencing these delays.

I don't have a windows machine so I cannot investigate.

alex-courtis · 2022-12-23T02:20:12Z

I do not know whether powershell/msys executable detection works either, which uses a different codepath.

The wsl code is buggy and is expensive, making many FS calls.

This is the only WSL specific codepath. Other windows codepaths are needed:

git
trash
create file
system open

We don't have the expertise or means to test these windows specific codepaths. I would like to remove executable flag functionality under windows. @gegoune ?

gegoune · 2022-12-24T09:29:11Z

I don't have ability to test windows either. Unless someone steps in and offers help I think removing that single functionality isn't big problem. Will just need a small info that this functionality is not available on that platform.

alex-courtis · 2022-12-31T00:44:58Z

Will just need a small info that this functionality is not available on that platform.

Good call.

https://github.com/nvim-tree/nvim-tree.lua/pull/1868/files#diff-b5b2d1abcb86ead5a2319f7e065a7545b834a407cc9f420590d7acebb285fca9

… vim freeze and performance concerns (#1868) * #1831 exploratory testing: disable file executable checks * fix(#1831): remove windows executable functionality

alex-courtis added the bug Something isn't working label Dec 17, 2022

alex-courtis mentioned this issue Dec 17, 2022

Archived: Performance / Lag issues #549

Closed

alex-courtis added a commit that referenced this issue Dec 17, 2022

fix(#1831): improve fs_scandir error handling, add profiling

89c79cb

alex-courtis added the OS Windows WSL specific to windows WSL label Dec 18, 2022

alex-courtis added a commit that referenced this issue Dec 19, 2022

#1831 exploratory testing: disable file executable checks

83d5ad4

alex-courtis added the awaiting feedback label Dec 19, 2022

alex-courtis added a commit that referenced this issue Dec 19, 2022

fix(#1831): remove error messages that were previously unreachable an…

547db6e

…d add no value

alex-courtis mentioned this issue Dec 19, 2022

bulk file deletion? #1804

Closed

alex-courtis added a commit that referenced this issue Dec 31, 2022

fix(#1831): remove windows executable functionality

7f92932

alex-courtis added the OS Windows PowerShell specific to windows powershell label Dec 31, 2022

alex-courtis mentioned this issue Dec 31, 2022

1831 remove windows executable functionality #1868

Merged

alex-courtis closed this as completed in #1868 Dec 31, 2022

alex-courtis added a commit that referenced this issue Feb 4, 2023

fix(#1831): remove instrumentation

0d9a737

alex-courtis added a commit that referenced this issue Feb 4, 2023

fix(#1831): remove instrumentation (#1968)

e0166d1

alex-courtis added a commit that referenced this issue Feb 4, 2023

fix(#1831): remove instrumentation

27d28f4

alex-courtis added a commit that referenced this issue Feb 4, 2023

fix(#1831): remove instrumentation (#1969)

7eb33d2

alex-courtis mentioned this issue Feb 13, 2023

Nvim freezes by inifinite loop of nvim-tree when working on C:\Users\{username}\AppData\Local #1961

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Round Number Delay When Starting Under WSL #1831

Round Number Delay When Starting Under WSL #1831

alex-courtis commented Dec 17, 2022 •

edited

Loading

alex-courtis commented Dec 17, 2022 •

edited

Loading

alex-courtis commented Dec 17, 2022

alex-courtis commented Dec 17, 2022

pedro2d10 commented Dec 17, 2022

alex-courtis commented Dec 19, 2022

alex-courtis commented Dec 19, 2022 •

edited

Loading

pedro2d10 commented Dec 19, 2022

alex-courtis commented Dec 19, 2022

alex-courtis commented Dec 23, 2022 •

edited

Loading

gegoune commented Dec 24, 2022

alex-courtis commented Dec 31, 2022

Round Number Delay When Starting Under WSL #1831

Round Number Delay When Starting Under WSL #1831

Comments

alex-courtis commented Dec 17, 2022 • edited Loading

alex-courtis commented Dec 17, 2022 • edited Loading

alex-courtis commented Dec 17, 2022

alex-courtis commented Dec 17, 2022

pedro2d10 commented Dec 17, 2022

alex-courtis commented Dec 19, 2022

alex-courtis commented Dec 19, 2022 • edited Loading

pedro2d10 commented Dec 19, 2022

alex-courtis commented Dec 19, 2022

alex-courtis commented Dec 23, 2022 • edited Loading

gegoune commented Dec 24, 2022

alex-courtis commented Dec 31, 2022

alex-courtis commented Dec 17, 2022 •

edited

Loading

alex-courtis commented Dec 17, 2022 •

edited

Loading

alex-courtis commented Dec 19, 2022 •

edited

Loading

alex-courtis commented Dec 23, 2022 •

edited

Loading