chrisbra / Colorizer

color hex codes and color names
547 stars 30 forks source link

Switching from normal to insert mode repeatedly makes Vim increasingly slow #68

Closed Anvoker closed 5 years ago

Anvoker commented 5 years ago

The steps I've narrowed down to reproduce this:

  1. Have g:colorizer_debug set to 0.
  2. Have g:colorizer_auto_color set to 1.
  3. Open .vimrc (I assume any file with some text in it will do, this was the most convenient)
  4. Start rapidly spamming insert and escape.

Over time all inputs in Vim get increasingly slower / unresponsive. After sufficient spamming, changing modes can take a couple of seconds. Worst of all, this slowness extends to basic things like typing and doesn't seem to go away.

I've tried numerous timeout settings and disabled all of my other plugins for this issue and I'm relatively sure it has something to do with Colorizer in particular since it's the only plugin installed (besides Vundle) and this behaviour does not happen without it.

I would have loved to paste debug logs but the moment I set let g:colorizer_debug = 1 the problem stops manifesting! I can consistently get the problem if I comment the debug line and then consistently get rid of it by having debug mode on.

Looking at the vim process in KSysGuard shows that it stays at full core's load (25%) for about 15 seconds after doing the spam and stopping. After that time it goes back to 0% CPU usage but Vim remains sluggish. I've waited 10 minutes to see if Vim ever recovers - it doesn't. Only restarting it fixes it.

For now I've just opted for having the debug mode on all the time. I've managed to reinstall every plugin I had and the issue still doesn't appear as long as I have let g:colorizer_debug = 1. I've attached my vimrc.

vimrc.txt

chrisbra commented 5 years ago

could it be that the matchlist is getting too large?

chrisbra commented 5 years ago

If you do :set eventignore=InsertLeave will that be better?

chrisbra commented 5 years ago

okay, I have made some small adjustments, can you test 73e69c3 please?

Anvoker commented 5 years ago

The new commit did not fix it. I also trimmed my .vimrc down to purely just your plugin (with autocolor on and debug off) and the problem persisted.

However :set eventignore=InsertLeave yielded interesting results. Running that line made the problem disappear completely as long as Colorizer was not invoked before doing so.

If insert/leave was spammed, then CPU usage went to 25% for a while, back down to 0% when the program was left alone and then there was persisted lag and high CPU usage when doing anything in Vim, but most of all scrolling (or just CursorMove?). Running :set eventignore=InsertLeave after that point didn't make the persistent lag go away.

I did some profiling of insert spamming and moving the cursor around and got this:

FUNCTIONS SORTED ON TOTAL TIME
count  total (s)   self (s)  function
  204   2.778565   0.003836  Colorizer#ColorLine()
   72   2.774729   0.235532  Colorizer#DoColor()
  144   1.643450   0.013730  <SNR>17_LoadSyntax()
   72   0.820937   0.047033  <SNR>17_ColorInit()
   71   0.720607   0.702818  Colorizer#ColorOff()
  143   0.034081             Colorizer#LocalFTAutoCmds()
  144   0.031317   0.009272  <SNR>17_SaveRestoreOptions()
  256   0.026109   0.025319  <SNR>17_Xterm2rgb256()
   72   0.022045             <SNR>17_SaveOptions()
   72   0.020059             Colorizer#AutoCmds()
  132   0.010182             <SNR>22_Highlight_Matching_Pair()
 2016   0.009407             <SNR>17_Reltime()
  144   0.007427             <SNR>17_TermConceal()
   72   0.005455             <SNR>17_GetColorPattern()
  648   0.003338             <SNR>17_IsInComment()
  648   0.002997             <SNR>17_CheckTimeout()
   72   0.002104             Colorizer#ColorWinEnter()
   72   0.001184             <SNR>17_PrintColorStatistics()
   72   0.001151             <SNR>17_HasGui()
  143   0.001056             <SNR>17_GetMatchList()

