CODEWITHSUNDEEP
pythondebuggingtrace
Don Kirkby
Don Kirkby

Reputation: 56620

Code object has unexpected file name during import when using sys.settrace()

I'm trying to write a program that will trace through Python code and print a report of changes to local variable values. I've got it working well with simple assignments, loops, and function calls, but I'm having problems when I use an import statement.

I only want to trace code in the main module, I want to stop tracing as soon as it calls into the imported module. I can do this when I import a simple module that I wrote, and I just stop tracing when the frame's code object points to a different file.

This doesn't work, though, when I try to import the decimal module. I can eliminate most of the code that's running in the decimal module, but I have one call to a code block called DecimalTuple that claims to be running in the main module. That doesn't make any sense, though, because the line numbers don't exist in that module.

Are there some other attributes on the frame or code objects that I can use to tell that DecimalTuple isn't in the main module? Obviously, I could add a special case for DecimalTuple, but that won't help me if other modules have the same problem.

Here's my example. It executes the quoted code and traces the calls with settrace(). If you comment out the first two lines of global_trace() it will also display all the code that executes in the other modules.

import sys

class tracer:

    count = 0

    def __init__(self):
        self.index = tracer.count = tracer.count + 1

    def global_trace(self, frame, event, arg):
        if frame.f_code.co_filename != '<string>':
            return
        print 'global %d, line %d: %s, %s' % (self.index,
                                         frame.f_lineno,
                                         event,
                                         frame.f_code)
        return tracer().local_trace

    def local_trace(self, frame, event, arg):
        print 'local %d, line %d: %s, %s' % (self.index,
                                         frame.f_lineno,
                                         event,
                                         frame.f_code)
        return self.local_trace

code = """\
def foo(r):
    return r + 3

y = foo(2)

import decimal

x = decimal.Decimal('10')
"""

sys.settrace(tracer().global_trace)

exec code in dict()

Here is the trace output. You can see that the call to foo() and its execution are all in the <string> module that represents the string of code I passed in as the main module. However, when it gets to the import statement on line 6, it starts calling code that can't possibly be in the <string> module.

global 1, line 1: call, <code object <module> at 0x266a030, file "<string>", line 1>
local 2, line 1: line, <code object <module> at 0x266a030, file "<string>", line 1>
local 2, line 4: line, <code object <module> at 0x266a030, file "<string>", line 1>
global 1, line 1: call, <code object foo at 0x266a730, file "<string>", line 1>
local 3, line 2: line, <code object foo at 0x266a730, file "<string>", line 1>
local 3, line 2: return, <code object foo at 0x266a730, file "<string>", line 1>
local 2, line 6: line, <code object <module> at 0x266a030, file "<string>", line 1>
global 1, line 1: call, <code object <module> at 0x27c2130, file "<string>", line 1>
local 4, line 1: line, <code object <module> at 0x27c2130, file "<string>", line 1>
global 1, line 1: call, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 1: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 2: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 4: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 6: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 8: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 12: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 13: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 20: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 24: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 28: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 30: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 37: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 41: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 42: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 43: line, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 5, line 43: return, <code object DecimalTuple at 0x27c21b0, file "<string>", line 1>
local 4, line 1: return, <code object <module> at 0x27c2130, file "<string>", line 1>
local 2, line 8: line, <code object <module> at 0x266a030, file "<string>", line 1>
local 2, line 8: return, <code object <module> at 0x266a030, file "<string>", line 1>

Upvotes: 2

Views: 211

Answers (1)

Nick Bastin
Nick Bastin

Reputation: 31319

This happens, as it turns out, because collections.namedtuple does some very hinky things (and DecimalTuple is a namedtuple, so your call to import decimal subsequently calls this code). As it happens, around line 300 in collections.py (in Python 2.7 at least - your line number may vary in different versions), you will see a comment that says:

# Execute the template string in a temporary namespace and
# support tracing utilities by setting a value for frame.f_globals['__name__']

The code after this causes your tracer to misinterpret what it is observing - because the template to create the class is done using exec itself, there is more code executed in the <string> "file", just not your <string>.

Upvotes: 2

Related Questions