In general, one may use the time Bash utility (see man time for more information) to run a program, and obtain runtime duration and system resource usage summaries. But how can one time particular sections of code, directly from within the Bash source code?
Using some easy variable assignments and calculations, it is possible to achieve accurate timing metrics for Bash script executions.
In this tutorial you will learn:
- How to time Bash scripts using variable assignments and calculations
- How to use overlapping timers to time specific sections of your scripts
- Examples which exemplify how specific sections of code can be timed
Software requirements and conventions used
| Category | Requirements, Conventions or Software Version Used |
|---|---|
| System | Linux Distribution-independent |
| Software | Bash command line, Linux based system |
| Other | Any utility which is not included in the Bash shell by default can be installed using sudo apt-get install utility-name (or yum install for RedHat based systems) |
| Conventions | # – requires linux-commands to be executed with root privileges either directly as a root user or by use of sudo command$ – requires linux-commands to be executed as a regular non-privileged user |
Date basics
We will be using the date command for our timings. Specifically, we will use date +%s to obtain the time in seconds since epoch, or in other words, the number of seconds since 1970-01-01 00:00:00 UTC.
$ date +%s 1607481317
The date command can also provide nanoseconds (000000000..999999999) precision, if your timings need to be super-accurate:
$ date +%s%N 1607488248328243029
Discussing the implementation of nanosecond precise timers is outside of the scope of this article, but please let us know if this topic interest you. The setup would be very similar to the setup demonstrated below, with a few extra calculations and provisions to handle the seconds versus the milliseconds etc.
Example 1: A simple timing example
Let’s start with an easy example, where we will time a single command, namely sleep 1, using two date +%s commands and one variable assignment. Store the below script into a file called test.sh:
#!/bin/bash
START="$(date +%s)"
sleep 1
DURATION=$[ $(date +%s) - ${START} ]
echo ${DURATION}
Here we first indicate we want the script to be executed as Bash code by using the #!/bin/bash interpreter selection. We also executed chmod +x ./test.sh to make the script executable after creating it.
Next we set the variable START to the current seconds since epoch time by calling a subshell (as indicated by $(...)) and within that subshell we execute date +%s. We then use the sleep function to pause our script for one second. Note that the sleep 1 could be substituted for your actual program code, in other words the part you want to time.
Finally we set a new variable DURATION by doing a calculation (as indicated by $[ ... ]) – namely that we take the current seconds since epoch (again by using date +%s from within a subshell) and then subtracting the START time from the same. The result is the number of seconds which have passed since start.
When we execute this script, the output is as expected:
$ ./test.sh 1
Example 2: A little more complex timing example
This time, let’s expand a little and make the timings more modular. test2.sh:
#!/bin/bash
START1="$(date +%s)"
sleep 2
END1="$(date +%s)"
sleep 2
START2="$(date +%s)"
sleep 3
END2="$(date +%s)"
DURATION1=$[ ${END1} - ${START1} ]
DURATION2=$[ ${END2} - ${START2} ]
echo "The 1st part of the code took: ${DURATION1}"
echo "The 2nd part of the code took: ${DURATION2}"
Here we made a similar setup to the first example, but this time we timed two different commands, using a double set of variables, and we structured things a little more by using an END variable for both commands. We could have also written the last echo lines as follows test3.sh:
#!/bin/bash
START1="$(date +%s)"
sleep 2
END1="$(date +%s)"
sleep 2
START2="$(date +%s)"
sleep 3
END2="$(date +%s)"
echo "The 1st part of the code took: $[ ${END1} - ${START1} ]"
echo "The 2nd part of the code took: $[ ${END2} - ${START2} ]"
As the two DURATION variables were in some ways unnecessary. The may have made the code clearer to read, but they fulfill no real other function, unlike the START and END variables used for actual calculations.
Note however that we could not have written test4.sh:
#!/bin/bash
START1="$(date +%s)"
sleep 2
sleep 2
START2="$(date +%s)"
sleep 3
echo "The 1st part of the code took: $[ $(date +%s) - ${START1} ]"
echo "The 2nd part of the code took: $[ $(date +%s) - ${START2} ]"
Because the date captured inside the subshell is the time when the echo is being executed, the timings for both would be off: the end timings should instead have been taking directly after the relevant commands.
Perhaps for the second timing it would have been possible to use a date +%s directly in the echo (as the first echo would only take some milliseconds to execute, even with the subshell and date included), but it is not perfect, and would definitely not work if nanosecond precision timing is required. It is also not clean coding and harder to read/understand.
Let’s execute these scripts and compare the output:
$ ./test2.sh The 1st part of the code took: 2 The 2nd part of the code took: 3 $ ./test3.sh The 1st part of the code took: 2 The 2nd part of the code took: 3 $ ./test4.sh The 1st part of the code took: 7 The 2nd part of the code took: 3
The test2.sh and test3.sh reported correct timings, as expected. The test4.sh script reported incorrect timings, also as expected.
Can you see how long the script ran overall, approximately in seconds, irrespective of any timings? If you answer was six seconds you are correct. You can see how in test2.sh and test3.sh there is an additional sleep 2 which is not being captures in the timing commands. This exemplifies how you can time various code sections.
Example 3: Overlapping Timers
Let’s now look at a final example which has overlapping timers and times a function.test5.sh:
#!/bin/bash
my_sleep_function(){
sleep 1
}
OVERALL_START="$(date +%s)"
FUNCTION_START="$(date +%s)"
my_sleep_function
FUNCTION_END="$(date +%s)"
sleep 2
OVERALL_END="$(date +%s)"
echo "The function part of the code took: $[ ${FUNCTION_END} - ${FUNCTION_START} ] seconds to run"
echo "The overall code took: $[ ${OVERALL_END} - ${OVERALL_START} ] seconds to run"
Here we define a function my_sleep_function which simply sleeps for one second. We next set an overall start timer by using the OVERALL_START variable and again our date +%s in a subshell. Next we start another timer (the function timer based on the FUNCTION_START variable). We run the function and end immediately end the function timer by setting the FUNCTION_END variable.
We then do an additional sleep 2 and then end the overall timer by setting the OVERALL_END timer. Finally, we output the information in a nice format near the end of the script. The two echo statements are not part of the timing, but their runtime would be minimal; usually we are attempting to time various and specific sections of our code which tend to have long durations like extensive loops, external program calls, many subshells etc.
Let’s look at the out of test5.sh:
$ ./test5.sh The function part of the code took: 1 seconds to run The overall code took: 3 seconds to run
Looks good. The script correctly timed the function to 1 second, and the overall script runtime as 3 seconds, being the combination of the function call and the extra two second sleep.
Note that if the function is recursively, it may make sense to use an additional global timing variable to which the function runtime can be added unto. You could also count the number of functions calls and then in the end divide the number of function calls by using bc (ref How To Make Decimal Calculations In Bash Using Bc). In this use case, it may make be best to move the start and stop timers, as well as the function duration calculation to inside the function. It makes for cleaner and clearer code and may eliminate unnecessary code duplication.
Conclusion
In this article, we looked at timing various parts of our Bash script code by using date +%s as a basis for obtaining seconds since epoch time, as well as one or more variable assignments to calculate performance timings one or more sections of the code. Using these basic building blocks, one can make complex timing measurement structures, per function, per called script or even timers which overlap (for example one per script as well as one per function etc.) by using different variables. Enjoy!
If you are interested in learning more about Bash, please see our Useful Bash Command Line Tips and Tricks series.