FUNCTIONS SORTED ON SELF TIME
count  total (s)   self (s)  function
   71   0.720607   0.702818  Colorizer#ColorOff()
   72   2.774729   0.235532  Colorizer#DoColor()
   72   0.820937   0.047033  <SNR>17_ColorInit()
  143              0.034081  Colorizer#LocalFTAutoCmds()
  256   0.026109   0.025319  <SNR>17_Xterm2rgb256()
   72              0.022045  <SNR>17_SaveOptions()
   72              0.020059  Colorizer#AutoCmds()
  144   1.643450   0.013730  <SNR>17_LoadSyntax()
  132              0.010182  <SNR>22_Highlight_Matching_Pair()
 2016              0.009407  <SNR>17_Reltime()
  144   0.031317   0.009272  <SNR>17_SaveRestoreOptions()
  144              0.007427  <SNR>17_TermConceal()
   72              0.005455  <SNR>17_GetColorPattern()
  204   2.778565   0.003836  Colorizer#ColorLine()
  648              0.003338  <SNR>17_IsInComment()
  648              0.002997  <SNR>17_CheckTimeout()
   72              0.002104  Colorizer#ColorWinEnter()
   72              0.001184  <SNR>17_PrintColorStatistics()
   72              0.001151  <SNR>17_HasGui()
  143              0.001056  <SNR>17_GetMatchList()

The time in seconds that I see here does not seem to account at all for the time I feel Vim wastes afterwards when just moving around. It would total to more than 5 seconds and a lot of time spent in this profile log goes to the insert spamming. So whatever is causing the slowdown is probably a consequence of what Colorizer does, not a direct slowdown from its code running.

I went through Colorizer.vim myself for a bit. au InsertLeave * sil call Colorizer#ColorLine('!', line('w0'), line('w$')) is definitely the culprit, or well, at least the gateway to the culprit since commenting that out has the same effect as the eventignore setting.

Changing au InsertLeave * sil call Colorizer#ColorLine('!', line('w0'), line('w$')) to au InsertLeave * sil call Colorizer#ColorLine('', line('w0'), line('w$')) also seems to fix the problem.

But, without spending more time understanding the code, I don't know what the implications are of not forcing a full refresh on InsertLeave and I don't think this could be seen as a root cause exactly. But I think it's the workaround I'm going to stick with since I can't see any loss of functionality so far? Looking through DoColor I wasn't able to understand yet what part could be causing this whole problem. It might have something to do with ColorInit but I haven't done enough poking to say what's up since other lines also reference the force variable.

chrisbra commented 5 years ago

Well, I noticed the slowdown myself. Ironically, this seems to come from the *CheckTimeout function, for the terminal related search patterns.

I think we can safely remove the force attribute from the InsertLeave autocommand, since the TextChangedI should make sure, that the current window viewpoint is correctly updated, so the force on InsertLeave should not be needed.

Also it probably makes sense to disable raw terminal like ascii highlighting for all filetypes except for text files (logfiles) and when the filetype is not set. This should keep Vim responsive. From my logfile, it looks like the search expression for the terminal highlighting is too expansive. I have no clue, why this is. Playing around with regexpengine setting did not change anything.

And finally, the check for whether the terminal highlighting is disabled should be moved before the timeout is checked.

Please check, if this works better now.

Anvoker commented 5 years ago

I reverted any changes in my local repo, updated with Vundle. Seems fixed to me. No amount of insert leave spamming produced any anomalous behavior. I tried several ways of mutating color strings to see if they would be left in an unupdated state, but everything just worked fine. Thank you!

mg979 commented 5 years ago

Is it this fixed? I'm still seen big slowdowns, they seem to build up when Colorizer is toggled on and off repeatedly. I see also that some syntax highlight gets messed up. Doing :e fixes both highlight and slowdowns. Here are two pics of syntime report before and after some Colorizer toggling on and off, It seems some syntax elements are redefined over and over?

Imgur

Imgur