Python Logging Exposed

In my previous post I outlined the logging requirements for Lokai file processing. This time I’m going to look at the logging module to see what it provides, and to identify what extensions we will need.

Just to be clear, I’m talking Python 2.x here, not 3. I don’t think there’s any significant difference, but I’m not an expert.

To start with, you, the programmer, do not actually instantiate any logging objects. To do anything at all you have to refer to a logger by name:

import logger
# Find or create the 'A' logger instance
log_instance_a = logger.getLogger('A')
# Send a message of level ERROR
log_instance_a.log(ERROR, 'Oops, an error')

As it says in the documentation, this means you always get the same logger instance and you do not need to pass things around.

You can name as many different logger instance as you like, and you can create hierarchies. The logger ‘A.B.C’ gets you the ‘C’ logger underneath ‘A.B’. The particular feature of such a hierarchy is that, by default, any message sent to logger ‘A.B.C’ will also go to logger ‘A.B’ and thence to ‘A’.

The next point is that messages are all allocated a level number. This is used to distinguish types of messages. The levels defined in the module are:

ERROR = 40
INFO = 20
DEBUG = 10

You can choose the level you want to log when you set up your logger, so, within your code you can be liberal with debug output, for example, and turn it on or off for each program run by setting the appropriate parameter in the initialisation.

So far this is looking pretty flexible, but there is more. For this I’m going to illustrate the path taken by a message when logger.log is invoked. What follows is not code, exactly, but it should identify the key entry points for making any alterations or additions that may be needed.

    instance = logger.getLogger('A')
    instance.log(ERROR, 'text)
        #[Enter Logger.log method]
(a)     if self.isEnabledFor(level):
            self._log(level, msg, args, **kwargs)
                #[Enter Logger._log]
                record = self.makeRecord( ... msg ... )
                    #[Enter Logger.handle]
(b)                 allowed = self.filter(record)
                        #[Enter Filterer.filter]
(c)                     for f in self.filters:
                            if not f.filter(record):
                                return True
                        return False
    		if allowed:
                        #[Enter Logger.callHandlers]
(d)                     # ignoring propagation up hierarchy 
(e)                     for hdlr in self.handlers:
(f)                         if record.levelno >= hdlr.level:
                                #[Enter Handler.handle] 
(g)                             if self.filter(record):
                                    # do something with the record

So, let’s look at what is going on. Firstly, the whole run of code is aimed at passing a log record to a handler. This is where the work gets done and the logger module has a range of example handlers that you can use. These include simple write to standard error, write to file, buffer records for later, send by email, send across a socket, and so on. In fact, a given logger instance can have any number of handlers, so your single message can result in any number of different storage or communication actions.

Secondly, there are 4 places where the message can be rejected or accepted. Point (a) is the basic limit on the numeric value of the message level. Anything less than this limit is rejected. Point (b) introduces logger level filtering. You can add any number of filters (see point (c)) and the first one to pass allows the message through. It gets better, because we see at point (f) that each individual handler also has a numeric filter, and, at point (g), its own set of filters. The result is that you have both coarse and fine control over what gets published at all, and what gets handled by which handler.

That covers the basics, but there are two more things to be aware of. One is that any handler has a format method that can be tuned to structure records into something meaningful, depending on the target output. The other is that a buffering handler must have a method of outputting records. This can be another Handler object (with filtering, if you wish).

That looks pretty flexible. You can link together handlers and filters in whatever combination suits your application, and you can write your own Handler objects. Next time we’ll see how that matches the Lokai requirements.

Category: Development | Tags: , , Comments Off on Python Logging Exposed

Comments are closed.

Back to top