Custom Event Handler Tutorial

Author: Pete Kazmier
Version: custom-tutorial.txt,v 1.2 2003/08/01 19:13:53 kaz Exp

Introduction

The standard LogWrap distribution comes with a handful of event handlers that can be used to process events which are generated by matching lines in a log file. These event handlers can do the following: printing of messages to a file, email generation, SNMP Trap notifications, as well as some suppression handlers. If these event handlers are not sufficient or do not meet your requirements, you can provide your own custom event handlers. It is this topic that will be explored in this tutorial.

Overview

In this tutorial, you will learn how to create and use your own custom event handler using the logwrap program and its XML configuration file. Lets assume for this tutorial that you are going to require an event handler that can telnet to a host and execute a command when certain messages arrive in your log file (/var/log/app.log). Specifically, when a line in the following form:

WARNING: Disk Space Low on 10.11.12.13

Upon receipt of this message, you want to telnet to the host identified in the message, 10.11.12.13, and then issue a df command to display the amount of free disk space on the host (this tutorial assumes the hosts are UNIX-based). To avoid flooding the host with telnet requests, you will also limit the frequency your custom event handler is triggered. In this example, the event handler will only be executed if a message for the same host is received 3 or more times within a 10-second interval.

You are now ready to proceed in the implementation of your own custom event handler. The next section will discuss the XML configuration file that drives the logwrap program by specifying sets of rules and their associated event handlers that should be executed upon a successful match. Following that section, the custom event handler is implemented in a simple Python script that logwrap will use to load the event handler.

XML Configuration

The XML configuration file specifies which log files are to be monitored, the patterns that are to be matched, and the event handlers used to process each match. The following is a trivial configuration file that contains a single rule that matches lines in the format described earlier as well as the event handlers used to process that log message:

<?xml version="1.0" encoding="ISO-8859-1"?>

<logWrap>
  <handlerDirectory dir="/home/kaz/src"/>

  <logEncapsulator name="Tutorial Encapsulator">
    <logFile file="/var/log/app.log"/>

    <rule>
      <regexp>WARNING: Disk Space Low on (\d+\.\d+\.\d+\.\d+)</regexp>

      <handler type="Frequency" threshold="3" interval="10" match_on="1"/>
      <handler type="CustomEventHandlers:TelnetHost"
               host="\1"
               user="kaz"
               password="blahblah"
               command="df"/>
    </rule>

  </logEncapsulator>
</logWrap>

The above configuration file should be familiar to you (with the exception of our new event handler definition). If this is not the case, it is recommended that you read the sample XML configuration file that comes with the distribution because every feature is documented.

There are a few items of interest. First, the <handlerDirectory> specifies a directory where you'll put your custom event handlers (more on that later). Next, a single encapsulator is defined to monitor the /var/log/app.log file. This encapsulator contains a single rule that matches any lines matching the specified <regexp>. Not only does it match the regular expression, but the grouping operators (the parentheses) are used to group the IP address that is part of the log entry. For example:

WARNING: Disk Space Low on 10.11.12.13

The IP address, 10.11.12.13, will be "saved" for use later. By using the grouping operators, event handlers have the opportunity to inspect and use the items that have been grouped. As you'll see later, both of the specified event handlers will utilize this information in one manner or the other.

The next set of elements in the configuration is a series of event handlers which are executed in the specified order. This is called an event handler chain. Any of the event handlers may terminate the chain if desired. This is how the Frequency handler operates. When it is invoked, it will terminate the event chain unless 3 log messages have occurred in 10 seconds containing the same IP address. The same IP address is matched because of the match_on attribute, which specifies a comma-separated list of numbers. These numbers are positional parameters indicating one of the groups that were saved from the regular expression.

Finally, if the appropriate number of messages arrive in the given interval, the custom event handler called TelnetHost is executed. A custom event handler's type is specified in the following manner:

ModuleName:EventHandlerClass

The ModuleName specifies a Python module that contains the EventHandlerClass. ModuleName must be located in the directory specified by the <handlerDirectory> element at the beginning of the configuration. If EventHandlerClass is not found in ModuleName, EventHandler is appended to the EventHandlerClass. For example, given the following custom event handler specification:

CustomEventHandlers:TelnetHost

Either TelnetHost or TelnetHostEventHandler must be defined in the Python module /home/kaz/src/CustomEventHandlers.py. This concludes the XML configuration required for our custom event handler. In the next section, we'll explore the actual Python class that implements the event handler functionality.

