plugin load times

[eddietejeda]

So I've been experiencing slow boot-ups of my shell recently and I suspected I had too many bash-it plugins enabled, so I did a little digging. I calculated the load times of each plugin by making this minor modification to the * _load_bash_it_files* function.

For me, it appears it was the NVM plugin that was causing delays. I disabled it and my shell boots up much faster.

I then enabled all the plugins and got the user, real and sys execution times of each plugin. I graphed them and below you can see the results. It's not very scientific, but hopefully others find this useful.

# Helper function loading various enable-able files
function _load_bash_it_files() {


  subdirectory="$1"

  if [ ! -d "${BASH_IT}/${subdirectory}/enabled" ]
  then
    continue
  fi
  FILES="${BASH_IT}/${subdirectory}/enabled/*.bash"
  for config_file in $FILES
  do
    echo ${config_file}

    if [ -e "${config_file}" ]; then
      time source $config_file
    fi
  done
}

[nwinkler]

Wow, this is fantastic - very cool! Thanks for doing this!

I'll take a look to see why e.g. the node plugin takes such a long time to load...

[ahmadassaf]

Using the same modified function I have also noticed that the alias-completion takes also a very considerable amount of time to load

... /.bash_it/plugins/enabled/alias-completion.bash

real    0m26.792s
user    0m0.728s
sys 0m0.327s

[trinitronx]

Thanks for the time profiling info!! I was able to disable a couple slow plugins I wasn't using to gain speed. Super-helpful!

I'd like to chime in with some results that I found in my particular use case (in case someone else stumbles upon their bash-it PS1 prompt behaving slowly due to this):

When testing bash-it on OSX with a docker-machine VM, that has /Users shared inside the VM & nested docker container running inside it... I noticed a particularly slow PS1 prompt. I ran set -x and hit enter to show the prompt & all the trace output for the bash-it code that was running. One set of commands in particular were so slow that I could visibly see the hang in the output... no need for modifying any code to add time calls in ~/.bash_it/ even!

The slow commands I found were calls in base.theme to get git status:

local status="$(git status -b --porcelain ${git_status_flags} 2> /dev/null ||
                git status --porcelain ${git_status_flags} 2> /dev/null)"

Timing them showed at least a second for each call... worse if the first one exits with nonzero status, it runs the second one (without -b), resulting in at least 2-3 seconds delay added to all the rest of the bash-it code execution!

$ time git status -b --porcelain
[...SNIP...]
real    0m1.814s
user    0m0.030s
sys     0m0.820s

I did some digging as to why this might be slower inside the container, and found that git status is tied to the efficiency of the lstat system call, which along with other FS operations inside a VM with shared folders, will be slower due to the virtualization overhead and indirection due to the shared folder.

After reading the code, I could immediately see a couple things to try, and found that:

• export SCM_GIT_IGNORE_UNTRACKED=true improved performance slightly (~ 718 ms improvement)
• git config --global bash-it.hide-status 1 to skip the slow git status commands entirely improved performance by ~3.85 seconds!

I added time prompt_command to the theme I was using to get a comparision with and without bash-it.hide-status set:

diff --git a/themes/bobby/bobby.theme.bash b/themes/bobby/bobby.theme.bash
index e001175..d70f45d 100644
--- a/themes/bobby/bobby.theme.bash
+++ b/themes/bobby/bobby.theme.bash
@@ -17,4 +17,4 @@ function prompt_command() {
     PS1="\n$(battery_char) $(clock_char) ${yellow}$(ruby_version_prompt) ${purple}\h ${reset_color}in ${green}\w\n${bold_cyan}$(scm_char)${green}$(scm_prompt_info) ${green}→${reset_color} "
 }

-PROMPT_COMMAND=prompt_command;
+PROMPT_COMMAND='time prompt_command;'

Without bash-it.hide-status:

real    0m4.573s
user    0m0.070s
sys     0m1.890s

With bash-it.hide-status 1:

real    0m0.723s
user    0m0.060s
sys     0m0.110s

Hope this helps somebody!

[edubxb]

Very useful analysis, thanks @trinitronx!