Python Logging and Django

This post dives into some of the tricky aspects of the Python logging system. What makes them tricky is they are either not documented or hard to find in the docs. This exploration into the bowels of logging was inspired by this code from the Django docs:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'verbose': {
            'format': '%(levelname)s%(asctime)s%(module)s%(process)d%(thread)d%(message)s'
        },
        'simple': {
            'format': '%(levelname)s%(message)s'
        },
    },
    'filters': {
        'special': {
            '()': 'project.logging.SpecialFilter',
            'foo': 'bar',
        }
    },
    'handlers': {
        'null': {
            'level': 'DEBUG',
            'class': 'django.utils.log.NullHandler',
        },
        'console':{
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
            'filters': ['special']
        }
    },
    'loggers': {
        'django': {
            'handlers': ['null'],
            'propagate': True,
            'level': 'INFO',
        },
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': False,
        },
        'myproject': {
            'handlers': ['console', 'mail_admins'],
            'level': 'INFO',
            'filters': ['special']
        }
    }
}

At this point its useful to review the python logger hierarchy and default behavior (for more info see this excellent post). The python logging system consists of a dot-separated tree of loggers. In the example above, django.requests is a child of django. If you send a logging message to django.requests, it will handle the message and since propagate is False that will be the end of it. If propagate were True, then the message would be handled and then passed to the django logger. Cool. But how does the “myproject” logger relate to the django loggers? It turns out there is a top level logger called the root logger. The django loggers and myproject pass their messages to the root logger.

In one of the python modules you might see something like this:

import logging
logging.debug('my message')

This statement send the logging message directly to the root logger.

Cool, but here comes the tricky part. What does the root logger do with this message since we have not defined a root logger (to define a root logger, make logger in the dict above with the name ”)? Here is my best guess at the defaults:

  • level = WARNING
  • handler = StreamHandler
  • format = %(levelname)s%(name)s%(message)s

Time for more magic. What happens if you run these commands?

import logging
logger = logging.getLogger(__name__)
logger.debug('another message')

The getLogger method creates a new logger, attached to the root logger, with the name equal to the module that contains the code. Note, you can name that logger anything you want. Giving it a name that is equal to the module name is especially helpful if you are aggregating the logging messages from multiple modules in one place (in this case, they are all going to StreamHandler).

FileHandler

With FileHandler, you specify the filename. But what directory does that file end up in? Not surprising, its the current working directory. However this can cause some confusion if you run your code from different directories, for example from the root dir using cron and the project dir at other times. This post shows how to specify the dir.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s