Event Handler Implementation

With the XML configuration completed, all that is left is the implementation of the event handler. Writing your own event handler is a very easy. There are a few things you should be aware of before starting. First, all event handlers must subclass the base event handler com.kazmier.event.Event.EventHandler. For example, here are the first few lines of our event handler:

from com.kazmier.event.Event import EventHandler

class TelnetHostEventHandler(EventHandler):
    ...

In addition, there several other topics that deserve further attention. They are the initialization, execution, and access to event data including timestamps, the line that caused the match, as well as any saved group data from the regular expression. Each of these topics is covered in the following sections.

Initialization

As with all Python classes, you may choose to pass arguments to your constructor when creating an instance of your event handler. This is done via the standard method called __init__ in Python. In order to make the TelnetHost event handler generic, parameters such as host, port, username, password, and the command to execute should be passed at creation time:

class TelnetHostEventHandler(EventHandler):
    def __init__(self, host, port=23, user, password, command):
        self.host = host
        self.port = port
        self.user = user
        self.password = password
        self.command = command

By storing these values, the event handler can use them later when processing an event (the result of a matched line in a log). The above is sufficient if one is only ever going to use the LogWrap API directly. However, this tutorial is using the logwrap script and XML configuration file. In this mode of operation, the user does not invoke this constructor and thus cannot pass values to it.

It turns out that the LogWrap framework has a little bit of magic baked in to facilitate the passing of values to an event handler's constructor when using the XML configuration file. Users can specify values by setting XML attributes to the <handler> element in the configuration file. Each attribute's name must be the same as the name of the argument in the constructor. For example:

<handler type="CustomEventHandlers:TelnetHost"
         host="\1"
         user="kaz"
         password="blahblah"
         command="df"/>

The above XML sets four attributes (not counting the type attribute which you must set to specify the event handler). Each of the attribute names corresponds to the argument names in the constructor. Note: if an value is not passed (such as the port), it must have a default value set in the constructor (23 in this case). Sometimes passing values via XML attributes is not sufficient because you have multiline data to pass or characters that cannot appear in an XML attribute's value. In this case, an alternative syntax is provided:

<handler type="CustomEventHandlers:TelnetHost">
  <host>\1</host>
  <user>kaz</user>
  <password>blahblah</password>
  <command>df</command>
</handler>

Instead of passing the values as attributes, you can pass the values as the text of a child element whose name corresponds to the arguments in the constructor. When using this notation, you can also use CDATA blocks if desired.

Now that you've seen the magic that the LogWrap framework provides, there is one caveat the programmer must remember: If arguments are passed to an event handler's constructor via the XML configuration file, they are passed as strings. As such, you must handle the conversion of these strings to other data types as appropriate. In our simple event handler, none of the values passed are non-string objects, however, if we were to pass a port number via an XML attribute, it would be passed as a string. Thus, we should handle the conversion of this string to an integer in our constructor:

class TelnetHostEventHandler(EventHandler):
    def __init__(self, host, port=23, user, password, command):
        self.host = host
        self.port = int(port) # Convert to integer if not already
        self.user = user
        self.password = password
        self.command = command

You've now seen how an event handler is instantiated via the XML configuration file. The next section provides the details on the execution of the event handler.

Execution

A little background on the LogWrap event framework is first needed before proceeding with the implementation of the custom event handler. Included in the distribution of the LogWrap framework is a separate event framework. The event framework consists of two threads interconnected by an event queue. The first thread is responsible for the generation of events and the placement of these events into the event queue. The second thread is responsible for the dequeuing and processing of events. It is the latter thread that invokes all of the event handlers. See the following diagram:

                        |
                        |
                 +-------------+
Generator -----> | Event Queue | -----> Processor
                 +-------------+
                        |
              Thread 1  |  Thread 2

The fact that event processing occurs in a separate thread is important because your custom event handler does not have to be "spawned" off in another process or thread to avoid losing events. Event generation and queuing are not affected if your event handler takes a few seconds to execute because the event queue acts as a buffer. This simplifies the coding of event handlers.

On a side note, if your event handler is very slow, and you have an excessive amount of events being generated for a constant time, your queue will grow and grow and grow. At that point, you need to investigate the use of the frequency suppression event handlers included with the LogWrap framework. However, with that said, the most common scenario is that the queue will fluctuate over time growing larger when bursts of events arrive and emptying when there is little event generation taking place.

