Tracing python code

published Nov 25, 2011 03:05   by admin ( last modified Jun 08, 2015 03:17 )

I have used this to figure out what is happening in complex pieces of software, such as Plone.

The hook is set via the sys.settrace() function. This takes a function which is called during any of several events. One is the "line" event. Before the interpreter executes a line it calls the trace function with the current frame and the string "line". (The function gets a third argument which is None; that fields is used by other events.

 

import sys
import linecache

def traceit(frame, event, arg):
    if event == "line":
        lineno = frame.f_lineno
        filename = frame.f_globals["__file__"]
        if (filename.endswith(".pyc") or
            filename.endswith(".pyo")):
            filename = filename[:-1]
        name = frame.f_globals["__name__"]
        line = linecache.getline(filename, lineno)
        print "%s:%s: %s" % (name, lineno, line.rstrip())
    return traceit

You start the tracing by calling the function defined above:

sys.settrace(traceit)

...and then your code follows.

Read more: Tracing python code, Tracing a Program As It Runs - Python Module of the Week

 

Here is a version I made some years ago, that probably works. It seems to track function calls:

def traceit(frame, event, arg):
    fo = open('/tmp/recur_log','a')
    if event != 'call':
        return
    co = frame.f_code
    func_name = co.co_name
    if func_name == 'write':
        # Ignore write() calls from print statements
        return
    func_line_no = frame.f_lineno
    func_filename = co.co_filename
    caller = frame.f_back
    caller_line_no = caller.f_lineno
    caller_filename = caller.f_code.co_filename
    fo.write(  'Call to %s on line %s of %s from line %s of %s\n' % (func_name, func_line_no, func_filename, caller_line_no, caller_filename))
    fo.close()
    return traceit

It doesn't seem to extract the module name though, can be done with:

name = frame.f_globals["__name__"]