Vim is blocked for 3 sec when opening first tex file

[kiryph]

Initializing vimtex has become quite slow on my machine. I have configured a minimal vim config with only vimtex:

❯ tree -L 6 ~/.vim
/Users/kiryph/.vim
├── pack
│   └── lervag
│       └── start
│           └── vimtex
│               ├── CONTRIBUTING.md
│               ├── ISSUE_TEMPLATE.md
│               ├── LICENSE.md
│               ├── README.md
│               ├── after
│               │   ├── ftplugin
│               │   └── syntax
│               ├── autoload
│               │   ├── health
│               │   ├── unite
│               │   ├── vimtex
│               │   └── vimtex.vim
│               ├── doc
│               │   └── vimtex.txt
│               ├── ftplugin
│               │   ├── bib.vim
│               │   └── tex.vim
│               ├── indent
│               │   ├── bib.vim
│               │   └── tex.vim
│               ├── media
│               │   └── quick_start.gif
│               ├── rplugin
│               │   └── python3
│               └── test
│                   ├── examples
│                   ├── features
│                   ├── issues
│                   └── vader
├── profile.log
└── vimrc

22 directories, 13 files

~
❯ cat ~/.vim/vimrc
set nocompatible

filetype plugin indent on
syntax enable

" Vimtex options go here
" NONE

I have checked out the most recent commit from master

~/.vim/pack/lervag/start/vimtex master
❯ git log -1
commit 36cd8be5e3bcc5465bfbb52e2de3c0d99b1d12d1 (HEAD -> master, origin/master, origin/HEAD)
Author: Karl Yngve Lervåg <karl.yngve+git@gmail.com>
Date:   Tue Aug 14 22:42:44 2018 +0200

    Improved TOC filter implementation

When I simply open vim and type :set ft=tex, the editor is blocked for a while. I have profiled this with

$ vim
:profile start profile.log
:profile func *
:profile file *
:set ft=tex
:profile pause
:noautocmd qall!

The summary in the resulting profile.log is:

FUNCTIONS SORTED ON TOTAL TIME
count  total (s)   self (s)  function
    1   3.453665   0.001237  <SNR>6_LoadFTPlugin()
    1   3.448878   0.000187  vimtex#init()
    1   2.231296   0.000335  <SNR>26_init_state()
    1   2.230015   0.000090  vimtex#state#init()
    1   2.226485   0.001608  1()
    1   2.215433   0.000227  vimtex#compiler#init_state()
    1   2.214367   0.000049  vimtex#compiler#latexmk#init()
    1   2.214318   0.000208  28()
    2   2.213719   0.001251  <SNR>36_parse_latexmkrc_option()
    1   1.193944   0.000967  vimtex#init_options()
    1   1.119530   0.000082  30()
    1   1.094347   0.000076  29()
    1   0.044766   0.000511  <SNR>9_SynSet()
    1   0.018838   0.004393  <SNR>26_init_buffer()
    1   0.004097   0.000513  vimtex#imaps#init_buffer()
    1   0.003801   0.000535  <SNR>26_init_default_mappings()
   63   0.003584             <SNR>60_create_map()
    1   0.003579   0.001956  vimtex#fold#init_state()
    1   0.003422   0.000317  <SNR>28_get_main()
  101   0.003266             <SNR>26_map()

FUNCTIONS SORTED ON SELF TIME
count  total (s)   self (s)  function
    1   0.018838   0.004393  <SNR>26_init_buffer()
   63              0.003584  <SNR>60_create_map()
  101              0.003266  <SNR>26_map()
   12              0.002007  TexNewMathZone()
    1   0.003579   0.001956  vimtex#fold#init_state()
    1   2.226485   0.001608  1()
    1   0.001750   0.001261  <SNR>28_get_main_recurse()
    2   2.213719   0.001251  <SNR>36_parse_latexmkrc_option()
    1   3.453665   0.001237  <SNR>6_LoadFTPlugin()
    2              0.001008  <SNR>28_findfiles_recursive()
    1   1.193944   0.000967  vimtex#init_options()
   64              0.000942  <SNR>26_init_option()
    1              0.000812  <SNR>26_init_highlights()
    1   0.000753   0.000586  <SNR>55_get_delim()
    1              0.000541  vimtex#util#command()
    1   0.003801   0.000535  <SNR>26_init_default_mappings()
    1   0.004097   0.000513  vimtex#imaps#init_buffer()
    1   0.044766   0.000511  <SNR>9_SynSet()
    1   0.000685   0.000477  <SNR>55_init_delim_regexes()
    1              0.000458  vimtex#motion#init_buffer()

