Loggly

A Logging Library for Django - How We Log at Loggly

Posted 22 May, 2010 by raffy@loggly.com in Code and Log Management

In my last blog entry, I showed you how you can enable logging in Django 1.2. Now we are going to look at the logging library that we built for Loggly to simplify the task of logging in our own Django application, the Loggly Web interface.

Here is how we log from within our application:

from loggly.logging import *

error({'object':'input','action':'create'})

That’s it. The above code creates the following log entry:

Mar 18 15:34:03 app loggly: severity=ERROR,user=logdog_zrlram,request_id=
08BaswoAAQgAADVDG3IAAAAD,object=input,action=create,status=failure

The logging call expects a dict of key-value pairs. This is to enforce key-value based log entries that make it easy for consumers to understand what a specific value means. Without the inclusion of a key, a value is more or less useless. In the example above, note that I only provided two keys: object, and action. However, the log entry contains a number of other data items. Those items are automatically added to the log entries by our logging library without burdening the developer to explicitly include them.

It is probably time to show you Loggly’s logging library:

import logging
import inspect

DEFAULT_LOGGER = 'loggly_web'
logs = None

def logHelper(rest=None, request=None):

    global logs
    output = list()

    # get the logger
    if not logs:
        logs = logging.getLogger(DEFAULT_LOGGER)

    # Loop through all the stack frames until you find the request
    stack = inspect.stack()
    for frame in stack:
        if frame[0].f_locals.has_key('request'):
            request = frame[0].f_locals['request']
            if request is None:
                continue
            # there is a request object
            if hasattr(request,'user') and hasattr(request.user,'username') and len(request.user.username)>0:
                output.append("user="+str(request.user.username).strip())
            if hasattr(request,'META') and request.META.has_key('UNIQUE_ID'):
                output.append("request_id="+str(request.META['UNIQUE_ID']).strip())
            # we found the request object. Get out of here
            break

    # getting input dictionary and appending
    if rest:
        for key in rest:
            output.append("%s=%s" % (str(key.strip()), str(rest[key]).strip()))

    ret = ",".join(map(str, output))
    return ret

def info(rest=None, user=None):

    msg = logHelper(rest, request)
    logs.info(msg)

def error(rest=None, user=None):

    msg = logHelper(rest, request)
    logs.error(msg)

Note that this is only an extract. Download the entire library if you want to use it in your own code. Here are some important things the code does:

• line 17 to 29: This part of the code inspects the call stack to check whether there is an HTTP request object somewhere. The request object contains the username for the session and that is what we automatically extract . This frees the user from manually adding that information to the logging call. Automation is good!


• line 26 and 27: We are using UNIQUE_IDs in Apache. In order to track a request from the Apache logs down into our application, we include that same ID into our Django logs. This is a huge win for associating Apache logs with our application logs.


• line 32 to 24: All the dict entries are added as ‘key=value’ pairs to the log entry. So you can log any key you want.


• line 39 to 47: These are the calls that you use in your code. Note that you can add a user field, which overwrites the username from the request. In some cases that is necessary and useful.

Let us know if you are using our library. I would love to hear back from you. I will post another blog entry later, where I will be talking about how to patch Django itself to do some more logging. We will be looking at how the authentication methods can be extended.

The links:
Django 1.2 Logging Patch
Loggly Logging Library

Tweet