Question

Parse the log file to calculate the average time

Asked by: wesly_chen

Hi,

   I have a log file and I do
grep "doMatch\(\)" info.log | tail -5
with the output like
Case 1:
===================
2008-10-29 17:52:28,606 [INFO ] AM_thread -- END doMatch()
2008-10-29 17:56:28,288 [INFO ] AM_thread -- START doMatch()
2008-10-29 17:59:39,496 [INFO ] AM_thread -- END doMatch()
2008-10-29 18:03:39,582 [INFO ] AM_thread -- START doMatch()
2008-10-29 18:06:57,863 [INFO ] AM_thread -- END doMatch()
====================
or
Case 2:
----------
2008-10-29 17:59:39,496 [INFO ] AM_thread -- END doMatch()
2008-10-29 18:03:39,582 [INFO ] AM_thread -- START doMatch()
2008-10-29 18:06:57,863 [INFO ] AM_thread -- END doMatch()
========================
   I want to extract out the event start and end time and calculate the average time span for the event.
In case 1, there are two events,
 Event1 started at 2008-10-29 17:56:28,288 and ended at 2008-10-29 17:59:39,496. So this event spends 191.208 seconds.
 Event 2 started at 2008-10-29 18:03:39,582 and ended at 2008-10-29 18:06:57,863. So event 2 spends 198.281 seconds.

  For average of two events, it is ( 191.208 + 198.281 ) / 2 = 194.745 seconds

In case 2, there are one event,
 This event started at 2008-10-29 18:03:39,582 and ended at 2008-10-29 18:06:57,863. So event 2 spends 198.281 seconds.
 So the average time is  198.281 seconds

  I need the help to write a script to parse the log files and and calculate the average time in case 1 or case 2.
This script will
1. parse the output from "grep "doMatch\(\)" info.log | tail -5" and
  if there are 4 or 5 lines from the output, then calculate the average time with two events, (between START - END)
  if there are 3 or 2 lines from the output, then calculate the time difference between START - END
  if there are less than 2 lines, error out with message "There are less than two timestamp to calculate the average time"
2. convert those timestamp into ms format and calculate the difference and average time.
3. Print out the result.

The output of this script will sho
1. The end time of the last event, in this example, it is 2008-10-29 18:06:57,863
2. The average time, 194.745 (or 198.281) seconds in my example.
such as
-----------
Time calculated : 2008-10-29 18:06:57,863
Average time    : 194.745 seconds
-----------

    The challenge part is converting the time format (2008-10-29 18:06:57,863) into ms format then do the calculation.

    It is really appreciated that some experts can help me out on this.

This Question has been solved and asker verified All Experts Exchange premium technology solutions are available to subscription members.

Subscribe now for full access to Experts Exchange and get

Instant Access to this Solution

  • Plus...
  • 30 Day FREE access, no risk, no obligation
  • Collaborate with the world's top tech experts
  • Unlimited access to our exclusive solution database
  • Never be left without tech help again

Subscribe Now

Asked On
2008-10-29 at 11:53:05ID23859238
Tags

Perl

Topics

Perl Programming Language

,

Shell Scripting

Participating Experts
1
Points
500
Comments
7

Trusted by hundreds of thousands everyday for fast, accurate and reliable tech support.

  • "The time we save is the biggest benefit of Experts Exchange to Warner Bros. What could take multiple guys 2 hours or more each to find is accessed in around 15 minutes on Experts Exchange." Mike Kapnisakis, Warner Bros.
  • "Our team likes having a resource that is more secure than just using Google and most experts using this service really know their stuff. It's nice to look here first versus using Google." Dayna Sellner, Lockheed Martin
  • "Anytime that I've been stumped with a problem, 9 out of 10 times Experts Exchange has either the accepted solution or an open discussion of the potential solution to the problem." Kenny Red, eBay Inc.

See what Experts Exchange can do for you.

Got a question?

We've got the answer.

Experts Exchange has been collecting answers to technology questions since 1996…3 million and counting! If you have a question, chances are we already have your answer.

Screenshot of Experts Exchange Knowledgebase

Need individual assistance?

Our experts are ready to help.

If you can't find the exact answer you're looking for, ask our exclusive community of 50,000 experts. You’ll get a personalized answer from a trusted professional.

Screenshot of Experts Exchange Knowledgebase

Want to learn from the best?

Read articles from industry experts.

Thousands of free tech tips, tricks, how-to’s and tutorials are available in our peer reviewed articles section. See for yourself how smart our experts are, no login required.

Screenshot of an Article

Working on a long term project?

Store your work and research.

