10046.pl

#!/usr/bin/perl
#===============================================================================
#
#         FILE:  10046_events.pl
#
#        USAGE:  ./10046_events.pl 
#
#  DESCRIPTION: Provides statistical report of 10046 wait events from
#               raw trace file.
#
#               For pre Oracle 10.2 trace files the breakdown and histogram
#               sections of the report are based on unique P1 and event
#               combinations. For tracefiles produced from 10.2 onwards
#               these sections are reported for each unique combination
#               of obj# and event.
#
#      OPTIONS:  -h -t trace_file.trc
# REQUIREMENTS:  ---
#         BUGS:  ---
#        NOTES:  ---
#       AUTHOR:  Clive Bostock (Oracle ACS)
#      COMPANY: 
#      VERSION:  1.2
#      CREATED:  17/04/2011 11:14:22
#     REVISION:  19/05/2011 Kyle Hailey (Oracle ACE) - modified parsing event names
#===============================================================================
use strict;
use warnings;
use File::Basename;
use Getopt::Std;

my @trace_file;
my @events;
my %event_records;
my %tot_sort;
my %tot_objn_sort;
my $ver = '1.2';
my $trace_file;
our $opt_t;
our $opt_h;
our $prog     = basename($0);
my $event_line;
my $event_rec;
my $aggr_rec;
my $er;
my %event_stat;
my %event_aggr;
my $event;
my $elapsed;
my $tot_ela = 0;
my $ela_ms;
my $objid;
my $objid_event;
my $pre_10_2    = 0;
my $obj_header  = 'Object Id';
my $e1    = 0;
my $e2    = 0;
my $e4    = 0;
my $e8    = 0;
my $e16   = 0;
my $e32   = 0;
my $e64   = 0;
my $e128  = 0;
my $e256  = 0;
my $e512  = 0;
my $e1024 = 0;

our $SD="\/";
our $SP=":";
our $os = $ENV{'OS'};
if ( ! $os )
  { $os = $ENV{'OSTYPE'}; }
if ( ! $os )
  {
     $os = `uname`;
     chomp $os; 
  }
if ( ! $os )
  {
     $os = 'Unknown';
  }

$SD="\\" if($os  =~ /Win/i);
$SP=";" if($os   =~ /Win/i);

getopts('ht:') or
    die "\nInvalid options specified, use $prog -h.\n$prog: Deploying chute and bailing out!!!\n";

if (defined($opt_t))
{
    $trace_file = $opt_t;
}
if (defined($opt_h))
{
    print "\nUsage:  $prog -t trace_file.trc\n\n";
    exit;
}

if (! defined($opt_t))
{
    print "\nUsage:  $prog -t trace_file.trc\n\n";
    exit;
}

open(TRACEFILE, $trace_file) || die "Failed to open trace file ($trace_file)\n";

printf "$prog: 10046 traces events analyser ver $ver\n\n";
@trace_file = <TRACEFILE>;
close(TRACEFILE);

print "*** Trace file header details ***\n\n";
foreach $event_line (@trace_file)
{
    chomp $event_line;
    if (length($event_line))
         { printf("$event_line\n"); }
    else { last; }
}
print "Trace input file : $trace_file\n";
                                       #**************************************/
                                       #* Load only the WAIT event lines     */
                                       #* into @events                       */
                                       #**************************************/
@events = grep(/WAIT/, @trace_file);
chomp @events;

