Performance profiling tools for shell scripts
You could pipe the output of running under -x
through to something that timestamps each line when it is received. For example, tai64n
from djb's daemontools.
At a basic example,
sh -x slow.sh 2>&1 | tai64n | tai64nlocal
This conflates stdout and stderr but it does give everything a timestamp. You'd have to then analyze the output to find expensive lines and correlate that back to your source.
You might also conceivably find using strace
helpful. For example,
strace -f -ttt -T -o /tmp/analysis.txt slow.sh
This will produce a very detailed report, with lots of timing information in /tmp/analysis.txt
, but at a per-system call level, which might be too detailed.
You can set PS4
to show the time and line number. Doing this doesn't require installing any utilities and works without redirecting stderr to stdout.
For this script:
#!/bin/bash -x
# Note the -x flag above, it is required for this to work
PS4='+ $(date "+%s.%N ($LINENO) ")'
for i in {0..2}
do
echo $i
done
sleep 1
echo done
The output looks like:
+ PS4='+ $(date "+%s.%N ($LINENO) ")'
+ 1291311776.108610290 (3) for i in '{0..2}'
+ 1291311776.120680354 (5) echo 0
0
+ 1291311776.133917546 (3) for i in '{0..2}'
+ 1291311776.146386339 (5) echo 1
1
+ 1291311776.158646585 (3) for i in '{0..2}'
+ 1291311776.171003138 (5) echo 2
2
+ 1291311776.183450114 (7) sleep 1
+ 1291311777.203053652 (8) echo done
done
This assumes GNU date, but you can change the output specification to anything you like or whatever matches the version of date that you use.
Note: If you have an existing script that you want to do this with without modifying it, you can do this:
PS4='+ $(date "+%s.%N ($LINENO) ")' bash -x scriptname
In the upcoming Bash 5, you will be able to save forking date
(but you get microseconds instead of nanoseconds):
PS4='+ $EPOCHREALTIME ($LINENO) '
Sounds like you want to time each echo. If echo is all that you're doing this is easy
alias echo='time echo'
If you're running other command this obviously won't be sufficient.