Easy tracing of nested function calls in Python
August 22nd, 2012 at 4:24 amSometimes, when executing algorithms with complex function call sequences, and especially ones that require recursion, it’s useful to see what calls actually occurred during execution, their arguments and return values, and so on.
Here is a simple Python decorator (works on both 2.7 and 3.2+) that helps me do it without much effort for new code:
import sys
from functools import wraps
class TraceCalls(object):
""" Use as a decorator on functions that should be traced. Several
functions can be decorated - they will all be indented according
to their call depth.
"""
def __init__(self, stream=sys.stdout, indent_step=2, show_ret=False):
self.stream = stream
self.indent_step = indent_step
self.show_ret = show_ret
# This is a class attribute since we want to share the indentation
# level between different traced functions, in case they call
# each other.
TraceCalls.cur_indent = 0
def __call__(self, fn):
@wraps(fn)
def wrapper(*args, **kwargs):
indent = ' ' * TraceCalls.cur_indent
argstr = ', '.join(
[repr(a) for a in args] +
["%s=%s" % (a, repr(b)) for a, b in kwargs.items()])
self.stream.write('%s%s(%s)\n' % (indent, fn.__name__, argstr))
TraceCalls.cur_indent += self.indent_step
ret = fn(*args, **kwargs)
TraceCalls.cur_indent -= self.indent_step
if self.show_ret:
self.stream.write('%s--> %s\n' % (indent, ret))
return ret
return wrapper
And here’s how we can use it:
@TraceCalls()
def iseven(n):
return True if n == 0 else isodd(n - 1)
@TraceCalls()
def isodd(n):
return False if n == 0 else iseven(n - 1)
print(iseven(7))
Output:
iseven(7)
isodd(6)
iseven(5)
isodd(4)
iseven(3)
isodd(2)
iseven(1)
isodd(0)
False
The indentation level is shared between different functions – this is a key feature of the tracer. Note that the tracer is a class; while a function can also serve as a decorator, I find a class easier to reason about. Moreover, this tracer has some useful parameters to tweak and a decorator with arguments is much simpler to express with a class. Here are the parameters:
- stream: the stream to print tracing output to. By default it’s printed to sys.stdout.
- indent_step: by how many space chars to grow the indentation for each nested call.
- show_ret: when True, shows the return value of each call.
What follows is an example that demonstrates a less linear call sequence and also the usage of some of the parameters:
@TraceCalls(indent_step=4, show_ret=True)
def flatten(lst):
if isinstance(lst, list):
return sum((flatten(item) for item in lst), [])
else:
return [lst]
list(flatten([1, 2, [3, [4, 5], 6, [7, [9], 12]], 4, [6, 9]]))
Output:
flatten([1, 2, [3, [4, 5], 6, [7, [9], 12]], 4, [6, 9]])
flatten(1)
--> [1]
flatten(2)
--> [2]
flatten([3, [4, 5], 6, [7, [9], 12]])
flatten(3)
--> [3]
flatten([4, 5])
flatten(4)
--> [4]
flatten(5)
--> [5]
--> [4, 5]
flatten(6)
--> [6]
flatten([7, [9], 12])
flatten(7)
--> [7]
flatten([9])
flatten(9)
--> [9]
--> [9]
flatten(12)
--> [12]
--> [7, 9, 12]
--> [3, 4, 5, 6, 7, 9, 12]
flatten(4)
--> [4]
flatten([6, 9])
flatten(6)
--> [6]
flatten(9)
--> [9]
--> [6, 9]
--> [1, 2, 3, 4, 5, 6, 7, 9, 12, 4, 6, 9]
References:
- Python decorators
- Documentation of functools.wraps
- Thanks to Paul Butler for his tracing function. Parts of my tracer are inspired by his.
Related posts:
August 22nd, 2012 at 09:17
Perhaps it’s not a great idea to reset TraceCalls.cur_indent to 0 each time a TraceCalls is instantiated. The proposed will break if @TraceCalls() is used on a function defined within another function call.
But really, the idea of nested traces only makes sense if multiple functions share the same stream and indent size, so the following application makes more sense:
trace_calls = TraceCalls()
@trace_calls
def is_odd(…): …
@trace_calls
def is_odd(…): …
Since show_ret may be set differently for each wrapped function, you could offer the syntax:
@trace_calls.show_return
by modifying TraceCalls.__call__ to take a default show_ret=False argument, and defining TraceCalls.show_return as partial(__call__, show_ret=True)
August 22nd, 2012 at 22:33
Typo, need comma after ’4′:
@TraceCalls(indent_step=4, show_ret=True)
def flatten(lst):
… etc …
August 23rd, 2012 at 04:36
A N Owen,
Thanks, fixed.
August 23rd, 2012 at 11:10
Great tool! Thanks for publishing. Got me reading the documentation for
functools.wraps.August 23rd, 2012 at 20:44
Nice article!
Very useful. Already using it.
Thanks!
August 25th, 2012 at 14:02
Excellent tutorial. I think there is a lack of good understanding about how to write tracers, and those of us with the need for them all fumble a bit to learn the details. They aren’t as friendly as they could be, but abstractions like this make them a lot nicer.
I’ve been working on my own abstraction around the tracer system, called tracerlib.
http://tracerlib.readthedocs.org/en/latest/index.html