Can someone confirm this?

[kiryph]

My current guess is the function

    2   2.218903   0.001251  <SNR>36_parse_latexmkrc_option()

I think there have been recently changes.

Also in older versions of vimtex 6ba4685 latexmkrc parsing was slow but not as bad as right now:

    1   1.106570   0.000061  vimtex#compiler#latexmk#init()

Significant improvement can be achieved with

let g:vimtex_compiler_enabled = 0

Minor improvements with

let g:vimtex_imaps_enabled = 0
let g:vimtex_matchparen_enabled = 0

From my point of view the convenience functions <SNR>60_create_map() and <SNR>26_map() illustrate that vimscript is quite slow.

I have two thoughts for improvement:

• async initialization: typically, a user want to see the file (syntax highlighting) and use some mappings; the compiler could be made waiting until latexmkrc parsing is finished.
• Writing the inititialization code of the plugin in python/lua/ when available (not sure if this can improve it)

[lervag]

I can' reproduce this. For me, vimtex loads in O(0.1) seconds when I do :set ft=tex. For large projects, I agree it can take some time, but typically not more than 1 second.

Which version of Vim are you on, and which OS? (I guess I should start to remember this now, but alas...)

[kiryph]

Thanks for looking into this.

I was suspecting that this is not the case for everyone. Otherwise this would not have been unnoticed. I would be totally fine if vimtex would load on :set ft=tex in 0.1 seconds and for large projects around 1 second.

Sorry for missing some information:

OS: macOS Sierra 10.12.6

vim version:

❯ mvim --version
VIM - Vi IMproved 8.1 (2018 May 17, compiled Jun 17 2018 23:04:26)
macOS version
Included patches: 1-72
Compiled by travis@Traviss-Mac-1044.local
Huge version with MacVim GUI.  Features included (+) or not (-):
[REMOVED]
   system vimrc file: "$VIM/vimrc"
     user vimrc file: "$HOME/.vimrc"
 2nd user vimrc file: "~/.vim/vimrc"
      user exrc file: "$HOME/.exrc"
  system gvimrc file: "$VIM/gvimrc"
    user gvimrc file: "$HOME/.gvimrc"
2nd user gvimrc file: "~/.vim/gvimrc"
       defaults file: "$VIMRUNTIME/defaults.vim"
    system menu file: "$VIMRUNTIME/menu.vim"
  fall-back for $VIM: "/Applications/MacVim.app/Contents/Resources/vim"
Compilation: clang -c -I. -Iproto -DHAVE_CONFIG_H -DFEAT_GUI_MACVIM -Wall -Wno-unknown-pragmas -pipe  -DMACOS_X -DMACOS_X_DARWIN  -g -O2 -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=1
Linking: clang   -L. -fstack-protector -L/usr/local/lib -L/usr/local/opt/libyaml/lib -L/usr/local/opt/openssl/lib -L/usr/local/opt/readline/lib -L. -fstack-protector -L/usr/local/lib -L/usr/local/opt/libyaml/lib -L/usr/local/opt/openssl/lib -L/usr/local/opt/readline/lib  -L/usr/local/lib -o Vim -framework Cocoa -framework Carbon       -lm  -lncurses -liconv -framework AppKit   -fstack-protector  -L/System/Library/Perl/5.18/darwin-thread-multi-2level/CORE

I also add the content of my latexmkrc:

❯ cat ~/.config/latexmk/latexmkrc
$pdf_mode = 1; # pdflatex

$clean_ext = "paux lox pdfsync out";
push @generated_exts, "run.xml";
push @generated_exts, "synctex.gz";
push @generated_exts, "run.xml";
push @generated_exts, "bbl";

