Analyzes how long each line of your shell script takes. Very useful for finding areas of improvement or testing what technique works the fastest.
This library is intended to be used both within BPM projects and as a standalone command.
It requires Python to be installed on the system. Right now the Python script is aimed at Python 2.x. The Python is used for the profile timestamping to keep the time stamps accurate and to have a single process that handles adding time. Improvements are welcome. No Python is used to analyze the timestamps.
If you are working on a BPM-enabled project, you can add this package to your bpm.ini.
[devDependencies]
profile=*
Run bpm install to add the library. Finally, use it in your scripts.
#!/usr/bin/env/bash
. bpm
bpm::include profile
profile::start
# Optionally, you can turn off profiling
profile::stop
When you start profiling, a new temporary file is created. Its location will be written to /dev/stderr (file descriptor 2). You can instead force the filename when you call profile::start by placing the desired filename after the function.
profile::start /tmp/the-profile.txt
Installation requires [BPM] to be installed and with your $PATH environment variable set correctly. Install this with BPM by running this command.
bpm install profile
Next, you can enable profiling during your script by sourcing the command.
#!/usr/bin/env bash
# This is your script and you simply add the one following line
. bash-profile-start
# If you want to turn it off, you can source this file.
. bash-profile-stop
When you start profiling, a new temporary file is created. Its location will be written to /dev/stderr (file descriptor 2). You can instead force the filename when you call bash-profile-start by placing the desired filename after the command.
. bash-profile-start /tmp/the-profile.txt
When a profile is written, it will contain lines like the following:
0.000000000 0.000023127 Initialization and waiting for first command
0.000023127 0.000022888 + echo 'This line is being profiled.'
0.000046015 0.000003099 + echo 'These echo statements should take almost no time.'
0.000049114 0.000002861 + echo 'Defining a function'
0.000051975 0.000000954 + echo 'Sleeping 1 second'
0.000052929 0.967961073 + sleep 1
0.968014002 0.000031948 + echo 'Testing Ackermann 3 3'
0.968045950 0.000022173 + ackermann 3 3
0.968068123 0.000087976 + local a
The first number is the time elapsed (in seconds) since profiling started until the start of the command shown. The second number is the amount of time a single call consumed. To be very specific, it's the amount of time that elapsed since the command was reported to the profiling script and when the next command is reported to the profiling script. After that you can have a series of plus symbols (+) that indicate the call depth in Bash. There will be more as you dive deeper into subshells. Finally, there is the command that was executed.
The first line is created by the profiling script when it starts and it waits for the first command to be sent to it from Bash. What happens in this script is that it leaves the profile::start function and is immediately followed by an echo. From this, one could guess that calling echo takes 0.00002 seconds, but that also includes leaving the profiling function and any teardown of internal structures in Bash, which don't print out in the profile.
You can also see that the sleep command doesn't actually sleep for 1 full second. Are you interested by that result?
Near the end of this snippet is local a. This is the first line in the ackermann function. The setup of anything internal to Bash took nearly 0.00009 seconds, which isn't really too bad.
Start profiling.
- $1 - Profile filename to use. Optional. If not specified, generates a random filename.
Returns 0 (true) on success, 1 if it could not generate a random file.
Turn off profiling.
Returns nothing.