How to benchmark individual shell script sections to identify slow parts
I use a couple of different methods for this, depending on whether I'm writing a new script and want to benchmark different approaches or need to debug an existing script to identify slow sections.
When writing something new and trying to identify the most efficient method for accomplishing a task, I'll usually take a block of code and save as multiple separate functions, each using a different method, then benchmark each function to compare performance costs of different approaches using the Bash builtin "time".
For example:
OneWay()
{
some code
more code
}
OtherWay()
{
some code
more code
}
Then time each function:
for cmd in OneWay OtherWay; do
echo -e "\n=== $cmd ==="
for run in {1..3}; do
time $cmd &> /dev/null
done
done
=== OneWay ===
real 0m0.421s
user 0m0.416s
sys 0m0.004s
real 0m0.418s
user 0m0.408s
sys 0m0.008s
real 0m0.416s
user 0m0.412s
sys 0m0.000s
=== OtherWay ===
real 0m0.580s
user 0m0.572s
sys 0m0.004s
real 0m0.566s
user 0m0.564s
sys 0m0.004s
real 0m0.570s
user 0m0.564s
sys 0m0.004s
But if I want to benchmark individual sections of an existing script, something like the following might be better. First, insert the following function at the top of the script to be benchmarked:
RuntimePrint()
{
duration=$(echo "scale=3;(${m2t}-${m1t})/(1*10^09)"|bc|sed 's/^\./0./')
echo -e "DEBUG: lines ${m1l}-${m2l}\t${duration}\tsec"
}
Then wrap the parts of the script to be benchmarked as follows:
m1t=$(date +%s%N); m1l=$LINENO
# some code here
m2t=$(date +%s%N); m2l=$LINENO; RuntimePrint
m1t=$(date +%s%N); m1l=$LINENO
# more code here
m2t=$(date +%s%N); m2l=$LINENO; RuntimePrint
m1t=$(date +%s%N); m1l=$LINENO
# even more
# code here
m2t=$(date +%s%N); m2l=$LINENO; RuntimePrint
Then run the script as usual or pipe output to grep to just get the benchmark results without script's usual output:
SomeScript.sh | grep "^DEBUG:" | column -t
DEBUG: lines 9-18 0.004 sec
DEBUG: lines 20-25 0.012 sec
DEBUG: lines 27-32 0.008 sec
DEBUG: lines 34-39 0.004 sec
DEBUG: lines 41-46 0.004 sec
DEBUG: lines 48-54 0 sec
DEBUG: lines 56-63 0.008 sec
DEBUG: lines 65-70 0.236 sec
DEBUG: lines 72-90 78.647 sec
DEBUG: lines 92-94 0.076 sec
DEBUG: lines 96-111 0.024 sec
DEBUG: lines 113-115 0.004 sec
Leave a comment