Recipe8.5.Tracing Expressions and Comments in Debug Mode

Recipe 8.5. Tracing Expressions and Comments in Debug Mode

Credit: Olivier Dagenais

Problem

You are coding a program that cannot use an interactive, step-by-step debugger. Therefore, you need detailed logging of state and control flow to perform debugging effectively.

Solution

The extract_stack function from the TRaceback module is the key here because it lets your debugging code easily perform runtime introspection to find out about the code that called it:

import sys, traceback traceOutput = sys.stdout watchOutput = sys.stdout rawOutput = sys.stdout # calling 'watch(secretOfUniverse)' prints out something like: # File "trace.py", line 57, in _ _testTrace #    secretOfUniverse <int> = 42 watch_format = ('File "%(fileName)s", line %(lineNumber)d, in'                  ' %(methodName)s\n   %(varName)s <%(varType)s>'                  ' = %(value)s\n\n') def watch(variableName):     if _ _debug_ _:         stack = traceback.extract_stack( )[-2:][0]         actualCall = stack[3]         if actualCall is None:             actualCall = "watch([unknown])"         left = actualCall.find('(')         right = actualCall.rfind(')')         paramDict = dict(varName=actualCall[left+1:right]).strip( ),                          varType=str(type(variableName))[7:-2],                          value=repr(variableName),                          methodName=stack[2],                          lineNumber=stack[1],                          fileName=stack[0])         watchOutput.write(watch_format % paramDict) # calling 'trace("this line was executed")' prints out something like: # File "trace.py", line 64, in ? #    this line was executed trace_format = ('File "%(fileName)s", line %(lineNumber)d, in'                  ' %(methodName)s\n   %(text)s\n\n') def trace(text):     if _ _debug_ _:         stack = traceback.extract_stack( )[-2:][0]         paramDict = dict(text=text,                          methodName=stack[2],                          lineNumber=stack[1],                          fileName=stack[0])         watchOutput.write(trace_format % paramDict) # calling 'raw("some raw text")' prints out something like: # Just some raw text def raw(text):     if _ _debug_ _:         rawOutput.write(text)

Discussion

Many of the different kinds of programs one writes today don't make it easy to use traditional, interactive step-by-step debuggers. Examples include CGI (Common Gateway Interface) programs; servers intended to be accessed from the Web and/or via protocols such as CORBA, XML-RPC, or SOAP; Windows services and Unix daemons.

You can remedy this lack of interactive debugging by sprinkling a bunch of print statements all through the program, but this approach is unsystematic and requires cleanup when a given problem is fixed. This recipe shows that a better-organized approach is quite feasible, by supplying a few functions that allow you to output the value of an expression, a variable, or a function call, with scope information, trace statements, and general comments.

The key is the extract_stack function from the TRaceback module. traceback.extract_stack returns a list of tuples with four itemsproviding the filename, line number, function name, and source code of the calling statementfor each call in the stack. Item [-2] (the penultimate item) of this list is the tuple of information about our direct caller, and that's the one we use in this recipe to prepare the information to emit on file-like objects bound to the traceOutput and watchOutput variables.

If you bind the traceOutput, watchOutput, or rawOutput variables to an appropriate file-like object, each kind of output is redirected appropriately. When _ _debug_ _ is false (i.e., when you run the Python interpreter with the -O or -OO switch), all the debugging-related code is automatically eliminated. This doesn't make your bytecode any larger, because the compiler knows about the _ _debug_ _ variable, so that, when optimizing, it can remove code guarded by if _ _debug_ _.

Here is a usage example, leaving all output streams on standard output, in the form we'd generally use to make such a module self-testing, by appending the example at the end of the module:

def _ _testTrace( ):     secretOfUniverse = 42     watch(secretOfUniverse) if _ _name_ _ == "_ _main_ _":     a = "something else"     watch(a)     _ _testTrace( )     trace("This line was executed!")     raw("Just some raw text...")

When run with just python (no -O switch), this code emits:

File "trace.py", line 61, in ?   a <str> = 'something else' File "trace.py", line 57, in _ _testTrace   secretOfUniverse <int> = 42 File "trace.py", line 64, in ?   This line was executed! Just some raw text...

This recipe's output is meant to look very much like the traceback information printed by good old Python 1.5.2 while being compatible with any version of Python. It's easy to modify the format strings to your liking, of course.

Recipe8.5.Tracing Expressions and Comments in Debug Mode