X-Recipient: archive-cygwin AT delorie DOT com X-Original-To: cygwin AT cygwin DOT com Delivered-To: cygwin AT cygwin DOT com DMARC-Filter: OpenDMARC Filter v1.4.1 sourceware.org 25BD73858D39 Authentication-Results: sourceware.org; dmarc=none (p=none dis=none) header.from=spocom.com Authentication-Results: sourceware.org; spf=pass smtp.mailfrom=spocom.com DomainKey-Signature: a=rsa-sha1; c=nofws; q=dns; d=spocom.com; s=mail; h=received:date:from:to:subject:message-id:mail-followup-to :mime-version:content-type:content-disposition:x-operating-system :user-agent; b=oeoxd6rmpscTWbi12zZcHsj/ha5CbF+fPS91tJuO0B8vm1jq7z2RbquunpNUXzcWa Ufi4HM8nRJ9VAx0YgXfSg== Date: Thu, 10 Mar 2022 16:55:40 -0800 From: Gary Johnson To: cygwin AT cygwin DOT com Subject: Bash runs my vim slower than Cygwin's vim Message-ID: <20220311005540.GB5869@phoenix> Mail-Followup-To: cygwin AT cygwin DOT com MIME-Version: 1.0 Content-Disposition: inline X-Operating-System: Linux 2.6.32-74-generic GNU/Linux User-Agent: Mutt/1.5.20 (2009-06-14) X-Spam-Status: No, score=-1.5 required=5.0 tests=BAYES_00, DKIM_SIGNED, DKIM_VALID, SPF_HELO_NONE, SPF_PASS, TXREP, T_SCC_BODY_TEXT_LINE autolearn=ham autolearn_force=no version=3.4.4 X-Spam-Checker-Version: SpamAssassin 3.4.4 (2020-01-24) on server2.sourceware.org X-BeenThere: cygwin AT cygwin DOT com X-Mailman-Version: 2.1.29 List-Id: General Cygwin discussions and problem reports List-Archive: List-Post: List-Help: List-Subscribe: , Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Sender: "Cygwin" 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 AT 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 -- Problem reports: https://cygwin.com/problems.html FAQ: https://cygwin.com/faq/ Documentation: https://cygwin.com/docs.html Unsubscribe info: https://cygwin.com/ml/#unsubscribe-simple