Find Elapsed Time or Duration of Long Running jobs without using sleep command

Question

I am trying to capture the elapsed time for long running jobs in Linux.

I tried the following method 1, but it shows WRONG duration as the operation took 4 hours, but actual duration in minutes only

METHOD 1:

$ TAR_STARTTIMESTAMP=$(date +%s)
$ TAR_STARTTIME=`date +"%d/%b/%Y %H:%M"`
$ tar -cvf /u05/expdpdump/exppdb/TAR_EXP_DUMP_Wallet.tar /u05/expdpdump/exppdb/*.dmp
tar: Removing leading '/' from member names
/u05/expdpdump/exppdb/NoTDE_PDB_FULL.dmp
tar: /u05/expdpdump/exppdb/NoTDE_PDB_FULL.dmp: file changed as we read it
/u05/expdpdump/exppdb/NoTDE_PDB_FULL_wallet_01.dmp
/u05/expdpdump/exppdb/NoTDE_PDB_FULL_wallet_02.dmp
$ TAR_TAR_ENDTIMESTAMP=$(date +%s)
$ TAR_ENDTIME=`date +"%d/%b/%Y %H:%M"`
$ TAR_DIFFTIMESTAMP=$(( ${TAR_ENDTIMESTAMP} - ${TAR_STARTTIMESTAMP} ))
$ TAR_DIFFTIME=`date -u -d @${TAR_DIFFTIMESTAMP} "+%H hours, %M minutes and %S seconds"`

$ echo "Tar Started: ${TAR_STARTTIME}" >> /u05/expdpdump/exppdb/EXP_TAR_DUMP.log
$ echo "Tar Finished: ${TAR_ENDTIME}" >> /u05/expdpdump/exppdb/EXP_TAR_DUMP.log
$ echo "Tar took ${TAR_DIFFTIME} to complete" >> /u05/expdpdump/exppdb/EXP_TAR_DUMP.log

$ less /u05/expdpdump/exppdb/EXP_TAR_DUMP.log
Tar Started: 19/Mar/2019 19:12
Tar Finished: 19/Mar/2019 20:29
Tar took 04 hours, 47 minutes and 30 seconds to complete

I tried to change with the following shell to assign variables and create log

METHOD 2

Here is my code

### Code Starts Here ###
read -p "Enter the File Path: " FILE_PATH 
read -p "Enter the Log Name: " LOG_NAME
read -p "Enter the Activity Name: " ACTIVITY


touch $FILE_PATH/$LOG_NAME

"${ACTIVITY}"_START_TIMESTAMP=$(date +%s)
ACTIVITY_START_TIME=`date "+%Y/%m/%d %H:%M:%S"`

# run the desired long running activity

$ACTIVITY_END_TIMESTAMP=$(date +%s)
$ACTIVITY_END_TIME=`date "+%Y/%m/%d %H:%M:%S"`
$ACTIVITY_DIFF_TIMESTAMP=$(( ${ACTIVITY_END_TIMESTAMP} - ${ACTIVITY_START_TIMESTAMP} ))
$ACTIVITY_DIFF_TIME=`date -u -d @${ACTIVITY_DIFF_TIMESTAMP} "+%H hours, %M minutes and %S seconds"`


echo "$ACTIVITY Started: ${ACTIVITY_STARTTIME}" >>  $FILE_PATH/$LOG_NAME
echo "$ACTIVITY Finished: ${ACTIVITY_ENDTIME}" >> $FILE_PATH/$LOG_NAME
echo "$ACTIVITY took ${ACITIVITY_DIFFTIME} to complete" >> $FILE_PATH/$LOG_NAME

### Code Ends Here ###

when i try to export the following variable, i get the error

$ ${ACTIVITY}_START_TIMESTAMP=$(date +%s)
-bash: TAR_START_TIMESTAMP=1553021544: command not found
$ '${ACTIVITY}'_START_TIMESTAMP=$(date +%s)
-bash: ${ACTIVITY}_START_TIMESTAMP=1553021623: command not found
$ "${ACTIVITY}"_START_TIMESTAMP=$(date +%s)
-bash: TAR_START_TIMESTAMP=1553021737: command not found
$ "${ACTIVITY}_START_TIMESTAMP=$(date +%s)"
-bash: TAR_START_TIMESTAMP=1553021808: command not found

Can someone either help fixing my first method or 2nd Method.

Why not just use the [`time`](https://linux.die.net/man/1/time) command? This is exactly the kind of thing it was designed for. — Mike Holt, Mar 19 '19 at 21:18
Too bad I couldn't add my answer. The problem is that you are mixing `-u` option usage. Either you use is on all options or you don't. Compare the result of this command with and without `-u`: `date --debug -u -d @$(( $(date '+%s') - $( date -d '4 hour ago' '+%s') )) "+%H hours, %M minutes and %S seconds"`. You will notice a difference that is precisely the timezone offset in your box. — LMC, Mar 20 '19 at 02:40

Dmitrii · Accepted Answer · 2019-03-20T11:29:45.163

Code

#!/bin/bash

array=()

function dump () {
   timestamp=$(date +%s)
   object=${1}
   action=${2}

    if [ "${action}" == "start" ]; then
        array[object]=${timestamp}
    elif [ "${action}" == "end" ]; then
        spent=$(( ${timestamp} - ${array[${object}]} ))

        echo "Time report for ${object}"
        echo "Started: $(date -d @${array[${object}]})"
        echo "Ended: $(date -d @${timestamp})"
        printf "Spent: %dh:%dm:%ds\n" $((${spent}/3600)) $((${spent}%3600/60)) $((${spent}%60))
    fi
}

# MAIN

dump "iter1" "start"
echo "iter1 started"
sleep 2
dump "iter1" "end"

echo "iter2 started"
dump "iter2" "start"
echo "iter3 started"
dump "iter3" "start"

sleep 2

dump "iter2" "end"

sleep 2

dump "iter3" "end"

Output

iter1 started
Time report for iter1
Started: Wed Mar 20 11:27:17 UTC 2019
Ended: Wed Mar 20 11:27:19 UTC 2019
Spent: 0h:0m:2s
iter2 started
iter3 started
Time report for iter2
Started: Wed Mar 20 11:27:19 UTC 2019
Ended: Wed Mar 20 11:27:21 UTC 2019
Spent: 0h:0m:2s
Time report for iter3
Started: Wed Mar 20 11:27:19 UTC 2019
Ended: Wed Mar 20 11:27:23 UTC 2019
Spent: 0h:0m:4s

Reiterating what @MikeHolt asked, *"Why not just use the time command?"* — jww, Mar 20 '19 at 02:36
Thanks Dmitri. It works partially, but i want to generate logs dynamically with custom names for a different set of activities, so that logs can be referred for future purpose. — CoolChap007, Mar 20 '19 at 03:04

Find Elapsed Time or Duration of Long Running jobs without using sleep command

METHOD 1:

METHOD 2

1 Answers1