Change in profiler behaviour in CPython 3.10

[joerick]

Hello there! I noticed something in the unit tests for pyinstrument while adding CPython 3.10. Here's a script:

import greenlet
import sys

def greenlet_profiler():
    def dummy_profiler(frame, what, arg):
        if what == 'call':
            print(frame)
        if what == 'c_call':
            print(arg)

    sys.setprofile(dummy_profiler)

    def x():
        pass

    x()
    greenlet.greenlet(x).switch()

    sys.setprofile(None)

if __name__ == '__main__':
    greenlet_profiler()

If you run this code on Python 3.9, you get this:

$ env/bin/python3.9 private/greenlet_test.py
<frame at 0x7faf0d535c50, file '/Users/joerick/Projects/pyinstrument/private/greenlet_test.py', line 41, code x>
<built-in method switch of greenlet.greenlet object at 0x1095569e0>
<frame at 0x7faf0d535c50, file '/Users/joerick/Projects/pyinstrument/private/greenlet_test.py', line 41, code x>
<built-in function setprofile>

On CPython 3.10.0rc1, this is the output:

$ python private/greenlet_test.py      
<frame at 0x10dff7240, file '/Users/joerick/Projects/pyinstrument/private/greenlet_test.py', line 41, code x>
<built-in method switch of greenlet.greenlet object at 0x10e179d20>
<built-in function setprofile>

What's interesting is that on 3.10, a profiler that's started outside the greenlet doesn't get to 'see' inside the greenlet that it switches to. It sees only the greenlet.switch. That's a change from 3.9 and before.

I was wondering if this was an expected change? It's not necessarily an issue per-se, pyinstrument doesn't officially support greenlet anyway, so I'm not complaining, just curious if this change in behaviour is likely to be permanent.

[jamadden]

Thanks for the report!

This is an issue with how greenlet is handling python/cpython#25276 from 3.10 beta1+. A fix that works (defined as "3.10rc1 produces the same output as 3.9") is to change green_new to copy the current use_tracing value, though it's not 100% clear to me that this is obviously correct:

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
modified: src/greenlet/greenlet.c
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
@@ -922,6 +923,7 @@ green_new(PyTypeObject* type, PyObject* args, PyObject* kwds)
         ((PyGreenlet*)o)->parent = ts_current;
 #if GREENLET_USE_CFRAME
         ((PyGreenlet*)o)->cframe = &PyThreadState_GET()->root_cframe;
+        ((PyGreenlet*)o)->cframe->use_tracing = PyThreadState_GET()->cframe->use_tracing;
 #endif
     }
     return o;

Possibly that should be the cframe->use_tracing of the parent greenlet, but it doesn't always have one. (And if that's the right decision, should assigning to glet.parent also make the copy? Probably not.)

This does clarify that we could use some better tests of our interaction with tracing events.

[jamadden]

Possibly that should be the cframe->use_tracing of the parent greenlet, but it doesn't always have one. (And if that's the right decision, should assigning to glet.parent also make the copy? Probably not.)

Yeah, so a big no on both of those. The cframe in question could be an ephemeral object located on the C stack. We can't link that into a linked list that could have longer dynamic lifetime.

The problem with the proposed solution above is that it boils down to essentially PyThreadState_GET()->root_cframe->use_tracing = <some value>. The root_cframe is a shared structure that serves as the base of the eval tree for all evaluations that happen in the current thread. Could there ever be more than one? That is, is it really an eval forest instead of a tree? AFAICS, no, I don't think so, at least not in CPython core (it's noted that the CFrame objects must be treated with careful "stack discipline", so switching between different subtrees is not really imagined in the CPython implementation). At most, setting that value to 1 might slow down the interpreter some, reverting the speedup from the python/cpython#25276. Still, the root_cframe is not intended to be modified, even if execution never actually uses that as its cframe, so it would be best to avoid modifying it.

That leaves us either creating our own new root_cframe we can mutate at will and use as the CFrame root for a greenlet, or, possibly, performing a check and setting use_tracing on switching greenlets.

[jamadden]

4287a40 fixed the problem demonstrated in this example, but as 7eee763 demonstrates, that simple, cheap solution doesn't fix all the cases, not by a longshot. To handle those I think we may wind up having to do switch-time checks.

[joerick]

Hey @jamadden, thanks! I can't say that I fully followed the solution, but I appreciate the updates :). By the way, mad props on having a library that's heavily used by 81,000 projects(!) and you're only up to 259 issues. You must be doing something right :)

[joerick]

I can confirm that in the latest release of Greenlet, Python 3.10 behaviour matches previous versions 👍