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.
7 read-only comments
These are the read-only comments I've exported from Disqus (which I no longer use). If you'd like to share your thoughts about this article, you can ✍️ Reply by email.
```
python bashprofile.py /tmp/bashstart.32463.log -n 20
Traceback (most recent call last):
File "bashprofile.py", line 19, in <module>
time = int(nanoseconds)
ValueError: invalid literal for int() with base 10: 'N'
```
python -V
Python 2.7.10
I'd assume something's off with the string you're parsing.
Add `print line` before the `int(nanoseconds)` conversion, what does it print before the error?
['++', '1471987120.N', 'export', 'LANG=ru_RU']
Traceback (most recent call last):
File "bashprofile.py", line 20, in <module>
time = int(nanoseconds)
ValueError: invalid literal for int() with base 10: 'N'
ok, http://stackoverflow.com/qu...
i replaced date to gdate and now it working
Glad that works!
found adding this helps me with empty lines:
```
for line in f.readlines():
if not line or not line.strip():
continue
```
Minor changes for me:
- Print out the log filename for convenience
BASHPROFILELOG=/tmp/bashstart.$$.log
echo "$BASHPROFILELOG"
exec 3>&2 2> "$BASHPROFILELOG"
- Use `/usr/local/bin/gdate` instead of `date` for nanoseconds on MacOS
- Update for python3:
2to3 -w bashprofile.py
- Rename reused `line` variable to `words = line.split()`
- Reverse order of checks in this line to avoid IndexError for empty lines:
if len(words) < 3 or "+" not in words[0]:
Thanks for the post!