Booting a new shell had gotten slow. Opening a new Terminal window was getting tedious. I decided it was time to finally solve this.
I found a wonderful blog post entitled “Even faster bash startup”, in which the author tackled this same problem.
They started with the hyperfine utility to benchmark the login:
$ hyperfine -i 'bash -l'
Benchmark #1: bash -l
Time (mean ± σ): 1.242 s ± 0.089 s [User: 648.1 ms, System: 559.0 ms]
Range (min … max): 1.129 s … 1.415 s 10 runs
Almost 1.5 seconds for bash to login on my machine. But how can you determine what exactly is taking up this time?
The real “Eureka!” moment from this post is under the title “death by a thousand cuts”:
My
.bashrcis split into several smaller parts in~/.bashrc.d, so I can profile these and see if anything stands out.
Genius. I followed suit and created a ~/.bashrc.d directory (saved in my dotfiles repo of course) and split up the contents of my .bashrc file into discrete files. My ~/.bashrc file became largely setting up the benchmarking and sourcing other files. I could then run __bashrc_bench=1 . ~/.bashrc:
$ __bashrc_bench=1 . ~/.bashrc
/Users/parker/.bashrc.d/10_env.sh: 0.001
/Users/parker/.bashrc.d/20_history.sh: 0.000
/Users/parker/.bashrc.d/30_prompt.sh: 0.000
/Users/parker/.bashrc.d/40_completion.sh /usr/local/opt/fzf/shell/key-bindings.bash: 0.001
/Users/parker/.bashrc.d/40_completion.sh: 0.001
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/brew: 0.005
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/cheat.bash: 0.000
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/fd.bash: 0.001
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/gh: 0.015
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/git-completion.bash: 0.010
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/git-prompt.sh: 0.002
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/rg.bash: 0.001
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/etc/bash_completion.d/youtube-dl.bash-completion: 0.000
/Users/parker/.bashrc.d/41_brew_completion.sh /usr/local/share/autojump/autojump.bash: 0.013
/Users/parker/.bashrc.d/41_brew_completion.sh: 0.050
/Users/parker/.bashrc.d/50_aliases.sh: 0.004
/Users/parker/.bashrc.d/60_functions.sh: 0.000
/Users/parker/.bashrc.d/70_git_dotfiles.sh: 0.000
/Users/parker/.bashrc.d/80_fzf.sh: 0.000
/Users/parker/.bashrc.d/81_rbenv.sh /usr/local/opt/rbenv/completions/rbenv.bash: 0.000
/Users/parker/.bashrc.d/81_rbenv.sh: 1.068
/Users/parker/.bashrc.d/82_iterm2.sh: 0.000
/Users/parker/.bashrc.d/99_localrc.sh: 0.000
This is just from today. 15ms on the gh auto-completion, 13ms on the autojump completion, and… 1068ms on rbenv? It’s not from the rbenv bash completion, so it must be something in the script itself. This is almost 85% of the total bash boot time that we found earlier with hyperfine!
I recently found myself discussing the nuances of building openssl for rbenv ruby installations on macOS, and one of the maintainers of the ruby-build installation utility had recommended using the Homebrew-managed openssl, so I added the following line to my 81_rbenv.sh file:
export RUBY_CONFIGURE_OPTS="--with-openssl-dir=$(brew --prefix openssl)"
Hm, exporting a variable is extremely fast. How long does brew --prefix openssl take?
$ hyperfine 'brew --prefix openssl'
Benchmark #1: brew --prefix openssl
Time (mean ± σ): 1.063 s ± 0.019 s [User: 561.5 ms, System: 478.6 ms]
Range (min … max): 1.032 s … 1.094 s 10 runs
Yikes. That entire script’s time is just running brew! I wonder: could we hardcode this instead of calling brew?
$ brew --prefix openssl
/usr/local/opt/openssl@1.1
$ ls -l /usr/local/opt/openssl*
lrwxr-xr-x 1 parker admin 28 Apr 1 22:03 /usr/local/opt/openssl -> ../Cellar/openssl@1.1/1.1.1k
lrwxr-xr-x 1 parker admin 28 Apr 1 22:03 /usr/local/opt/openssl@1.1 -> ../Cellar/openssl@1.1/1.1.1k
Yes! It looks like I could use either of those two paths instead. In order to be modular, it’s best to use a variable. How about $HOMEBREW_PREFIX? Thus, the line becomes:
export HOMEBREW_PREFIX="${HOMEBREW_PREFIX:="/usr/local"}"
export RUBY_CONFIGURE_OPTS="--with-openssl-dir=${HOMEBREW_PREFIX}/opt/openssl"
Does that fix our issue?
$ hyperfine -i 'bash -l'
Benchmark #1: bash -l
Time (mean ± σ): 49.4 ms ± 10.2 ms [User: 32.0 ms, System: 14.4 ms]
Range (min … max): 42.0 ms … 117.3 ms 62 runs
50ms? Yes, that’s significantly better than 1200ms! This is a huge success, with many thanks to ~/.bashrc.d for making the benchmarking of each snippet so much easier.
Do you have a complicated ~/.bashrc or ~/.zshrc? Consider following this same method! It makes tracking down those pesky slow start-up scripts so much easier. Reusing this benchmarking code in bash is easy too – the combination of $TIMEFORMAT and time makes this a simple proposition. Profiling bash scripts of all shapes and sizes has never been so easy!