There’s only so far you can get by cargo-culting other people’s ~/.vim folders. An important next step is understanding how to debug Vim; knowing what to do when it’s slow or misbehaving. Learn how to scratch things that itch.

This post illustrates a range of debugging and profiling approaches for Vim by walking through real issues I’ve recently investigated, diagnosed and resolved. There’s very little to copy into your ~/.vimrc but hopefully some useful techniques that you can use.

If you take anything from this post, let it be that Vim has excellent support for debugging and profiling and, with a little knowledge, it’s easy to resolve most annoyances.

Contents:

“Why isn’t it working?”

I noticed that hashivim/vim-terraform supports running terraform fmt as a pre-save autocommand by setting g:terraform_fmt_on_save = 1 . I already had the ftplugin component of hashivim/vim-terraform installed via sheerun/vim-polyglot , yet after adding the above setting to ~/.vimrc , it wasn’t working. Saving a poorly formatted Terraform file didn’t do anything; it seemed that terraform fmt wasn’t being run. Why?

Print statements

I first identified the file responsible for handling this setting with a quick search:

$ ag -l terraform_fmt_on_save ~/.vim/bundle/ ~/.vim/bundle/vim-polyglot/ftplugin/terraform.vim

then sprinkled a few:

echom "Got here"

statements into that file, opened a new Terraform file-type buffer:

: edit sample . tf

and ran:

: messages

to see the results. This showed that the plugin was prematurely finish ing on this guard:

if exists ( "g:loaded_terraform" ) || v : version < 700 || & cp || ! executable ( 'terraform' ) finish endif

I then :echo ed each predicate at the command prompt to identify the culprit:

: echo executable ( 'terraform' ) 0

Turned out that executable('terraform') was returning 0 due to the way I had configured my shell’s $PATH environment variable. Specifically, downloaded Hashicorp binaries were in a ~/hashicorp folder that was added to $PATH in ~/.bashrc like so:

HASHICORP = "~/hashicorp" PATH = " $HASHICORP : $PATH " export $PATH

This works fine in shell sessions but Vim doesn’t expand the ~ when running the executable check and so doesn’t find the terraform binary.

The fix was to update ~/.bashrc to use $HOME instead of the ~ shorthand:

HASHICORP = " $HOME /hashicorp" PATH = " $HASHICORP : $PATH " export $PATH

After that, saving a Terraform file ran terraform fmt automatically. Phew.

Related help docs

:help echom

:help messages (note, there’s a superior :Messages command provided by Tim Pope’s tpope/vim-scriptease that loads the messages into the quickfix list which is much more convenient).

(note, there’s a superior command provided by Tim Pope’s that loads the messages into the quickfix list which is much more convenient). :help executable

Debug mode

I could have solved the same mystery using Vim’s little-known debug mode by adding a breakpoint at the start of the suspect ftplugin file:

: breakadd file ~ /.vim/ bundle /vim-polyglot/ ftplugin / terraform . vim

then opening a Terraform file-type buffer in debug mode:

: debug edit sample . tf

which drops you at a debugger prompt:

Entering Debug mode. Type "cont" to continue . cmd edit sample.tf >

After hitting c to continue to the breakpoint:

>c "sample.tf" [ New File ] Breakpoint in "~/.vim/bundle/vim-polyglot/ftplugin/terraform.vim" line 1 ~/.vim/bundle/vim-polyglot/ftplugin/terraform.vim line 1: if !exists ( 'g:polyglot_disabled' ) || index ( g:polyglot_disabled, 'terraform' ) == -1 >

you can run each Ex expression individually to pinpoint the problem:

> echo exists ( 'terraform' ) 0

It’s also possible to simply insert:

breakadd here

to set a breakpoint in a file.

Further reading:

Verbose mode

Another approach is to use “verbose mode” to find out what Vim is doing. You can start Vim in verbose mode with:

$ vim -V9 some-file

which echo s out what Vim is doing (the 9 indicates the level of verbosity).

You can inspect with output with :messages (or :Messages ) but it’s often useful to write the output to file using the verbosefile option. Here’s an example of doing that for a single action:

: set verbose = 9 : set verbosefile = /tmp/ output . txt : verbose { some action }

Further reading:

Process of elimination

Finally, you can try and locate the source of a problem through stripping away all custom plugins and configuration, then slowly add them back in until the symptoms reappear.

Start by verifying the problem is not present when Vim is loaded without custom configuration ( -N means nocompatible mode):

$ vim -u NONE -U NONE -N

then comment out everything in your ~/.vimrc files and slowly uncomment blocks until the problem appears.