Save solutions to your questions, answers you’ve discovered through searching plus helpful articles in your personal knowledgebase for easy future access.

Screenshot of Experts Exchange Knowledgebase

Access the answers to your technology questions today.

Subscribe Now

30-day free trial. Register in 60 seconds.

What Makes Experts Exchange Unique?

Members of the expert community talk about why the experience at Experts Exchange is different than what you will find anywhere else.

Trusted by the world's most respected brands.

image of each brand's logo

Faithfully serving IT professionals since 1996.

Experts Exchange Logo

Try it out and discover for yourself.

Subscribe Now

30-day free trial. Register in 60 seconds.

Related Solutions

  1. par file
    Waht is a file with .par used for and what does this extension mean? Can I list the parameters for import in a .par file and use this file in imp, like imp file=filename.par Please suggest.
  2. par io err laserjet 4 plus
    Every time I start my computer my old laserjet 4 plus comes up with an error message on the control panel "err par io" the work around is to cycle power on the printer after the computer is loaded. This problem started when I got a new computer. I have tried chan...
  3. PAR Protocol
    How has the PAR Protocol been extended for use in the Internet?
  4. Converting from PERL to Executable using PAR
    I have a PERL script that begins with the following: use Win32::OLE qw(in with); use Win32::OLE::Const 'Microsoft Excel'; When I convert my PERL script to an executable using pp -o file.exe file.pl, there is no problem. But, when I run file.exe I receive the following pop-...
  5. What does the /par in a .bat file mean?
    I am learning to do batch files, and came across this /par in my .bat file. I dont know really how it got there, as I was just manually creating the batch. I did just install easy batch creator, but I didnt use that prog. Anyway here is the code that I have in my batch, but ...
  6. tail, grep, and logger
    Hi, When I do the following in bash shell, it works well. [root@lwlx root]# tail -f -n 1 /u/email.log | logger But, when I integrate the grep command, it stops working and not producing any output. [root@lwlx root]# tail -f -n 1 /u/email.log | grep Blocked | logger Any po...

Free Tech Articles

  1. WARNING: 5 Reasons why you should NEVER fix a computer for free.
    It is in our nature to love the puzzle. We are obsessed. The lot of us. We love puzzles. We love the challenge. We thrive on finding the answer. We hate disarray. It bothers us deep in our soul. W...
  2. SCCM OSD Basic troubleshooting
    SCCM 2007 OSD is a fantastic way to deploy operating systems, however, like most things SCCM issues can sometimes be difficult to resolve due to the sheer volume of logs to sift through and the dispe...
  3. Migrate Small Business Server 2003 to Exchange 2010 and Windows 2008 R2
    This guide is intended to provide step by step instructions on how to migrate from Small Business Server 2003 to Windows 2008 R2 with Exchange 2010. For this migration to work you will need the fo...
  4. Create a Win7 Gadget
    This article shows you how to create a simple "Gadget" -- a sort of mini-application supported by Windows 7 and Vista. Gadgets can be dropped anywhere on the desktop to provide instant information, ...
  5. Outlook continually prompting for username and password
    There have been a lot of questions recently regarding Outlook prompting for a username and password whilst using Exchange 2007. There are a few reasons why this would happen and I will try to cover t...
  6. Backup Exchange 2010 Information Store using Windows Backup
    There seems to be quite a lot of confusion around the ability to backup Exchange 2010 using the built in Windows Backup feature. This stems from the omission of this feature prior to Exchange 2007 s...

Cloud Class Webinars

  1. Avoiding Bugs in Microsoft Access
    Alison Balter takes and in-depth look at avoiding bugs in Access. In this webinar you will learn about using the immediate window to debug your applications, invoking the debugger, using breakpoints to troubleshoot, stepping through code, setting the next statement to execute, ...
  2. Top 10 Best New Features in Visio 2010
    Scott Helmers gives live demonstrations of the top 10 new features in Visio 2010. This webinar will teach you how to create compelling diagrams by adding shapes to the page with a single click, linking the shapes in a diagram to data in Excel (or SQL Server, or SharePoint), ...
  3. IT Consultant Business Secrets Revealed
    Michael Munger, Experts Exchange tech pro and IT consultant, pulls back the curtain on his very successful businesses and answers question on every IT consultant and business owner should know about. He shares secrets on what he did to solve the 5 most common problems in IT, ...
  4. Disaster Recovery and Business Continuity
    Quest CTO, Mike Billon, gives an overview of the steps involved in building a dunamic disaster recovery plan. Through case studies and an examination of software/hardware tooles for monitoring and testing, you'll gain a better understandin of where you are, where you want ...
  5. Organize Your Visio Diagrams with Containers and Lists
    Scott Helmers uses cross functional flowcharts, wireframe diagrams, data graphic legends and seating charts to teach you: how to ustilize all three new structured diagram components in Visio 2010, the best practices for organizeing shapes in previous version of Visio, how to organize ...
  6. How to Us Objects, Properties, Events and Methods in Microsoft Access
    Alison Dalter gives an in-depbth look at objects, properties, events and methods in Microsoft Access. In this webinar you will learn about using the object browser, referring to objects, working with properties and methods, working with object variables, understanding the ...

