[Python-Dev] sys.settrace: behavior doesn't match docs

[Ned Batchelder]

This week I learned something new about trace functions (how to write a 
C trace function that survives a sys.settrace(sys.gettrace()) 
round-trip), and while writing up what I learned, I was surprised to 
discover that trace functions don't behave the way I thought, or the way 
the docs say they behave.

The docs say:

    The trace function is invoked (with /event/ set to 'call') whenever
    a new local scope is entered; it should return a reference to a
    local trace function to be used that scope, or None if the scope
    shouldn't be traced.

    The local trace function should return a reference to itself (or to
    another function for further tracing in that scope), or None to turn
    off tracing in that scope.

It's that last part that's wrong: returning None from the trace function 
only has an effect on the first call in a new frame.  Once the trace 
function returns a function for a frame, returning None from subsequent 
calls is ignored.  A "local trace function" can't turn off tracing in 
its scope.

To demonstrate:

    import sys

    UPTO_LINE = 1

    def t(frame, event, arg):
         num = frame.f_lineno
         print("line %d" % num)
         if num < UPTO_LINE:
             return t

    def try_it():
         print("twelve")
         print("thirteen")
         print("fourteen")
         print("fifteen")

    UPTO_LINE = 1
    sys.settrace(t)
    try_it()

    UPTO_LINE = 13
    sys.settrace(t)
    try_it()

Produces:

    line 11
    twelve
    thirteen
    fourteen
    fifteen
    line 11
    line 12
    twelve
    line 13
    thirteen
    line 14
    fourteen
    line 15
    fifteen
    line 15

The first call to try_it() returns None immediately, preventing tracing 
for the rest of the function.  The second call returns None at line 13, 
but the rest of the function is traced anyway.  This behavior is the 
same in all versions from 2.3 to 3.2, in fact, the 100 lines of code in 
sysmodule.c responsible for Python tracing functions are completely 
unchanged through those versions.  (A deeper mystery that I haven't 
looked into yet is why Python 3.x intersperses all of these lines with 
"line 18" interjections.)

I'm writing this email because I'm not sure whether this is a behavior 
bug or a doc bug.  One of them is wrong, since they disagree.  The 
documented behavior makes sense, and is what people have all along 
thought the trace function did.  The actual behavior is a bit more 
complicated to explain, but is what people have actually been 
experiencing.  FWIW, PyPy implements the documented behavior.

Should we fix the code or the docs?  I'd be glad to supply a patch for 
either.

--Ned.


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/python-dev/attachments/20110430/33f7f201/attachment.html>