For this and many other situations, its useful to use the :scriptnames command to see all the sourced files for your current buffer. Like :messages , this has a superior counterpart, :Scriptnames , in tpope/vim-scriptease , that loads each script into the quickfix list.

Alternatively, you can capture the output of :scriptnames (or any other Ex command) in a buffer for further interrogation. Do this by redirecting messages to a register of your choice:

: redir @ a : scriptnames : redir END

which you can then paste into a buffer and examine in detail.

Further reading:



Now a few more specific scenarios:

“Why isn’t my option working?”

I noticed the other day that the textwidth option I had carefully suggested in ~/.vim/ftplugin/gitcommit.vim wasn’t in effect when editing a git commit message.

You can check an option’s value with:

set textwidth ?

To investigate, I looked up which Vim file had last set the option by prepending :verbose :

: verbose set textwidth ?

revealing:

textwidth=72 Last set from ~/.vim/bundle/vim-polyglot/ftplugin/gitcommit.vim line 17

So the ftplugin file from sheerun/vim-polyglot was to blame.

When you set options from files in ~/.vim/ftplugin/ , there’s always a danger they will be clobbered by your plugins (which are sourced afterwards).

The solution was to move the option assignment to ~/.vim/after/ftplugin/gitcommit.vim to ensure it gets sourced after other matching filepaths on Vim’s $RUNTIMEPATH .

Note that you can prepend :verbose to map (and several other) commands to see where particular mappings are defined. Eg:

: verbose imap < leader >

Further reading:

“Why isn’t syntax highlighting working as I want?”

I recently enabled spell-checking for all file-types:

" ~/.vimrc set spell

but found that this also includes spell-checking strings in Python, which I can’t imagine anyone wanting.

To resolve, I used the zS command from tpope/scriptease to identify the syntax region name for Python strings: pythonString . Then used :verbose to determine where this was last set:

: verbose hi pythonString pythonString xxx links to String Last set from ~ /.vim/ bundle /vim-polyglot/ syntax / python . vim line 442

Line 442 isn’t actually where the syn region declarations are, but they are in the same file.

To resolve this issue, I needed to remove @Spell from the syn region pythonString declarations. I’m sure this can be elegantly scripted but I resorted to duplicating the relevant lines into ~/.vim/after/syntax/python.vim and removing the @Spell clusters. Ugly but effective.

Further reading:

“Why is Vim slow to start up?”

Recently, after accumulating several plugins, I noticed Vim was taking noticeably longer to start-up. Why?

Profile start-up

I started Vim in profiling mode:

$ vim --startuptime startup.txt startup.txt

where each executed expression is timed and listed in the specified file (which is also opened):

times in msec clock self + sourced self : sourced script clock elapsed : other lines 000 . 010 000 . 010 : --- VIM STARTING --- 000 . 152 000 . 142 : Allocated generic buffers 001 . 230 001 . 078 : locale set ... 276 . 800 002 . 201 : VimEnter autocommands 276 . 802 000 . 002 : before starting main loop 276 . 957 000 . 155 : first screen update 276 . 959 000 . 002 : --- VIM STARTED ---

At the bottom of the file, you can see the start-up time was around 280 ms in total.

For reference, your baseline start-up time can be found by starting Vim with no custom config:

$ vim +q -u NONE -U NONE -N --startuptime startup-no-config.txt

which, on my 2015 MacBook Pro, gives:

000 . 007 000 . 007 : --- VIM STARTING --- 000 . 108 000 . 101 : Allocated generic buffers 000 . 530 000 . 422 : locale set ... 016 . 709 000 . 129 : VimEnter autocommands 016 . 717 000 . 008 : before starting main loop 017 . 167 000 . 450 : first screen update 017 . 169 000 . 002 : --- VIM STARTED ---

17ms – so I’m spending around 260 ms loading my own configuration and plugins each time I open Vim.

Anyway, I sorted the startup.txt buffer numerically by the second column to see the slowest operations:

:%! sort - rnk2 | head -2

yielding:

times in msec 254 . 008 187 . 506 187 . 506 : sourcing ~ /.vim/ bundle /black/ plugin / black . vim 053 . 178 034 . 800 008 . 475 : sourcing $ HOME /. vimrc

So the Python formatting plugin ambv/black , which we’ve been toying with adopting at work, was the culprit, consuming more than half of the start-up time.

In this case, the solution was to switch to using Ale’s “fixer” functionality to run black but this could be the starting point for an exciting profiling session (see next section).

Of course, the scripts sourced at start-up depend on the file-types being opened (the above example doesn’t open a file). For instance, if opening Python files is slow, ensure you profile with the right filetype set:

$ vim --startuptime python-startup.txt -c ":set ft=python" python-startup.txt

