Analyse SLAPD Logs

Overview

The script now also writes out the CN/DN and filters into files for re-processing for use in the test scripts.

$ cat analyse.py 
#!/usr/bin/env python
#
#  Purpose:
#
#  $Id:$
#
#-------------------------------------------------------------------------------

"""
  Analyse SLAPD logs

  ...
"""
#-------------------------------------------------------------------------------

import os
import re
import sys
import copy
import getopt
import logging

#-------------------------------------------------------------------------------

from datetime import datetime

#-------------------------------------------------------------------------------

__version__   = "1.1.1"
__id__        = "@(#)  analyse.py  [%s]  01/05/2008"

verbose_flg   = False

debug_level   = 0

LOGFILE       = "log/analyse.log"

log           = None
pid           = None
file_name     = None

#===============================================================================

def INFO(msg):
   if log: log.info(' ' + msg)
   if verbose_flg: print "[analyse]  %s" % msg

#-------------------------------------------------------------------------------

def ERROR(msg):
   if log: log.error(msg)
   sys.stderr.write('[analyse]  %s\n' % msg)

#-------------------------------------------------------------------------------

def WARNING(msg):
   if log: log.warning('*****' + msg + '*****')
   if verbose_flg: print "[analyse]  %s" % msg

#===============================================================================

def analyse(fname):
   try:
      f = open(fname, 'r')
   except IOError, e:
      sys.stderr.write('[analyse]  Open failed: ' + str(e) + '\n')
      sys.exit(1)

   try:
      h_bind = open('d_bind.dat', 'w')
   except IOError, e:
      sys.stderr.write('[analyse]  Open failed: ' + str(e) + '\n')
      sys.exit(1)

   try:
      h_srch = open('d_srch.dat', 'w')
   except IOError, e:
      sys.stderr.write('[analyse]  Open failed: ' + str(e) + '\n')
      sys.exit(1)

   try:
      h_mod = open('d_mod.dat', 'w')
   except IOError, e:
      sys.stderr.write('[analyse]  Open failed: ' + str(e) + '\n')
      sys.exit(1)

   try:
      h_add = open('d_add.dat', 'w')
   except IOError, e:
      sys.stderr.write('[analyse]  Open failed: ' + str(e) + '\n')
      sys.exit(1)

   try:
      h_del = open('d_del.dat', 'w')
   except IOError, e:
      sys.stderr.write('[analyse]  Open failed: ' + str(e) + '\n')
      sys.exit(1)

   s_result = 'RESULT'
   p_result = re.compile(s_result)

   BIND     = 'BIND'
   UNBIND   = 'UNBIND'
   SRCH     = 'SRCH'
   MOD      = 'MOD'
   ADD      = 'ADD'
   DEL      = 'DEL'

   s_BIND   = r'BIND dn="([^"]*)" method=[0-9]*'
   p_BIND   = re.compile(s_BIND)
   s_UNBIND = r'UNBIND'
   p_UNBIND = re.compile(s_UNBIND)
   s_SRCH   = r'SRCH base="([^"]*)" scope=[0-9]* filter="([^"]*)"'
   p_SRCH   = re.compile(s_SRCH)
   s_MOD    = r'MOD dn="(.*)"'
   p_MOD    = re.compile(s_MOD)
   s_ADD    = r'ADD dn="([^"]*)"'
   p_ADD    = re.compile(s_ADD)
   s_DEL    = r'DEL dn="(.*)"'
   p_DEL    = re.compile(s_DEL)

   pat = '(......) (.*) hx73 slapd\[[0-9]*\]: conn=([0-9]*) op=([0-9]*) (.*)'

   p = re.compile(pat)

   print p

   stats =  []

   counters = {
     'SRCH'   : 0,
     'MOD'    : 0,
     'ADD'    : 0,
     'DEL'    : 0,
     'BIND'   : 0,
     'UNBIND' : 0
   }

   for i in range(24):
      stats.append(copy.deepcopy(counters))

   line_cnt = 0

   while True:
      line = f.readline()

      if not line: break

      line_cnt += 1

      line = line.strip()

      m = p_result.search(line)

      if m:
          continue

      m = p.search(line)

      if m:
         # print line
         date    = m.group(1)
         time    = m.group(2)
         (hour, min, sec) = time.split(':')

         hour    = int(hour)
         min     = int(min)
         sec     = int(sec)

         conn    = int(m.group(3))
         op      = m.group(4)
         rest    = m.group(5)

         m1 = p_BIND.search(rest)
         if m1:
            bind_dn  = m1.group(1)
            rest = 'BIND  %s' % bind_dn
            stats[hour][BIND] += 1
            h_bind.write("%s\n" % bind_dn)

         m1 = p_UNBIND.search(rest)
         if m1:
            rest = 'UNBIND'
            stats[hour][UNBIND] += 1

         m1 = p_SRCH.search(rest)
         if m1:
            base   = m1.group(1).replace(',dc=performiq,dc=com,dc=au', '')
            filter = m1.group(2)
            rest   = 'SRCH  %s  %s' % (base, filter)
            stats[hour][SRCH] += 1
            h_srch.write("%s %s\n" % (base, filter))

         m1 = p_MOD.search(rest)
         if m1:
            mod_dn  = m1.group(1)
            rest = 'MOD   %s' % mod_dn
            stats[hour][MOD] += 1
            h_mod.write("%s\n" % mod_dn)

         m1 = p_ADD.search(rest)
         if m1:
            add_dn  = m1.group(1)
            rest = 'ADD   %s' % add_dn
            stats[hour][ADD] += 1
            h_add.write("%s\n" % add_dn)

         m1 = p_DEL.search(rest)
         if m1:
            del_dn  = m1.group(1)
            rest = 'DEL   %s' % del_dn
            stats[hour][DEL] += 1
            h_del.write("%s\n" % del_dn)

         if verbose_flg: print "%s  %3d  %s" % (time, conn, rest)

   f.close()

   print "Hour   BIND  UNBIND    SRCH     MOD     ADD     DEL"
   for i in range(24):
      counters[BIND]    +=  stats[i][BIND]
      counters[UNBIND]  +=  stats[i][UNBIND]
      counters[SRCH]    +=  stats[i][SRCH]
      counters[MOD]     +=  stats[i][MOD]
      counters[ADD]     +=  stats[i][ADD]
      counters[DEL]     +=  stats[i][DEL]

      print "%02d:  %8d  %6d  %6d  %6d  %6d  %6d" % (
         i,
         stats[i][BIND],
         stats[i][UNBIND],
         stats[i][SRCH],
         stats[i][MOD],
         stats[i][ADD],
         stats[i][DEL]
      )

   total = 0
   for key in counters.keys():
      total += counters[key]

   print "Total:%7d  %6d  %6d  %6d  %6d  %6d - %8d" % (
         counters[BIND],
         counters[UNBIND],
         counters[SRCH],
         counters[MOD],
         counters[ADD],
         counters[DEL],
         total
      )

   print "%%:   %8.2f  %6.2f  %6.2f  %6.2f  %6.2f  %6.2f" % (
         (100.0 * counters[BIND]) / total,
         (100.0 * counters[UNBIND]) / total,
         (100.0 * counters[SRCH]) / total,
         (100.0 * counters[MOD]) / total,
         (100.0 * counters[ADD]) / total,
         (100.0 * counters[DEL]) / total
      )

   if debug_level > 5: INFO("Processed %d lines" % line_cnt)

   return line_cnt

