Login or Register to Ask a Question and Join Our Community


Shell Programming and Scripting

time diffrence between two lines in a log file

Login to Discuss or Reply to this Discussion in Our Community

 
Thread Tools Search this Thread
Top Forums Shell Programming and Scripting time diffrence between two lines in a log file
# 1  
Old 04-28-2009
time diffrence between two lines in a log file
Hi Experts,

I am writing a shell/Perl script tp get a time diffrence of two lines in a log file. I am pasting a snippet of my log file, how it look likes.

Code:
Sun Apr 26 02:11:03.162 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: calling ARRF_LIB_Evaluate.
Sun Apr 26 02:11:03.162 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering ARRF_LIB_Evaluate
Sun Apr 26 02:11:03.162 2009 Greenwich Standard Time INFO:    pid 488 tid 2072: 0: 251360: Received Request ARRF_LIB_Evaluate
Sun Apr 26 02:11:03.162 2009 Greenwich Standard Time LOW:     pid 488 tid 1
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Decrementing load for 0 pool in Primary List
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Exiting ArPFExtRuleSetEval::evaluate
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: CollatedResultDetail [USERKNOWN.DETAIL=RESULT=0|DEVICEIDCHECK.DETAIL=RESULT=0|UNTRUSTEDIP.DETAIL=RESULT=0|SIGMATCH.DETAIL=RESULT=0;REASON=DEVICEIDCHECK_FAILED|TDDefaultAmount.DETAIL=|TDDefaultMerchantCountry.DETAIL=RESULT=1|SCORE.DETAIL=SCORE=65;ADVICE=4;EXITAT=TDDefaultMerchantCountry|]
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering setEvaluateResponse
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Exiting setEvaluateResponse
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering ARRFDbOperations::insertEvalTx
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Exiting getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Exiting getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Exiting getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Exiting getIntResult
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Entering ARRFDbOperations::insertSysAuditLog
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Acquiring ReaderWriter Lock
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Acquired ReaderWriter Lock, going to select pool
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Selecting Pool with minimum load
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Trying to find next in round robin
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: _numberOfPools [1] activePool size [1]
Sun Apr 26 02:11:03.224 2009 Greenwich Standard Time LOW:     pid 488 tid Sun Apr 26 02:11:03.240 2009 Greenwich Standard Time INFO:    pid 488 tid 2072: 0: 251360: Sending Response ARRF_LIB_Evaluate
Sun Apr 26 02:11:03.240 2009 Greenwich Standard Time LOW:     pid 488 tid 2072: 0: 251360: Exiting ARRF_LIB_Evaluate

I want to get a time diffrence between the lines "Entering ARRF_LIB_Evaluate" and "Exiting ARRF_LIB_Evaluate".
Thses lines come repeatedly in the log file so everytime i need to get what is the difference of timebetween these lines.
Any kind of help is greatly appericiated. I am trying with my own and will post you with my script, what i have tried so far.

If any information is required kindly let me know.

Thanks
NT
# 2  
Old 04-28-2009
Hi,

I have tried this so far but time diffrence is not coming , it is showing syntax error for the time diffrence line.
Code:
#!/usr/bin/ksh
#set -x
start_time=0;
end_time=0;
result=0;
while [ logfile ]
       do
           for line in logfile
           do
           var1=`grep "Entering ARRF_LIB_Evaluate" $line`
           start_time=`echo $var1 | cut -d " " -f4`
           echo "$start_time"
           var2=`grep "Exiting ARRF_LIB_Evaluate" $line`
           end_time=`echo $var2 | cut -d " " -f4`
           echo "$end_time"
           result=`expr $end_time - $start_time`
           echo $result
           done
done

When i ran this script i am getting --
[root@tsrh4ent shell_perl_script]# sh timediff.sh
02:11:03.162
02:11:03.240
expr: non-numeric argument

and it is going on in infinite loop, i want it like, when the logfile ends it should stop.

Kindly help me in this..

Thanks
NT
Last edited by namishtiwari; 04-28-2009 at 11:55 AM.. Reason: added $ before start_time
# 3  
Old 04-28-2009
Quote:
Originally Posted by namishtiwari
Hi,