# Enable synctex, shell-escape and recorder
$lualatex = 'lualatex -shell-escape -recorder -synctex=1 %O %S';
$pdflatex = 'pdflatex -shell-escape -recorder -synctex=1 %O %S';

#  Set this only on macOS in /Users/kiryph/.config/latexmk/latexmkrc
#  not in a project .latexmkrc
$pdf_previewer = "open -a Skim";

# Copy this to projects with local `texmf` folder
#
#{
#no warnings 'uninitialized';
#$ENV{'TEXINPUTS'} = './texmf//:'.$ENV{'TEXINPUTS'};
#}

# Support package 'glossaries'

# add_cus_dep('glo', 'gls', 0, 'run_makeglossaries');
# add_cus_dep('acn', 'acr', 0, 'run_makeglossaries');

# sub run_makeglossaries {
#   if ( $silent ) {
#     system "makeglossaries -q '$_[0]'";
#   }
#   else {
#     system "makeglossaries '$_[0]'";
#   };
# }
# push @generated_exts, 'glo', 'gls', 'glg';
# push @generated_exts, 'acn', 'acr', 'alg';
# $clean_ext .= ' %R.ist %R.xdy';

# pythontex
# add_cus_dep('pytxcode','tex',0,'pythontex');
# sub pythontex { return system("pythontex --interpreter python:python3 \"$_[0]\""); }

[lervag]

Thanks. I don't see anything that explains your problem.

Also, it does not seem like the profiling info quite makes sense. That is, the product of self time and the count does not add up to the O(1) seconds. Perhaps you could do some custom profiling by using the reltime() function inside vimtex#init(), e.g. add:

function! vimtex#init() " {{{1
  let l:time = reltime()
  call vimtex#init_options()

  call s:init_highlights()
  call s:init_state()
  call s:init_buffer()
  call s:init_default_mappings()

  if exists('#User#VimtexEventInitPost')
    doautocmd <nomodeline> User VimtexEventInitPost
  endif

  augroup vimtex_main
    autocmd!
    autocmd VimLeave * call s:quit()
  augroup END
  echom 'timing:' reltimestr(reltime(l:time))
endfunction

This way, you could pinpoint the part of the init that is taking a long time to finish.

[kiryph]

function! vimtex#init() " {{{1
  let l:time = reltime()
  echom 'timing:' reltimestr(reltime(l:time))
  call vimtex#init_options()
  echom 'timing:' reltimestr(reltime(l:time))

  call s:init_highlights()
  echom 'timing:' reltimestr(reltime(l:time))
  call s:init_state()
  echom 'timing:' reltimestr(reltime(l:time))
  call s:init_buffer()
  echom 'timing:' reltimestr(reltime(l:time))
  call s:init_default_mappings()
  echom 'timing:' reltimestr(reltime(l:time))

  if exists('#User#VimtexEventInitPost')
    doautocmd <nomodeline> User VimtexEventInitPost
  endif
  echom 'timing:' reltimestr(reltime(l:time))

  augroup vimtex_main
    autocmd!
    autocmd VimLeave * call s:quit()
  augroup END
  echom 'timing:' reltimestr(reltime(l:time))
endfunction

returns

timing:   0.000009 after let l:time = reltime()
timing:   1.184300 after call vimtex#init_options()
timing:   1.185110 after call s:init_highlights()
timing:   3.493891 after call s:init_state()
timing:   3.525956 after call s:init_buffer()
timing:   3.530732 after call s:init_default_mappings()
timing:   3.530783 after if exists('#User#VimtexEventInitPost') ... endif
timing:   3.531002 after augroup vimtex_main ... augroup END

The slow parts are obviously:

1. timing: 1.184300 after call vimtex#init_options()
2. timing: 3.493891 after call s:init_state()

I also surrounded each line or block to see the timing:

timing:   1.159266 only call vimtex#init_options()
timing:   0.000688 only call s:init_highlights()
timing:   2.419747 only call s:init_state()
timing:   0.023658 only call s:init_buffer()
timing:   0.004407 only call s:init_default_mappings()
timing:   0.000011 only if exists('#User#VimtexEventInitPost') ... endif
timing:   0.000117 only augroup vimtex_main ... augroup END

[kiryph]

