[Windows] PlugUpdate seems to have become really slow

[raghur]

I have 53 plugins. vim-plug used to update plugins decently quickly on windows (30s) earlier. on my linux desktop, this is closer to 10s. However, of late, it's started taking a really long time (~120s) and the update looks to be happening serially.
If I open task manager though - I see multiple copies of git.exe being spawned - so that doesn't look to be the issue.
This happens both under vim8 and neovim on windows.
For neovim, I have *jobstart, ruby and python3.
For vim8, python3 and ruby are available.

I'm not quite sure what else to check - so is there anything else to get some diagnostics into where PlugUpdate is slowing down?

---

NVIM v0.2.1-939-gdb999821d
Build type: RelWithDebInfo
Compilation: C:/msys64/mingw64/bin/gcc.exe -Wconversion -DNVIM_MSGPACK_HAS_FLOAT32 -DNVIM_UNIBI_HAS_VAR_FROM -Og -g -Wall -Wextra -pedantic -Wno-unused-parameter -Wstrict-prototypes -std=gnu99 -D__USE_MINGW_ANSI_STDIO -D_WIN32_WINNT=0x0600 -Wvla -fdiagnostics-color=auto -DINCLUDE_GENERATED_DECLARATIONS -IC:/projects/neovim/build/config -IC:/projects/neovim/src -IC:/projects/neovim/.deps/usr/include -IC:/projects/neovim/.deps/usr/include -IC:/msys64/mingw64/include -IC:/projects/neovim/.deps/usr/include -IC:/projects/neovim/.deps/usr/include -IC:/projects/neovim/.deps/usr/include -IC:/msys64/mingw64/include -IC:/msys64/mingw64/include -IC:/projects/neovim/build/src/nvim/auto -IC:/projects/neovim/build/include
Compiled by appveyor@APPVYR-WIN

• Type:
  • Bug
  • Enhancement
  • Feature Request
  • Question
• OS:
  • All/Other
  • Linux
  • OS X
  • Windows
• Vim:
  • Terminal Vim
  • GVim
  • Neovim

[raghur]

neovim :CheckHealth returns

## Python 2 provider (optional)
  - INFO: Disabled. g:loaded_python_provider=1

## Python 3 provider (optional)
  - INFO: Using: g:python3_host_prog = "d:/sdks/python36/python.exe"
  - INFO: Executable: d:/sdks/python36/python.exe
  - INFO: Python3 version: 3.6.1
  - INFO: python.exe-neovim version: 0.1.13
  - SUCCESS: Latest python.exe-neovim is installed: 0.1.13

## Ruby provider (optional)
  - INFO: Ruby: ruby 2.4.1p111 (2017-03-22 revision 58053) [x64-mingw32]
  - INFO: Host: C:/tools/ruby24/bin/ruby.EXE
  - SUCCESS: Latest "neovim" gem is installed: ruby 2.4.1p111 (2017-03-22 revision 58053) [x64-mingw32]

[janlazo]

#676 and #681 are merged so vim-plug runs most shell commands by writing it to a temporary batchfile and then executing it. This is for properly escaping some arguments and working around implementation differences between Vim and Neovim. fzf's Vim plugin and fzf.vim use the same strategy for Windows support but more robustly because the user can pass a list type, similar to jobstart, and each token is escaped for cmd.exe.

cmd.exe is the only reliable shell on Windows because powershell is too slow and bash (without WSL) can mess up the command if it contains double quotes.

The implementation can be improved but Vim and Neovim will be handled separately.

[partounian]

I'm on macOS and it seems my setup is getting slow out of nowhere also.

macOS 10.13.1
neovim 0.2.0
python2 and 3 neovim 0.2.1

[mboughaba]

I am experiencing this too, plug update become really slow on Windows. Ubuntu is still rather fast.

[janlazo]

FYI, vim 8 has job_start, similar to neovim's jobstart, so vim-plug uses native job API instead of python/ruby. The bottleneck is on Vim writing to a temporary batchfile for every :!, system(), job_start() (vim 8) or jobstart() (nvim). Running the command directly may break break valid command on cmd.exe because of Vim's implementation for :! and system(). Neovim doesn't have this limitation anymore in the nightly release so it can be optimized.

If the issue is Vim 8 job_start, just upgrade to a newer version for bugfixes.

