Time individual statements in bash

Sometimes the 1000+ line bash script you inherited at work takes 3 hours to complete and you’re not sure where the time is being spent. StackOverflow has some good answers on this topic:

http://stackoverflow.com/questions/5014823/how-to-profile-a-bash-shell-script
http://stackoverflow.com/questions/18039751/how-to-debug-a-bash-script-and-get-execution-time-per-command

The simplest one that gives me the most value for the least effort (imo) is:

PS4='+[${SECONDS}s][${BASH_SOURCE}:${LINENO}]: ${FUNCNAME[0]:+${FUNCNAME[0]}(): }'
#!/bin/bash

PS4='+[${SECONDS}s][${BASH_SOURCE}:${LINENO}]: ${FUNCNAME[0]:+${FUNCNAME[0]}(): }'
set -x

echo 1
sleep 1
echo 2
sleep 2
echo 3

This produces the following output:

joao@home:~> ./timings.sh
+[0s][./timings.sh:7]: echo 1
1
+[0s][./timings.sh:8]: sleep 1
+[1s][./timings.sh:9]: echo 2
2
+[1s][./timings.sh:10]: sleep 2
+[3s][./timings.sh:11]: echo 3
3

Happy bash profiling !

Time individual statements in bash

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s