[SOLVED] duration, start time and end time of a command after it is finished

blueray · 01-02-2021, 11:44 PM

This question was originally posted on https://unix.stackexchange.com/quest...it-is-finished

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

Code:

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

I mainly want to run rsync, youtube-dl, tail -f etc with this command.

The solution I got was

Code:

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

Example usage:

Code:

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

It has few deal breaking issues.

1. It does not print the report at the end when the command within has stdout of its own. try:

Code:

./reporttime cat reporttime.

2. It waits till the whole command is complete, then it shows the whole output at once.

For example, try monitoring a log file with this script.

Code:

./reporttime tail -f /var/log/apache2/access.log

3. If I use ctrl+c to close a command, it does not show the report. Ex

Code:

./reporttime tail -f /var/log/apache2/access.log

then press ctrl+c.

The code I was originally working with was:

Code:

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}"

It had few issues of its own.

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.

What might be a solution here.

RandomTroll · 01-02-2021, 11:58 PM

I do this with:

Code:

Before=`date +%s`
The commands I want to time
After=`date +%s`
let Duration=After-Before
echo "This took $Duration seconds"

blueray · 01-03-2021, 12:06 AM

I used:

Code:

#! /bin/bash

Before=`date +%s`
tail -f ~/.xsession-errors
After=`date +%s`
let Duration=After-Before
echo "This took $Duration seconds"

After I press ctrl+c, it does not show the report.

Code:

% ./reporttime
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)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
Cinnamon warning: Log level 128: posix_spawn avoided (fd close requested)
^C

blueray · 01-03-2021, 12:11 AM

I think we have to use a wrapper function like

Code:

do_cmd()
{
    "$@"
    ret=$?
    if [[ $ret -eq 0 ]]
    then
        echo "Successfully ran [ $@ ]"
    else
        echo "Error: Command [ $@ ] returned $ret"
        return $ret
    fi
}

Source: https://stackoverflow.com/questions/...s-and-logs-the

blueray · 01-03-2021, 12:35 AM

I tried:

Code:

#! /bin/bash

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

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

The output is:

Code:

 ./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

Does not show the report.

blueray · 01-03-2021, 12:40 AM

Nothing is executed after `exec "$@"`

Code:

% ./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%

syg00 · 01-03-2021, 12:47 AM

Perhaps you should give some thought to the command you are attempting to run. Try it with "df" .

blueray · 01-03-2021, 12:50 AM

Code:

% ./reporttime df
1609656553
Filesystem      1K-blocks       Used Available Use% Mounted on
udev             16225816          0  16225816   0% /dev
tmpfs             3253832       1600   3252232   1% /run
/dev/sda2       238798492   46347360 180251096  21% /
tmpfs            16269152     191900  16077252   2% /dev/shm
tmpfs                5120          4      5116   1% /run/lock
tmpfs            16269152          0  16269152   0% /sys/fs/cgroup
/dev/sda1          523248       7984    515264   2% /boot/efi
tmpfs             3253828         40   3253788   1% /run/user/1000
/dev/sdb1      3844639728 2894974052 754298460  80% /media/blueray/WDRed

Same nothing is printed after `exec "$@"`

rnturn · 01-03-2021, 12:56 AM

Quote:

Originally Posted by blueray

I tried:

Code:

#! /bin/bash

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

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

The output is:

Code:

 ./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

Does not show the report.

You'll likely have to trap the Ctrl-C interruption to the shell script and have it execute the "After" portion of the calculations if you want that execution summary to be displayed after you've whacked the script while it was running. Since you'll do a couple of different calculations as part of the end-of-timing task, make that a shell function---it can be invoked "manually" in your script when needed or specified as the action to take when a Ctrl-C is received. It's been a while since I've done it (I'd have to track down an old script that used it) but you can have that calculation done automagically by trapping the normal script exit as well as Ctrl-Cs. (BTW, that is a nifty way to force your script(s) to do their temp file clean up or any other end-of-script processing you need done.)

HTH...

lvm_ · 01-03-2021, 01:38 AM

Ahem. Any particular reason you don't want to use 'time' or 'times' command which is built in into some shells (not sure about zsh though) and available as external command in time package?

Code:

$ time sleep 1

real    0m1.013s
user    0m0.003s
sys     0m0.000s

blueray · 01-03-2021, 01:47 AM

time command do not have start time, end time and duration. moreover, it does not show in the format I am looking for which is:

Quote:

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

Ser Olmy · 01-03-2021, 02:46 AM

Quote:

Originally Posted by blueray

Nothing is executed after `exec "$@"`

As one would expect. From man bash:

Quote:

exec [-cl] [-a name] [command [arguments]]

If command is specified, it replaces the shell. No new process
is created.

lvm_ · 01-03-2021, 02:50 AM

Actually time does have an overall duration: for external /usr/bin/time it is available via -f formatting options, for built-in time it can be set via TIMEFORMAT variable, at least in bash.

Code:

$ /usr/bin/time -f "Total duration %E" sleep 1
Total duration 0:01.00

blueray · 01-03-2021, 03:07 AM

Thanks to Stéphane Chazelas the solution that is working for me is:

Code:

#! /bin/zsh -

trap true INT QUIT

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
strftime -s end 'End Time: %d/%m/%y %I:%M%P'
ret=$?
print -rlu2 $start $end $duration
return $ret

pan64 · 01-03-2021, 05:34 AM

still not ok, ret=$? should be moved one line up, before strftime (at least).