# DBalert.def: Analyzes alert.log
# $Id: DBalert.def,v 1.12 2009/01/14 11:53:24 ldens Exp $
# ARCS: $Header: /u02/webapps/workbench/cvs/RDA_4/src/scripting/lib/modules/DBalert.def,v 1.12 2009/01/14 11:53:24 ldens Exp $
#
# Change History
# 20090114  LDE  Change the copyright notice.

=head1 NAME

DBalert - Analyzes alert.log

=head1 DESCRIPTION

This module analyzes the alert.log file and produces an analysis summary. Times
are truncated at the second level.

=cut

# Make the module persistent and share macros
keep $KEEP_BLOCK,@SHARE_MACROS
var @SHARE_MACROS = ('analyze_alert')

# Macros to format or decode a time stamp
macro fmt_time
 return replace(localtime('%d-%b-%Y %H:%M:%S',$arg[0]),' ',' ',true)

macro log_tsp
{var (undef,$mon,$day,$hur,$min,$sec,$yer) = split('\s+|:',$arg[0])
 return concat('TSP=',mktime($sec,$min,$hur,$day,$mon,$yer))
}

macro xml_tsp
{var ($yer,$mon,$day,$hur,$min,$sec) = \
   match($arg[0],'^(\d{4})-(\d+)-(\d+)T(\d+):(\d+):(\d+)')
 decr $mon
 return concat('TSP=',mktime($sec,$min,$hur,$day,$mon,$yer))
}

# Macro for reading the alert.log
macro analyze_alert
{var ($fil,$xml) = @arg
 var %sta = ('fil',$fil)
 var (@cmd,@err,@swt,@trc,%err) = ()

 debug ' Inside DBalert module, analyzing the alert.log data (can take time)'
 if createBuffer('ALS','R',$fil)
 {# Define parsing macros
  macro parse_cmd
  {var (\%sta,\@cmd,$lin,$tim) = @arg
   var @cmd = (@cmd,concat(fmt_time(value($tim)),'|',$lin))
   return -1
  }

  macro parse_cnt
  {var (\%sta,$key) = @arg
   incr $sta{$key}
   return -1
  }

  macro parse_err
  {var (\%sta,\@err,\%err,$lin,$tim) = @arg
   if !$sta{'err'}
   {var $sta{'err'} = true
    var @err = (@err,$tim)
   }
   var @err = (@err,$lin)
   if match($lin,'^((ORA|PLS)-\d+)')
   {var ($err) = (last)
    incr $err{$err}
   }
   return -1
  }

  macro parse_str
  {var (\%sta,\@err,\@trc,$tim) = @arg
   incr $sta{'str'}
   # Add the event in the error summary
   if !$sta{'err'}
   {var $sta{'err'} = true
    var @err = (@err,$tim)
   }
   var @err = (@err,'Instance was restarted')
   # Add the event in the trace summary
   if !$sta{'trc'}
   {var $sta{'trc'} = true
    var @trc = (@trc,$tim)
   }
   var @trc = (@trc,'Instance was restarted')
   return -1
  }

  macro parse_swt
  {var (\%sta,\@swt,$lin,$tim) = @arg
   incr $sta{'swt'}
   var @swt = (@swt,$tim)
   return -1
  }

  macro parse_trc
  {var (\%sta,\@trc,$lin,$tim) = @arg
   if !$sta{'trc'}
   {var $sta{'trc'} = true
    var @trc = (@trc,$tim)
   }
   var @trc = (@trc,$lin)
   return -1
  }

  macro parse_log_tsp
  {var (\%sta,$tim) = @arg
   var $sta{'beg'} = nvl($sta{'beg'},$tim)
   var $sta{'cur'} = $tim
   var $sta{'end'} = $tim
   var $sta{'err'} = false
   var $sta{'trc'} = false
   return -1
  }

  macro parse_xml_tsp
  {var (\%sta,$lin) = @arg
   var ($tim) = match($lin,"<msg time='([^']+)'")
   var $sta{'beg'} = nvl($sta{'beg'},$tim)
   var $sta{'cur'} = $tim
   var $sta{'end'} = $tim
   var $sta{'err'} = false
   var $sta{'trc'} = false
   return -1
  }

  # Parse the alert.log
  call parseReset()
  call parseVar($lin)
  if $xml
  {call parsePattern('TOP','<msg time=',parse_xml_tsp(\%sta,$lin))
   call parseBegin('TOP','^\s*<txt>','TXT')
   call parseInfo('TXT','beg',parseReplace(replace($lin,'^\s*<txt>')))
   call parseInfo('TXT','flp',true)
   call parsePattern('TXT',\
     'Starting ORACLE instance',\
       parse_str(\%sta,\@err,\@trc,xml_tsp($sta{'cur'})),\
     '^Thread .* advanced to log sequence',\
       parse_swt(\%sta,\@swt,$lin,xml_tsp($sta{'cur'})),\
     '^Checkpoint not complete',\
       parse_cnt(\%sta,'chk'),\
     '^Thread .* cannot allocate new log',\
       parse_cnt(\%sta,'non'),\
     '^ALTER SYSTEM',\
       parse_cmd(\%sta,\@cmd,$lin,xml_tsp($sta{'cur'})),\
     '^(ORA-|PLS-|SVR4 Error:|Additional information:|Linux Error:|\
        IBM AIX RISC System\/6000 Error:|O\/S-Error:|OSD-)',\
       parse_err(\%sta,\@err,\%err,$lin,xml_tsp($sta{'cur'})),\
     '^(Errors in file|Details in trace file)',\
       parse_trc(\%sta,\@trc,$lin,xml_tsp($sta{'cur'})))
   call parseEnd('TXT','^\s*</txt>')
  }
  else
   call parsePattern('TOP',\
     '^(Mon|Tue|Wed|Thu|Fri|Sat|Sun)\b',\
       parse_log_tsp(\%sta,$lin),\
     'Starting ORACLE instance',\
       parse_str(\%sta,\@err,\@trc,log_tsp($sta{'cur'})),\
     '^Thread .* advanced to log sequence',\
       parse_swt(\%sta,\@swt,$lin,log_tsp($sta{'cur'})),\
     '^Checkpoint not complete',\
       parse_cnt(\%sta,'chk'),\
     '^Thread .* cannot allocate new log',\
       parse_cnt(\%sta,'non'),\
     '^ALTER SYSTEM',\
       parse_cmd(\%sta,\@cmd,$lin,log_tsp($sta{'cur'})),\
     '^(ORA-|PLS-|SVR4 Error:|Additional information:|Linux Error:|\
        IBM AIX RISC System\/6000 Error:|O\/S-Error:|OSD-)',\
       parse_err(\%sta,\@err,\%err,$lin,log_tsp($sta{'cur'})),\
     '^(Errors in file|Details in trace file)',\
       parse_trc(\%sta,\@trc,$lin,log_tsp($sta{'cur'})))
  call parse('ALS')
  var $sta{'lin'} = inputLine('ALS')

  # Report the analysis
  call write_alert_summary(\%sta,\%err,\@cmd,\@err,\@swt,\@trc,$xml)
 }
}