I identified an/the issue: I have added your profiling statements around following code part

❯ g diff
diff --git a/autoload/vimtex/compiler/latexmk.vim b/autoload/vimtex/compiler/latexmk.vim
index f4469b9..f234f49 100644
--- a/autoload/vimtex/compiler/latexmk.vim
+++ b/autoload/vimtex/compiler/latexmk.vim
@@ -607,12 +607,14 @@ function! s:parse_latexmkrc_option(root, opt, is_integer, default) abort " {{{1

   " Candidate files
   " - each element is a pair [path_to_file, is_local_rc_file].
+  let l:time = reltime()
   let l:files = [
         \ [a:root . '/latexmkrc', 1],
         \ [a:root . '/.latexmkrc', 1],
         \ [fnamemodify('~/.latexmkrc', ':p'), 0],
         \ [expand('$XDG_CONFIG_HOME/latexmk/latexmkrc'), 0],
         \]
+  echom 'timing:' reltimestr(reltime(l:time)). " expand('XDG_CONFIG_HOME')"

   for [l:file, l:is_local] in l:files
     if filereadable(l:file)

Now when I start vim and :set ft=tex, I get following timing result

timing:   1.187992 expand('XDG_CONFIG_HOME')
timing:   1.193442 expand('XDG_CONFIG_HOME')
Press ENTER or type command to continue

Vim documentation already says following under :h expr-env-expand:

Note that there is a difference between using $VAR directly and using
expand("$VAR").  Using it directly will only expand environment variables that
are known inside the current Vim session.  Using expand() will first try using
the environment variables known inside the current Vim session.  If that
fails, a shell will be used to expand the variable.  This can be slow, but it
does expand all variables that the shell knows about.  Example:
        :echo $shell
        :echo expand("$shell")
The first one probably doesn't echo anything, the second echoes the $shell
variable (if your shell supports it).

I am under macOS where $XDG_CONFIG_HOME is not defined and therefore this becomes slow as documented.

When I add to my vimrc

let $XDG_CONFIG_HOME = '/Users/kiryph/.config/'

the results are much better:

timing:   0.000046 expand('XDG_CONFIG_HOME')
timing:   0.000036 expand('XDG_CONFIG_HOME')
Press ENTER or type command to continue

And if I use again the snippet for vimtex#init() of my previous comment, I get:

timing:   0.000006
timing:   1.168938
timing:   1.170246
timing:   1.182250
timing:   1.200429
timing:   1.206377
timing:   1.206401
timing:   1.206567 

The remaining slow part is call vimtex#init_options().

Can you try my snippet for vimtex#init() for yourself, if it is still much faster for you than me?

[kiryph]

Another performance improvement can be achieved for Macvim or vim-homebrew user. has('mac') works for them (not the pre-installed /usr/bin/vim) and is faster than system('uname'):

diff --git a/autoload/vimtex/util.vim b/autoload/vimtex/util.vim
index d9bccea..26a8c64 100644
--- a/autoload/vimtex/util.vim
+++ b/autoload/vimtex/util.vim
@@ -22,7 +22,7 @@ function! vimtex#util#get_os() " {{{1
   if has('win32') || has('win32unix')
     return 'win'
   elseif has('unix')
-    if system('uname') =~# 'Darwin'
+    if has('mac') || system('uname') =~# 'Darwin'
       return 'mac'
     else
       return 'linux'

With this patch and let $XDG_CONFIG_HOME = '/Users/kiryph/.config/' in my vimrc I get following timing

timing:   0.000007
timing:   0.002422
timing:   0.003057
timing:   0.019661
timing:   0.045640
timing:   0.049957
timing:   0.049997
timing:   0.050246
Press ENTER or type command to continue

This is fine!!!

[kiryph]

I have created #1216.

I am not sure how one should use $XDG_CONFIG_HOME on macOS. I personally use the location $HOME/.config for my config files:

❯ tree -L 1 .config
.config
├── Binreader
├── QCAD
├── README.md
├── alacritty
├── configstore
├── cppman
├── darktable
├── enchant
├── git
├── grv
├── gtk-2.0
├── gtk-3.0
├── htop
├── hub
├── inkscape
├── karabiner
├── kitty
├── latexmk
├── mc
├── meld
├── menus
├── micro
├── nvim
├── oni
├── pdfpc
├── qtcurve
├── ranger
├── texstudio
├── tig
├── vifm
├── xm1
├── yarn
├── zathura
├── zim
└── zsh

