`PyMonitoring_FirePyStartEvent` results in incorrect duplicate calls to `sys.setprofile` profile functions

[godlygeek]

See bloomberg/memray#1037 and cython/cython#8032

The C API to programmatically trigger sys.monitoring events that was added in PR #116413 to solve issue #111997 and give Cython a way to trigger monitoring events for Cython frames does not work correctly with the legacy_tracing.c implementation of sys.setprofile profile functions.

When Cython uses sys.monitoring to signal that a Cython function has been entered, it creates a code object with PyCode_NewEmpty, sets a file name, function name, and line number for it, and then calls PyMonitoring_FirePyStartEvent. If there's a profile function that was installed by sys.setprofile, CPython's code in legacy_tracing.c registers an adapter callback that calls the sys.setprofile profile function. That adapter callback completely ignores the code object that is passed to it, and instead passes the sys.setprofile function the top frame of the Python stack, as returned by PyEval_GetFrame.

This interaction is completely broken: profilers installed by sys.setprofile never see the Cython frame, and instead see duplicates of the Python frame that called into Cython.

This could be fixed by CPython checking whether the code object that the monitoring callback receives is the code object held by the top frame of the Python stack, and refusing to call the tstate->c_profilefunc if not.

Or it could be fixed by CPython detecting that condition and creating a fake frame to pass to the c_profilefunc.

Or it could be fixed by Cython falling back to not using sys.monitoring whenever tstate->c_profilefunc is set.

I'm filing the issue against both CPython and Cython concurrently, in the hopes that if it's agreed this is a CPython bug the bugfix might get backported to 3.13 (which I think is, technically, getting one extra week of bug fix support, since 3.15.0 was delayed!)

[ZeroIntensity]

See #158748 (comment).

[ZeroIntensity]

Sorry! This one is legit. I was clicking through all the autogenerated issues and this one slipped in.

[godlygeek]

Here's a minimal reproducer for the issue, using ctypes to emulate what Cython does when a @cython.profile(True) function is called.

import ctypes
import sys

new_empty_code = ctypes.pythonapi.PyCode_NewEmpty
new_empty_code.argtypes = [ctypes.c_char_p, ctypes.c_char_p, ctypes.c_int]
new_empty_code.restype = ctypes.py_object

enter_scope = ctypes.pythonapi.PyMonitoring_EnterScope
enter_scope.argtypes = [ctypes.c_void_p, ctypes.POINTER(ctypes.c_uint64), ctypes.c_char_p, ctypes.c_ssize_t]
enter_scope.restype = ctypes.c_int

fire_py_start = ctypes.pythonapi._PyMonitoring_FirePyStartEvent
fire_py_start.argtypes = [ctypes.c_void_p, ctypes.py_object, ctypes.c_int32]
fire_py_start.restype = ctypes.c_int

fire_py_return = ctypes.pythonapi._PyMonitoring_FirePyReturnEvent
fire_py_return.argtypes = [ctypes.c_void_p, ctypes.py_object, ctypes.c_int32, ctypes.py_object]
fire_py_return.restype = ctypes.c_int

code = new_empty_code(b"ext.pyx", b"cython_function", 1)
states = ctypes.create_string_buffer(4)
version = ctypes.byref(ctypes.c_uint64(0))
start_state = states
return_state = ctypes.byref(states, 2)

def f():
    # Do what a Cython function compiled with profile=True does when called
    enter_scope(states, version, b"\0\2", 2)  # Events 0 and 2 are PY_START and PY_RETURN
    fire_py_start(start_state, code, 0)
    fire_py_return(return_state, code, 0, None)

sys.setprofile(lambda frame, event, arg: print(event, frame.f_code.co_name))
f()
sys.setprofile(None)

The output from running this is:

call f
call f
return f
return f
c_call <module>

Note that this indicates that f was called recursively and then returned twice, when in fact it's only entered once. Note also that cython_function is completely missing from the output. The last c_call is the call to sys.setprofile(None).