Further reading:

“Why is {ACTION} slow?”

I found writing the previous sections of this post, which is a markdown file, slightly laggy when typing in insert mode. That shouldn’t be the case – what is causing it?

Profile anything that is slow

The generic pattern to remember for profiling is:

: profile start profile . log : profile func * : profile file * { SLOW ACTIONS } : profile pause : wqall " Quit Vim (required)

which profiles all files and functions executed during the slow actions.

It pays to pipe together the three set-up commands so it’s easier to recall from command history :

: profile start profile . log | : profile func * | : profile file *

Back to the problem at hand, my {SLOW ACTIONS} were to type a simple sentence into a markdown-filetype buffer. I did this and collected the output.

The profile output shows summary tables at the bottom with detailed breakdowns above. of each function When interpreting the profile output, start at the bottom of the file which shows the most expensive functions.

FUNCTIONS SORTED ON SELF TIME count total ( s ) self ( s ) function 5805 0 . 267815 0 . 255992 Foldexpr_markdown () 27 0 . 011823 < SNR > 86 _is_mkdCode() 2 0 . 011755 < SNR > 79 _MarkdownHighlightSources() 53 0 . 005295 < SNR > 44 _Highlight_Matching_Pair() 2 0 . 000355 0 . 000284 ale # ShouldDoNothing () 2 0 . 000705 0 . 000247 ale # cursor # EchoCursorWarning () 2 0 . 011855 0 . 000100 < SNR > 79 _MarkdownRefreshSyntax() 2 0 . 000103 0 . 000080 ale # util # FindItemAtCursor () 1 0 . 000087 0 . 000064 ale # cursor # EchoCursorWarningWithDelay () 2 0 . 000030 ale # util # InSandbox () 2 0 . 000026 ale # FileTooLarge () 2 0 . 000023 ale # util # BinarySearch () 2 0 . 000015 ale # util # Mode () 1 0 . 000015 ale # Var () 1 0 . 000008 < SNR > 111 _StopCursorTimer()

This showed that Foldexpr_markdown was a bottleneck.

A quick :grep shows that the Foldexpr_markdown function lives in ~/.vim/bundle/vim-markdown/after/ftplugin/markdown.vim and a glance at the docs showed that folding can be disabled with a global plugin setting :

let g : vim_markdown_folding_disabled = 1

Profiling the same actions including this change gave a great improvement:

FUNCTIONS SORTED ON SELF TIME count total ( s ) self ( s ) function 2 0 . 011698 < SNR > 79 _MarkdownHighlightSources() 51 0 . 005496 < SNR > 44 _Highlight_Matching_Pair() 2 0 . 000323 0 . 000256 ale # ShouldDoNothing () 2 0 . 000627 0 . 000205 ale # cursor # EchoCursorWarning () 2 0 . 011833 0 . 000135 < SNR > 79 _MarkdownRefreshSyntax() 2 0 . 000099 0 . 000076 ale # util # FindItemAtCursor () 1 0 . 000091 0 . 000067 ale # cursor # EchoCursorWarningWithDelay () 2 0 . 000030 ale # util # InSandbox () 2 0 . 000023 ale # util # BinarySearch () 2 0 . 000023 ale # FileTooLarge () 1 0 . 000016 ale # Var () 2 0 . 000014 ale # util # Mode () 1 0 . 000008 < SNR > 111 _StopCursorTimer()

Of course, there’s no one-size-fits-all solution to addressing performance bottlenecks. There are a few things to try:

If the offending code is in a plugin, start by reading the docs and checking the issue tracker. Is this a known issue?

If the code is within Vim’s runtime files, read the source of the slow file. There’s often settings that can be used to tune or disable the behaviour.

Further reading:

:help profiling

Vimcast: Profiling Vimscript performance — an informative video demonstrating Vim’s --cmd and -c options for profiling your ~/.vimrc : vim --cmd "profile start vimrc.profile" --cmd "profile! file ~/.vimrc"

Profiling Vim by Jonathan Lehman (2015) — A detailed examination of profiling techniques.

Profiling Vim by Mauro Morales — Mentions you can cross-reference the <SNR> tag in the profile output with the numbers in :scriptnames to identify the source file.

Summary

Other than the advice above, here’s a couple of final thoughts:

Use tpope/scriptease – it provides a few really useful commands for debugging.

Keep your ~/.vim folder in source control, which makes it much easier to try out new things in branches or walk back through your history to find the commit that introduced a performance problem.

Above all, it’s not difficult to debug or profile Vim. Get into the habit of investigating and resolving annoying niggles when they appear.

Finally, here are some other articles and resources on the same topic as this post: