Pls help optomize - ksh version 60% faster!

[coreolyn]

Esteemed Monkages,

Sometimes a saint must expose what a novice they still are. This is running in 5.8 and CPAN is not an option. I can't believe this is 60% slower than a ksh script that does the same thing. Obviously I'm doing some thing in a painful fashion but I'm not seeing it. (I try to code for legibility so that whoever gets stuck supporting my scripts can make some heads or tails out of them.)

The purpose of the script is to read through a huge log file daily ( 44mb ) and report the counts of various triggers maintained in a separate ini file. The format of the ini file is

AppDescriptionCode~String to be matched.

#! /usr/local/bin/perl
use warnings;
use strict;

########################## Execution Setup ###########################
+###########
use Cwd;
# Local Modules

######################################################################
+###########
# File: $PWD/gcenrollrpt                                              
+          #
# Purpose: Retrieve logs creates a daily report of various gc statisti
+cs        #
# Usage:   gcenrollrpt  date YYYY-MM-DD                               
+          #
# Notes:                                                              
+          #
######################################################################
+###########
system("date");

# Command Line Syntax Checking 
if ( (! $ARGV[0] ) ) {
   print "\nUSAGE: $0 <date>\n";
   exit 1;
}

# set primary vars
my ( $today, $date, $host, @banks ); 
$today = `date +%Y-%m-%d`;
chomp($today);
$date = $ARGV[0];
chomp($ARGV[0]);
$host = `uname -n`;
chomp($host);
@banks = qw[ 321 920 144 ];

# Read in statements to be searched for in log from ini file
my (@entries, $iniFile);
$iniFile = "$ENV{'PWD'}/gcenrollrpt.ini";
open(INIFILE, $iniFile) or die "Can't open $iniFile $!\n";
while ( <INIFILE> )
{
   push(@entries, $_ );
} 

# Determine which log to read
my ($logfile, @logfile, $archive, $rmfile); 
$rmfile=0;
$archive = "/log_archive/GC/$host/GC/logs/GC.log.$date.gz";
if ( -e "/GC/logs/GC.log.$date" )
{
   $logfile = "/GC/logs/GC.log.$date";
}
elsif ( -e $archive )
{
   system("gzcat $archive >  /GC/logs/GC.log.$date" );
   $logfile = "/GC/logs/GC.log.$date";
   $rmfile = 1;
}
else 
{
   $logfile = "/GC/logs/GC.log";
}

# Parse the log
my ($rptType, %counts, @rptType, $logEntry );
open( LOGFILE, $logfile ) or die "Can't open file $logfile $!\n";
LOG:while ( <LOGFILE> )
{
   $logEntry = $_; 
   unless ( $logEntry =~ /^ $date/ )
   {
      next LOG;
   }
   foreach my $bank (@banks) 
   {

      # check each entry from the ini file against the log
      my ($entry, $rptType);
      ENTRY:for ( my $i=0; $i < @entries; $i++ ) 
      {

         # split the entry type from the actual verbage to be searched
+ for
         my $entryTemplate = $entries[$i]; 
         chomp($entryTemplate);
         if ( length($entryTemplate) == 0  )
         {
            next ENTRY;
         } else {
            $_ = $entryTemplate;
            /(.+)~(.+)/;
            $rptType = $1;
            $entry = $2;

            # make the search bank specific
            $entry =~ s/\$bank/$bank/g;
            if ( length($entry) == 0 || length($rptType) == 0 )
            {
               next ENTRY;
            }

            # set up counters for each type and store unique types for
+ each bank
            # serves as an index when outputting results
            my $rptTypeCount = @rptType;
            my $matchType = 0;
            if ( @rptType == 0 )
            {
               push( @rptType, $rptType);
            }
            foreach my $type ( @rptType )
            {
               if ( $type =~ /$rptType/ )
               {
                  $matchType = 1;
               }
            }
            if ( $matchType == 0 )
            {
               push ( @rptType, $rptType );
            }

            # set up the key $typeHour for the %counts var that stores
+ all the totals 
            # must be done first to set up counts for entries which th
+ere are no matches
            $_ = $logEntry;
            /\d{4}-\d{2}-\d{2}\s(\d{2}):/;
            my $hour = $1;
            my $typeHour = "$bank-$rptType-$hour";
           
            # Process Matching entries
            if ( $logEntry =~ $entry )
            {
               unless ( $counts{$typeHour} )
               {
                  $counts{$typeHour} = 1;
               } 
               else
               {
                  $counts{$typeHour} = $counts{$typeHour} + 1; 
               }
            } else {
               unless ( $counts{$typeHour} )
               {
                  $counts{$typeHour} = 0;
               }
            }
         } 
      }
   }
}
close (LOGFILE);

# Remove the log file if unzipped from the archive
if ( $rmfile == 1 )
{
   system("/usr/bin/rm -f $logfile");
}

# Create reports by bank
foreach my $bank (@banks)
{
   my $tmpFile1 = "/tmp/gcenrollrpt$bank.1.$$";
   open ( TMPFILE1, ">$tmpFile1" ) or die "Can't open $tmpFile1 $!\n";
   foreach my $type (@rptType)
   {
      for (my $i = 0; $i < 24; $i++)
      {
         foreach my $typeHour ( sort keys %counts )
         {
            my $hour;
            $_ = $typeHour;
            /(.+)-(.+)-(.+)/;
            my $bnk = $1;
            my $rptType = $2;
            my $hr = "$3:";
            if ( $i < 10 )
            {
               $hour = "0$i:";
            } else {
               $hour = "$i:";
            }
            if ( "$bank-$type-$hour" =~ /$bnk-$rptType-$hr/ )
            {
               if ( $i == 0 )
               {
                  print TMPFILE1 "\n\n$type\n";
               } else {
                  print TMPFILE1 "$hour $counts{$typeHour}\n";
               }
            }
         }
      } 
   } 
   close(TMPFILE1);
 
   # Mail the report out
   my $cmdLine = "cat $tmpFile1 | mailx -s \"OAC report for bank $bank
+ $date $host\" xxx\@xyz.com";
   system("$cmdLine");
   system("/usr/bin/rm -f $tmpFile1");
}

system("date");

0;

[ikegami]

This code is a good example of the axiom: "It's possible to write FORTRAN in any lanaguge."

There are many many cases of external processes being launched to perform tasks Perl can do natively. (date, rm, cat).

Regular expressions are incorrectly used: Special characters are not escaped when they should be, and they are recompiled needlessly. Almost everywhere in the above, index should probably be used instead of regular expressions.

I'm questioning the use of so much nesting. And on the ineffciency of doing expensive operations (such as compiling regexps and using sorts) at deep levels.

Some examples:

Read more... (2 kB)

[Skeeve]

I really can't tell what you are doing there. What I noticed is:
1. You are "split(ing) the entry type from the actual verbage to be searched for" for each and every log file entry found.
   Better is to do that once and for every ini file entry outside the loop
2. You are using some "strange constructs" like

   if (condition) {
       next LOOP;
   }
   else {
       # main part to do
   }
   

   instead of the "cleaner" solution without else.
   But I don't think this will add to the running time
3. Something I only use in java and never in perl found here: if (length($entry) == 0)why not simply: if (not $entry) or even if ($entry eq "")? But again: Not that runtime issue, i think.
I'd suggest to fix the entry preparation first.

Update: Thanks to ikegami for reminding me of 0 ;-)

[ikegami]

why not simply: if (not $entry)

Because that would also be false for "0".

if ($entry eq "")
(as you mentioned) works, and so does
if (not length $entry)
(my usual) and
unless (length $entry)

[coreolyn]

Actually I had those that way originally.. there was a $entry that passing the if. What's left was my attempts at finding that problem. I could now revert them back.

[davidrw]

Here's a version that (shouldn't) change the functionality, but cleans up some the code with "more perlish" code .. especially the regex usage (use $x =~ /foo/ instead of assigning to $_) and some of the if-else logic (most notably using grep). Diff against your original to see all the individual differences .. But hopefully this will shorten and clarify the code so it's easier for you to go from there...
Read more... (5 kB)

[Skeeve]

Question: instead of

push @rptType, $rptType unless @rptType;
push @rptType, $rptType unless grep /$rptType/, @rptType;

I would use

push @rptType, $rptType unless $seen{$rptType}++;

Don't you think this would be faster than the grep, besides the fact that (I think) a grep for $rptTyp being 'a' would match a stored $rptType of 'XaX'.

I know! The OP had that code and maybe it's exactly what the OP intended, but it "smells fishy" ;-)

[davidrw]

Yes, you're right -- the hashing would be more efficient, though @rptType is used later in the code, so need to keep %seen in addition, or the later use might be able to be keys %seen instead of @rptType (unless order matters) .. or could just always push onto @rptType and throw out dups later (see tihs idiom, but destroys order)

As for matching with /$rptType/, y, that seems suspicious .. i too now suspect that it should be eq instead, but can't say for sure..

also, looking at this again, the first of my two lines is unnecessary -- it seemed at first that the author wanted a double push onto @rptType, but that's not the case.. I've ammended my post above..

anyways, ++ and thanks for double-checking my post!!

[salva]

besides all the suggestions made by other monks, how about using a profiler?

Last week I released a new one, Devel::FastProf, that is able to tell in which lines the program spends more time.

Also, Devel::SmallProf does the same, it's slower but better tested.