Using Sentry-style logging in development

I think the most widely used manual debugging method is using print statements in your code. But this is highly inefficient and just plain crude.

With Sentry in your Django project it is possible to give extra keyword argument to the call to logging.debug and Sentry then formats the content of that argument nicely. I wanted to have the same functionality without Sentry running in the development environment. Problem was that default logging facility just ignores the extra argument.

Usually I use sentry-enhanced logging like this:

import logging
l = logging.getLogger(__name__)
l.debug('Something happened', extra={'data':foo})

Now, if the extra is ignored this just prints “Something happened” which if informative (remember to write meaningful string there), but does not have any information what was the context.

So I came up with this.

Django 1.3 allows using the LOGGING settings variable to set logging configuration using the dictConf format.

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'normal': {
            'format': '%(levelname)s %(name)s %(lineno)s %(message)s %(data)s'
        },
    },
    'filters': {
      'default': {
        '()': 'project.logging.Filter',
      },
    },
    'handlers': {
        'null': {
            'level':'DEBUG',
            'class':'django.utils.log.NullHandler',
        },
        'console':{
            'level':'DEBUG',
            'class':'logging.StreamHandler',
            'formatter': 'normal',
            'filters': ['default'],
        },
    },
    'loggers': {
        'django': {
            'handlers':['null'],
            'propagate': True,
        },
        '': {
            'handlers': ['console'],
            'level': 'DEBUG',
        }
    }
}

This configuration outputs all DEBUG level logging from our own code to console and uses our own filter to make sure the data parameter to the message formatter is always present and contains nice data.

Here is the filter code:

import json
class Filter:
  def filter(self, record):
    if not 'data' in record.__dict__:
      record.__dict__['data'] = None
    record.__dict__['data'] = json.dumps(record.__dict__['data'], sort_keys=True, indent=2)
    return True

Make sure you put this in a place where it can be imported. I used project.logging module.

The end result after all this is that I can see nicely formatted debug output in the console. I used json package to do the serializing and formatting of the data dict.