python - Tracing fIle path and line number

Question

I'm using python's trace module to trace some code. When I trace code this way, I can get one of the following two results:

Call:

tracer = trace.Trace(count=False, trace=True, ignoredirs=[sys.prefix, sys.exec_prefix])
r = tracer.run('run()')
tracer.results().write_results(show_missing=True)

Result:

<filename>(<line number>): <line of code>

Call [citation]:

tracer = trace.Trace(count=False, trace=True, ignoredirs=[sys.prefix, sys.exec_prefix], countfuncs=True)
r = tracer.run('run()')
tracer.results().write_results(show_missing=True)

Result:

filename:<filepath>, modulename:<module name>, funcname: <function name>

What I really need is a trace that gives me this:

<filepath> <line number>

It would seem that I could use the above information and interleave them to get what I need, but such an attempt would fail in the following use case:

• sys.path contains directory A and directory B.
• There are two files A/foo.py and B/foo.py
• Both A/foo.py and B/foo.py contain the function bar, defined on lines 100 - 120
• There are some minor differences between A/foo.py and B/foo.py

In this scenario, using such interleaving to correctly identifying which bar is called is impossible (please correct me if I'm wrong) without statically analyzing the code within each bar, which itself is very difficult for non-trivial functions.

So, how can I get the correct trace output that I need?

Answer 1

With a little monkey-patching, this is actually quite easy. Digging around in the source code of the trace module it seems that callbacks are used to report on each execution step. The basic functionality of Trace.run, greatly simplified, is:

sys.settrace(globaltrace)   # Set the trace callback function
exec function               # Execute the function, invoking the callback as necessary
sys.settrace(None)          # Reset the trace

globaltrace is defined in Trace.__init__ depending on the arguments passed. Specifically, with the arguments in your first example, Trace.globaltrace_lt is used as the global callback, which calls Trace.localtrace_trace for each line of execution. Changing it is simply a case of modifying Trace.localtrace, so to get the result you want:

import trace
import sys
import time
import linecache

class Trace(trace.Trace):
    def localtrace_trace(self, frame, why, arg):
        if why == "line":
            # record the file name and line number of every trace
            filename = frame.f_code.co_filename
            lineno = frame.f_lineno

            if self.start_time:
                print '%.2f' % (time.time() - self.start_time),
            print "%s (%d): %s" % (filename, lineno,
                                  linecache.getline(filename, lineno)),
        return self.localtrace


tracer = Trace(count=False, trace=True, ignoredirs=[sys.prefix, sys.exec_prefix])
r = tracer.run('run()')

There is a difference between the two examples you give; if the first the output is printed during the Trace.run call, in the second it is printed during write_results. The code I've given above follows the pattern of the former, so tracer.results().write_results() is not necessary. However, if you want to manipulate this output instead it can be achieved by patching the trace.CoverageResults.write_results method in a similar manner.