Solved

Shell - calculate time between log lines

Posted on 2014-11-06
11
119 Views
Last Modified: 2015-01-14
Hi,

Not sure if this is possible to be done but I need to have a script to calculate the time between two log lines apperas in a log file.

The log file has:

1- Several lines like this:
2014-11-04 00:19:36.183 [164] Debug      HttpReceiverServlet            Incoming request url : http://otasnq-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260567661995&ST.IMEI=86458702147373

And several lines like this:
2014-11-04 00:19:51.625 [232] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX-priv-opm:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260567661995,


NOTE that the IMSI and IMEI on these lines differ (not in lenght but in content), for example:

2014-11-04 00:19:37.066 [164] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260672532625&ST.IMEI=35406806239910

====

The log is linear so for each line like this one for a specific IMSI I have on for this IMSI as well:
2014-11-04 00:19:36.183 [164] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260567661995&ST.IMEI=86458702147373
.
.
2014-11-04 00:19:51.625 [232] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX-priv-opm:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260567661995,

So what I need is for every "pair" of this (connected by the IMSI) is the dif. of the timing between the lines.. i the case above 00:19:51.625 minus 00:19:36.183.

And give as output a count like this:
Difference less than 60 sec = X
Difference more than 60 secs and less the 60 minute = Y
Dif. more than 60 min = Z

Is this possible?

===

There is one more thing.... sometimes I can have a situation like this:

2014-11-06 12:54:33.481 [46] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260130369278&ST.IMEI=01262600179856
2014-11-06 12:59:05.874 [52] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260130369278&ST.IMEI=01262600179888
        ST.IMSI=310260130369278
2014-11-06 13:04:43.950 [232] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX-priv-opm:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260130369278,


Two Incomings and out Successfully... only the last Incoming should be considered.

Tks,
joao
0
Comment
Question by:joaotelles
  • 7
  • 4
11 Comments
 
LVL 84

Expert Comment

by:ozo
ID: 40427588
perl -e 'use Time::Piece;
while( <> ){
    if( /([^.]+).*?Successfully.*?IMSI=(\d+)/ ){
$d=Time::Piece->strptime($1,"%Y-%M-%D %T")->epoch - Time::Piece->strptime($I{$2},"%Y-%M-%D %T")->epoch;
$count[($d>60)+($d>3600)]++
    }
    $I{$2}=$1 if /([^.]+).*?Incoming.*?IMSI=(\d+)/;
}
print "Difference less than 60 sec = $count[0]\n";
print "Difference more than 60 secs and less the 60 minute = $count[1]\n";
print "Dif. more than 60 min = $count[2]\n"; ' < logfile
0
 

Author Comment

by:joaotelles
ID: 40428095
Tks!

But I got this error:
Can't locate Time/Piece.pm in @INC (@INC contains: /usr/perl5/5.8.4/lib/sun4-solaris-64int /usr/perl5/5.8.4/lib /usr/perl5/site_perl/5.8.4/sun4-solaris-64int /usr/perl5/site_perl/5.8.4 /usr/perl5/site_perl /usr/perl5/vendor_perl/5.8.4/sun4-solaris-64int /usr/perl5/vendor_perl/5.8.4 /usr/perl5/vendor_perl .) at -e line 1.
BEGIN failed--compilation aborted at -e line 1.
0
 

Author Comment

by:joaotelles
ID: 40428134
I have installed the time/Pice manually but now Im getting this:

Error parsing time at /usr/perl5/site_perl/5.8.4/sun4-solaris-64int/Time/Piece.pm line 469, <> line 174227.

I installed using this instructions:
# perl Makefile.PL
WARNING: META_MERGE is not a known parameter.
Checking if your kit is complete...
Looks good
'META_MERGE' is not a known MakeMaker parameter name.
Writing Makefile for Time::Piece
# /usr/perl5/bin/perlgcc Makefile.PL
WARNING: META_MERGE is not a known parameter.
'META_MERGE' is not a known MakeMaker parameter name.
Writing Makefile for Time::Piece

