kalekundert / vim-coiled-snake

Compact, but ready to strike. 🐍
124 stars 11 forks source link

Performance issue when repeating simple action #34

Open Gee19 opened 3 years ago

Gee19 commented 3 years ago

I noticed some weird performance issues when repeating a simple action in normal mode like x when in larger python repos. I initially thought this was a pyright issue but after profiling with the commands below it seems to be related to this plugin.

:profile start profile.log
:profile func *
:profile file *

I grepped the profile.log for functions that were called more than 1000 times, included 3 lines above and below each match for more info on the offending plugin, and total time spent for each.

[I] ❯ rg '^Called [1-9]\d{4,} times' -B 3 -A 3
profile.log
1-FUNCTION  <SNR>96_InitLineBlank()
2-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:473
3:Called 72435 times
4-Total time:   0.371109
5- Self time:   0.371109
6-
--
794-
795-FUNCTION  <SNR>96_InitLineParen()
796-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:444
797:Called 72435 times
798-Total time:   1.140331
799- Self time:   1.140331
800-
--
1007-
1008-FUNCTION  <SNR>96_InitFold()
1009-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:483
1010:Called 72435 times
1011-Total time:   5.007207
1012- Self time:   5.007207
1013-
--
1606-
1607-FUNCTION  <SNR>96_InitLineString()
1608-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:392
1609:Called 72435 times
1610-Total time:   2.236686
1611- Self time:   2.236686
1612-
--
1736-
1737-FUNCTION  <SNR>96_LowToHigh()
1738-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:718
1739:Called 91410 times
1740-Total time:   0.174459
1741- Self time:   0.174459
1742-
--
1937-
1938-FUNCTION  <SNR>96_InitLineBackslash()
1939-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:461
1940:Called 72435 times
1941-Total time:   0.540140
1942- Self time:   0.540140
1943-
--
1984-
1985-FUNCTION  <SNR>96_InitLine()
1986-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:370
1987:Called 72435 times
1988-Total time:   7.755420
1989- Self time:   2.754698
1990-
--
2074-
2075-FUNCTION  <SNR>96_InitLineComment()
2076-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:437
2077:Called 72435 times
2078-Total time:   0.712455
2079- Self time:   0.712455
2080-
--
2198-
2199-FUNCTION  coiledsnake#FoldExpr()
2200-    Defined: ~/.vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:20
2201:Called 72820 times
2202-Total time:  17.429653
2203- Self time:   0.395780
2204-

This seems odd as I am not interacting with folds at all while this is occuring, just deleting some characters. Let me know if I can help debug any further.

kalekundert commented 3 years ago

Thanks for pointing this out. I think I might know what's going on, but I'll have to look into it more closely.

Gee19 commented 3 years ago

