vim-bundler slows down vim startuptime significantly

[jottr]

In larger ruby projects, vim-bundler increases vim startup time to several seconds.
After bisecting my .vimrc I found the vim-bundler plugin to be the culprit.

Bundler version 1.6.2

$ rbenv version
2.0.0-p247 (set by RBENV_VERSION environment variable)

$ vim --version
VIM - Vi IMproved 7.4 (2013 Aug 10, compiled Sep 25 2014 15:27:10)
MacOS X (unix) version
Included patches: 1-430
Compiled by Homebrew
Huge version without GUI.  Features included (+) or not (-):
+acl             +farsi           +mouse_netterm   +syntax
+arabic          +file_in_path    +mouse_sgr       +tag_binary
+autocmd         +find_in_path    -mouse_sysmouse  +tag_old_static
-balloon_eval    +float           +mouse_urxvt     -tag_any_white
-browse          +folding         +mouse_xterm     -tcl
++builtin_terms  -footer          +multi_byte      +terminfo
+byte_offset     +fork()          +multi_lang      +termresponse
+cindent         -gettext         -mzscheme        +textobjects
-clientserver    -hangul_input    +netbeans_intg   +title
+clipboard       +iconv           +path_extra      -toolbar
+cmdline_compl   +insert_expand   +perl            +user_commands
+cmdline_hist    +jumplist        +persistent_undo +vertsplit
+cmdline_info    +keymap          +postscript      +virtualedit
+comments        +langmap         +printer         +visual
+conceal         +libcall         +profile         +visualextra
+cryptv          +linebreak       +python          +viminfo
+cscope          +lispindent      -python3         +vreplace
+cursorbind      +listcmds        +quickfix        +wildignore
+cursorshape     +localmap        +reltime         +wildmenu
+dialog_con      -lua             +rightleft       +windows
+diff            +menu            +ruby            +writebackup
+digraphs        +mksession       +scrollbind      -X11
-dnd             +modify_fname    +signs           -xfontset
-ebcdic          +mouse           +smartindent     -xim
+emacs_tags      -mouseshape      -sniff           -xsmp
+eval            +mouse_dec       +startuptime     -xterm_clipboard
+ex_extra        -mouse_gpm       +statusline      -xterm_save
+extra_search    -mouse_jsbterm   -sun_workshop    -xpm
   system vimrc file: "$VIM/vimrc"
     user vimrc file: "$HOME/.vimrc"
 2nd user vimrc file: "~/.vim/vimrc"
      user exrc file: "$HOME/.exrc"
  fall-back for $VIM: "/usr/local/share/vim"
Compilation: /usr/bin/clang -c -I. -Iproto -DHAVE_CONFIG_H   -F/usr/local/Frameworks -DMACOS_X_UNIX  -Os -w -pipe -march=native -mmacosx-version-min=10.9 -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=1      
Linking: /usr/bin/clang   -L. -L/Users/jottr/.rbenv/versions/2.0.0-p247/lib  -fstack-protector -L/usr/local/lib -L/usr/local/lib -F/usr/local/Frameworks -Wl,-headerpad_max_install_names -o vim        -lm  -lncurses -liconv -framework Cocoa   -fstack-protector -L/usr/local/lib  -L/System/Library/Perl/5.16/darwin-thread-multi-2level/CORE -lperl -framework Python   -lruby-static -lobjc -L/Users/jottr/.rbenv/versions/2.0.0-p247/lib   

[tpope]

I need a hell of a lot more to go on than "larger".

[jottr]

The huginn project made me notice.
Trying to open that projects Gemfile took several seconds.

[tpope]

On that project I get a bit less than half a second attributable to bundler.vim. Are you on modern hardware, fast storage (i.e. not an SD card or network share), and the latest version of bundler.vim?

[jottr]

This is on a very beefy machine with SSD.
I've run Vundles PluginUpdate a few days ago, so vim-bundler is up to date.

[tpope]

If it's not CPU or disk bound then the obvious potential culprits are the two Ruby invocations that happen:

1. ruby -rubygems -e "print Gem.path.join(%(;))"
2. ruby -rrbconfig -e "print RbConfig::CONFIG[\"ruby_version\"]"

See how fast those are. Try using :!time ...

[jottr]

ruby -rubygems -e "print Gem.path.join(app/models/agent.rb(;))" 0,38s user 0,12s system 95% cpu 0,519 total
ruby -rrbconfig -e "print RbConfig::CONFIG[\"ruby_version\"]" 0,38s user 0,12s system 95% cpu 0,523 total

Interestingly I notice the lag not only when opening the Gemfile, but also on any other ruby file from that project.