# make
cp Seconds.pm blib/lib/Time/Seconds.pm
cp Piece.pm blib/lib/Time/Piece.pm
/usr/perl5/5.8.4/bin/perl /usr/perl5/5.8.4/lib/ExtUtils/xsubpp  -typemap /usr/perl5/5.8.4/lib/ExtUtils/typemap  Piece.xs > Piece.xsc && mv Piece.xsc Piece.c
gcc -c   -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -D_TS_ERRNO -O2 -fno-strict-aliasing   -DVERSION=\"1.29\" -DXS_VERSION=\"1.29\" -fPIC "-I/usr/perl5/5.8.4/lib/sun4-solaris-64int/CORE"   Piece.c
Running Mkbootstrap for Time::Piece ()
chmod 644 Piece.bs
rm -f blib/arch/auto/Time/Piece/Piece.so
LD_RUN_PATH="" gcc  -G Piece.o  -o blib/arch/auto/Time/Piece/Piece.so
chmod 755 blib/arch/auto/Time/Piece/Piece.so
cp Piece.bs blib/arch/auto/Time/Piece/Piece.bs
chmod 644 blib/arch/auto/Time/Piece/Piece.bs
Manifying blib/man3/Time::Seconds.3
Seconds.pm:181: Unknown command paragraph "=encoding utf8"
Manifying blib/man3/Time::Piece.3