Is there anything I can do to help? I really miss this plugin :(

kalekundert commented 3 years ago

Sorry, I completely forgot about this. Can you point me to a file that has the performance problem? Also, do you have the FastFold plugin installed?

Gee19 commented 3 years ago

No worries. I'll try and post a reproducible example at some point this week (hopefully today after work). I do have FastFold installed.

Gee19 commented 3 years ago

Looks like my initial thought that it was related to Pyright or an LSP server was incorrect. I was able to reproduce this with a minimal vimrc and the flask repo using neovim 0.5 stable and vim 8.2.

VIM - Vi IMproved 8.2 (2019 Dec 12, compiled Apr 27 2021 18:57:19)
Included patches: 1-2815

NVIM v0.5.0
Build type: RelWithDebInfo
LuaJIT 2.1.0-beta3

.vimrc

call plug#begin('~/.vim/plugged')
Plug 'Konfekt/FastFold'
Plug 'kalekundert/vim-coiled-snake'
call plug#end()

git clone https://github.com/pallets/flask && cd flask vim src/flask/helpers.py hold the 'x' key on some random imports

The editor slows to a halt and accepts no input. I hope this helps and thanks for your time

kalekundert commented 3 years ago

Awesome, thanks for the minimal example. Sorry it's taken me so long to look into this, but I'll try to get to it soon.

kalekundert commented 3 years ago

I can reproduce the problem, although I haven't made any progress towards fixing it yet. It does seem that, for whatever reason, nvim does not suffer from this performance issue. So that could be a work-around, if you can easily use nvim.

Gee19 commented 3 years ago

@kalekundert what neovim version are you using? I saw it on 0.5 stable but I'm completely open to using a specific version to avoid this issue (I really like this plugin 😂)

kalekundert commented 3 years ago

I also have nvim==0.5.0. Not sure what the difference is. In any case, there is a real problem that needs to be fixed. This is related to #30: the problem goes away if I remove the code I added to fix that bug (which basically forces the folds to be recalculated every time the text changes).

I'm also getting the impression that coiledsnake is somehow preventing FastFold from working correctly. Specifically, I notice that :set foldmethod? seems to always return expr, while my understanding is that FastFold should keep it set to manual most of the time.

Gee19 commented 3 years ago

Could debouncing the calculation help? Probably not ideal though

Gee19 commented 3 years ago

@kalekundert I've been using the changes from that PR for a day or two and haven't noticed any bugs and it completely fixed the performance issue. I'm not going to pretend I understand the repercussions of this change but it seems promising

kalekundert commented 3 years ago

That's good to hear, I'll have to take a close look at that PR. I'm not sure I understand the repercussions either, unfortunately...

meshy commented 2 years ago

I'm using neovim, and have been encountering slowdown issues with this plugin too.

Gee19 commented 2 years ago

I'm using neovim, and have been encountering slowdown issues with this plugin too.

Have you tried the changes in the PR mentioned in this issue? You could also try it out by installing my fork: https://github.com/Gee19/vim-coiled-snake

I've been using it since October 2021 with no issues but haven't tested it extensively.

meshy commented 2 years ago

I have to admit now that I can't reproduce the slowdown with either branch. I probably should have taken better notes on my testing method before removing the plugin (and commenting :grimacing:). I'll re-install this version of vim-coiled-snake, and if I see a slowdown again, I'll compare with your branch. Apologies for the inconvenience!

meshy commented 2 years ago

I've started experiencing slow-downs again (on this version, not the fork), and did some profiling.

To test things, I ran the commands listed at the top of the file:

:profile start profile.log
:profile func *
:profile file *

Then I opened a new line with o<esc>, then undid the operation with u a few times (sorry, I didn't count). I'm afraid I can't share the file, but if it helps, it's a 2861-line pytest test file.

I'm not especially familiar with the profile file format, but here's the bits of the file that looked important (click to expand):

coiledsnake#RefreshFolds

``` FUNCTION coiledsnake#RefreshFolds() Defined: ~/personal/dotfiles/vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:38 Called 11 times Total time: 8.241507 Self time: 0.080745 count total (s) self (s) 11 0.000034 let b:coiled_snake_marks = {} 11 4.046652 0.000124 let lines = s:LinesFromBuffer() 11 4.130163 0.027628 let folds = s:FoldsFromLines(lines) " Cache where each fold should open and close. 1177 0.040233 0.028533 for lnum in sort(keys(folds), 's:LowToHigh') 1166 0.001275 let l:fold = folds[lnum] " Open a fold at the appropriate level on this line. 1166 0.002718 let b:coiled_snake_marks[l:fold.lnum] = '>' . l:fold.level " If no inside line was found, the fold reaches the end of the file and " doesn't need to be closed. 1166 0.001201 if l:fold.inside_line == {} 22 0.000014 continue " If this fold and the next are the same type and separated only by " blank lines, allow a certain number of those lines to be included in " the fold. 1144 0.003704 elseif l:fold.type == get(l:fold.next_fold, 'type', '') && l:fold.level == get(l:fold.next_fold, 'level') 847 0.002271 let closing_lnum = min([ l:fold.inside_line.lnum + l:fold.num_blanks_below, l:fold.outside_line.lnum - 1]) " If only an inside line was specified, close the fold exactly on that " line. 297 0.000097 else 297 0.000339 let closing_lnum = l:fold.inside_line.lnum 1144 0.000312 endif " Indicate that the fold should be closed, but don't overwrite any " previous entries. Due to the way the code is organized, any previous " entries will be higher level folds, and we want those to take " precedence. 1144 0.001649 if ! has_key(b:coiled_snake_marks, closing_lnum) 1089 0.002357 let b:coiled_snake_marks[closing_lnum] = '<' . l:fold.level 1144 0.000330 endif " Ignore folds that end up opening and closing on the same line. 1144 0.000888 if closing_lnum <= l:fold.lnum unlet b:coiled_snake_marks[closing_lnum] 1144 0.000279 endif 1155 0.000400 endfor 11 0.000017 return b:coiled_snake_marks ```

132_InitFold()

``` FUNCTION 132_InitFold() Defined: ~/personal/dotfiles/vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:483 Called 31476 times Total time: 2.059883 Self time: 2.059883 count total (s) self (s) 31476 0.036359 let fold = {} 31476 0.029046 let fold.parent = {} 31476 0.023744 let fold.type = "" 31476 0.030062 let fold.lnum = a:line.lnum 31476 0.026832 let fold.level = -1 31476 0.028199 let fold.indent = a:line.indent 31476 0.073737 let fold.ignore = a:line.text =~# s:manual_ignore_pattern 31476 0.024579 let fold.min_lines = 0 31476 0.023700 let fold.max_indent = -1 31476 0.022166 let fold.max_level = -1 31476 0.026476 let fold.num_blanks_below = 0 31476 0.028878 let fold.opening_line = a:line 31476 0.029874 let fold.inside_line = {} " The last line that should be in the fold. 31476 0.028627 let fold.outside_line = {} " The first line that shouldn't be in the fold. 31476 0.028839 let fold.next_fold = {} 31476 0.081705 let fold.FindClosingInfo = function('s:UndefinedClosingLine') 31476 0.023286 function! fold.NumLines() let l:open = self.opening_line.lnum let l:close = get(self.inside_line, 'lnum', line('$')) return l:close - l:open + 1 endfunction 31476 0.019642 function! fold.InsideLnumOrEOF() if self.inside_line == {} return line('$') else return self.inside_line.lnum endif endfunction 31476 0.094383 if a:line.code =~# s:import_pattern 297 0.000280 let fold.type = 'import' 297 0.000693 let fold.FindClosingInfo = function('s:CloseImports') 297 0.000228 let fold.min_lines = 4 31179 0.080252 elseif a:line.code =~# s:decorator_pattern 704 0.000738 let fold.type = 'decorator' 704 0.001929 let fold.FindClosingInfo = function('s:CloseDecorator') 30475 0.074643 elseif a:line.code =~# s:class_pattern 176 0.000168 let fold.type = 'class' 176 0.000467 let fold.FindClosingInfo = function('s:CloseBlock') 176 0.000162 let fold.num_blanks_below = 2 30299 0.140976 elseif a:line.code =~# s:function_pattern 979 0.001003 let fold.type = 'function' 979 0.002613 let fold.FindClosingInfo = function('s:CloseBlock') 979 0.000876 let fold.num_blanks_below = 1 29320 0.141199 elseif a:line.code =~# s:data_struct_pattern 3025 0.003243 let fold.type = 'struct' 3025 0.007983 let fold.FindClosingInfo = function('s:CloseDataStructure') 3025 0.002638 let fold.max_indent = 0 3025 0.002112 let fold.min_lines = 6 26295 0.164343 elseif a:line.code =~# s:string_struct_pattern 22 0.000076 let fold.FindClosingInfo = function('s:CloseOnPattern') 22 0.000286 let fold.close_pattern = 'END' . matchlist(a:line.code, s:string_struct_pattern)[1] 22 0.000152 if a:line.code =~# s:docstring_pattern && a:line.paren_level == 0 let fold.type = 'doc' 22 0.000011 else 22 0.000021 let fold.type = 'struct' 22 0.000018 let fold.max_indent = 0 22 0.000016 let fold.min_lines = 6 22 0.000008 endif 31476 0.009284 endif 31476 0.023476 return fold ```

132_InitLineString()

``` FUNCTION 132_InitLineString() Defined: ~/personal/dotfiles/vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:393 Called 31476 times Total time: 1.268763 Self time: 1.268763 count total (s) self (s) " Ignore lines in multiline strings. 31476 0.050118 if has_key(a:state, 'multiline_string_delim') 77 0.000069 let a:line.ignore_indent = 1 77 0.000156 if a:line.code =~# a:state.multiline_string_delim 22 0.000130 let a:line.code = 'END' . a:state.multiline_string_delim . split( a:line.code, a:state.multiline_string_delim, 1, )[-1] 22 0.000029 unlet a:state.multiline_string_delim 55 0.000024 else 55 0.000044 let a:line.code = '' 77 0.000025 endif 77 0.000044 return 31399 0.008832 endif " Ignore text within strings. 31399 0.520425 let a:line.code = substitute( a:line.code, s:uniline_string_pattern, '\1\1', 'g', ) " Check to see if this line begins a multiline string. 31399 0.251064 if a:line.code =~# s:multiline_string_start_pattern && a:line.code !~# s:multiline_string_start_end_pattern 22 0.000249 let a:state.multiline_string_delim = matchlist( a:line.code, s:multiline_string_start_pattern )[1] 22 0.000160 let a:line.code = split( a:line.code, a:state.multiline_string_delim, 1 )[0] . a:state.multiline_string_delim . 'START' 31399 0.010670 endif ```

I then repeated the experiment with the @Gee19's fork, and these are the (pretty similar looking) results:

coiledsnake#RefreshFolds

``` FUNCTION coiledsnake#RefreshFolds() Defined: ~/personal/dotfiles/vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:37 Called 8 times Total time: 7.322363 Self time: 0.058180 count total (s) self (s) 8 0.000040 let b:coiled_snake_marks = {} 8 3.774136 0.000109 let lines = s:LinesFromBuffer() 8 3.499767 0.019186 let folds = s:FoldsFromLines(lines) " Cache where each fold should open and close. 856 0.025754 0.016178 for lnum in sort(keys(folds), 's:LowToHigh') 848 0.001201 let l:fold = folds[lnum] " Open a fold at the appropriate level on this line. 848 0.002498 let b:coiled_snake_marks[l:fold.lnum] = '>' . l:fold.level " If no inside line was found, the fold reaches the end of the file and " doesn't need to be closed. 848 0.001229 if l:fold.inside_line == {} 16 0.000012 continue " If this fold and the next are the same type and separated only by " blank lines, allow a certain number of those lines to be included in " the fold. 832 0.003639 elseif l:fold.type == get(l:fold.next_fold, 'type', '') && l:fold.level == get(l:fold.next_fold, 'level') 616 0.002174 let closing_lnum = min([ l:fold.inside_line.lnum + l:fold.num_blanks_below, l:fold.outside_line.lnum - 1]) " If only an inside line was specified, close the fold exactly on that " line. 216 0.000089 else 216 0.000305 let closing_lnum = l:fold.inside_line.lnum 832 0.000278 endif " Indicate that the fold should be closed, but don't overwrite any " previous entries. Due to the way the code is organized, any previous " entries will be higher level folds, and we want those to take " precedence. 832 0.001537 if ! has_key(b:coiled_snake_marks, closing_lnum) 792 0.002134 let b:coiled_snake_marks[closing_lnum] = '<' . l:fold.level 832 0.000297 endif " Ignore folds that end up opening and closing on the same line. 832 0.000824 if closing_lnum <= l:fold.lnum unlet b:coiled_snake_marks[closing_lnum] 832 0.000242 endif 840 0.000370 endfor 8 0.000023 return b:coiled_snake_marks ```

132_InitFold()

``` FUNCTION 132_InitFold() Defined: ~/personal/dotfiles/vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:482 Called 22892 times Total time: 1.848917 Self time: 1.848917 count total (s) self (s) 22892 0.032874 let fold = {} 22892 0.026678 let fold.parent = {} 22892 0.021032 let fold.type = "" 22892 0.026744 let fold.lnum = a:line.lnum 22892 0.023873 let fold.level = -1 22892 0.025067 let fold.indent = a:line.indent 22892 0.066993 let fold.ignore = a:line.text =~# s:manual_ignore_pattern 22892 0.022191 let fold.min_lines = 0 22892 0.021101 let fold.max_indent = -1 22892 0.019555 let fold.max_level = -1 22892 0.023610 let fold.num_blanks_below = 0 22892 0.025717 let fold.opening_line = a:line 22892 0.026958 let fold.inside_line = {} " The last line that should be in the fold. 22892 0.025059 let fold.outside_line = {} " The first line that shouldn't be in the fold. 22892 0.024611 let fold.next_fold = {} 22892 0.075707 let fold.FindClosingInfo = function('s:UndefinedClosingLine') 22892 0.021625 function! fold.NumLines() let l:open = self.opening_line.lnum let l:close = get(self.inside_line, 'lnum', line('$')) return l:close - l:open + 1 endfunction 22892 0.017985 function! fold.InsideLnumOrEOF() if self.inside_line == {} return line('$') else return self.inside_line.lnum endif endfunction 22892 0.085365 if a:line.code =~# s:import_pattern 216 0.000293 let fold.type = 'import' 216 0.000652 let fold.FindClosingInfo = function('s:CloseImports') 216 0.000222 let fold.min_lines = 4 22676 0.071109 elseif a:line.code =~# s:decorator_pattern 512 0.000684 let fold.type = 'decorator' 512 0.001676 let fold.FindClosingInfo = function('s:CloseDecorator') 22164 0.066035 elseif a:line.code =~# s:class_pattern 128 0.000152 let fold.type = 'class' 128 0.000426 let fold.FindClosingInfo = function('s:CloseBlock') 128 0.000142 let fold.num_blanks_below = 2 22036 0.127106 elseif a:line.code =~# s:function_pattern 712 0.000921 let fold.type = 'function' 712 0.002523 let fold.FindClosingInfo = function('s:CloseBlock') 712 0.000788 let fold.num_blanks_below = 1 21324 0.133046 elseif a:line.code =~# s:data_struct_pattern 2200 0.003005 let fold.type = 'struct' 2200 0.007189 let fold.FindClosingInfo = function('s:CloseDataStructure') 2200 0.002342 let fold.max_indent = 0 2200 0.001889 let fold.min_lines = 6 19124 0.146579 elseif a:line.code =~# s:string_struct_pattern 16 0.000063 let fold.FindClosingInfo = function('s:CloseOnPattern') 16 0.000232 let fold.close_pattern = 'END' . matchlist(a:line.code, s:string_struct_pattern)[1] 16 0.000123 if a:line.code =~# s:docstring_pattern && a:line.paren_level == 0 let fold.type = 'doc' 16 0.000009 else 16 0.000018 let fold.type = 'struct' 16 0.000015 let fold.max_indent = 0 16 0.000013 let fold.min_lines = 6 16 0.000006 endif 22892 0.007978 endif 22892 0.020882 return fold ```

132_InitLineString()

``` FUNCTION 132_InitLineString() Defined: ~/personal/dotfiles/vim/plugged/vim-coiled-snake/autoload/coiledsnake.vim:392 Called 22892 times Total time: 1.273358 Self time: 1.273358 count total (s) self (s) " Ignore lines in multiline strings. 22892 0.049515 if has_key(a:state, 'multiline_string_delim') 56 0.000066 let a:line.ignore_indent = 1 56 0.000146 if a:line.code =~# a:state.multiline_string_delim 16 0.000117 let a:line.code = 'END' . a:state.multiline_string_delim . split( a:line.code, a:state.multiline_string_delim, 1, )[-1] 16 0.000026 unlet a:state.multiline_string_delim 40 0.000023 else 40 0.000042 let a:line.code = '' 56 0.000022 endif 56 0.000039 return 22836 0.008503 endif " Ignore text within strings. 22836 0.525457 let a:line.code = substitute( a:line.code, s:uniline_string_pattern, '\1\1', 'g', ) " Check to see if this line begins a multiline string. 22836 0.255785 if a:line.code =~# s:multiline_string_start_pattern && a:line.code !~# s:multiline_string_start_end_pattern 16 0.000219 let a:state.multiline_string_delim = matchlist( a:line.code, s:multiline_string_start_pattern )[1] 16 0.000137 let a:line.code = split( a:line.code, a:state.multiline_string_delim, 1 )[0] . a:state.multiline_string_delim . 'START' 22836 0.011038 endif ```

To my untrained eye, it looks as though 132_InitLineString and 132_InitFold being called lots of times is likely related to why so much time is spent in RefreshFolds.

meshy commented 2 years ago

On closer inspection, it seems that the regex line matching in a loop is consuming a lot of the time. I wonder if there's a way the pattern matching could be sped up, or the results of calls cached?

ipsod commented 2 years ago

I found a similar slowdown in NeoVim, with and without FastFold installed. Does anyone know of a anything that works? vim-coiled-snake does folding better than I can find elsewhere, but it makes neovim too slow.

meshy commented 2 years ago

I think the way to tackle the speed issue of this plugin (on large files) would be to try to speed up the comparisons made by these regexes: https://github.com/kalekundert/vim-coiled-snake/blob/ce50abca6c3533cb9bf48e910f87ae91f2969740/autoload/coiledsnake.vim#L2-L17.

Perhaps some of these comparisons could be done faster? Maybe there's a way to avoid re-running them so often?

ipsod commented 2 years ago

I worked on a Python neovim plugin that parses indented text (not Python code). It builds a tree of objects out of the parsed (indented) text. If I remember right, it was easy to subscribe to buffer changes, and the subscribing function receives line numbers any time buffer text changes, and it's then quite easy to only update the branch of the tree that has actually changed.

I wouldn't want to try to recreate the same thing in vimscript, though.