Use PS0 and PS1 to display execution time of each bash command

Question

It seems that by executing code in PS0 and PS1 variables (which are eval'ed before and after a prompt command is run, as I understand) it should be possible to record time of each running command and display it in the prompt. Something like that:

user@machine ~/tmp
$ sleep 1

user@machine ~/tmp 1.01s
$

However, I quickly got stuck with recording time in PS0, since something like this doesn't work:

PS0='$(START=$(date +%s.%N))'

As I understand, START assignment happens in a sub-shell, so it is not visible in the outer shell. How would you approach this?

Answer 1

As @tc said, using arithmetic expansion allows you to assign variables during the expansion of PS0 and PS1. Newer bash versions also allow PS* style expansion so you don't even need a subshell to get the current time. With bash 4.4:

# PS0 extracts a substring of length 0 from PS1; as a side-effect it causes
# the current time as epoch seconds to PS0time (no visible output in this case)
PS0='\[${PS1:$((PS0time=\D{%s}, PS1calc=1, 0)):0}\]'
# PS1 uses the same trick to calculate the time elapsed since PS0 was output.
# It also expands the previous command's exit status ($?), the current time
# and directory ($PWD rather than \w, which shortens your home directory path
# prefix to "~") on the next line, and finally the actual prompt: 'user@host> '
PS1='\nSeconds: $((PS1calc ? \D{%s}-$PS0time : 0)) Status: $?\n\D{%T} ${PWD:PS1calc=0}\n\u@\h> '

(The %N date directive does not seem to be implemented as part of \D{...} expansion with bash 4.4. This is a pity since we only have a resolution in single second units.)

Since PS0 is only evaluated and printed if there is a command to execute, the PS1calc flag is set to 1 to do the time difference (following the command) in PS1 expansion or not (PS1calc being 0 means PS0 was not previously expanded and so didn't re-evaluate PS1time). PS1 then resets PS1calc to 0. In this way an empty line (just hitting return) doesn't accumulate seconds between return key presses.

One nice thing about this method is that there is no output when you have set -x active. No subshells or temporary files in sight: everything is done within the bash process itself.

Answer 2

As correctly stated in the question, PS0 runs inside a sub-shell which makes it unusable for this purpose of setting the start time.

Instead, one can use the history command with epoch seconds %s and the built-in variable $EPOCHSECONDS to calculate when the command finished by leveraging only $PROMPT_COMMAND.

# Save start time before executing command (does not work due to PS0 sub-shell)
# preexec() {
#   STARTTIME=$EPOCHSECONDS
# }
# PS0=preexec

# Save end time, without duplicating commands when pressing Enter on an empty line
precmd() {
    local st=$(HISTTIMEFORMAT='%s ' history 1 | awk '{print $2}');
    if [[ -z "$STARTTIME" || (-n "$STARTTIME" && "$STARTTIME" -ne "$st") ]]; then
        ENDTIME=$EPOCHSECONDS
        STARTTIME=$st
    else
        ENDTIME=0
    fi
}

__timeit() {
    precmd;
    if ((ENDTIME - STARTTIME >= 0)); then
        printf 'Command took %d seconds.\n' "$((ENDTIME - STARTTIME))";
    fi

    # Do not forget your:
    #     - OSC 0 (set title)
    #     - OSC 777 (notification in gnome-terminal, urxvt; note, this one has preexec and precmd as OSC 777 features)
    #     - OSC 99 (notification in kitty)
    #     - OSC 7 (set url) - out of scope for this question
}

export PROMPT_COMMAND=__timeit

Note: If you have ignoredups in your $HISTCONTROL, then this will not report back for a command that is re-run.

Answer 3

I was looking for a solution to a different problem and came upon this question, and decided that sounds like a cool feature to have. Using @Scheff's excellent answer as a base in addition to the solutions I developed for my other problem, I came up with a more elegant and full featured solution.

First, I created a few functions that read/write the time to/from memory. Writing to the shared memory folder prevents disk access and does not persist on reboot if the files are not cleaned for some reason

function roundseconds (){
  # rounds a number to 3 decimal places
  echo m=$1";h=0.5;scale=4;t=1000;if(m<0) h=-0.5;a=m*t+h;scale=3;a/t;" | bc
}

function bash_getstarttime (){
  # places the epoch time in ns into shared memory
  date +%s.%N >"/dev/shm/${USER}.bashtime.${1}"
}

function bash_getstoptime (){
  # reads stored epoch time and subtracts from current
  local endtime=$(date +%s.%N)
  local starttime=$(cat /dev/shm/${USER}.bashtime.${1})
  roundseconds $(echo $(eval echo "$endtime - $starttime") | bc)
}

The input to the bash_ functions is the bash PID

Those functions and the following are added to the ~/.bashrc file

ROOTPID=$BASHPID
bash_getstarttime $ROOTPID

These create the initial time value and store the bash PID as a different variable that can be passed to a function. Then you add the functions to PS0 and PS1

PS0='$(bash_getstarttime $ROOTPID) etc..'
PS1='\[\033[36m\] Execution time $(bash_getstoptime $ROOTPID)s\n'
PS1="$PS1"'and your normal PS1 here'

Now it will generate the time in PS0 prior to processing terminal input, and generate the time again in PS1 after processing terminal input, then calculate the difference and add to PS1. And finally, this code cleans up the stored time when the terminal exits:

function runonexit (){
  rm /dev/shm/${USER}.bashtime.${ROOTPID}
}

trap runonexit EXIT

Putting it all together, plus some additional code being tested, and it looks like this:

The important parts are the execution time in ms, and the user.bashtime files for all active terminal PIDs stored in shared memory. The PID is also shown right after the terminal input, as I added display of it to PS0, and you can see the bashtime files added and removed.

PS0='$(bash_getstarttime $ROOTPID) $ROOTPID experiments \[\033[00m\]\n'