Join the Community

Give a Little. Get a Lot.

Join the community of experts here and help other tech pros by answering question in your area of expertise. You can earn FREE access to all Experts Exchange's premium features and resources.

Join the Community

Answers

 

by: Adam314Posted on 2008-10-29 at 12:17:36ID: 22834583

#!/usr/bin/perl
use strict;
use warnings;
use Time::Local;
 
my @pairs;
my $last;
while(<>) {
	next unless /((\d{4})-(\d{2})-(\d{2})\s+(\d{2}):(\d{2}):(\d{2}),(\d+)).*(START|END)/;
	$last = $1;
	my $tl = timelocal($7,$6,$5, $4,$3-1,$2-1900) + $8/1000;
	my $se = $9;
	next if (($se eq 'END') and ($#pairs<0 or $#{$pairs[-1]}==1));
	if($se eq 'END') {
		push @{$pairs[-1]}, $tl;
	}
	else {
		push @pairs, [$tl];
	}
}
 
my ($sum, $count);
$sum+=$_->[1] - $_->[0], $count++ foreach (@pairs);
my $average = $sum/$count;
 
print "Time calculated : $last\n";
printf "Average time    : %.3f seconds\n", $average;
                                              
1:
2:
3:
4:
5:
6:
7:
8:
9:
10:
11:
12:
13:
14:
15:
16:
17:
18:
19:
20:
21:
22:
23:
24:
25:
26:
27:

Select allOpen in new window

 

by: wesly_chenPosted on 2008-10-29 at 12:34:28ID: 22834740

Thanks Adam314 for the script.

With the input
-----------
2008-10-29 19:10:40,017 [INFO ] AM_thread -- START doMatch()
2008-10-29 19:14:12,467 [INFO ] AM_thread -- END doMatch()
2008-10-29 19:18:13,016 [INFO ] AM_thread -- START doMatch()
2008-10-29 19:21:34,862 [INFO ] AM_thread -- END doMatch()
2008-10-29 19:25:33,930 [INFO ] AM_thread -- START doMatch()
----------

You script fails with the following error messages:
-------------
Use of uninitialized value in subtraction (-) at /home/om/scripts/t_avg.pl line 23, <> line 5.
Time calculated : 2008-10-29 19:25:33,930
Average time    : -408435973.211 seconds
-------------

 

by: Adam314Posted on 2008-10-29 at 16:07:21ID: 22836732

With 5 lines, I expected it to always begin with END.  Here is an update that will work with your data.

...
my ($sum, $count);
foreach (@pairs) {
	next unless ($_->[0] and $_->[1]);
	$sum+=$_->[1] - $_->[0], $count++ 
}
my $average = $sum/$count;
...
                                              
1:
2:
3:
4:
5:
6:
7:
8:

Select allOpen in new window

 

by: wesly_chenPosted on 2008-10-29 at 17:09:43ID: 22837004

Thanks for the update.

One of criteria doesn't match is
-----
  if there are less than 2 lines, error out with message "There are less than two timestamp to calculate the average time"
-----
So if the output of "grep "doMatch\(\)" info.log | tail -5" have only one line or
---------
2008-10-29 17:52:28,606 [INFO ] AM_thread -- END doMatch()
2008-10-29 17:56:28,288 [INFO ] AM_thread -- START doMatch()
-----------
Then the script should print out error messages.

Now I got the following error message for 1 line input:
---------
Use of uninitialized value in division (/) at /home/om/scripts/match_avg.pl line 27, <> line 1.
Use of uninitialized value in division (/) at /home/om/scripts/match_avg.pl line 27, <> line 1.
Illegal division by zero at /home/om/scripts/match_avg.pl line 27, <> line 1.

 

by: Adam314Posted on 2008-10-29 at 18:50:12ID: 22837518

forgot about that part... here is an updated version again

#!/usr/bin/perl
use strict;
use warnings;
use Time::Local;
 
my @pairs;
my $last;
while(<>) {
        next unless /((\d{4})-(\d{2})-(\d{2})\s+(\d{2}):(\d{2}):(\d{2}),(\d+)).*(START|END)/;
        $last = $1;
        my $tl = timelocal($7,$6,$5, $4,$3-1,$2-1900) + $8/1000;
        my $se = $9;
        next if (($se eq 'END') and ($#pairs<0 or $#{$pairs[-1]}==1));
        if($se eq 'END') {
                push @{$pairs[-1]}, $tl;
        }
        else {
                push @pairs, [$tl];
        }
}
my ($sum, $count);
foreach (@pairs) {
        next unless ($_->[0] and $_->[1]);
        $sum+=$_->[1] - $_->[0], $count++ 
}
if(!$count) {
	print "There are less than two timestamp to calculate the average time\n";
}
else {
	my $average = $sum/$count;
	
	print "Time calculated : $last\n";
	printf "Average time    : %.3f seconds\n", $average;
}
                                              
1:
2:
3:
4:
5:
6:
7:
8:
9:
10:
11:
12:
13:
14:
15:
16:
17:
18:
19:
20:
21:
22:
23:
24:
25:
26:
27:
28:
29:
30:
31:
32:
33:
34:

Select allOpen in new window

 

by: wesly_chenPosted on 2008-10-29 at 20:04:54ID: 22837738

Thanks a lot.
Could you give me some explanation about your scripts?

 

by: Adam314Posted on 2008-10-29 at 20:28:44ID: 22837844

#!/usr/bin/perl
use strict;       #Require variable declarations
use warnings;     #warn about possible bugs
use Time::Local;  #include this module (converts sec,min,hour,month day,month,year into unix time)
 
my @pairs;
my $last;
while(<>) {  #while there is a line to read
        Look for pattern yyyy-mm-dd hh:mm:ss.hhh, skip line if it doesn't match
        next unless /((\d{4})-(\d{2})-(\d{2})\s+(\d{2}):(\d{2}):(\d{2}),(\d+)).*(START|END)/;
        $last = $1;  #save time to variable $last
        my $tl = timelocal($7,$6,$5, $4,$3-1,$2-1900) + $8/1000;  #save local time in unix format
        my $se = $9;  #save start/end in variable $se
        #skip this line if it is an END and there was no START
        next if (($se eq 'END') and ($#pairs<0 or $#{$pairs[-1]}==1));  
        if($se eq 'END') {
                #If an END, save with matching START
                push @{$pairs[-1]}, $tl;
        }
        else {
                #If a START, save a new entry
                push @pairs, [$tl];
        }
}
my ($sum, $count);
foreach (@pairs) {  #Loop through all START/END pairs
        #Skip unless there is a START and END
        next unless ($_->[0] and $_->[1]);
        $sum+=$_->[1] - $_->[0], $count++; #add this difference to $sum and $count
}
if(!$count) {  #if no pairs, display error
        print "There are less than two timestamp to calculate the average time\n";
}
else { #otherwise, display results
        my $average = $sum/$count;
        
        print "Time calculated : $last\n";
        printf "Average time    : %.3f seconds\n", $average;
}

                                              
1:
2:
3:
4:
5:
6:
7:
8:
9:
10:
11:
12:
13:
14:
15:
16:
17:
18:
19:
20:
21:
22:
23:
24:
25:
26:
27:
28:
29:
30:
31:
32:
33:
34:
35:
36:
37:
38:
39:

Select allOpen in new window

20120131-EE-VQP-002

3 Ways to Join

30-Day Free Trial

The Experts

98% positive feedback on 31,087 answers since March 2000. angeliii is a Microsoft Most Valuable Professional for his work with MS SQL Server & Develoment.

He has also proven his knowledge of Visual Basic Programming, PHP Scripting and Oracle Databases.

The Experts

97% positive feedback on 10,752 answers since July 2000. lrmoore has more than 18 years experience in the networking industry.

The six-time Mircosoft MVPs specialties include firewalls, virtual private networking, and network management.

Testimonials

"...and excellent source for support... Kind of like having your very own IT dept." Electriciansnet

Testimonials

"I was apprehensive at signing up at first. However... it has already made my life as an IT administrator much easier." JaCrews

Testimonials

"WOW! You guys have great, active, and knowledgeable people on here." moore50

Business Clients

Business Clients

In the Press

"If you’ve got a question... Experts Exchange can supply an answer.”

In the Press

"...an invaluable aid for both IT professionals and those who require tech support."

In the Press

"where IT professionals provide quick answers on just about any topic"

Business Account Plans

Loading Advertisement...