vim-matchup
vim-matchup copied to clipboard
andymass
High CPU use on mismatch
Explain the issue
neovim v0.5.0-593-g1ca67a73c
Open some file where vim-matchup is used, and produce a mismatch.
For example, open autoload/matchup/delim.vim and write function! in a new line.
The switch back to normal mode, and move the cursor around - it's sluggish.
Here's a profile when editing a lisp file: adding a mismatched paren, and moving the cursor 4 lines down (~3 secs in total):
FUNCTIONS SORTED ON TOTAL TIME
count total (s) self (s) function
6 1.508813 0.001101 <SNR>43_timer_callback()
5 1.507651 0.002345 7()
5 1.497701 0.000170 <SNR>43_highlight_surrounding()
5 1.497532 0.000128 matchup#delim#get_surrounding()
5 1.497404 0.003721 matchup#delim#get_surrounding_impl()
30 1.454504 0.005236 matchup#delim#get_matching()
30 1.447775 0.364335 <SNR>79_get_matching_delims()
26484 1.079824 0.211940 matchup#delim#skip_default()
26559 0.877356 0.206604 matchup#util#in_comment_or_string()
26559 0.670752 matchup#util#in_syntax()
40 0.038554 0.001226 <SNR>79_get_delim_multi()
40 0.037328 0.013461 <SNR>79_get_delim()
35 0.034399 0.000521 matchup#delim#get_prev()
75 0.011380 0.001879 matchup#delim#skip()
30 0.007151 0.006806 <SNR>79_parser_delim_new()
135 0.005114 0.004723 matchup#perf#toc()
5 0.004887 0.000212 matchup#delim#get_current()
200 0.004172 0.003582 <SNR>44_parse_args()
95 0.002169 0.000664 matchup#pos#set_cursor()
95 0.002042 0.001817 matchup#perf#timeout_check()
(For the vimscript example above, I got 0.36 sec total - still too much for "just" moving the cursor around.)
I guess some kind of per-buffer per-line cache (depending on b:changedtick?) would be nice to have here, to avoid the high number of calls to skip_default.
Can you share an example that demonstrates the issue?
Also did you play around with the following options? You might get better results.
let g:matchup_matchparen_deferred_show_delay = 50
let g:matchup_matchparen_deferred_hide_delay = 700
Well, if autoload/matchup/delim.vim and function! is not demonstrating the issue, use https://github.com/phmarek/alexandria/blob/master/alexandria-1/numbers.lisp and add a ( somewhere in the middle of a function.
With the default 50:
FUNCTIONS SORTED ON TOTAL TIME
count total (s) self (s) function
10 0.985260 0.002180 <SNR>43_timer_callback()
7 0.982950 0.003896 7()
7 0.965210 0.000623 <SNR>43_highlight_surrounding()
7 0.963285 0.000219 matchup#delim#get_surrounding()
7 0.963066 0.040168 matchup#delim#get_surrounding_impl()
432 0.508368 0.083262 matchup#delim#get_matching()
432 0.403959 0.154871 <SNR>88_get_matching_delims()
442 0.363435 0.008684 <SNR>88_get_delim_multi()
435 0.359925 0.005450 matchup#delim#get_prev()
442 0.354751 0.125993 <SNR>88_get_delim()
5315 0.215315 0.047568 matchup#util#in_comment_or_string()
4383 0.190676 0.039317 matchup#delim#skip_default()
5315 0.167747 matchup#util#in_syntax()
433 0.090007 0.085622 <SNR>88_parser_delim_new()
932 0.082113 0.018112 matchup#delim#skip()
1754 0.055390 0.051178 matchup#perf#toc()
2787 0.042828 0.041185 <SNR>44_parse_args()
1368 0.031738 0.009658 matchup#pos#set_cursor()
1304 0.024946 0.022147 matchup#perf#timeout_check()
861 0.019909 0.008576 matchup#pos#val()
Increasing the show_delay to 500 reduces the CPU load:
FUNCTIONS SORTED ON TOTAL TIME
count total (s) self (s) function
11 0.194137 0.002950 <SNR>43_timer_callback()
9 0.191005 0.006052 7()
8 0.159175 0.001031 <SNR>43_highlight_surrounding()
8 0.155451 0.000309 matchup#delim#get_surrounding()
8 0.155142 0.007252 matchup#delim#get_surrounding_impl()
19 0.080982 0.012720 matchup#delim#get_matching()
27 0.072279 0.002311 <SNR>88_get_delim_multi()
27 0.069968 0.026353 <SNR>88_get_delim()
19 0.064935 0.025584 <SNR>88_get_matching_delims()
18 0.058214 0.000922 matchup#delim#get_prev()
217 0.036740 0.006926 matchup#util#in_comment_or_string()
171 0.029874 0.005258 matchup#delim#skip_default()
217 0.029814 matchup#util#in_syntax()
19 0.018913 0.017853 <SNR>88_parser_delim_new()
46 0.015737 0.003543 matchup#delim#skip()
9 0.015543 0.000557 matchup#delim#get_current()
108 0.012775 0.011794 matchup#perf#toc()
135 0.009264 0.007763 <SNR>44_parse_args()
56 0.004716 0.001451 matchup#pos#set_cursor()
57 0.004153 0.003686 matchup#perf#timeout_check()
So yeah, that's a nice workaround... perhaps these should be settable per-buffer or per-filetype as well?
I've been running with the higher show_delay... but that's awful for normal work.
Can you choose a value between 50 and 500? Or is the larger value the least that works?
I feel that something else might be happening with your configuration. I cannot reproduce the issue in either vim script or lisp as in your example. Can you give me some more details on your setup and how to reproduce? What does :MatchupShowTimes say? Does it work in vim rather than neovim?
perhaps these should be settable per-buffer or per-filetype as well?
Unfortunately, it can't be, because match-up uses a single timer with a fixed cadence (show_delay), which is for performance reasons. I don't want to create a separate timer per buffer. There are still a few things you can try:
let g:matchup_matchparen_timeout = 300 # adjust this
let b:matchup_matchparen_timeout = 300 # adjust this per buffer
let g:matchup_matchparen_stopline = 400 " adjust this
You can also disable match-up per buffer using, in which case built-in matchparen will be used.
autocmd FileType lisp let b:matchup_matchparen_enabled = 0
Another datapoint:
nvim
:help winblend
<move cursor around a bit, but by pressing the key multiple times - not holding down>
:MatchupShowTimes
average last maximum
[delim]
get_surrounding#fail 2.99ms 2.99ms 2.99ms
get_surrounding#accept 274.10ms 293.10ms 293.10ms
[get_matching_delims]
initial_pair 1.58ms 7.91ms 7.99ms
get_matches 1.65ms 7.98ms 8.07ms
[loader_init_buffer]
done 1.51ms 1.59ms 3.56ms
[loading]
init_done 4.85ms 4.85ms 4.85ms
[loading_module]
misc 0.04ms 0.04ms 0.04ms
motion 0.28ms 0.16ms 0.31ms
loader 0.84ms 0.84ms 0.84ms
matchparen 1.59ms 1.59ms 1.59ms
[matchparen.highlight]
get_current 1.92ms 1.84ms 4.65ms
get_matching 7.07ms 7.07ms 7.07ms
end 8.01ms 8.01ms 8.01ms
[s:get_delim]
first_pass 0.81ms 0.53ms 12.75ms
got_results 1.11ms 0.97ms 13.53ms
nothing_found 0.88ms 0.98ms 1.12ms
Moving the cursor feels very laggy; and with a timeout of 300 it seems that most of the time I run into this timeout.
lines is 46, columns 191, so not even a really big window.
I'm on git HEAD, settings are
let g:matchup_matchparen_timeout=300
let g:matchup_matchparen_deferred_show_delay=50
I'm not sure whether this is about mismatching delimiters - the help file looks completely normal.
I notice in some of your timings you have references to get_surrounding/highlight_surrounding (are you using g:matchup_matchparen_hi_surround_always). I would say you should disable this feature as it's very expensive especially with mismatches.
Instead you can make a key map to <plug>(matchup-hi-surround) on demand. Do the problems still persist when you aren't using surround highlighting?
With g:matchup_matchparen_hi_surround_always=0 the laggy behaviour is gone, right.
I don't think :help winblend has a mismatch, though - so it seems to be expensive even on correct data.
Hmmm, I like this surround highlightning... can't it be made faster?
Eg., how about caching the start and end of the current block - and as long as the start is the same (and the buffer hasn't changed) the end must be the same as well. Treesitter wouldn't be compatible with vim (yet)... Perhaps caching of the syntax elements, to skip comments and strings faster?
FUNCTIONS SORTED ON SELF TIME
count total (s) self (s) function
2025 0.737957 matchup#util#in_syntax()
649 1.183972 0.226792 <SNR>76_get_delim()
640 0.295764 0.163259 <SNR>76_get_matching_delims()
640 0.143991 0.137242 <SNR>76_parser_delim_new()
640 0.447448 0.121171 matchup#delim#get_matching()
2592 0.076617 0.070759 matchup#perf#toc()
8 1.782004 0.056837 matchup#delim#get_surrounding_impl()
3866 0.054941 0.054643 <SNR>43_parse_args()
1921 0.035195 0.031287 matchup#perf#timeout_check()
1290 0.738760 0.023501 matchup#delim#skip()
2025 0.757054 0.019097 matchup#util#in_comment_or_string()
649 0.018506 matchup#loader#refresh_match_words()
1919 0.015748 matchup#loader#remove_capture_groups()
1921 0.043358 0.013103 matchup#pos#set_cursor()
1280 0.028488 0.012231 matchup#pos#val()
1919 0.011755 matchup#delim#fill_backrefs()
649 1.195633 0.011661 <SNR>76_get_delim_multi()
1357 0.010724 <SNR>76_anchor_regex()
4513 0.009766 <SNR>40_reltimefloat()
633 0.017352 0.009654 matchup#pos#prev()
I made a quick change that should improve g:matchup_matchparen_hi_surround_always a bit. I see some other possible improvements that I need to experiment with.
Feels better, thanks. :help winblend navigation doesn't lag so visibly.
Small nitpicks:
- For my ~10 cursor movements,
s:reltimefloatgot called 4518 times... seems to have been available since 2016 (dc913974638af5ba4b0d76bcb3b0efd838bf30a1), so is this layer really needed? parse_argsgot called 3870 times; if that's needed, how about sorting the clauses in most-often-called order?get_delimis called 648 times - how about caching the delimiter ranges so that unchanged parts of the buffer don't need re-parsing?
Thanks!