Log Normal

How many times have you added a print statement to your programs and scripts to see exactly why something is not working as expected? A separate function to let you output these messages or hide them at the flip of a switch would be a more elegant approach. However, both methods are unnecessary with Python, which has a powerful logging module to greatly facilitate development. For example, in web projects, you typically do not have a standard output channel, so the logging module can redirect program output to syslog.

The module was written by Vinay Sajip, who describes the concept in Python standard document PEP 282 [1] and has documented the implementation on his own website [2]. The developer put much thought into his work and was inspired by Java's log4j, among other things. In Python 2.3, the logging module [3] was finally added to the standard library, so assuming you have Python in place, you have nothing to install. To use the module, import it at the start of a script, like this:

import logging

The module provides static functions like debug, info, and warning that let you output information at different logging levels. The principle is perhaps best known from Unix/Linux daemons, such as Apache and the corresponding syslog daemon. Debug is the highest level and includes all the lower levels, such as Notice and Error.

After selecting the Debug logging level, the user gets to see every single piece of information that is output. The Warning log level doesn't include debug messages but still includes all error messages. The Python module doesn't implement all of the Unix syslog levels; rather, it takes a more pragmatic approach of just using five levels, as shown in Table 1.

If needed, you also can define your own log levels. If you select the Error log level, the program only outputs errors and does not show you any other messages. The following instructions in a Python script clarify this:

logging.debug('only for troubleshooting')
logging.info('an informative message')
logging.warning('a warning')

If you execute these lines in a script, you only see warnings by default. To see the other messages, you must increase the log level by selecting the matching logging module method:

logging.basicConfig(level=logging.DEBUG)

As you can see, the logging module outputs the log level in uppercase characters before the actual message. If you pass in the log level as a command-line argument or process it in your own script, you can define how verbose the program is by the way you launch the script. An easy way to output a logfile is to use basicConfig with the filename parameter:

logging.basicConfig(filename='debug.log')

The basicConfig function understands six parameters: filename, filemode (e.g., attach instead of overwrite), format, datefmt, level, and stream. The format parameter lets you change the log message format. For example, you can remove the root string (the so-called root logger) that is contained in the default messages by setting the following format:

logging.basicConfig(format='%(levelname)s:%(message)s')

But, more on that later. The variables available here are all attributes from the LogRecord class (e.g., various timestamps, information about the running process and threads, the module, the current function, and the line number in the script).

Structured

Instead of calling the static functions from the logging class, you can also use the object-oriented interface with logger objects. This lets you improve the logging structure in larger projects by distinguishing by program module, for example. To do so, you need to use getLogger to obtain a logger, which you can then work with. A string in brackets specifies the namespace to work in. With the use of a dot-separated format, as in Java and Python classes, you can structure logging for your own program modules and create a tree structure of loggers (e.g., Listing 1). At the start of the script, you need to call basicConfig; otherwise, you don't get a logger. The root of the tree is the root logger by default.

01 import logging
02
03 logging.basicConfig()
04
05 mylog = logging.getLogger("mylogger")
06 mainlog = logging.getLogger("mylogger.main")
07 mainlog.setLevel(logging.DEBUG)
08
09 mainlog.debug('only for troubleshooting')
10 mainlog.info('an informative message')
11 mainlog.warning('a warning')
12
13 mylog.debug('no message from My-Module')
14 mylog.setLevel(logging.DEBUG)
15 mylog.debug('another message from My-Module')

The loggers have methods that use the same names as the module (i.e., debug, info, warning, error, and critical), and the log level can be set for each logger, as you can see in Listing 1. If you call getLogger multiple times for various modules in a program, you are always given the same pointer to the logger. The documentation also notes that you must be careful when using the static module functions in Python versions below 2.7.1 or 3, if you are using threads. Under unfavorable circumstances, handlers could be created twice.

Handlers

To route output into a specific channel, you need a handler. With StreamHandler, a script will send output to the standard error output (sys.stderr) unless you specify a different stream as a parameter:

console = logging.StreamHandler()

A FileHandler writes the logging data to a file, and a RotatingFileHandler lets you rotate the logfiles depending on size and date. A SocketHandler logs over the network, but you need to do much of the work yourself. SysLogHandler makes things easier because it sends data not just to the local syslog daemon, but also to syslogs on other machines if configured to do so (as of Python 2.7 also using TCP [4]).

Windows users even have the NTEventLogHandler, which sends data to the Windows event log, and you can log via SMTP and HTTP as well.

If you use a handler that takes a bit longer to process calls, such as an SMTP logger, you need to make sure it doesn't block your program. One approach that the documentation suggests, which takes slightly longer, is to use a socket handler that passes the logging data to another thread; this thread then handles the actual logging. Python 3.2 has a new QueueHandler class for this. To assign a handler to an existing logger, use:

logging.getLogger('').addHandler(console)

This approach also supports assigning multiple handlers to a logger; the loggers can use different log levels and write to the console or to a logfile as needed. If you see a log message multiple times, remember that a logging event is passed upward through the logger hierarchy and processed by the responsible handler. To change this behavior, you can set the handler's propagate attribute to 0.

Configuration

Instead of setting up loggers, handlers, and so on in the program, you can also use a configuration file. Unfortunately, the format isn't entirely intuitive. To begin, you need to define keys, which are used further down in the configuration file (Listing 2).

01 [loggers]
02 keys=root,myLogger
03 ...
04 [logger_root]
05 level=DEBUG
06 handlers=rootHandler
07
08 [logger_myLogger]
09 level=INFO
10 handlers=myHandler
11
12 [handler_rootHandler]
13 ...
14 [handler_myHandler]

This process becomes easier as of Python 2.7, which introduced a dictionary-based format that makes these clumsy references unnecessary. The user must determine how to represent the configuration data in dictionary format. A configuration file can use JSON, YAML, or some other structured text format. Listing 3 is an example of a logger configuration in YAML.

01 handlers:
02   myHandler:
03     level: DEBUG
04   rootHandler:
05     level: INFO
06     class: logging.StreamHandler
07     stream: ext://sys.stdout
08 loggers:
09    myLogger:
10      handlers: [myHandler]
11 root:
12    handlers: [rootHandler]

Conclusions

The logging module in Python is easy to use and sufficiently flexible to convince programmers to use it for outputting important information from their scripts instead of print instructions – except where you want to inform the user directly. To get started, check out the basic tutorial, advanced tutorial, and logging cookbook; the Python documentation links to them. For up-to-date information and tips for Python logging, go to the developer blog [5].