Adding Dynamic elements to logging.filters in django 1.3

Question

I'm attempting to add some contextual information to some logs via the logging module. I need to be able to view a projectid next to each line in the logs, with over 20,000 projects created daily this data is really helpful. To do this I've created a derivative of the logging.Filter module.

import logging

class MTFilter(logging.Filter):

def __init__(self, projectid=0):
    self.projectid = projectid

def filter(self, record):
    record.projectid = self.projectid
    return True

Here's my LOGGING variable in settings.py

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'filters': {
        'project': {
            '()':  'app.proj.logging.mtfilter.MTFilter',
        },  
    },
    'formatters': { 
        'projectformat': {
            'format': '%(asctime)s %(levelname)8s PID[%(projectid)d] %(name)s[%(funcName)s]: %(message)s',
        },
    },
    'handlers': {
        'null': {
            'level': 'DEBUG',
            'class': 'django.utils.log.NullHandler',
        },
        'project-log': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'formatter': 'projectformat',
            'filename': os.path.join(SITE_ROOT, '../logs/django.log'),
            'filters':  ['project'],
            'maxBytes': 1024*1024*16, #16Mb
        },
    },
    'loggers': {
        '': {
            'handlers':     ['null'],
            'level':        'DEBUG',
            'propagate':    True,
        },
        'proj': {
             'handlers':    ['project-log'],
             'level':       'DEBUG',
         },
    }
}

And in my view I use the following

logger = logging.getLogger('proj')
logger.info('Log Message')

By not putting any value for 'projectid' in Logging.filters.project I get the default format value, which is '0'. The log result looks like the following:

2011-07-26 02:41:44,488     INFO PID[0] proj[view]: Log Message

What I'd like to do is grab the 'projectid' value dynamically somehow, eg. when creating a logger object, or using some Middleware but I just don't know how to do it. Does anyone have an suggestions?

I see your comment. Logging itself offers many ways to add contextual information to the log, e.g. `LoggingAdapter` or the `extra` keyword arg on logging calls. However, if you want to add contextual information to logging calls which you have no access to the source of (e.g. in 3rd party libraries) then there's the approach I've suggested. — Vinay Sajip, Jul 27 '11 at 14:48

score 3 · Accepted Answer · answered Jul 26 '11 at 09:52

What I'd like to do is grab the 'projectid' value dynamically somehow, eg. when creating a logger object, or using some Middleware but I just don't know how to do it.

It's not appropriate to do this when creating a logger, as that's a one-time operation. What you probably need to do is to find some way of getting the current project ID into the filter. For example, instead of passing the record into the filter at construction time, you could use a design with a callable that the filter calls to get the project ID. For example:

class ProjectFilter(logging.Filter):
    def __init__(self, func):
        self.func = func

    def filter(self, record):
        record.projectid = self.func()
        return True

The callable can be anything that knows how to get the project ID from the current context (e.g. a thread local - though that's not endorsed by the Django core team, it's what thread locals were invented for, and used quite successfully by other frameworks such as Flask). I don't know enough about your application to suggest how the callable might work.

Thanks Vinay, although it just doesn't feel right, seems overly complex for something so simple. I've accepted the answer because it was what I was after. PS - Love logging.py :) — Mark Walker, Jul 26 '11 at 22:29

score 0 · Answer 2 · answered Jul 27 '11 at 01:37

I know it's not the most elegant solution, but reviewing the source for logging I found that you can add contextual information by way of the 'extra' parameter.

logger.info('A long entry', extra={'projectid': 1})

I'll just derive a logger object with my own that overrides the log entry methods and appends the 'extra' parameter if exists.

I would have like to use LogAdaptors but the python version I'm using is 2.5x :(

Adding Dynamic elements to logging.filters in django 1.3

2 Answers2