# make test
PERL_DL_NONLAZY=1 /usr/perl5/5.8.4/bin/perl "-MExtUtils::Command::MM" "-e" "test_harness(0, 'blib/lib', 'blib/arch')" t/*.t
t/01base........ok
t/02core........ok
t/03compare.....ok
t/04mjd.........ok
t/05overload....ok
t/06subclass....ok
t/07arith.......ok
All tests successful.
Files=7, Tests=156,  0 wallclock secs ( 0.19 cusr +  0.00 csys =  0.19 CPU)

# make install
Installing /usr/perl5/site_perl/5.8.4/sun4-solaris-64int/auto/Time/Piece/Piece.so
Installing /usr/perl5/site_perl/5.8.4/sun4-solaris-64int/auto/Time/Piece/Piece.bs
Files found in blib/arch: installing files in blib/lib into architecture dependent library tree
Installing /usr/perl5/site_perl/5.8.4/sun4-solaris-64int/Time/Seconds.pm
Installing /usr/perl5/site_perl/5.8.4/sun4-solaris-64int/Time/Piece.pm
Installing /usr/perl5/5.8.4/man/man3/Time::Seconds.3
Installing /usr/perl5/5.8.4/man/man3/Time::Piece.3
Writing /usr/perl5/site_perl/5.8.4/sun4-solaris-64int/auto/Time/Piece/.packlist
Appending installation info to /usr/perl5/5.8.4/lib/sun4-solaris-64int/perllocal.pod
0
 
LVL 84

Expert Comment

by:ozo
ID: 40428341
What is in line 174227 of your logfile?
0
 

Author Comment

by:joaotelles
ID: 40428362
dpa@otablv04 mdm1a> sed -n 174227p mdm1a20141031.log
2014-10-31 06:52:54.302 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260211557257,

Looks exacltly the same as the others...

For example:
2014-10-31 06:52:54.698 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX
-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260002579222,

and

2014-10-31 06:52:54.729 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX
-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260802727386,

Tks,
Joao
0
How your wiki can always stay up-to-date

Quip doubles as a “living” wiki and a project management tool that evolves with your organization. As you finish projects in Quip, the work remains, easily accessible to all team members, new and old.
- Increase transparency
- Onboard new hires faster
- Access from mobile/offline

 
LVL 84

Accepted Solution

by:
ozo earned 500 total points
ID: 40428405
Sorry,
$d=Time::Piece->strptime($1,"%Y-%M-%D %T")->epoch - Time::Piece->strptime($I{$2},"%Y-%M-%D %T")->epoch;
should have been
$d=Time::Piece->strptime($1,"%Y-%m-%d %T")->epoch - Time::Piece->strptime($I{$2},"%Y-%m-%d %T")->epoch;
0
 

Author Comment

by:joaotelles
ID: 40428434
Tks Ozo!

Sorry to ask but is there a way to analyze only the lines with IMSIs that appear one time (one pair of Incoming and Notification) ?

I mean to ignore cases like this: where I have more than one Incoming line for a same IMSI and more than one notification for a same IMSI as well...

2014-11-06 12:54:33.481 [46] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260130369278&ST.IMEI=01262600179856
2014-11-06 12:59:05.874 [52] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260130369278&ST.IMEI=01262600179888
        ST.IMSI=310260130369278
2014-11-06 13:04:43.950 [232] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX-priv-opm:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260130369278,

===

So only analyze IMSIs with only one pair of the lines below, if there more than one pair, ignore both of them...
2014-11-04 00:19:36.183 [164] Debug      HttpReceiverServlet            Incoming request url : http://otasnq-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260567661995&ST.IMEI=86458702147373

And several lines like this:
2014-11-04 00:19:51.625 [232] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX-priv-opm:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260567661995,
0
 
LVL 84

Expert Comment

by:ozo
ID: 40428456
I'm not sure I understand.  Could you give a small example of a complete log file with the output you would want to produce from it?
0
 

Author Comment

by:joaotelles
ID: 40428488
Ok.. Sry...

In the logs I have several lines like this:
2014-10-31 06:52:35.619 [79] Debug      HttpReceiverServlet            Incoming request url : http://otablv-priv-nfcmh-vip:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260112638088&ST.IMEI=35881005000146
2014-10-31 06:52:35.622 [75] Debug      HttpReceiverServlet            Incoming request url : http://otablv-priv-nfcmh-vip:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260112637956&ST.IMEI=35881005000178
2014-10-31 06:52:35.682 [75] Debug      HttpReceiverServlet            Incoming request url : http://otablv-priv-nfcmh-vip:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260502806226&ST.IMEI=35881005000159
2014-10-31 06:52:35.696 [75] Debug      HttpReceiverServlet            Incoming request url : http://otablv-priv-nfcmh-vip:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260220831752&ST.IMEI=35881005000190


And several lines like this:
2014-10-31 06:53:54.662 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://otablv-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260902527165,
2014-10-31 06:53:54.773 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://otablv-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260612012289,
2014-10-31 06:53:54.899 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://otablv-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260612012237,
2014-10-31 06:53:54.972 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://otablv-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260112633332,


The thing is for the same IMSI I can have more than one pair of Incoming line and Successfully sent request line.

For example for this one I have only a pair, so this would be taking in consideration for the script to count the time between the lines:
2014-10-31 06:53:22.501 [83] Debug      HttpReceiverServlet            Incoming request url : http://otablv-priv-nfcmh-vip:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260112633332&ST.IMEI=35881005000914

2014-10-31 06:53:54.972 [36] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://otablv-snq-opm-vip:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260112633332,

====

But for example on this case:

2014-11-06 12:54:33.481 [46] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260130369278&ST.IMEI=01262600179856
2014-11-06 12:59:05.874 [52] Debug      HttpReceiverServlet            Incoming request url : http://XXXXXX-nmnet-nfce:7900/httpeventadapter/SP_ADD/httpAdapter/ST.TERMINAL_SWITCH query string ST.IMSI=310260130369278&ST.IMEI=01262600179888

2014-11-06 13:04:43.950 [232] Flow       DbSender                       Successfully sent request RequestHolder [Notification name=TerminalSwitch_Post, URL=http://XXXXXX-priv-opm:9010/opm/sg/notification,  Method=GET, ContentType=application/x-www-form-urlencoded, Url parameters=SG.IMSI=310260130369278,

All these lines would be ignored by the script (not taken in consideration for the final count in the output)

===

So I think this would require a check to see if the IMSI only appear in one pair (to be used) or in several (to be ignored)...

NOTE that the IMSI appear in other lines that are to be ignored... so a grep on a IMSI can have more lines that are not in use for this script as well... like:
2014-10-31 06:53:22.846 [100] Trace      SubscriptionDetectionChunk     Subscription detection for subscription id 12065088, msisdn 18588919955, imsi 089310260902669658, imei 35881005000916, iccid null. Result: 15


Tks,
jaoo
0
 

Author Comment

by:joaotelles
ID: 40432382
Hi Ozo,

Pls le me know if the description was good or need more detail...

Tks in advance.
Joao
0
 

Author Closing Comment

by:joaotelles
ID: 40549063
Tks
0

Featured Post

What Is Threat Intelligence?

Threat intelligence is often discussed, but rarely understood. Starting with a precise definition, along with clear business goals, is essential.

Join & Write a Comment

The following is a collection of cases for strange behaviour when using advanced techniques in DOS batch files. You should have some basic experience in batch "programming", as I'm assuming some knowledge and not further explain the basics. For some…
There are many situations when we need to display the data in sorted order. For example: Student details by name or by rank or by total marks etc. If you are working on data driven based projects then you will use sorting techniques very frequently.…
Learn several ways to interact with files and get file information from the bash shell. ls lists the contents of a directory: Using the -a flag displays hidden files: Using the -l flag formats the output in a long list: The file command gives us mor…
Explain concepts important to validation of email addresses with regular expressions. Applies to most languages/tools that uses regular expressions. Consider email address RFCs: Look at HTML5 form input element (with type=email) regex pattern: T…

760 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question

Need Help in Real-Time?

Connect with top rated Experts

16 Experts available now in Live!

Get 1:1 Help Now