[tpope]

So that explains one second, but not several. (I get 0.1 seconds each for them, for the record.)

Does the delay happen at start up only, or does it continue to happen upon opening additional files from the same project?

[jottr]

It happens during startup and when opening other files.
Uninstalling vim-bundler immediately resolves the issue.

[tpope]

Bundler.vim aggressively caches, so if it happens repeatedly, the ultimate culprit is likely another plugin. Bundler.vim puts all your gems into 'tags' and 'path', so if another plugin is doing some moderately expensive operation on each entry, that could add up fast. Try with just bundler.vim installed and see what happens.

[jottr]

🙇
Thx, I will try and let you know.
Here's the output of vim --startuptime with vim-bundler still enabled, and here's my current .vimrc sans vim-bundler.
Maybe you can glean something off this which I can't.

[jottr]

Ok. Disabling all other plugins except vim-bundler eliminates the lag as well.

[tpope]

Okay, so the next step is to add plugins back and figure out which is the trigger.

[jottr]

I'll have to retract my last comment. Commenting out all other plugins, augroups and settings except vim-bundler will NOT remove the lag.

[tpope]

Try doautocmd User Bundler and see how slow that is.

[carlesso]

I have faced this problem too. If can help, I've traced the output of vim --startuptime for a file inside or outside of a rails projeect:

• Rails Project https://gist.github.com/carlesso/b234e0cb197251a9e9b3#file-with_vim_bundler-L146
• Non Rails Project https://gist.github.com/carlesso/0c417ca5b9ad846eab74#file-without_vim_bundler-L145

You can see around line 146 the time of sourcing vim-bundler.

For this test I was in this situation:

./Gemfile
./project
./project/Gemfile

I was in the root directory, in project there is a Rails project. Opening the Gemfile in root is very fast. the latter takes a long time.
I'm noticing right now that in the first vim is loading autoload/rails, if it may be relevant for some reason.

[tpope]

That's on compiler/bundler.vim, which if you look inside I think you'll agree is a nonsensical culprit. Check the results with it deleted.

[carlesso]

I've done a test commenting out the content of https://github.com/tpope/vim-bundler/blob/master/compiler/bundler.vim in my .vim/bundle/vim-bundler/compiler/bundler.vim and even if I agree with you and compiler/bundler.vim looks harmless, the results are the same as the one shared above.