foreach $event_line (@events)
{

    $event = $elapsed = $objid = $event_line;
    # $event =~ s/^.*nam='([\\:\w\s\d-]+)'.*/$1/;
    $event =~ s/^.*nam='//;
    $event =~ s/' ela=.*//;
    $elapsed  =~ s/^.*ela=[\s]*([\d]+) .*/$1/;
    if ( $pre_10_2 == 0 )
    {
        if ( $event_line !~ m/obj#/ )
        {
            print "\n\n***********************************************\n";
            print "*** Trace file format looks pre Oracle 10.2 ***\n";
            print "***********************************************\n\n";
            $pre_10_2 = 1;
        }
    }

    if ($pre_10_2 )
    {
        $objid  =~ s/^.*p1=[-\s]*([\d]+) .*/$1/;
        $obj_header = 'P1';
    }
    else
    {
        $objid  =~ s/^.*obj#=[-\s]*([\d]+) .*/$1/;
    }

    $objid_event = sprintf("%-19s: %-45s", $objid, $event);
#   printf ("%s %s %s\n", $event, $elapsed, $objid);

                                       #**************************************/
                                       #*  We maintain this (simple) hash    */
                                       #* as a method of sorting by total    */
                                       #* elapsed time per event             */
                                       #**************************************/
    if (exists $tot_sort{$event})
    {   
      $tot_sort{$event} = $tot_sort{$event} + $elapsed;
    }
    else
    {
      $tot_sort{$event} = $elapsed;
    }

                                       #**************************************/
                                       #*  Get histogram counts              */
                                       #**************************************/
    $ela_ms = $elapsed / 1000;
    $tot_ela = $tot_ela + $elapsed;
    $e1 = $e2 = $e4 = $e8 = $e16 = $e32 = $e64 = $e128  = $e256 = $e512 = $e1024 = 0;
    if ( $ela_ms < 1 )
    { $e1 = 1 }
    elsif ( $ela_ms < 2  &&  $ela_ms >= 1 )
    { $e2 = 1 }
    elsif ( $ela_ms < 4  &&  $ela_ms >= 2 )
    { $e4 = 1 }
    elsif ( $ela_ms < 8  &&  $ela_ms >= 4 )
    { $e8 = 1 }
    elsif ( $ela_ms < 16  &&  $ela_ms >= 8 )
    { $e16 = 1 }
    elsif ( $ela_ms < 32  &&  $ela_ms >= 16 )
    { $e32 = 1 }
    elsif ( $ela_ms < 64  &&  $ela_ms >= 32 )
    { $e64 = 1 }
    elsif ( $ela_ms < 128  &&  $ela_ms >= 64 )
    { $e64 = 1 }
    elsif ( $ela_ms < 256  &&  $ela_ms >= 128 )
    { $e128 = 1 }
    elsif ( $ela_ms < 512  &&  $ela_ms >= 256 )
    { $e256 = 1 }
    else
    { $e1024 = 1 };


                                       #**************************************/
                                       #*  Build an anonymous record         */
                                       #* structure containing our event     */
                                       #* data.                              */
                                       #**************************************/
    $event_rec = {OBJ_EVENT => $objid_event
               , TOT_ELA => $elapsed
               , COUNT => 1
               , E1    => $e1
               , E2    => $e2
               , E4    => $e4
               , E8    => $e8
               , E16   => $e16
               , E32   => $e32
               , E64   => $e64
               , E128  => $e128
               , E256  => $e256
               , E512  => $e512
               , E1024 => $e1024
                 };
    if ($er = $event_stat{$objid_event})
        {
            $er->{COUNT}   = $er->{COUNT} + 1;
            $er->{TOT_ELA} = $er->{TOT_ELA} + $event_rec->{TOT_ELA};
            $er->{TOT_ELA} = $er->{TOT_ELA} + 1;
            $er->{E1}      = $er->{E1}      + $event_rec->{E1};
            $er->{E2}      = $er->{E2}      + $event_rec->{E2};
            $er->{E4}      = $er->{E4}      + $event_rec->{E4};
            $er->{E8}      = $er->{E8}      + $event_rec->{E8};
            $er->{E16}     = $er->{E16}     + $event_rec->{E16};
            $er->{E32}     = $er->{E32}     + $event_rec->{E32};
            $er->{E64}     = $er->{E64}     + $event_rec->{E64};
            $er->{E128}    = $er->{E128}    + $event_rec->{E128};
            $er->{E256}    = $er->{E256}    + $event_rec->{E256};
            $er->{E512}    = $er->{E512}    + $event_rec->{E512};
            $er->{E1024}   = $er->{E1024}   + $event_rec->{E1024};
            $event_stat {$er -> {OBJ_EVENT}} = $er;
            $er->{E1} = $er->{E1} + $event_rec->{E1};
            $tot_objn_sort{$objid_event} = $tot_objn_sort{$objid_event} + $elapsed;
        }
    else
        {
            $event_stat {$event_rec -> {OBJ_EVENT}} = $event_rec;
            $tot_objn_sort{$objid_event} = $elapsed;
        }

    $aggr_rec = {EVENT => $event, TOT_ELA => $elapsed,  COUNT => 1};
    if ($er = $event_aggr{$event})
        {
            $er->{COUNT}   = $er->{COUNT} + 1;
            $er->{TOT_ELA} = $er->{TOT_ELA} + $aggr_rec->{TOT_ELA};
            $er->{TOT_ELA} = $er->{TOT_ELA} + 1;
            $event_aggr {$er -> {EVENT}} = $er;
        }
    else
        {
            $event_aggr {$aggr_rec -> {EVENT}} = $aggr_rec;
        }
}

print "\nEVENT AGGREGATES\n";
print "================\n\n";
printf ("Wait Event %s Count        Elapsed (ms)     Avg Ela (ms)  %%Total \n",' ' x 34);
printf ("~~~~~~~~~~~%s ~~~~~~~~~~~~ ~~~~~~~~~~~~     ~~~~~~~~~~~~  ~~~~~~\n",'~' x 34);
foreach $objid_event (sort {$tot_sort{$b} <=>  $tot_sort{$a} } keys %event_aggr)
{
    my $ev = $event_aggr{$objid_event};
    printf("%45s %12d %12d     %12d  %6.2f\n",$ev->{EVENT}, $ev->{COUNT}, $ev->{TOT_ELA}/1000, ($ev->{TOT_ELA}/$ev->{COUNT})/1000, ($ev->{TOT_ELA}*100/$tot_ela) );
}
printf("           %s              ~~~~~~~~~~~~                         \n",' ' x 34);
printf ("         %s Total Elapsed: %12d                                   \n",' ' x 34,$tot_ela / 1000);
print "\nEVENT AGGREGATE BREAKDOWN\n";
print "=========================\n\n";
printf ("%-9s          : Wait Event %s Count        Tot Ela (ms) %%Total Avg Ela (ms)\n",$obj_header, ' ' x 34);
printf ("~~~~~~~~~~~~~~~~~~ : ~~~~~~~~~~~%s ~~~~~~~~~~~~ ~~~~~~~~~~~~ ~~~~~~ ~~~~~~~~~~~~\n",'~' x 34);
foreach $objid_event (sort {$tot_objn_sort{$b} <=>  $tot_objn_sort{$a} } keys %event_stat)
{
    my $ev = $event_stat{$objid_event};
    printf("%57s %12d %12d  %5.2f %12d\n",$ev->{OBJ_EVENT}, $ev->{COUNT}, $ev->{TOT_ELA}/1000
                                       , $ev->{TOT_ELA}*100/$tot_ela, ($ev->{TOT_ELA}/$ev->{COUNT})/1000);
}
print "\nEVENT HISTOGRAM BREAKDOWN\n";
print "===========================\n\n";
print "This section splits the event counts into elapsed time\n";
print "buckets so that we can see if there are any suspiciousn\n";
print "or anomalous response time / frequency patterns.\n\n";
printf("%-9s          : Wait Event %s <1ms    <2ms    <4ms    <8ms    <16ms   <32ms   <64ms   <128ms  <256ms  <512ms  >=1024ms\n",$obj_header, ' ' x 34);
printf("~~~~~~~~~~~~~~~~~~ : ~~~~~~~~~~~%s ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~ ~~~~~~~~\n",'~' x 34);
foreach $objid_event (sort {$tot_objn_sort{$b} <=>  $tot_objn_sort{$a} } keys %event_stat)
{
    my $ev = $event_stat{$objid_event};
    printf("%60s ", $ev->{OBJ_EVENT});
    printf("%7s %7s %7s ", $ev->{E1},    $ev->{E2},    $ev->{E4});
    printf("%7s %7s %7s ", $ev->{E8},    $ev->{E16},   $ev->{E32});
    printf("%7s %7s %7s ", $ev->{E64},   $ev->{E128},  $ev->{E256});
    printf("%7s %8s\n", $ev->{E512},  $ev->{E1024} );
}
printf("\n\n*** End of report ***\n");

Comments