How would you write a @debuggable decorator in python?

Question

When debugging, I like to print out all the inputs and outputs of a function (I know I need a better IDE, but humour me, this could be used for error reporting). So, I'd ideally like to have:

@debuggable
def myfunc(argA,argB,argC):
    return argB+1

and use a global variable to switch on or off debugging. No, you don't like globals either, I guessed.

The best I can come up with is:

DEBUG = True

def debuggable(func):
    if DEBUG:
        def decorated(*args):
            print "Entering ",func.func_name
            print "    args ",args
            ret = func(*args)
            print ret
            return ret
        return decorated
    else:
        return func

@debuggable
def myfunc(this,that):
    return this+that

And running:

>>> myfunc(1,3)
Entering  myfunc
   args  (1, 3)
4

How can I improve that?

Bandstand

There's a fairly long blog post on the subject of tracing decorators at Word Aligned. – Foxtrot

Answer 1

Use a debugger. Seriously. Decorating every function you want to keep track is a bad idea.

Python has a debugger included, so you don't need a good IDE.

If you don't want to use a debugger, you can use the trace function.

import sys

@sys.settrace
def trace_debug(frame, event, arg):
    if event == 'call':
        print ("calling %r on line %d, vars: %r" % 
                (frame.f_code.co_name, 
                 frame.f_lineno,
                 frame.f_locals))
        return trace_debug
    elif event == "return":
        print "returning", arg

def fun1(a, b):
    return a + b

print fun1(1, 2)

That prints:

calling 'fun1' on line 14, vars: {'a': 1, 'b': 2}
returning 3
3

Even easier would be to use Winpdb:

It is a platform independent graphical GPL Python debugger with support for remote debugging over a network, multiple threads, namespace modification, embedded debugging, encrypted communication and is up to 20 times faster than pdb.

Features:

• GPL license. Winpdb is Free Software.
• Compatible with CPython 2.3 or later.
• Compatible with wxPython 2.6 or later.
• Platform independent, and tested on Ubuntu Gutsy and Windows XP.
• User Interfaces: rpdb2 is console based, while winpdb requires wxPython 2.6 or later.

_{(source: winpdb.org)}

Jodoin

While this is nice info, it is not really an answer to the question. – Abdul

Answer 2

I think what you're after isn't really a debugging decorator, but more of a logging decorator.

It might make sense to use Python's logging module so you can have more fine grained control over the logging itself. For example you would be able to output to a file for later analysing the output.

The decorator might then look something more like:

import logging

logger = logging.getLogger('TraceLog')
# TODO configure logger to write to file/stdout etc, it's level etc


def logthis(level):
    def _decorator(fn):
        def _decorated(*arg,**kwargs):
            logger.log(level, "calling '%s'(%r,%r)", fn.func_name, arg, kwargs)
            ret=fn(*arg,**kwargs)
            logger.log(level, "called '%s'(%r,%r) got return value: %r", fn.func_name, arg, kwargs, ret)
            return ret
        return _decorated
    return _decorator

@logthis(logging.INFO)
def myfunc(this,that):
    return this+that

Then if you configure the logger to output to stderr you'd see:

>>> logger.setLevel(logging.INFO)
>>> handler=logging.StreamHandler()
>>> logger.addHandler(handler)
>>> myfunc(1,2)
calling 'myfunc'((1, 2),{})
called 'myfunc'((1, 2),{}) got return value: 3

Hippodrome

Answer 3

I agree with nosklo using a debugger is much better than writing your own. I'll post an improvement to your code. But I still think you should follow nosklo's advice.

Use decorator classes to make your debugger neater:

class Debugger(object):
    enabled = False
    def __init__(self, func):
        self.func = func

    def __call__(self, *args, **kwargs):
        if self.enabled:
            print 'Entering', self.func.func_name 
            print '    args:', args, kwargs
        return self.func(*args, **kwargs)

Debugger.enabled = True

@Debugger
def myfunc(a, b, c, d):
    pass

Pretext

Nice. I didn't know that classes could be used as decorators, but I guess it should have been obvious that it is possible. ;p – Fayre

Answer 4

Here is my debug decorator.

import sys
import time

level = 0

def debug(f):
    def decorated(*args, **kwargs):
        global level
        sys.stderr.write("[debug] %s%s(%s)\n"
            % (' ' * level,
                f.__name__, ", ".join(
                    [str(a) for a in args]
                    + ["%s=%s" % (k, v) for (k, v) in kwargs.items()])))
        level += 1
        t0 = time.time()
        res = f(*args, **kwargs)
        t1 = time.time()
        level -= 1
        sys.stderr.write("[debug] %s= %r (%.9f s)\n"
            % (' ' * level, res, t1 - t0))
        return res
    return decorated

This is an improvement over Phil’s because :

• it uses stderr, hence preserving meaningful output on stdout,
• it improves visibility on recursive calls
• it measures the duration of the debugged function (not requested, but not a big hindrance either)

I use f.__name__ instead of f.func_name, because the former doesn’t work anymore in python 3.8.

I took the hint from John Montgomery to not forget to treat kwargs.

I did not keep the DEBUG global variable, not because of its nature, but because I consider it simpler to put/remove a line with @debug where I want it debugged/cleaned. I won’t commit them, as I differentiate punctual manual debug to logging.

Small example

@debug
def f(a, b):
    return a + b

@debug
def g(a, b, c):
    return f(a, b) * c

class C:
    @debug
    def m1(self, a, b):
        return a / b

    @classmethod
    @debug
    def m2(c, a, b):
        return b - a

    @staticmethod
    @debug
    def m3(a, b):
        return a * b

if __name__ == '__main__':
    f(1, b=2)
    g(1, 2, 3)
    C().m1(3, 4)
    C.m2(5, 6)
    C.m3(7, 8)

Output

$./test.py >/dev/null
[debug] f(1, b=2)
[debug] = 3 (0.000001431 s)
[debug] g(1, 2, 3)
[debug]  f(1, 2)
[debug]  = 3 (0.000000477 s)
[debug] = 9 (0.000024557 s)
[debug] m1(<__main__.C object at 0x7f10a6465d90>, 3, 4)
[debug] = 0.75 (0.000000715 s)
[debug] m2(<class '__main__.C'>, 5, 6)
[debug] = 1 (0.000000477 s)
[debug] m3(7, 8)
[debug] = 56 (0.000000477 s)

I understand that a real debugger is a tool that should be known, but the simplicity of adding a small decorator in the editor should be taken in account. As with any tool, proper usage is defined by context.

Taster

Answer 5

You can use as decorator for debug; (@debug)

def debug(func):
    import functools

    @functools.wraps(func)
    def wrapper_debug(*args, **kwargs):
        args_repr = [repr(a) for a in args]  # 1
        kwargs_repr = [f"{k}={v!r}" for k, v in kwargs.items()]  # 2
        signature = ", ".join(args_repr + kwargs_repr)  # 3
        print(f"Call {func.__name__}({signature})")
        value = func(*args, **kwargs)
        print(f"{func.__name__!r} return {value!r}")  # 4
        return value

    return wrapper_debug

Occident

Answer 6

I second what nosklo said.

Another thing to notice is that your function is a bit dangerous:

b = myfunc(1,3)

In this case, "b" is None, because the decorated function doesn't return anything.

Tritheism