Solved

Shell - calculate time between log lines

Posted on 2014-11-06
11
157 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
[X]
Welcome to Experts Exchange

Add your voice to the tech community where 5M+ people just like you are talking about what matters.

  • Help others & share knowledge
  • Earn cash & points
  • Learn & ask questions
  • 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
Independent Software Vendors: We Want Your Opinion

We value your feedback.

Take our survey and automatically be enter to win anyone of the following:
Yeti Cooler, Amazon eGift Card, and Movie eGift Card!

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

Free Tool: Subnet Calculator

The subnet calculator helps you design networks by taking an IP address and network mask and returning information such as network, broadcast address, and host range.

One of a set of tools we're offering as a way of saying thank you for being a part of the community.

Question has a verified solution.

If you are experiencing a similar issue, please ask a related question

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…
How to remove superseded packages in windows w60 or w61 installation media (.wim) or online system to prevent unnecessary space. w60 means Windows Vista or Windows Server 2008. w61 means Windows 7 or Windows Server 2008 R2. There are various …
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…

724 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