I’m not a huge fan of step-through debuggers, because I generally find them to be a crutch that keeps you from attempting to get a holistic understanding of the program you’re debugging.  I’ve certainly never had an issue that I haven’t been able to solve without a debugger.

Of course when debugging, you still need to get information about what’s going on from somewhere; Usually for me this means relying heavily on print statements and logging.  I would say that the most interesting pieces of information to collect would be the values that methods are getting as input and giving as output, and what methods are called.  For example, for a function add() that adds two numbers, I do debugging log entries that look like this:

add called with *args: (1, 1), **kwargs: {}  --> 2

This is pretty simple stuff.  I’m sure lots of people write debug output like this.  The problem though is that it’s a pain to sprinkle the print or log statements everywhere, and it’s a pain to clean them up later.

Enter the Decorator

I got this idea from Bram Cohen’s blog, but I have no idea if he actually does what I’m doing here: using Python’s decorators feature to make logging of any method (add() in this example) as easy as slapping a “@log__calls_decorator” at the top of the method’s definition, like this:

@log__calls_decorator
def add(operand1, operand2):
	return operand1 + operand2

So that’s how the dream decorator would be applied.  This decorator annotation syntax is really just a shortcut for this:

add = log_calls_decorator(add)

You can see that add() is simply being replaced with whatever the output of log_calls_decorator(add) is.  The decorator must take a callable as input and provide one as output.  A decorator basically *replaces* the method it decorates, though *usually* in its replacement functionality, it also calls that method it is decorating.  That’s how decorators “wrap” methods and it’s why we pass the original add() to it: we want it to be able to still run add() at some point in its execution.

Let’s just create a decorator that does nothing additional first:

def log_calls_decorator(f):
    def wrapped(*args, **kwargs):
        try:
            retval = f(*args, **kwargs)
			return retval
        except Exception, e:
            raise
    return wrapped

You can see that log_calls_decorator takes a function as input, calls it, and either returns its result or re-raises any exception that it raises.  It might seem unnecessary to catch an exception just to reraise it, but when we start to add additional functionality to the decorator, we’ll want different output in the case of exceptions: Something like this:

add called with *args: (1, "blah"), **kwargs: {}  RAISED EXCEPTION TypeError, somefile.py, 20

All we need to do is add the extra functionality we want now (For the sake of simplicity, we’ll just use print output instead of a logger, but changing this to use a logger should be elementary).

def log_calls_decorator(f):
    def wrapped(*args, **kwargs):
        call_string = "%s called with *args: %r, **kwargs: %r " % (f.__name__, args, kwargs)
        try:
            retval = f(*args, **kwargs)
            call_string += " --> " + repr(retval)
            print call_string
            return retval
        except Exception, e:
            top = traceback.extract_stack()[-1]   # get traceback info to print out later
            call_string += " RAISED EXCEPTION: "
            call_string += ", ".join([type(e).__name__, os.path.basename(top[0]), str(top[1])])
            print call_string
            raise
    return wrapped

Basically, with this little gem, I can just slap this decorator on any function I want to track as far as calls / inputs / outputs go!  Debugging is now one-step less frustrating and time-consuming.

3 thoughts on “The Debuggerator: A Practical Intro to Decorators in Python

  1. Pingback: Challenging Patterns « caines.ca/blog

  2. You should use @functools.wraps(f) around the ‘def wrapped’, it preserves the wrapped function’s name and other metadata – maybe not terribly important, but this is the way decorators are supposed to be used.

  3. Pingback: Tweets that mention The Debuggerator: A Practical Intro to Decorators in Python « caines.ca/blog -- Topsy.com

Leave a reply

required

<a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>