I will keep let $XDG_CONFIG_HOME = '/Users/kiryph/.config/' in my vimrc so it is faster.

If you are ok with my PR, this issue can be closed.

[lervag]

I just pushed your suggested changes; for the expand(), I reckoned that one would not really need to expand it at all, and so I simply check if the env variable exist, and if it does, then I add the last candidate to the candidate list. Does this work as expected?

[lervag]

Btw., it feels like there should be a better way of checking for MacOS. E.g., perhaps checking for the existence of a certain file that typically is there for OSX but not Linux/FreeBSD with filereadable()?

[kiryph]

You added a typo:

diff --git a/autoload/vimtex/util.vim b/autoload/vimtex/util.vim
index eca6a70..26a8c64 100644
--- a/autoload/vimtex/util.vim
+++ b/autoload/vimtex/util.vim
@@ -22,7 +22,7 @@ function! vimtex#util#get_os() " {{{1
   if has('win32') || has('win32unix')
     return 'win'
   elseif has('unix')
-    if has('max') || system('uname') =~# 'Darwin'
+    if has('mac') || system('uname') =~# 'Darwin'
       return 'mac'
     else
       return 'linux'

[lervag]

Oh, and: Why are system() calls on OSX so slow? On my Linux, system('uname') runs in appr. 0 time...

[kiryph]

My current suspicion is my default shell zsh with the file .zshenv. .zshenv is sourced for any shell: non-interactive, interactive, login, non-login. It contains a few non trivial lines:

# PATH
PATH="/usr/local/bin:$PATH"
# already on path (but not in alacritty)
PATH="/usr/local/sbin:$PATH"
# pip2.6/3.1 install --user
PATH="/Users/kiryph/.local/bin:$PATH"
# pip2/3 install --user
PATH="/Users/kiryph/Library/Python/2.7/bin:$PATH"
PATH="/Users/kiryph/Library/Python/3.6/bin:$PATH"
# perl5
PATH="/Users/kiryph/perl5/bin${PATH:+:${PATH}}";

PATH="$HOME/.cargo/bin:$PATH"

# homebrew perl
eval "$(perl -I$HOME/perl5/lib/perl5 -Mlocal::lib=$HOME/perl5)"

export PATH=$PATH:~/.android-sdk-macosx/platform-tools

if which ruby >/dev/null && which gem >/dev/null; then
    PATH="$(ruby -rubygems -e 'puts Gem.user_dir')/bin:$PATH"
fi

if command -v pyenv 1>/dev/null 2>&1; then
  eval "$(pyenv init -)"
fi

# pyenv and pyenv-virtualenv (conda)
if which pyenv > /dev/null; then eval "$(pyenv init -)"; fi
if which pyenv-virtualenv-init > /dev/null; then eval "$(pyenv virtualenv-init -)"; fi

export PATH;

I guess I should profile this one as well.

[lervag]

Ah. I would keep the Vim shell to its default /bin/sh, because running shell commands from Vim should not fire up your "terminal shell". (IMHO)

But in any case, I think your vimtex slow init issue should be resolved, right?

[kiryph]

Yes, my vimtex issue is resolved 😌😃.

In general I agree with you regarding /bin/sh.

However, I configured macOS so that zsh is the default and not the old bash 3.2 version preinstalled by Apple:

❯ /bin/sh --version
GNU bash, version 3.2.57(1)-release (x86_64-apple-darwin16)
Copyright (C) 2007 Free Software Foundation, Inc.
❯ /bin/bash --version
GNU bash, version 3.2.57(1)-release (x86_64-apple-darwin16)
Copyright (C) 2007 Free Software Foundation, Inc.

Apple cannot provide a more recent bash version due to licensing issues (new gpl license of bash).

I also like a consistent PATH variable between interactive and non-interactive shells.

[lervag]

Ah, ok. I see. In any case, it is good to see yet another issue resolved. :)