Shell - calculate time between log lines

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
joaotellesAsked:
Who is Participating?

[Product update] Infrastructure Analysis Tool is now available with Business Accounts.Learn More

x
I wear a lot of hats...

"The solutions and answers provided on Experts Exchange have been extremely helpful to me over the last few years. I wear a lot of hats - Developer, Database Administrator, Help Desk, etc., so I know a lot of things but not a lot about one thing. Experts Exchange gives me answers from people who do know a lot about one thing, in a easy to use platform." -Todd S.

ozoCommented:
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
joaotellesAuthor Commented:
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.
joaotellesAuthor Commented:
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
Exploring ASP.NET Core: Fundamentals

Learn to build web apps and services, IoT apps, and mobile backends by covering the fundamentals of ASP.NET Core and  exploring the core foundations for app libraries.

ozoCommented:
What is in line 174227 of your logfile?
joaotellesAuthor Commented:
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
ozoCommented:
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;

Experts Exchange Solution brought to you by

Your issues matter to us.

Facing a tech roadblock? Get the help and guidance you need from experienced professionals who care. Ask your question anytime, anywhere, with no hassle.

Start your 7-day free trial
joaotellesAuthor Commented:
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,
ozoCommented:
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?
joaotellesAuthor Commented:
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
joaotellesAuthor Commented:
Hi Ozo,

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

Tks in advance.
Joao
joaotellesAuthor Commented:
Tks
It's more than this solution.Get answers and train to solve all your tech problems - anytime, anywhere.Try it for free Edge Out The Competitionfor your dream job with proven skills and certifications.Get started today Stand Outas the employee with proven skills.Start learning today for free Move Your Career Forwardwith certification training in the latest technologies.Start your trial today
Shell Scripting

From novice to tech pro — start learning today.