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

[Guido van Rossum]

I think you need to go back farther in time. :-) In Python 2.0 the
call_trace function in ceval.c has a completely different signature
(but the docs are the same). I haven't checked all history but
somewhere between 2.0 and 2.3, SET_LINENO-less tracing was added, and
that's where the implementation must have gone wrong. So I think we
should fix the code.

--Guido

On Sat, Apr 30, 2011 at 3:49 PM, Ned Batchelder <ned at nedbatchelder.com> wrote:
> 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.
>
>
> _______________________________________________
> Python-Dev mailing list
> Python-Dev at python.org
> http://mail.python.org/mailman/listinfo/python-dev
> Unsubscribe:
> http://mail.python.org/mailman/options/python-dev/guido%40python.org
>
>



-- 
--Guido van Rossum (python.org/~guido)