I don't regularly upgrade my plugins so this is a low priority for me. Feel free to open a PR to tweak it for Neovim (nightly) if you're familiar with cmd.exe quirks.

[tankorsmash]

I had the same problem, but updating my Win10 install to the most recently available one seems to not have helped.

I'm in the same boat though, that :PlugUpdate isn't a commonly run command but it was nice when it seemed like it ran much quicker before. Having the command prompt flash open seems like it's the thing that started when the slowness began.

[janlazo]

I assume you were using python/ruby before because this slowness is specific to GVim on Windows because cmd.exe needs a console. This slowness is not as noticeable in terminal Vim because the batchfiles run in the same console. You can try set guioptions+=! to use :terminal for :! but that's outside vim-plug's scope and system will still force a new console. Perhaps vim-plug can batch the creation/deletion of temporary batchfiles but I don't know how to do it.

If vim-plug is updated to not use batchfiles for nvim 0.3, s:shellesc and fzf#shellescape in https://github.com/junegunn/fzf should be updated as well since they use the same shellescape code for cmd.exe.

[janlazo]

#860 is merged which should speed up parallel install/update if using Vim 8 or Neovim regardless of the user's shell. If it's not fast enough, s:system can be enhanced to bypass the shell on Neovim.

[raghur]

So gvim 8.1 - 302s
neovim 4.0 unstable 200s

Since I first ran gvim, it actually had to pull in updates to plugins. When neovim ran, everything was up to date

Also, I'm now at only 44 plugins (compared to 53 of the initial report)

[janlazo]

I assume it increased because the temporary batchfiles increased in size to support utf-8 (same code from fzf Vim plugin, WIP) and the new shellescape code. Shellescape can be optimized similar to how vim-fugitive does it in https://github.com/tpope/vim-fugitive/blob/c63fd1b71be037d4fd583649303875ad0fd17b57/autoload/fugitive.vim#L51. I don't know how else to improve the performance with the Windows shell.

@raghur Do you change your &shell before running PlugInstall?

[raghur]

@raghur Do you change your &shell before running PlugInstall?

No I didn't. Should I?

I did try set guioptions+=! - but that didn't seem to help much.

[janlazo]

@raghur Do you change your &shell before running PlugInstall?

No I didn't. Should I?

I did try set guioptions+=! - but that didn't seem to help much.

It's fine. Default case (cmd.exe) hasn't improved 😞 .

[janlazo]

Is the performance better now?

[raghur]

Unfortunately, no. I ran PlugUprade and then restarted and ran PlugUpdate
45 Plugins - updated in 161s
Win10 x64, Neovim nightly

[Shougo]

@raghur You can test the PR.
#937

[raghur]

Here goes with plug.vim from the PR. Btw, my config's reduced to 39 plugins now. I'm a little puzzled why I'm not seeing an improvement.

Updated. Elapsed time: 338.211278 sec.
[=======================================]

- Finishing ... Done!
- Post-update hook for fzf ... OK
- Post-update hook for coc.nvim ... OK
- Latest tag for * -> v0.0.78 (coc.nvim)
- vim-polyglot:  create mode 100644 syntax/unison.vim
- vim-choosewin: Already up to date.
- ale:  create mode 100644 test/test_hover_parsing.vader
- vim-textobj-line: Already up to date.
- vim-textobj-user: Already up to date.
- fzf.vim: Aborting
- vim-snippets:  create mode 100644 snippets/gitcommit.snippets
- MatchTag: Already up to date.
- vim-textobj-function: Already up to date.
- vim-helpnav: Already up to date.
- vim-hug-neovim-rpc:  1 file changed, 4 insertions(+)
- clever-f.vim: Already up to date.
- vim-go:  15 files changed, 477 insertions(+), 122 deletions(-)
- vim-repeat: Already up to date.
- vim-commentary: Already up to date.
- coc.nvim:    c5f78fdc..806ce475  release    -> origin/release
- NeoFormat:  create mode 100644 autoload/neoformat/formatters/typescriptreact.vim
- eregex.vim: Already up to date.
- vim-textobj-function-javascript: Already up to date.
- ultisnips: Already up to date.
- vim-ghost: Already up to date.
- matchit.zip: Already up to date.
- vim-bookmarks: Already up to date.
- vim-misc: Already up to date.
- vim-airline-themes:  2 files changed, 10 insertions(+), 9 deletions(-)
- vim-surround: Already up to date.
- vim-colorschemes: Already up to date.
- auto-pairs: Already up to date.
- targets.vim: Already up to date.
- vim-closetag: Already up to date.
- sparkup: Already up to date.
- fzf:  16 files changed, 462 insertions(+), 112 deletions(-)
- vim-ragtag: Already up to date.
- vim-airline:  create mode 100644 autoload/airline/formatter/short_path.vim
- undotree: Already up to date.
- nvim-yarp: Already up to date.
- vim-gnupg: Already up to date.
- vim-session: Already up to date.
- vim-rooter:  4 files changed, 389 insertions(+), 288 deletions(-)