I have tried this so far but time diffrence is not coming , it is showing syntax error for the time diffrence line.
Code:
#!/usr/bin/ksh
#set -x
start_time=0;
end_time=0;
result=0;
while [ logfile ]
       do
           for line in logfile
           do
           var1=`grep "Entering ARRF_LIB_Evaluate" $line`
           start_time=`echo $var1 | cut -d " " -f4`
           echo "$start_time"
           var2=`grep "Exiting ARRF_LIB_Evaluate" $line`
           end_time=`echo $var2 | cut -d " " -f4`
           echo "$end_time"
           result=`expr $end_time - start_time`
           echo $result
           done
done

When i ran this script i am getting --
[root@tsrh4ent shell_perl_script]# sh timediff.sh
02:11:03.162
02:11:03.240
expr: non-numeric argument

and it is going on in infinite loop, i want it like, when the logfile ends it should stop.

Kindly help me in this..

Thanks
NT

You missed out "$" in the below line:
Code:
 result=`expr $end_time - $start_time`

Give it a try!!!
# 4  
Old 04-28-2009
In my shell script which i am trying has $ sign before start_time. Here by mistake i guess i forgot.


Thanks
NT
# 5  
Old 04-28-2009
Hello,

Before coming to a conclusion, i wanted to know what exactly this line meant??
Code:
Sun Apr 26 02:11:03.224

I am not sure what that red things mean!!!

Comming to the script, you need to sort out one problem:
Code:
`echo $var1 | cut -d " " -f4`

the output of the above command looks like this: 02:11:03.162
which you are storing in the variable start_time.
And same's the case with end_time.

So it is known that a shell cannot evaluate a non-integer thing. Hence expr: non-numeric argument

And one more thing, no need to print the start_time and end_time values inside the loop, hence commenting out could be better as you are looking for the timestamp diff. But depends on your requirement. What say!!!
# 6  
Old 04-28-2009
Code:
Sun Apr 26 02:11:03.224

The red thing means that the time is in mili seconds.

That is fine and that is why i want to know how i can get the diffrence of those two variable. I just wanted to see the values of the variable so i echoed them.
I hope things are clear now.
I want to get the diffrence of the two time stamps i captured in start_time and end_time and i want when the logfile ends it should also stop, it should not go to infinite loop.
Rest everything printing and decorating i will do later.

Thanks
NT
# 7  
Old 04-28-2009
you can't just expr and subtract time/date like that. you might want to use some date manipulation module, like that of Date::Calc/strptime/strftime that goes with Perl. here's one way with Python
Code:
import time

def calctime(line):
    line = line.split()
    day,month,mday, TIME, year = line[0],line[1],line[2],line[3],line[4]    
    hr,mm,sec = TIME.split(":")
    sec,ms = sec.split(".")
    time2parse = "%s %s %s %s:%s:%s %s" % (day,month,mday,hr,mm,sec, year)
    stringtime = time.strptime(time2parse,"%a %b %d %H:%M:%S %Y")
    return [time.strftime("%s",stringtime),ms]

for line in open("file"):
    flag=1
    line=line.strip()
    if "Entering ARRF_LIB_Evaluate" in line:
        startT,startms = calctime(line)        
    if "Exiting ARRF_LIB_Evaluate" in line:
        endT,endms = calctime(line)        
        flag=0
    if flag == 0:
        diff = int(endT) - int(startT)
        if diff==0: print "Time difference(ms) " , int(endms) - int(startms)
        else: print "Time different %d (s)" % diff

output
Code:
# ./test.py
Time difference(ms)  78
Login or Register to Ask a Question

Previous Thread | Next Thread

10 More Discussions You Might Find Interesting

1. Shell Programming and Scripting

Collecting all lines between two time stamp from the log

Can you help me to collect the entire logs between two time stamp. The below awk command collecting the logs only if the line has time stamp. awk '$0>=from && $0<=to' from="150318 23:19:04" to="150318 23:55:04" log file 150318 23:19:04 logentries 150318 23:29:04 logentries 150318... (11 Replies)
Discussion started by: zenkarthi
11 Replies

