0

To calculate last command's wall time I use this code (code #1):

#
# Taken from https://stackoverflow.com/a/34812608/9881330
# Slightly modified.
#
function timer_now {
    date +%s%N
}

function timer_start {
    timer_start=${timer_start:-$(timer_now)}
}


function timer_stop {
    local delta_us=$((($(timer_now) - $timer_start) / 1000))
    local us=$((delta_us % 1000))
    local ms=$(((delta_us / 1000) % 1000))
    local s=$(((delta_us / 1000000) % 60))
    local m=$(((delta_us / 60000000) % 60))
    local h=$((delta_us / 3600000000))
    # Goal: always show around 3 digits of accuracy
    if ((h > 0)); then timer_show=${h}h${m}m
    elif ((m > 0)); then timer_show=${m}m${s}s
    elif ((s >= 10)); then timer_show=${s}.$((ms / 100))s
    elif ((s > 0)); then timer_show=${s}.$(printf %03d $ms)s
    elif ((ms >= 100)); then timer_show=${ms}ms
    elif ((ms > 0)); then timer_show=${ms}.$((us / 100))ms
    else timer_show=${us}us
    fi
    unset timer_start
}


set_prompt () {
    PS1="\n$?"
    timer_stop
    PS1+=" / $timer_show"
    PS1+="\n\n[\e]0;\w\a][\e[32m]\u@\h [\e[33m]\w[\e[0m]\n$ "
}


trap 'timer_start' DEBUG
PROMPT_COMMAND='set_prompt'

And it works pretty well:

$ gcc
gcc: fatal error: no input files
compilation terminated.

1 / 108ms


$ date
Sun Dec 27 14:53:10 RTZST 2020


0 / 89.3ms

However, to solve the history is lost after ssh connection is reset by peer problem (Bash: history is lost after ssh connection is reset by peer: how to save the history?), after the previous code (code #1) I put this code (code #2):

PROMPT_COMMAND="${PROMPT_COMMAND:+${PROMPT_COMMAND/%;};}history -a"

Now the last command's wall time is calculated incorrectly (while the commands visually run in a milliseconds as usual):

$ gcc
gcc: fatal error: no input files
compilation terminated.

1 / 1.990s


$ date
Sun Dec 27 14:56:07 RTZST 2020


0 / 3.586s

Question: why adding code #2 after code #1 makes code #1 produce incorrect results? How to fix?

pmor
  • 599

1 Answers1

1

Chain of events (it is assumed that reader knows what ${var:-someval} works):

  • You type some command.
  • When you hit enter, DEBUG trap is executed.
    • timer_start=${timer_start:-$(timer_now)}
  • Then the command is executed.
  • Then set_prompt is executed.
    • Bla bla bla, then
    • unset timer_start - timer is restarted.
  • Then DEBUG trap is executed before history -a
    • timer_start=${timer_start:-$(timer_now)}
  • Then history -a is executed.
  • Time passes, you type your command.
  • Then DEBUG trap is executed before your typed command.
    • timer_start=${timer_start:-$(timer_now)}
    • but timer_start is already set, so nothing happens.
  • Then your command is executed.
  • set_prompt is super long, cause it measures time from the last prompt_command when history -a was executed.

Execute history -a for example before set_prompt or remove DEBUG trap when running it.

KamilCuk
  • 860
  • Execute history -a for example before set_prompt: excellent! Thanks for the detailed answer! – pmor Dec 27 '20 at 17:43