Re-running plugupdate with already updated plugins results in

Updated. Elapsed time: 262.420459 sec.

[Shougo]

@mattn Ping.

[Shougo]

@raghur Can you profile the vim-plug code?
:help :profile

[mattn]

@raghur Generally, Windows external command execution is very slow. vim-plug runs a lot of git commands. Get the branch name, get the commit ID, get the remote. And fetch. My patch only makes some of these things faster. By the way, I'm using 38 plugins and PlugUpdate finishes in about 40 seconds.

[raghur]

Yeah - I understand the why. I think my numbers might be something to do outside of Vim - likely antivirus/real time scanning etc. that I cannot disable (work m/c)

[raghur]

Yeah - I know.. but when the slowdown was first noticed, even then the same antivirus/endpoint protection crap was active - so I reasoned that it wasn't a factor. Today as I was digging into this, I noticed that some processes of the antivirus suite are going up to 30% CPU :( - so maybe it is a factor.

BTW, I tried profiling - :profile start filename, :PlugUpdate, :profile stop - but it just writes a 0byte file.

[Shougo]

:profile func
is needed.
You need to research func name pattern.

[raghur]

With profiling turned on

Updated. Elapsed time: 260.067702 sec.
[=======================================]

and the profile:

FUNCTION  <SNR>14_update_finish()
    Defined: ~\AppData\Local\nvim\autoload\plug.vim:1280
Called 1 time
Total time: 132.359899
 Self time:   0.243230