2. Shell Programming and Scripting

Check/Parse log file's lines using time difference/timestamp

I was looking at this script which outputs the two lines which differs less than one sec. #!/usr/bin/perl -w use strict; use warnings; use Time::Local; use constant SEC_MILIC => 1000; my $file='infile'; ## Open for reading argument file. open my $fh, "<", $file or die "Cannot... (1 Reply)
Discussion started by: cele_82
1 Replies

3. Shell Programming and Scripting

Read multiple lines at a time from file

Hello All, I have a file like below.... dn: cn=user1,ou=org,o=org cn=user1 uid=user1 cn=user2,ou=org,o=org cn=user2 uid=user2 cn=user3,ou=org,o=org cn=user3 cn=user33 uid=user3 cn=user4,ou=org,o=org cn=user4 uid=user4 (6 Replies)
Discussion started by: s_linux
6 Replies

4. Shell Programming and Scripting

Read two lines at time from a file

Hello community, what I need to do is read 2 rows at time from a file. I have this simple solution: File to read: LINE1 LINE2 LINE3 LINE4 LINE5 LINE6 LINE7 LINE8Read routine:#!/bin/ksh sed '1,3d' /out.txt | while read line; do read line2 echo $line $line2 doneResult:LINE1... (5 Replies)
Discussion started by: Lord Spectre
5 Replies

5. Shell Programming and Scripting

Find time difference between two consecutive lines in same file.

Hello I have a file in following format: IV 08:09:07 NM 08:12:01 IC 08:12:00 MN 08:14:20 NM 08:14:15 I need a script to compare time on each line with previous line and show the inconsecutive line. Ex.: 08:12:00 08:14:15 A better way... (6 Replies)
Discussion started by: vilibit
6 Replies

6. Shell Programming and Scripting

Get all lines in a file after particular time

Hi All, I am lookig for a way to get all the lines from a log file which has been updated 5 mins prior to the system time. The log file will be like below: 09:01:00 Started polling 09:01:05 Checking directory test 09:02:00 Error! Cannot access directory test 09:03:00 Polling I get... (8 Replies)
Discussion started by: deepakgang
8 Replies

7. Shell Programming and Scripting

Extracting lines in file based on time

Hi, anyone has any ideas on how do we extract lines from a file with format similiar to this: (based on current time) Jun 18 00:16:50 .......... ............. ............ Jun 18 00:17:59 .......... ............. ............ Jun 18 01:17:20 .......... ............. ............ Jun 18... (5 Replies)
Discussion started by: faelric
5 Replies

8. Shell Programming and Scripting

To find the time difference between two lines of the same log file

Hello Friends, I want to write a script for the following: nlscux62:tibprod> grep "2008 Apr 30 01:" SA_EHV_SPEED_SFC_IN_03-SA_EHV_SPEED_SFC_IN_03-2.log | grep -i post | more 2008 Apr 30 01:01:23:928 GMT +2 SAPAdapter.SA_EHV_SPEED_SFC_IN_03-SA_EHV_SPEED_SFC_IN_03-2 Info AER3-000095 IDOC... (2 Replies)
Discussion started by: satyakam
2 Replies

9. Shell Programming and Scripting

Processing a log file based on date/time input and the date/time on the log file

Hi, I'm trying to accomplish the following and would like some suggestions or possible bash script examples that may work I have a directory that has a list of log files that's periodically dumped from a script that is crontab that are rotated 4 generations. There will be a time stamp that is... (4 Replies)
Discussion started by: primp
4 Replies

10. UNIX for Dummies Questions & Answers

Can any how we can find the time diffrence...?

Hi, I am trying to caluate the time elasped by the job to run.For that i have used the following command: I have one file which contains the following more start.txt 991 STARTED Fri Aug 10 14:04:20 2007 Starting Job JOB_NAME. (...) 1036 STARTED Fri Aug 10 14:04:31 2007 ... (1 Reply)
Discussion started by: Amey Joshi
1 Replies
Login or Register to Ask a Question