Andrew Channels Dexter Pinion

Wherein I write some stuff that you may like to read. Or not, its up to you really.

March 07, 2003

Logging in Python

I have started to convert all of my code from using "print" debug statements to some more industrial strength logging. Rather than re-invent the wheel I've been using the logging module which will be included in Python 2.3.

It is a joy and a wonder. But the module and its documentation are a little bit on the complicated side. Which is right and proper as it is an industrial strength solution. I am a simple soul though, and generally just want one log per application writing to a file. After a little experimentation I have come up with my own logging function which hides the complexity of the logging module. I thought I would share it with you;

import logging
def log(logName, fileName):
    "Instantiate logName and make sure its output is written to fileName"
    logging.basicConfig()
    myLog = logging.getLogger(logName)
    myLog.setLevel(logging.INFO)
    # Define the handler and formmatter
    myHandler = logging.FileHandler(fileName, "w")
    myFormatter = logging.Formatter("%(asctime)s - %(levelname)-5s : %(message)s","%Y-%m-%d %H:%M:%S")
    # Attach the formatter to the handler and the handler to the log
    myHandler.setFormatter(myFormatter)
    myLog.addHandler(myHandler)
    return myLog

Which probably deserves a little explanation. The basic object we need to play with is a logger, which we get by calling getLogger. But, and this is a little unclear in the documentation, it will only write to standard output unless you attach a FileHandler object to it.

In turn, if you want to change the default message format (which I do) you have to attach a Formatter object to the FileHandler.

A quick trap for young players is the default logging level. This is set to WARN. I created my logger and started sending it INFO messages and was rather perplexed when nothing appeared. Until I guessed the logging level default. Which I couldn't easily find in the documentation. I tend to the verbose so I set the output level to INFO by default. My application code is then free to change it of course.

Posted by Andy Todd at March 07, 2003 05:27 PM

Comments

this is a great jumpstart! thanks ; )

as an addition i'll include a simple extension to the logging.Logger class which just adds a method for debug tracing, in case you want to be able to varry your debug output:


import logging


DEBUG_LEVEL = 20

class MyLogger (logging.Logger):

def __init__(self, name, level=logging.NOTSET):
logging.Logger.__init__(self, name, level)


def debugTrace(self, warning_level, msg, *args, **kwargs):
"""
Log 'msg % args' with severity 'DEBUG'.

To pass exception information, use the keyword argument exc_info with
a true value, e.g.

logger.debug("Houston, we have a %s", "thorny problem", exc_info=1)
"""
if self.manager.disable >= logging.DEBUG:
return
if logging.DEBUG >= self.getEffectiveLevel() and DEBUG_LEVEL >= warning_level:
apply(self._log, (logging.DEBUG, msg, args), kwargs)


def log(log_name, file_name):
""" Instantiate log_name and make sure its output is written to file_name """
logging.setLoggerClass(MyLogger)
logging.basicConfig()
myLog = logging.getLogger(log_name)
myLog.setLevel(logging.DEBUG)
# Define the handler and formmatter
myHandler = logging.FileHandler(file_name, "w")
myFormatter = logging.Formatter("%(asctime)s - %(levelname)-5s : %(message)s","%Y-%m-%d %H:%M:%S")
# Attach the formatter to the handler and the handler to the log
myHandler.setFormatter(myFormatter)
myLog.addHandler(myHandler)
return myLog


log = log('log_test', 'log.txt')

log.debugTrace(5, 'debuggin is NI')

log.debugTrace(15, 'debuggin is NOT NI')

Posted by: hawkeye on May 22, 2003 11:31 PM