Bash runs my vim slower than Cygwin's vim
Gary Johnson
garyjohn@spocom.com
Fri Mar 11 00:55:40 GMT 2022
I build my own copy of Vim for the Cygwin terminal from the source
at https://github.com/vim/vim.git. Lately, I've noticed the startup
time getting slower, so I investigated. One of the things
I discovered was this difference between the run times of the
official Cygwin vim package and the vim I built myself. Both are
version 8.2.4372 and built using the same configuration and compiler
flags except for some options such as Ruby that I don't have support
for on my system.
$ time /usr/bin/vim -N -u NONE -i NONE -cq
real 0m0.119s
user 0m0.062s
sys 0m0.015s
$ time /usr/local/src/vim-debug/vim/src/vim -N -u NONE -i NONE -cq
real 0m1.422s
user 0m0.015s
sys 0m0.093s
I ran the same commands using strace and found the cumulative times
to be the same within a few milliseconds (about 320 ms).
Since the difference didn't appear to be in Vim itself, I thought
the difference might be in bash, so I ran both programs using strace
like this.
$ strace -o strace_bash_cygwin_vim bash -c "/usr/bin/vim -N -u NONE -i NONE -cq"
$ strace -o strace_bash_local_vim bash -c "/usr/local/src/vim-debug/vim/src/vim -N -u NONE -i NONE -cq"
Those traces show a significant difference in the times bash takes
to perform these three operations on those two vim executables.
1. [main] bash {PID} child_info_spawn::worker: priority class 32
Cygwin's vim: 261 us
My vim: 247217 us
2. [main] bash {PID} child_info_spawn::worker: pid {PID}, prog_arg {program}, cmd line (null))
Cygwin's vim: 4515 us
My vim: 709705 us
3. [main] bash {PID}! child_info::sync: pid {PID}, WFMO returned 0, exit_code 0x103, res 1
Cygwin's vim: 16156 us
My vim: 575127 us
Those operations are shown as they appear in the strace outputs with
some context below.
strace_bash_cygwin_vim
----------------------
104 240566 [main] bash 9075 spawnve: spawnve (/usr/bin/vim, /usr/bin/vim, 0x80005A9D0)
94 240660 [main] bash 9075 child_info_spawn::worker: mode = 3, prog_arg = /usr/bin/vim
51 240711 [main] bash 9075 perhaps_suffix: prog '/usr/bin/vim'
63 240774 [main] bash 9075 normalize_posix_path: src /usr/bin/vim
64 240838 [main] bash 9075 normalize_posix_path: /usr/bin/vim = normalize_posix_path (/usr/bin/vim)
52 240890 [main] bash 9075 mount_info::conv_to_win32_path: conv_to_win32_path (/usr/bin/vim)
49 240939 [main] bash 9075 mount_info::conv_to_win32_path: src_path /usr/bin/vim, dst C:\cygwin64\bin\vim, flags 0x20008, rc 0
132 241071 [main] bash 9075 symlink_info::check: 0xC0000034 = NtCreateFile (\??\C:\cygwin64\bin\vim)
49 241120 [main] bash 9075 symlink_info::check: 0xC0000034 = NtQueryInformationFile (\??\C:\cygwin64\bin\vim)
135 241255 [main] bash 9075 symlink_info::check: 0x0 = NtCreateFile (\??\C:\cygwin64\bin\vim.exe)
201 241456 [main] bash 9075 symlink_info::check: not a symlink
74 241530 [main] bash 9075 symlink_info::check: 0 = symlink.check(C:\cygwin64\bin\vim.exe, 0xFFFFA410) (mount_flags 0x20008, path_flags 0x0)
48 241578 [main] bash 9075 path_conv::check: this->path(C:\cygwin64\bin\vim.exe), has_acls(1)
68 241646 [main] bash 9075 perhaps_suffix: buf C:\cygwin64\bin\vim.exe, suffix found '.exe'
261 241907 [main] bash 9075 child_info_spawn::worker: priority class 32
138 242045 [main] bash 9075 fhandler_console::need_invisible: invisible_console 0
99 242144 [main] bash 9075 build_env: envp 0x80005A9D0
...
158 243852 [main] bash 9075 child_info::child_info: subproc_ready 0x228
4515 248367 [main] bash 9075 child_info_spawn::worker: pid 9075, prog_arg /usr/bin/vim, cmd line (null))
92 248459 [main] bash 9075! child_info_spawn::worker: new process name \\?\C:\cygwin64\bin\vim.exe
98 248557 [main] bash 9075! child_info_spawn::worker: spawned windows pid 36936
58 248615 [main] bash 9075! child_info::sync: n 2, waiting for subproc_ready(0x228) and child process(0x274)
--- Process 36936 created
...
87 6496 [main] vim 9075 child_info::ready: signalled 0x228 that I was ready
16156 264771 [main] bash 9075! child_info::sync: pid 36936, WFMO returned 0, exit_code 0x103, res 1
77 264848 [main] bash 9075! fhandler_base::close_with_arch: line 1181: /dev/cons0<0x18035A7C0> usecount + -1 = 3
strace_bash_local_vim
---------------------
96 235661 [main] bash 9090 spawnve: spawnve (/usr/local/src/vim-debug/vim/src/vim, /usr/local/src/vim-debug/vim/src/vim, 0x80005A9F0)
69 235730 [main] bash 9090 child_info_spawn::worker: mode = 3, prog_arg = /usr/local/src/vim-debug/vim/src/vim
59 235789 [main] bash 9090 perhaps_suffix: prog '/usr/local/src/vim-debug/vim/src/vim'
57 235846 [main] bash 9090 normalize_posix_path: src /usr/local/src/vim-debug/vim/src/vim
71 235917 [main] bash 9090 normalize_posix_path: /usr/local/src/vim-debug/vim/src/vim = normalize_posix_path (/usr/local/src/vim-debug/vim/src/vim)
49 235966 [main] bash 9090 mount_info::conv_to_win32_path: conv_to_win32_path (/usr/local/src/vim-debug/vim/src/vim)
61 236027 [main] bash 9090 mount_info::conv_to_win32_path: src_path /usr/local/src/vim-debug/vim/src/vim, dst C:\cygwin64\usr\local\src\vim-debug\vim\src\vim, flags 0x30008, rc 0
140 236167 [main] bash 9090 symlink_info::check: 0xC0000034 = NtCreateFile (\??\C:\cygwin64\usr\local\src\vim-debug\vim\src\vim)
63 236230 [main] bash 9090 symlink_info::check: 0xC0000034 = NtQueryInformationFile (\??\C:\cygwin64\usr\local\src\vim-debug\vim\src\vim)
133 236363 [main] bash 9090 symlink_info::check: 0x0 = NtCreateFile (\??\C:\cygwin64\usr\local\src\vim-debug\vim\src\vim.exe)
237 236600 [main] bash 9090 symlink_info::check: not a symlink
95 236695 [main] bash 9090 symlink_info::check: 0 = symlink.check(C:\cygwin64\usr\local\src\vim-debug\vim\src\vim.exe, 0xFFFFA3F0) (mount_flags 0x30008, path_flags 0x0)
47 236742 [main] bash 9090 path_conv::check: this->path(C:\cygwin64\usr\local\src\vim-debug\vim\src\vim.exe), has_acls(1)
59 236801 [main] bash 9090 perhaps_suffix: buf C:\cygwin64\usr\local\src\vim-debug\vim\src\vim.exe, suffix found '.exe'
247217 484018 [main] bash 9090 child_info_spawn::worker: priority class 32
254 484272 [main] bash 9090 fhandler_console::need_invisible: invisible_console 0
78 484350 [main] bash 9090 build_env: envp 0x80005A9F0
...
84 486764 [main] bash 9090 child_info::child_info: subproc_ready 0x338
709705 1196469 [main] bash 9090 child_info_spawn::worker: pid 9090, prog_arg /usr/local/src/vim-debug/vim/src/vim, cmd line (null))
153 1196622 [main] bash 9090! child_info_spawn::worker: new process name \\?\C:\cygwin64\usr\local\src\vim-debug\vim\src\vim.exe
160 1196782 [main] bash 9090! child_info_spawn::worker: spawned windows pid 37316
85 1196867 [main] bash 9090! child_info::sync: n 2, waiting for subproc_ready(0x338) and child process(0x3AC)
--- Process 37316 created
...
161 6615 [main] vim 9090 open_shared: name (null), n 0, shared 0x180000000 (wanted 0x180000000), h 0x20C, *m 6
130 6745 [main] vim 9090 child_info::ready: signalled 0x338 that I was ready
575127 1771994 [main] bash 9090! child_info::sync: pid 37316, WFMO returned 0, exit_code 0x103, res 1
94 1772088 [main] bash 9090! fhandler_base::close_with_arch: line 1181: /dev/cons0<0x18035A7C0> usecount + -1 = 3
My vim version
--------------
VIM - Vi IMproved 8.2 (2019 Dec 12, compiled Mar 10 2022 13:42:57)
Included patches: 1-4372
Compiled by user@hostname
Huge version without GUI. Features included (+) or not (-):
+acl +file_in_path +mouse_urxvt -tag_any_white
+arabic +find_in_path +mouse_xterm -tcl
+autocmd +float +multi_byte +termguicolors
+autochdir +folding +multi_lang +terminal
-autoservername -footer -mzscheme +terminfo
-balloon_eval +fork() +netbeans_intg +termresponse
+balloon_eval_term +gettext +num64 +textobjects
-browse -hangul_input +packages +textprop
++builtin_terms +iconv +path_extra +timers
+byte_offset +insert_expand +perl/dyn +title
+channel +ipv6 +persistent_undo -toolbar
+cindent +job +popupwin +user_commands
-clientserver +jumplist +postscript +vartabs
+clipboard +keymap +printer +vertsplit
+cmdline_compl +lambda +profile +vim9script
+cmdline_hist +langmap -python +viminfo
+cmdline_info +libcall -python3 +virtualedit
+comments +linebreak +quickfix +visual
+conceal +lispindent +reltime +visualextra
+cryptv +listcmds +rightleft +vreplace
+cscope +localmap -ruby +wildignore
+cursorbind -lua +scrollbind +wildmenu
+cursorshape +menu +signs +windows
+dialog_con +mksession +smartindent +writebackup
+diff +modify_fname -sodium -X11
+digraphs +mouse -sound -xfontset
-dnd -mouseshape +spell -xim
-ebcdic +mouse_dec +startuptime -xpm
+emacs_tags -mouse_gpm +statusline -xsmp
+eval -mouse_jsbterm -sun_workshop -xterm_clipboard
+ex_extra +mouse_netterm +syntax -xterm_save
+extra_search +mouse_sgr +tag_binary
-farsi -mouse_sysmouse -tag_old_static
system vimrc file: "$VIM/vimrc"
user vimrc file: "$HOME/.vimrc"
2nd user vimrc file: "~/.vim/vimrc"
user exrc file: "$HOME/.exrc"
defaults file: "$VIMRUNTIME/defaults.vim"
fall-back for $VIM: "/usr/local/share/vim"
Compilation: gcc -c -I. -Iproto -DHAVE_CONFIG_H -ggdb -O2 -fstack-protector-strong -D_REENTRANT -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=1
Linking: gcc -L/usr/local/lib -Wl,--as-needed -o vim.exe -lm -lncursesw -liconv -lacl -lintl -Wl,--enable-auto-import -Wl,--export-all-symbols -Wl,--enable-auto-image-base -fstack-protector-strong -L/usr/lib/perl5/5.32/x86_64-cygwin-threads/CORE -lperl -lpthread -ldl -lcrypt
So, does anyone know why is takes so much longer for bash to run the
vim I built than the official Cygwin vim? More importantly, how do
I fix this?
Waiting 1.4 seconds for vim to start isn't too bad, but when
I actually edit a file with my normal configuration, it takes
5 seconds for vim to start vs. 1.2 seconds for Cygwin's vim.
Cygwin and all my Cygwin programs are up-to-date. I'm running
Windows 10 Enterprise version 1909.
Regards,
Gary
More information about the Cygwin
mailing list