找出导致Vim运行缓慢的插件

2018-08-08|Categories: awk-sed-grep, Linux, Vim|

影响Vim使用体验的除了启动缓慢之外,更多时候是运行缓慢,而这通常都是插件导致的,此时我们需要对Vim做性能分析,以便从一大堆插件中找出「罪魁祸首」,然后调整相关配置,或者直接换用其它插件。幸运的是,Vim内建了性能分析命令:profile

生成Vim性能分析日志

首先,打开Vim,然后依次执行以下:profile命令生成性能分析日志:

" https://stackoverflow.com/a/12216578/3025050

:profile start ~/vim_profile.log
:profile func *
:profile file *
" At this point do slow actions
:profile pause
:noautocmd qall!

" unlike quitting `noautocmd` is not really required, it just makes vim quit faster.

性能分析日志~/vim_profile.log主要包含两部分内容:

  • SCRIPT:所有被加载的文件的性能分析
  • FUNCTION:所有被调用的函数的性能分析
$ grep -m1 'SCRIPT' -A20 vim_profile.log
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete.vim
Sourced 1 time
Total time:   0.000106
 Self time:   0.000106

count  total (s)   self (s)
                            "=============================================================================
                            " FILE: deoplete.vim
                            " AUTHOR: Shougo Matsushita <Shougo.Matsu at gmail.com>
                            " License: MIT license
                            "=============================================================================

    1              0.000005 function! deoplete#initialize() abort
                              return deoplete#init#_initialize()
                            endfunction
    1              0.000001 function! deoplete#is_enabled() abort
                              return deoplete#init#_is_handler_enabled()
                            endfunction
    1              0.000002 function! deoplete#enable() abort
                              if deoplete#initialize()
                                return 1
$ grep -m1 'FUNCTION' -A10 vim_profile.log
FUNCTION  yarp#core#jobstart()
Called 2 times
Total time:   0.003335
 Self time:   0.000079

count  total (s)   self (s)
    2              0.000004     if ! has_key(self, 'cmd')
    1   0.000500   0.000343         call self.init()
    1              0.000003         if ! has_key(self, 'cmd')
                                        call self.error("cmd of the job is not set")
                                        return

直接查看FUNCTION的性能统计信息

性能日志末尾已经包含了所有FUNCTION的统计信息:

FUNCTIONS SORTED ON TOTAL TIME
count  total (s)   self (s)  function
    1   0.745586   0.000029  deoplete#enable()
    1   0.744262   0.000082  deoplete#initialize()
    1   0.743858   0.000166  deoplete#init#_initialize()
    4   0.638692   0.000129  yarp#core#notify()
    1   0.638040   0.000180  deoplete#init#_channel()
    4   0.636820   0.631110  yarp#core#wait_channel()
    8   0.113939   0.000806  airline#check_mode()
    2   0.112393   0.005422  airline#highlighter#highlight()
    1   0.105089   0.000270  <SNR>90_init_internal_variables()
    2   0.103830   0.003435  neovim_rpc#serveraddr()
    6   0.100642             <SNR>92_py()
  185   0.087485   0.010858  airline#highlighter#get_highlight()
  370   0.075121             <SNR>79_get_syn()
  129   0.069103   0.012661  airline#highlighter#exec()
    1   0.059051             UltiSnips#TrackChange()
   28   0.044535   0.001367  <SNR>79_exec_separator()
   56   0.037162   0.001018  airline#themes#get_highlight()
    3   0.007725   0.000210  <SNR>98_completion_begin()
    4   0.007353   0.004630  deoplete#init#_context()
    2   0.005722   0.000126  <SNR>98_completion_async()

可以看到,仅deoplete插件相关的函数差不多就执行了3秒钟,这就是我在运行Vim时感觉到明显延迟的原因所在。

手工统计SCRIPT的性能信息

与FUNCTION不一样,所有被加载文件(SCRIPT)对性能的影响没有在日志中进行总结,需要我们手工处理。

第一步,我们需要筛选出每一个脚本的加载时间,此处仅显示前三个匹配项(-m3)作为示例:

$ grep 'SCRIPT' -A2 -m3 vim_profile.log
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete.vim
Sourced 1 time
Total time:   0.000106
--
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete/init.vim
Sourced 1 time
Total time:   0.000299
--
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete/util.vim
Sourced 1 time
Total time:   0.000520

第二步,把每个脚本相关的四行合并为一行:

$ grep 'SCRIPT' -A2 -m3 vim_profile.log | xargs -d'\n' -n4 | column -t
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete.vim       Sourced  1  time  Total  time:  0.000106  --
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete/init.vim  Sourced  1  time  Total  time:  0.000299  --
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete/util.vim  Sourced  1  time  Total  time:  0.000520

多行合并为一行的关键是xargs -d'\n' -n4,表示xargs以换行符作为标准输入(stdin)的分隔符(默认分隔符是空白字符,包括空格、制表符、换行符),把每4行合并为一个参数,合并后的参数内部用一个空格分隔原有的各行。column -t仅仅是为了让输出更美观。

注意,最后一行的行尾没有--(grep添加的分隔符),这会影响后续的awk处理,因此我们要用--no-group-separator选项禁止grep显示分隔符:

$ grep --no-group-separator 'SCRIPT' -A2 -m3 vim_profile.log | xargs -d'\n' -n3 | column -t
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete.vim       Sourced  1  time  Total  time:  0.000106
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete/init.vim  Sourced  1  time  Total  time:  0.000299
SCRIPT  /root/.vim/plugged/deoplete.nvim/autoload/deoplete/util.vim  Sourced  1  time  Total  time:  0.000520

此时就可以用awk脚本提取我们需要的字段进行统计:

$ grep --no-group-separator 'SCRIPT' -A2 vim_profile.log | xargs -d '\n' -n3 | \
awk -F'[ /]' '{print $7,$NF}' | \
awk '{plug[$1]++; time[$1]+=$2} END {for (i in plug) {printf "%20s %10.6f sec\n", i, time[i] | "sort -k2nr"}}'
           ultisnips   0.080386 sec
       deoplete.nvim   0.002275 sec
           nvim-yarp   0.000809 sec
  vim-hug-neovim-rpc   0.000426 sec

可以看到,相对于函数调用所花费的时间,加载文件花费的时间非常短暂,基本上可以忽略不计。

以上就是Vim性能分析、统计的完整过程,有了这些统计信息,下一步就可以进行针对性的优化,最终让Vim运行流畅,「如丝般顺滑」。

更多资料

http://inlehmansterms.net/2015/01/17/profiling-vim/

Leave A Comment