count  total (s)   self (s)
    1              0.000002   if exists('s:git_terminal_prompt')
                                let $GIT_TERMINAL_PROMPT = s:git_terminal_prompt
    1              0.000000   endif
    1   0.000037   0.000007   if s:switch_in()
    1              0.000008     call append(3, '- Updating ...') | 4
   40              0.000474     for [name, spec] in items(filter(copy(s:update.all), 'index(s:update.errors, v:key) < 0 && (s:update.force || s:update.pull || has_key(s:update.new, v:key))'))
   39   0.016823   0.000988       let [pos, _] = s:logpos(name)
   39              0.000051       if !pos
                                    continue
   39              0.000025       endif
   39              0.000140       if has_key(spec, 'commit')
                                    call s:log4(name, 'Checking out '.spec.commit)
                                    let out = s:checkout(spec)
   39              0.000117       elseif has_key(spec, 'tag')
    1              0.000004         let tag = spec.tag
    1              0.000008         if tag =~ '\*'
    1   1.969490   0.000073           let tags = s:lines(s:system('git tag --list '.plug#shellescape(tag).' --sort -version:refname 2>&1', spec.dir))
    1              0.000007           if !v:shell_error && !empty(tags)
    1              0.000005             let tag = tags[0]
    1   0.005765   0.000034             call s:log4(name, printf('Latest tag for %s -> %s', spec.tag, tag))
    1              0.000016             call append(3, '')
    1              0.000002           endif
    1              0.000000         endif
    1   0.003681   0.000020         call s:log4(name, 'Checking out '.tag)
    1   2.025852   0.000082         let out = s:system('git checkout -q '.plug#shellescape(tag).' -- 2>&1', spec.dir)
   38              0.000025       else
   38              0.000149         let branch = get(spec, 'branch', 'master')
   38   0.191398   0.000977         call s:log4(name, 'Merging origin/'.s:esc(branch))
   38 121.514751   0.002422         let out = s:system('git checkout -q '.plug#shellescape(branch).' -- 2>&1'. (has_key(s:update.new, name) ? '' : ('&& git merge --ff-only '.plug#shellescape('origin/'.branch).' 2>&1')), spec.dir)
   39              0.000055       endif
   39              0.110829       if !v:shell_error && filereadable(spec.dir.'/.gitmodules') && (s:update.force || has_key(s:update.new, name) || s:is_updated(spec.dir))
                                    call s:log4(name, 'Updating submodules. This may take a while.')
                                    let out .= s:bang('git submodule update --init --recursive'.s:submodule_opt.' 2>&1', spec.dir)
   39              0.000054       endif
   39   0.003489   0.001143       let msg = s:format_message(v:shell_error ? 'x': '-', name, out)
   39              0.000086       if v:shell_error
                                    call add(s:update.errors, name)
                                    call s:regress_bar()
                                    silent execute pos 'd _'
                                    call append(4, msg) | 4
   39              0.000125       elseif !empty(out)
   38              0.000537         call setline(pos, msg[0])
   39              0.000040       endif
   39              0.121478       redraw
   40              0.000153     endfor
    1              0.000019     silent 4 d _
    1              0.000002     try
    1   5.353058   0.000240       call s:do(s:update.pull, s:update.force, filter(copy(s:update.all), 'index(s:update.errors, v:key) < 0 && has_key(v:val, "do")'))
                                catch
                                  call s:warn('echom', v:exception)
                                  call s:warn('echo', '')
                                  return
    1              0.000001     endtry
    1   1.038236   0.000025     call s:finish(s:update.pull)
    1              0.000041     call setline(1, 'Updated. Elapsed time: ' . split(reltimestr(reltime(s:update.start)))[0] . ' sec.')
    1   0.000108   0.000008     call s:switch_out('normal! gg')
    1              0.000000   endif

FUNCTION  <SNR>14_update_vim()
    Defined: ~\AppData\Local\nvim\autoload\plug.vim:1516
Called 1 time
Total time:   1.785626
 Self time:   0.000018

count  total (s)   self (s)
    1              0.000002   let s:jobs = {}
                            
    1   0.000137   0.000006   call s:bar()
    1   1.785485   0.000009   call s:tick()

FUNCTION  <SNR>14_update()
    Defined: ~\AppData\Local\nvim\autoload\plug.vim:797
Called 1 time
Total time:   2.204861
 Self time:   0.000020

count  total (s)   self (s)
    1   2.204858   0.000017   call s:update_impl(1, a:force, a:names)

FUNCTION  <SNR>14_update_impl()
    Defined: ~\AppData\Local\nvim\autoload\plug.vim:1152
Called 1 time
Total time:   2.204841
 Self time:   0.047145

count  total (s)   self (s)
    1              0.000024   let sync = index(a:args, '--sync') >= 0 || has('vim_starting')
    1              0.000006   let args = filter(copy(a:args), 'v:val != "--sync"')
    1              0.000007   let threads = (len(args) > 0 && args[-1] =~ '^[1-9][0-9]*$') ? remove(args, -1) : get(g:, 'plug_threads', 16)
                            
    1   0.000385   0.000265   let managed = filter(copy(g:plugs), 's:is_managed(v:key)')
    1              0.000079   let todo = empty(args) ? filter(managed, '!v:val.frozen || !isdirectory(v:val.dir)') : filter(managed, 'index(args, v:key) >= 0')
                            
    1              0.000002   if empty(todo)
                                return s:warn('echo', 'No plugin to '. (a:pull ? 'update' : 'install'))
    1              0.000001   endif
                            
    1              0.000003   if !s:is_win && s:git_version_requirement(2, 3)
                                let s:git_terminal_prompt = exists('$GIT_TERMINAL_PROMPT') ? $GIT_TERMINAL_PROMPT : ''
                                let $GIT_TERMINAL_PROMPT = 0
                                for plug in values(todo)
                                  let plug.uri = substitute(plug.uri, '^https://git::@github\.com', 'https://github.com', '')
                                endfor
    1              0.000001   endif
                            
    1              0.001817   if !isdirectory(g:plug_home)
                                try
                                  call mkdir(g:plug_home, 'p')
                                catch
                                  return s:err(printf('Invalid plug directory: %s. '. 'Try to call plug#begin with a valid directory', g:plug_home))
                                endtry
    1              0.000001   endif
                            
    1              0.000017   if has('nvim') && !exists('*jobwait') && threads > 1
                                call s:warn('echom', '[vim-plug] Update Neovim for parallel installer')
    1              0.000000   endif
                            
    1              0.000003   let use_job = s:nvim || s:vim8
    1              0.000041   let python = (has('python') || has('python3')) && !use_job
    1              0.000019   let ruby = has('ruby') && !use_job && (v:version >= 703 || v:version == 702 && has('patch374')) && !(s:is_win && has('gui_running')) && threads > 1 && s:check_ruby()
                            
    1              0.000041   let s:update = { 'start':   reltime(), 'all':     todo, 'todo':    copy(todo), 'errors':  [], 'pull':    a:pull, 'force':   a:force, 'new':     {}, 'threads': (python || ruby || use_job) ? min([len(todo), threads]) : 1, 'bar':     '', 'fin':     0 }
                            
    1   0.371882   0.000024   call s:prepare(1)
    1              0.000017   call append(0, ['', ''])
    1              0.000045   normal! 2G
    1              0.044511   silent! redraw
                            
    1              0.000007   let s:clone_opt = []
    1              0.000007   if get(g:, 'plug_shallow', 1)
    1              0.000008     call extend(s:clone_opt, ['--depth', '1'])
    1   0.000073   0.000021     if s:git_version_requirement(1, 7, 10)
    1              0.000009       call add(s:clone_opt, '--no-single-branch')
    1              0.000001     endif
    1              0.000000   endif
                            
    1              0.000028   if has('win32unix') || has('wsl')
                                call extend(s:clone_opt, ['-c', 'core.eol=lf', '-c', 'core.autocrlf=input'])
    1              0.000000   endif
                            
    1   0.000050   0.000012   let s:submodule_opt = s:git_version_requirement(2, 8) ? ' --jobs='.threads : ''
                            
                              " Python version requirement (>= 2.7)
    1              0.000003   if python && !has('python3') && !ruby && !use_job && s:update.threads > 1
                                redir => pyv
                                silent python import platform; print platform.python_version()
                                redir END
                                let python = s:version_requirement( map(split(split(pyv)[0], '\.'), 'str2nr(v:val)'), [2, 6])
    1              0.000000   endif
                            
    1              0.000002   if (python || ruby) && s:update.threads > 1
                                try
                                  let imd = &imd
                                  if s:mac_gui
                                    set noimd
                                  endif
                                  if ruby
                                    call s:update_ruby()
                                  else
                                    call s:update_python()
                                  endif
                                catch
                                  let lines = getline(4, '$')
                                  let printed = {}
                                  silent! 4,$d _
                                  for line in lines
                                    let name = s:extract_name(line, '.', '')
                                    if empty(name) || !has_key(printed, name)
                                      call append('$', line)
                                      if !empty(name)
                                        let printed[name] = 1
                                        if line[0] == 'x' && index(s:update.errors, name) < 0
                                          call add(s:update.errors, name)
                                        end
                                      endif
                                    endif
                                  endfor
                                finally
                                  let &imd = imd
                                  call s:update_finish()
                                endtry
    1              0.000000   else
    1   1.785635   0.000009     call s:update_vim()
    1              0.000004     while use_job && sync
                                  sleep 100m
                                  if s:update.fin
                                    break
                                  endif
    1              0.000002     endwhile
    1              0.000001   endif

FUNCTIONS SORTED ON TOTAL TIME
count  total (s)   self (s)  function
    1 132.359899   0.243230  <SNR>14_update_finish()
    1   2.204861   0.000020  <SNR>14_update()
    1   2.204841   0.047145  <SNR>14_update_impl()
    1   1.785626   0.000018  <SNR>14_update_vim()

FUNCTIONS SORTED ON SELF TIME
count  total (s)   self (s)  function
    1 132.359899   0.243230  <SNR>14_update_finish()
    1   2.204841   0.047145  <SNR>14_update_impl()
    1   2.204861   0.000020  <SNR>14_update()
    1   1.785626   0.000018  <SNR>14_update_vim()

[Shougo]

Oh, git checkout is too slow in your environment.

[raghur]

hmm - under WSL takes 26.92 seconds only.

[junegunn]

Closing an old issue. Please leave a comment if this still matters to you.