While working with Twisted and Nevow, I ran into a situation where something terribly nasty was happening well below any code I had written. Basically, I was faced with the classic high level development problem of “something I did long ago broke something deep within several layers of large scale systems I did not write”.
In these situations, a debugger does little good because there is little clue as to where things went awry. What I really needed was a way to trace execution.
It turns out that Python has excellent hooks for doing exactly that.
Add the following to any random hunk o’ code:
def traceit(frame, event, arg):
if event == 'line':
lineno = frame.f_lineno
if '__file__' in frame.f_globals:
filename = frame.f_globals['__file__']
if (filename.endswith('.pyc') or
filename = filename[:-1]
name = frame.f_globals['__name__']
line = linecache.getline(filename, lineno)
name = '[unknown]'
src = inspect.getsourcelines(frame)
line = src[lineno]
line = 'Unknown code named [%s]. VM instruction #%d' % \
print '%s:%s: %s' % (name, lineno, line.rstrip())
Then, to turn it on, call sys.settrace(). You can easily toggle the trace functionality, thus reducing the tracing to a very limited portion of the overall execution. This prevents one from drowning in data.
Note that the function has a frame object as an argument. That frame object allows for extremely deep introspection of the execution state, including variable state and just about anything else you would like to find out about the underlying virtual machine.
The original code was cribbed from the dalke scientific site. That article has an awesome explanation of the details of tracing. I just added some error checking and fallback code in the case where the original file/source cannot be determined. This enables the tracing functionality to work seamlessly within the context of Twisted.
It has already saved me a ton of time and I’m about to throw this permanently into my local Python library.