With the full file commented, the load time is still of a second (if I delete the file, I'll have an error here, if I comment out that line, the problem is still there).

As additional info, I'm using pathogen, and ls .vim/bundle gives me:

closetag.vim
ctrlp.vim
gist-vim
mustache
nerdcommenter
nerdtree
syntastic
tagbar
tcomment_vim
vim-airline
vim-bundler
vim-coffee-script
vim-colors-solarized
vim-easygrep
vim-endwise
vim-rails
vim-rspec
vim-sensible
vim-surround
webapi-vim

[tpope]

Regardless of the mechanics at play, that file itself isn't to blame. The profiler will give more useful information.

[derekprior]

I also noticed a slowdown with vim-bundler. It was particualrly bad with this one project I revisted from time to time. Profiling showed that it was taking over 1 second to load, but in actuality it seemed vim would take 2-3 seconds before vim was usable. Removing vim-bundler removed the lag. I went through the binary search process to try to identify plugins that vim-bundler interacted with and found vim-rails and vim-projectionist were contributing. If I removed those then I could keep vim-bundler and have a better startup time. But I wanted to keep everything...

I noticed that this project used a version of ruby (2.1.0) that I no-longer had installed. I used rbenv/ruby-build to install it, and then startup time was acceptable again.

Is it possible to better handle the scenario where the required ruby is not installed?

[tpope]

Okay, that's quite a few clues. With the required Ruby not installed, Can you try the two Ruby commands listed above and report both their times and output?

[derekprior]

Sorry, I was away on vacation for the last week.

I get a syntax error from the first command you pasted, so I modified it to: ruby -rubygems -e "print Gem.path.join('%')". Not sure if this is the same as you had in mind. But here are the numbers:

With the ruby missing:

rbenv: version `2.1.1' is not installed
rbenv: version `2.1.1' is not installed
ruby -rubygems -e "print Gem.path.join('app/models/course.rb')"  0.02s user 0.02s system 99% cpu 0.048 total

shell returned 1

rbenv: version `2.1.1' is not installed
rbenv: version `2.1.1' is not installed
ruby -rrbconfig -e "print RbConfig::CONFIG[\"ruby_version\"]"  0.02s user 0.02s system 98% cpu 0.045 total

shell returned 1

With the ruby installed:

/Users/derek/.gem/ruby/2.1.0app/models/course.rb/Users/derek/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0ruby -rubygems -e "print Gem.path.join('app/models/course.rb')"  0.05s user 0.03s system 96% cpu 0.080 total

2.1.0ruby -rrbconfig -e "print RbConfig::CONFIG[\"ruby_version\"]"  0.05s user 0.03s system 96% cpu 0.079 total

[UrsaDK]

This one still appears to be an issue… Has anyone managed to get to the bottom of this?

[nikhgupta]

I did some tests for this with some settings, and the results can be seen here: https://gist.github.com/nikhgupta/86011b5ab70fb492ec52.

Summarized here are the load times with a minimal vimrc (I did some tests after posting that gist, and hence, some of the following values are not seen in the above gist):

• Without any plugins, without any file: ~60ms
• Without any plugins, with ruby file: ~195ms
• With vim-bundler, without any file: ~65ms
• With vim-bundler, with ruby file: ~470ms
• Without any plugins, without any file, with 2 system('echo') commands in vimrc: ~115ms
• Without any plugins, with ruby file, with 2 system('echo') commands in vimrc: ~255ms
• Total execution time for 2 commands used by vim-bundler in my shell: ~180ms
• Without any plugins, without any file, with the 2 vim-bundler system calls in vimrc: ~305ms
• Without any plugins, with ruby file, with the 2 vim-bundler system commands in vimrc: ~450ms

Overall, this all seems consistent to me, and considering that vim-bundler uses 2 system calls, the above values are as per expected.

@tpope However, I would really really love to know a way to suppress these 2 system calls if possible to lower this down further. One of the commands can be suppressed by setting $GEM_HOME, while I am not sure about the other.

It seems that the other command is trying to get the ruby version for the current bundle. If so, can I make it read from .ruby_version file, instead or can it be read from an environment variable as well? I use a single ruby version, and hence, this can be useful to me, for instance.

[tpope]

How long does a single system('echo') take? Seems like speeding up your shell might be the low hanging fruit?

[tpope]

We already check $GEM_PATH; not sure what you hope to accomplish with $GEM_HOME.

[nikhgupta]

@tpope A single system('echo')takes 28ms on my system. And, yeah sorry about that, I meant $GEM_PATH itself.

Also, by checking the time for these commands, what I wanted to convey was that vim-bundler is not slow, but instead command invocations via system are inherently slow for users who are having such problems. And, therefore, if we can somehow circumvent calls to system, we can resolve the current issues for everyone.

[tpope]

Yeah no doubt that even in the best case system() is going to be slow. I was guessing yours was very slow but mine is 20ms so maybe not.

See #34 for more info about that abi_version assignment, and about the challenges of doing it without a system(). If you can figure out an improvement there, great.

Looking at the code also suggests that maybe abi_version isn't even needed in the common case? If true, it could probably be made lazy.

[Confusion]

You will also run into vim starting noticeably slowly when using vim-bundler in combination with jruby.

The abi_version system call mentioned in an earlier comment will each take ~2 seconds, due to JVM startup time. Unfortunately I don't see a reliable alternative either.

What helps a bit for the 'abi_version' call, is adding the --disable-gems switch to the ruby call. This also speeds up the command for regular MRI ruby (from ~50 ms to ~30 ms on my machine). Jruby users could further ensure JRUBY_OPTS="--dev" is set. Those two combined reduce the time to ~1 second.

In my setup the abi_version call is actually performed twice during startup and I'm not yet clear on why that is.

Added a pull request for the change I'm locally using: #47

[tpope]

With RUBY VERSION in the lock file now, maybe we could lean on that? What does it look like for JRuby?

[Confusion]

For instance like ruby 2.3.3p0 (jruby 9.1.17.0); indicating compatibility with MRI 2.3.3. So no abi version unfortunately.

[tpope]

Are there any exceptions to the rule that Ruby version 2.x.y has ABI version 2.x.0? It seems like it would be simple to map between the two. Maybe limit ourselves to 2.4 and earlier so we don't get screwed by future releases.

I guess one additional concern is that RUBY VERSION might not reflect the actually running version, seeing as how it's a basically a comment.

[rainerborene]

Maybe we can do this Ruby detection in background using jobstart?

[tpope]

We need the resulting path synchronously for most uses, so the most that could do would be to allow it to happen in parallel with the rest of the detection. And it doesn't sound like that would help much.

[tpope]

It feels worth calling out that 04d2980 combined the ABI version query and Gem path query into a single call. Multiple comments of mine above suggest possible ways to avoid the ABI version query, but they won't help with the Gem path query, so they're effectively useless now as far as I'm concerned.