#===============================================================================

def init():
   global log
   global pid

   pid = os.getpid()

   log  = logging.getLogger('xxx')
   hdlr = logging.FileHandler(LOGFILE)
   fmtr = logging.Formatter('%(asctime)s %(levelname)s %(message)s')

   hdlr.setFormatter(fmtr)
   log.addHandler(hdlr)
   log.setLevel(logging.INFO)

   INFO("Started processing")

   if (not verbose_flg):
      INFO("PID is %d" % pid)

#===============================================================================

def main():
   global verbose_flg
   global debug_level
   global file_name

   try:
      opts, args = getopt.getopt(sys.argv[1:], "df:D:vVw?")
   except getopt.error, msg:
      print __doc__
      return 1

   for o, a in opts:
      if o == '-d':
         debug_level   += 1
      elif o == '-D':
         debug_level    = int(a)
      elif o == '-f':
         file_name      = a
      elif o == '-v':
         verbose_flg    = True
      elif o == '-V':
         print "[analyse]  Version: %s" % __version__
         return 1
      elif o == '-?':
         print __doc__
         return 1

   print "[analyse]  Working directory is %s" % os.getcwd()

   if (debug_level > 0): print "Debugging level set to %d" % debug_level

   init()

   if file_name:
      analyse(file_name)

   return 0

#-------------------------------------------------------------------------------

if __name__ == '__main__' or __name__ == sys.argv[0]:
   try:
      sys.exit(main())
   except KeyboardInterrupt, e:
      print "[analyse]  Interrupted!"

#-------------------------------------------------------------------------------

"""
Revision History:

     Date     Who   Description
   --------   ---   ------------------------------------------------------------
   20080501   plh   Initial implementation

Problems to fix:

To Do:

Issues:

"""

#-------------------------------------------------------------------------------

Output

Hour   BIND  UNBIND    SRCH     MOD     ADD     DEL
00:        52      18     228       0       0       0
01:       124      23   16024    6893     564    1229
02:        67      22    5574    2539     164      52
03:        29       7     109       0       0       0
04:        43      11     131       0       0       0
05:        41      15     140       0       0       0
06:        69      10     247       0       0       0
07:        79       8    1287       0       0       0
08:       151      15   21634    9067     197      91
09:       302      36    4722       6       1       0
10:       329      39    6504       8       0       0
11:       346      26    7766       3       0       0
12:       378      34    6353       7       0       0
13:       511      46   11213       8       0       0
14:       439      38   11639      10       1       0
15:       379      49    9288      97       3       3
16:       318      24    7990       2       0       0
17:       209      32    5418      13       0       0
18:       154      24    3271       2       0       0
19:       108      28    2536       2       0       0
20:       120      20     863       1       0       0
21:       102      26     608       1       0       0
22:       104      32     466       1       0       0
23:        89      27     528       1       1       0
Total:   4543     610  124539   18661     931    1375 -   150659
%:       3.02    0.40   82.66   12.39    0.62    0.91