All event handlers are invoked by the EventProcessor which passes the Event as the only argument to the process_event method of the event handler. The following is a simple event handler that does nothing other than print the Event object to the screen:

class SimpleEventHandler(EventHandler):
    def process_event(self, event):
        print "event =", event
        return 1

It is important to note that this event handler returns 1 which indicates that subsequent handlers should be invoked if this event handler was part of a event handler chain (as described earlier). If you want to stop the execution of the chain, return a value of 0 instead.

In the next section, we will explore the Event object and all of the data it can provide to us when we write our implementation of our event handler.

Event Data

An event handler would not be very useful unless it had access to context information related to the event in question. Specifically, the timestamp, the originator of the event, the original line that triggered the event in the log file, as well as any grouped data specified in the regular expression that was used to match the event. Fortunately, all of the above are available to the programmer via the Event object when writing an event handler. The following event handler illustrates how one can access this information:

class ExamineEventHandler(EventHandler):
    def process_event(self, event):
        print "------------------"
        print "Creation Time:    ", time.ctime(event.time)
        print "Originator's Name:", event.originator
        print "Original Line:    ", event.data.line,
        print "Match Object:     ", event.data.match.groups()
        return 1

A more verbose description of each of the above is provided below:

event.time
Contains the time when this event was created. The value is stored as a number of seconds since Epoch.
event.originator
Contains a reference to the originator of this event. In the event framework, this refers to an EventGenerator. Within the LogWrap context, this object refers to the LogEncapsulator (a subclass of an EventGenerator). The string representation of the LogEncapsulator is simply its name. This is the same name that was specified in the <logEncapsulator> element.
event.data
Contains a reference to a piece of arbitrary data that has been associated with this event. The EventGenerator specifies the contents of this variable. In this context, the LogEncapsulator stores a reference to a LogMatch object.
event.data.line
Contains the original line that generated the event. This value is stored as part of the LogMatch object.
event.data.match
Contains a MatchObject (from the Python re module) which can be queried for items that were grouped in the regular expression. This enables the event handler to gain access to parts of the original log message. In this tutorial, this will be used to access the IP address of the host.

TelnetHost Implementation

You are now armed with all of the necessary information to write the full implementation of the TelnetHost custom event handler. The contents of following script must be located in a file called /home/kaz/src/CustomEventHandlers.py (unless you have changed the value of the <handlerDirectory> element in the XML configuration file):

from com.kazmier.event.Event import EventHandler

class TelnetHostEventHandler(EventHandler):  # Must extend EventHandler

    # The construct defines the args we expect in the XML file,
    # you'll notice for each arg here, there is a corresponding XML
    # attribute defined in the config file.
    def __init__(self, host, port=23, user, password, command):
        self.host = host
        self.port = int(port) # Handle the conversion from string to int
        self.user = user
        self.password = password
        self.command = command

    # This is the method that is called when the event handler is
    # invoked.  It is passed a reference to the event itself which
    # lets us do some nifty things like get at those parts of the
    # regular expression that we grouped using the parens.
    def process_event(self, event):
        import telnetlib

        # And here is the magic that converts "\1" into the IP
        # address that was sent to the log file.  This simply uses
        # the MatchObject from the re library to do the expansion.
        telnet = telnetlib.Telnet(event.data.match.expand(self.host))

        # Login to the host
        telnet.read_until("login: ")
        telnet.write(self.user + "\n")
        telnet.read_until("Password: ")
        telnet.write(self.password + "\n")

        # Run the command that was specified in the XML configuration  
        telnet.write(self.command + "\n")
        telnet.write("exit\n")
        output = telnet.read_all()
        telnet.close()

        # We'll probably want to do something other than just
        # printing the output to the screen, but this will suffice
        # for this tutorial.
        print output

        # Its important to return 1 if you want to permit other
        # event handlers defined in the configuration to run.  If
        # you don't, you effectively stop the event handler chain.
        # This is how the frequency suppression handler works.
        return 1

You can test this example with the following commands:

$ touch /var/log/app.log   # Create the file if it doesn't exit
$ logwrap path_to_xml_configuration_file

Then, in another shell (or window):

$ echo "WARNING: Disk Space Low on 10.11.12.13" >> /var/log/app.log

At this point, in the first window, you should see the output of the df command for the host 10.11.12.13.

Congratulations! You've successfully written your own custom event handler. Custom event handlers are useful if you are seeking functionality that isn't provided by an event handler included in the LogWrap distribution.