# Macro for writing the alert.log summary
macro write_alert_summary
{var (\%sta,\%err,\@cmd,\@err,\@swt,\@trc,$xml) = @arg
 import $TOP,$TOC

 # Define a macro to report events, while merging duplicates
 macro write_nodup
 {# Define a macro to report an event
  macro write_event
  {var ($beg,$end,$cnt,$evt) = @arg
   if $cnt
   {incr $cnt
    write '|',fmt_time(value($beg)),' |',\
              fmt_time(value($end)),' | ',$cnt,'|',$evt,' |'
   }
   else
    write '|',fmt_time(value($beg)),' |||',$evt,' |'
  }

  # Merge duplicates
  var ($cnt,$old,$new) = (0)
  loop $lin (@arg,'TSP=')
  {if match($lin,'^TSP=') # Compare event list
   {if compare('eq',$new,$old)
    {incr $cnt
     var ($end,$new) = ($lst)
    }
    else
    {if $old
      call write_event($beg,$end,$cnt,$old)
     var ($old,$beg,$cnt,$new) = ($new,$lst,0)
    }
    var $lst = $lin
   }
   else # Add to the new list until a time stamp is found
    var $new = join('%BR%',$new,$lin)
  }

  # Treat the remaining occurrences
  if $old
   call write_event($beg,$end,$cnt,$old)
 }

 # Define a macro to report the last 10 shortest redo log switches
 macro write_redo
 {var ($beg,@tbl) = @arg
  var ($cnt,$max,$nul,@tb_nul,%tb_dur,%tb_rec) = (10)
  import $TOP

  # Get the begin time
  var $beg = value($beg)

  loop $cur (@tbl)
  {# Determine the redo log switch time interval
   var $end = value($cur)
   var $dur = difftime($end,$beg)

   # Treat the switch
   if $dur
   {# Keep the 10 shortest ones
    if $cnt
    {decr $cnt
     var $key = localtime('%Y%m%d%H%M%S',$end)
     var $tb_dur{$key} = $dur
     var $tb_rec{$key} = join('|',$end,$beg,$dur)
     var $max = max($dur,$max)
    }
    elsif expr('<=',$dur,$max)
    {var ($del,$lst) = keys(%tb_dur,'ND')
     delete $tb_dur{$del},$tb_rec{$del}
     var $key = localtime('%Y%m%d%H%M%S',$end)
     var $tb_dur{$key} = $dur
     var $tb_rec{$key} = join('|',$end,$beg,$dur)
     var $max = max($dur,$tb_dur{$lst})
    }

    # Keep the switch time
    var $beg = $end
   }
   else
   {# Store time stamps of null duration
    if !compare('eq',$nul,$end)
     var ($nul,@tb_nul) = ($end,@tb_nul,fmt_time($end))
   }
  }

  # Report the shortest durations
  loop $tim (keys(%tb_dur,'NA'))
  {var ($beg,$end,$dur) = split('\|',$tb_rec{$tim})
   write '|',fmt_time($end),' |',fmt_time($beg),' | ',$dur,'|'
  }

  # Report null durations
  if $nul
  {if hasOutput(true)
    write $TOP
   write '---+ Times for Redo Log Switches of 0 Seconds'
   write '%COL5%',join('%BR%',@tb_nul),'%ENDCOL%'
  }
 }

 debug ' Inside DBalert module, reporting alert.log analysis results'
 write '---+!! Alert.log Analysis'
 write '---## For ',$sta{'fil'}
 write $TOC

 if $xml
  var ($beg,$end) = (xml_tsp($sta{'beg'}),xml_tsp($sta{'end'}))
 else
  var ($beg,$end) = (log_tsp($sta{'beg'}),log_tsp($sta{'end'}))
 write '---+ Processing Totals'
 write '|*Total alert.log records(lines) read*| ',nvl($sta{'lin'},0),'|'
 write '|*Start time*|',fmt_time(value($beg)),' |'
 write '|*End time*|',fmt_time(value($end)),' |'
 write '|*Total instance startups encountered*| ',nvl($sta{'str'},0),'|'
 write '|*Total log switches found*| ',nvl($sta{'swt'},0),'|'
 write '|*Total ``Checkpoint not complete`` messages found*| ',\
       nvl($sta{'chk'},0),'|'
 write '|*Total ``Cannot allocate new log`` messages found*| ',\
       nvl($sta{'non'},0),'|'
 write $TOP

 if @swt
 {prefix
  {write '---+ 10 Shortest Redo Log Switch Times'
   write '|*Event Time Stamp*|* Previous Event Time Stamp*| \
           *Duration(seconds)*|'
  }
  call write_redo(@swt)
  if hasOutput(true)
   write $TOP
 }

 prefix
 {write '---+ Alter System Commands'
  write '|*Time Stamp*|*Command*|'
 }
 loop $lin (@cmd)
  write '|',$lin,'|'
 if hasOutput(true)
  write $TOP

 prefix
 {write '---+ Counts by Error'
  write '|*Error*| *Count*|*Error*| *Count*|*Error*| *Count*|'
 }
 var @tbl = keys(%err)
 while scalar(@tbl)
 {var ($key1,$key2,$key3,@tbl) = @tbl
  write '|',$key1,' | ',\
            $err{$key1},'|',\
            $key2,' | ',\
            $err{$key2},'|',\
            $key3,' | ',\
            $err{$key3},'|'
 }
 if hasOutput(true)
  write $TOP

 prefix
 {write '---+ Error Summary'
  write '|*First Occurrence*|*Last Occurrence*|*Count*|*Event*|'
 }
 call write_nodup(@err)
 if hasOutput(true)
  write $TOP

 prefix
 {write '---+ Trace Summary'
  write '|*First Occurrence*|*Last Occurrence*|*Count*|*Event*|'
 }
 call write_nodup(@trc)
 if hasOutput(true)
  write $TOP
}

=begin credits

=over 10

=item RDA 4.8:  Jeff Gregory, Anatoli Karol, Michel Villette.

=back

=end credits

=head1 COPYRIGHT NOTICE

Copyright (c) 2002-2009, Oracle. All rights reserved.

=head1 TRADEMARK NOTICE

Oracle, JD Edwards, PeopleSoft, and Siebel are registered trademarks of Oracle
Corporation and/or its affiliates. Other names may be trademarks of their
respective owners.

=cut