Profiling slow bashrc
I’ve recently noticed that it takes a long time for my bash to load. I’ve found
following StackOverflow answer to be useful, and I based my solution to find a
startup time hog in my ~/.bashrc
upon it.
First off, add following few lines to your /etc/bash.bashrc
,
~/.bash_profile
, or wherever you’d like to begin tracing the script:
PS4='+ $(date "+%s.%N")\011 '
exec 3>&2 2>/tmp/bashstart.$$.log
set -x
And add following few lines where you want to stop the trace:
set +x
exec 2>&3 3>&-
Now start your bash session (you can simply open a new terminal Window for
that). The above will create /tmp/bashstart.<PID>.log
. To analyze it, I wrote
a little Python script:
import argparse
import heapq
parser = argparse.ArgumentParser(description='Analyze bashstart log for speed.')
parser.add_argument('filename', help='often /tmp/bashstart.<PID>.log')
parser.add_argument('-n', default=20, help='number of results to show')
args = parser.parse_args()
filename, n = args.filename, int(args.n)
with open(filename, 'r') as f:
q = []
prev_time = None
for line in f.readlines():
line = line.split()
if '+' not in line[0] or len(line) < 3:
continue
text = ' '.join(line[2:])
seconds, nanoseconds = line[1].split('.')
time = int(nanoseconds)
diff = time - prev_time if prev_time is not None else 0
prev_time = time
heapq.heappush(q, (diff, text))
for diff, text in heapq.nlargest(n, q):
print float(diff) / 1000000000, 's:', text
Save it as bashprofile.py
, and run it as follows (replace file name with an
appropriate):
python bashprofile.py /tmp/bashstart.2831.log -n 20
0.050056909 s: _powerline_init_tmux_support
0.045323022 s: _powerline_setup_prompt
0.044722024 s: _powerline_setup_prompt
0.044423727 s: '[' -f /usr/local/google/home/ruslano/.local/lib/python2.7/site-packages/powerline/bindings/bash/powerline.sh ']'
0.044364097 s: '[' -f /usr/local/google/home/ruslano/.local/lib/python2.7/site-packages/powerline/bindings/bash/powerline.sh ']'
0.044137159 s: _powerline_init_tmux_support
0.015839574 s: __shell_name=bash
0.010850276 s: command which which
0.010105462 s: PS2='\[\] \[\] \[\]'
0.010000598 s: PS3=' Select variant '
0.009837956 s: complete -F _svn -o default -X '@(*/.svn|*/.svn/|.svn|.svn/)' svn
0.009767517 s: PS2='\[\] \[\] \[\]'
0.0095753 s: PS3=' Select variant '
0.007915565 s: other_utils=(ant automake autoreconf libtoolize make mount patch readlink)
0.00771205 s: for script in version functions/selector cd functions/cli cli override_gem
0.007008299 s: for gnu_util in '"${gnu_utils[@]}"'
0.00693653 s: complete -F _crow crow
0.006803049 s: complete -F _svn -o default -X '@(*/.svn|*/.svn/|.svn|.svn/)' svn
0.006672906 s: for script in version functions/selector cd functions/cli cli override_gem
0.005912399 s: for entry in '${scripts[@]}'
In my example, Powerline turned out to be a massive hog. Looks like I’ll have to troubleshoot the speed or plain disable it.
Don’t forget to remove the lines you added to your bash configuration files after you’re done profiling.