Kent's Korner

by Kent S Johnson

Basic logging

Using the logging module can be as simple as:

import logging
logging.error('Something has gone terribly wrong')

The logging module has five pre-defined logging levels - DEBUG, INFO, WARNING, ERROR and CRITICAL. Each level has a corresponding module-level method - debug(), info(), warning(), error() and critical(). Any log message whose level is equal or higher than the level of the logger it goes to will be logged.

The default configuration of the logging module is to print any messages with severity WARNING or higher to sys.stderr, so the code above will print an error message to the console.

Basic configuration

The logging module includes a basicConfig() function that is useful for, well, basic configuration. It allows you to configure the logging level and format and to choose between output to a stream or a file. For example to log all messages (DEBUG and higher level) to a file named output.log, set up the module like this:

logging.basicConfig(level=logging.DEBUG, filename='output.log')

With this configuration, logging output will go to a file instead of to sys.stderr.

For more examples of basicConfig() use see section 14.5.2 Basic example in the documentation for the module.

Formatting

The logging module gives you extensive control over the format of log entries. The easiest way to control the format is to provide a format argument to basicConfig(). The format argument is just a string format that uses pre-defined variables to insert logging information.

The default format string is "%(levelname)s:%(name)s:%(message)s". This will show the level of the message (e.g. INFO), the name of the logger used to generate the message (more about that later) and the actual log message.

Often it's useful to include a time stamp in the logging message, and for simple uses the name of the logger is always root which is not very interesting. So a more useful format might be "%(asctime)s %(levelname)s %(message)s". This format shows the date and time (in ISO8601 format), the log level, and the message.

The date format is controlled with the datefmt parameter which takes a date format string. This string will be passed to time.strftime() and can use any format characters supported by time.strftime().

Multiple destinations

The logging module can be configured to log to multiple destinations. Each destination has its own log format and level. For example you can log all messages to a file with a date stamp and log INFO messages to the console without a datestamp. This is a handy configuration - error messages are shown in the console with detailed debugging information available in a file.

For details of this configuration see section 14.5.3 Logging to multiple destinations in the module documentation.

The logging module comes with a wide variety of possible log destinations (called Handlers). The possibilities include

• Log to a file (FileHandler) with optional rollover by date (TimedRotatingFileHandler) or file size (RotatingFileHandler)
• Log to a stream (StreamHandler)
• Send log messages to an email account (SMTPHandler)
• Log to a system event log (SysLogHandler and NTEventLogHandler)
• Log to a TCP or UDP socket or to a web server

Custom handlers

It's easy to write your own handlers and integrate them into the logging system - just subclass logging.Handler and define the emit() method. For example here is a handler that outputs to a wxPython text control:

import logging

class LogToText(logging.Handler):
  def __init__(self, textCtl):
      logging.Handler.__init__(self)
      self.textCtl = textCtl

  def emit(self, record):
      self.textCtl.AppendText(self.format(record))
      self.textCtl.AppendText('\n')

A complete working example that uses this logger is available here.

Multiple loggers

Simple use of the logging module uses module methods (info(), etc.) for output. These methods delegate to the root logger for the actual logging. For finer control you can explicitly create multiple, named loggers in your program. This allows you to

• identify the source of a logging message with the %(name)s parameter in the format string
• have separate logging levels and handlers for log messages originating in different parts of the system
• filter logging messages by criteria you define

Loggers are created and accessed by calling

logging.getLogger(name)

where name is the name for the logger; typically this will be a package or subsystem name.

The logging module organizes loggers into a hierarchy by name using the same syntax as Python packages - a period separates the name into parts and defines the hierarchy. A logger named myapp.text is a child of the logger named myapp which is a child of the root logger.

By default, a logger doesn't have any handlers assigned to it, and logging messages sent to the handler will propagate up the logging hierarchy to its parent logger and ultimately the root logger. Any logger that has handlers assigned will send the message to its handlers. So a logger that is created by calling logging.getLogger() will by default log to the handlers configured for the root logger. The log messages will be shown with the name given in the call to getLogger().

To change this behaviour, create a handler and assign it to the logger.

The Logging to multiple destinations section of the documentation has an example of creating multiple loggers.

And more

If the keyword parameter exc_info=True is included in a call to any of the logging functions, an exception stack trace will be included in the log.

Logging can be configured from a file. (See section 14.5.10 Configuration in the docs.) If you configure your application's logging this way, it can be changed without any coding. This can be useful for enabling debug logging, for example.

I have just scratched the surface of what can be done with this very flexible module. It has a wealth of configuration options. See the documentation for more information and examples.