6

I want to have a report like the following after a command finishes:

Start Time: 02/01/21 01:27pm
End Time: 02/01/21 02:29pm
Total Duration: 01 Hour 02 Minutes

I figured out I can get the Start Time and End Time using date +"%d/%m/%y %I:%M%P".

For example,

start=$(date +"%d/%m/%y %I:%M%P")
start_duration=$(date +%s)
youtube-dl
end=$(date +"%d/%m/%y %I:%M%P")
end_duration=$(date +%s)
runtime=$((end_duration-start_duration))
echo "Start Time: ${start}"
echo "End Time: ${end}"

Few Issues.

  1. I am not understanding how to print Total Duration: 01 Hour 02 Minutes
  2. How can I make this script universal so that I can use any command, not just youtube-dl in this script.

I tried:

#! /bin/bash

Before=$(date +%s)
echo "$Before"
exec "$@"
ret=$?
After=$(date +%s)
echo "$After"
let Duration=After-Before
echo "$Duration"


if [[ $ret -eq 0 ]]
then
    echo "Start Time: ${Before}"
    echo "End Time: ${After}"
    echo "Total Duration: ${Duration}"
    return $ret
else
    echo "Error: Command [ $@ ] returned $ret"
    echo "Start Time: ${Before}"
    echo "End Time: ${After}"
    echo "Total Duration: ${Duration}"
    return $ret
fi

But it does not work if I use ctrl+c

$ ./reporttime tail -f ~/.xsession-errors
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
^C

In fact, probably nothing is executed after exec "$@"

% ./reporttime cat reporttime
1609655953
#! /bin/bash

Before=$(date +%s)
echo "$Before"
exec "$@"
ret=$?
After=$(date +%s)
echo "$After"
let Duration=After-Before
echo "$Duration"


if [[ $ret -eq 0 ]]
then
    echo "Start Time: ${Before}"
    echo "End Time: ${After}"
    echo "Total Duration: ${Duration}"
    return $ret
else
    echo "Error: Command [ $@ ] returned $ret"
    echo "Start Time: ${Before}"
    echo "End Time: ${After}"
    echo "Total Duration: ${Duration}"
    return $ret
fi%
Ahmad Ismail
  • 2,678

1 Answers1

7

With zsh:

zmodload zsh/datetime
TIMEFMT='Total duration for %J: %*E'
preexec() strftime 'Start Time: %d/%m/%y %I:%M%P'
precmd() strftime 'End Time: %d/%m/%y %I:%M%P'
REPORTTIME=0

And then, you'll get the start time printed when you enter a command line, end time printed just before displaying the next prompt, and the duration of each non-builtin command (more precisely, for each process waited for by the shell):

$ sleep 1; sleep 2
Start Time: 02/01/21 08:31am
Total duration for sleep 1: 1.002
Total duration for sleep 2: 2.003
End Time: 02/01/21 08:31am

You can change REPORTTIME=0 to REPORTTIME=10 for instance to only report the time of commands that take more than 10 seconds of CPU Time (not elapsed time), or prefix each command you want to time with time.

As a script that takes an arbitrary command to run:

#! /bin/zsh -
zmodload zsh/datetime
TIMEFMT='Total duration: %*E'
strftime -s start 'Start Time: %d/%m/%y %I:%M%P'
{
  duration=$(
    exec 4>&2 2>&1 1>&3 3>&-
    time "$@" 2>&4 4>&-
  )
} 3>&1
ret=$?

strftime -s end 'End Time: %d/%m/%y %I:%M%P'
print -rlu2 $start $end $duration
exit $ret

And then:

$ ./reporttime sleep 65
Start Time: 02/01/21 09:26am
End Time: 02/01/21 09:26am
Total duration: 1:05.00

Instead of relying on time, you can also use the $SECONDS or $EPOCHSECONDS special variables (or $EPOCHREALTIME/$epochtime if you want subsecond granularity)

#! /bin/zsh -
zmodload zsh/datetime
start=($epochtime)
"$@"
end=($epochtime) ret=$?
strftime >&2 'Start Time: %FT%T.%3.%z' $start
strftime >&2 'End Time: %FT%T.%3.%z' $end
printf >&2 'Total duration: %.3f\n' $((
  end[1] - start[1] + (end[2] - start[2]) / 1e9
))
exit $ret

This time using a standard and non-ambiguous time format:

$ ./reporttime2 sleep 1
Start Time: 2021-01-02T09:50:49.261+0000
End Time: 2021-01-02T09:50:50.264+0000
Total duration: 1.003

If you still want to report those timing when you press Ctrl + C or Ctrl + \ which otherwise would kill both zsh and the command being timed, you can add a:

trap true INT QUIT

at the top of those scripts for the shell to intercept those signals and not die there. Don't do trap '' INT QUIT which would cause the signals to be ignored altogether and the timed command not to be killed in that case.

Stéphane Chazelas
  • 544,893
  • I just noticed, If I use the second script in the fpath removing the #! /bin/zsh -, then when the reporttime sleep 1 command finish, the terminal is automatically closed. – Ahmad Ismail Jan 02 '21 at 09:40
  • @blueray, exit is the command to exit the shell. Those are meant to be scripts. It's not particularly useful to make them zsh functions, as that would mean they could only be invoked from within zsh. But If you still wanted to, you'd want to replace the exit with return and probably also declare the variables local. – Stéphane Chazelas Jan 02 '21 at 09:44
  • @blueray, Ctrl+C causes SIGINT to be sent to the current foreground job, the foreground process group of the terminal, so it would kill the timed command and the shell. See edit if you want the shell to survive the SIGINT (I've also fixed a couple of mistakes in the scripts). – Stéphane Chazelas Jan 03 '21 at 07:58
  • @blueray, see the end of my answer. Add that trap true INT QUIT at the top (just below the shebang). That tells zsh to run true (which does nothing) upon receiving SIGINT or SIGQUIT instead of dying. – Stéphane Chazelas Jan 03 '21 at 08:35