`sys._setprofileallthreads` race condition

[colesbury]

Bug report

There's a race on tstate->c_profilefunc if profiling is disable concurrently via sys._setprofileallthreads or threading.setprofile_all_threads or PyEval_SetProfileAllThreads.

cpython/Python/legacy_tracing.c

Lines 37 to 57 in 001461a

	static PyObject *
	call_profile_func(_PyLegacyEventHandler *self, PyObject *arg)
	{
	PyThreadState *tstate = _PyThreadState_GET();
	if (tstate->c_profilefunc == NULL) {
	Py_RETURN_NONE;
	}
	PyFrameObject *frame = PyEval_GetFrame();
	if (frame == NULL) {
	PyErr_SetString(PyExc_SystemError,
	"Missing frame when calling profile function.");
	return NULL;
	}
	Py_INCREF(frame);
	int err = tstate->c_profilefunc(tstate->c_profileobj, frame, self->event, arg);
	Py_DECREF(frame);
	if (err) {
	return NULL;
	}
	Py_RETURN_NONE;
	}

Repro

import sys
import threading

done = threading.Event()

def foo():
 pass

def my_profile(frame, event, arg):
 return None

def bg_thread():
 while not done.is_set():
 foo()
 foo()
 foo()
 foo()
 foo()
 foo()
 foo()
 foo()
 foo()
 foo()
 

def main():
 bg_threads = []
 for i in range(10):
 t = threading.Thread(target=bg_thread)
 t.start()
 bg_threads.append(t)

 for i in range(100):
 print(f"Iteration {i}")
 sys._setprofileallthreads(my_profile)
 sys._setprofileallthreads(None)

 done.set()
 for t in bg_threads:
 t.join()

 
if __name__ == "__main__":
 main()

Linked PRs

• gh-137400: Fix a crash when disabling profiling across all threads #137471
• gh-137400: Stop the world when swapping profile functions #137472
• gh-137400: Fix thread-safety issues when profiling all threads #137518
• [3.14] gh-137400: Fix a crash when disabling profiling across all threads (gh-137471) #137648
• [3.13] gh-137400: Fix a crash when disabling profiling across all threads (gh-137471) #137649
• [3.14] gh-137400: Fix thread-safety issues when profiling all threads (gh-137518) #137730
• [3.13] gh-137400: Fix thread-safety issues when profiling all threads (gh-137518) #137733

[colesbury]

cc @pablogsal

[xuantengh]

Seems like this could be fixed by adding LOCK_SETUP and UNLOCK_SETUP before and after C profile function calls to prevent concurrent modifications. If this approach is acceptable, I may raise an PR for that.

[colesbury]

Seems like this could be fixed by adding LOCK_SETUP and UNLOCK_SETUP before and after C profile function calls to prevent concurrent modifications. If this approach is acceptable, I may raise an PR for that.

No, we don't want to lock before every C profile function call. We need to refactor how we install/uninstall trace hooks.

[ZeroIntensity]

I see two options that shouldn't kill performance:

1. Switch c_profilefunc and c_profileobj reads and writes to atomic operations, and then load them each a single time in call_profile_func.
2. Use an RW lock for call_profile_func, where _PyEval_SetProfile has exclusive access.

Which do you think makes the most sense?

[colesbury]

I think the eventual goal should be to perform all the setup under:

1. A stop-the-world pause
2. HEAD_LOCK(runtime) for things like PyEval_SetProfileAllThreads that currently iterate over all threads. Currently the iteration is unsafe (even with the GIL) and may crash if a thread concurrently terminates.

That means we would need to refactor things so that:

1. _PySys_Audit calls happen outside the stop the world and lock
2. Any objects with non-trivial destructors get collected and decref'd only oustide the lock and stop-the world pause

Near term, we may want to consider a smaller change where we just add another stop-the-world pause around the modifications to tstate->c_tracefunc and similar.

[godlygeek]

Near term, we may want to consider a smaller change where we just add another stop-the-world pause around the modifications to tstate->c_tracefunc and similar.

This small patch seems to be enough to fix the crash in your reproducer (and in Memray, too!):

diff --git a/Python/legacy_tracing.c b/Python/legacy_tracing.c
index dbd19d7755c..0a0d231cb12 100644
--- a/Python/legacy_tracing.c
+++ b/Python/legacy_tracing.c
@@ -484,13 +484,19 @@ setup_profile(PyThreadState *tstate, Py_tracefunc func, PyObject *arg, PyObject
 }
 }

+ _PyEval_StopTheWorld(tstate->interp);
+
 int delta = (func != NULL) - (tstate->c_profilefunc != NULL);
 tstate->c_profilefunc = func;
 *old_profileobj = tstate->c_profileobj;
 tstate->c_profileobj = Py_XNewRef(arg);
 tstate->interp->sys_profiling_threads += delta;
 assert(tstate->interp->sys_profiling_threads >= 0);
- return tstate->interp->sys_profiling_threads;
+ Py_ssize_t ret = tstate->interp->sys_profiling_threads;
+
+ _PyEval_StartTheWorld(tstate->interp);
+
+ return ret;
 }

 int

But that pays the cost of a stop-the-world even if we're setting the profile function for our own attached thread state, and still accesses tstate->interp->sys_profile_initialized from a different thread without holding a lock... Maybe we need something more like this?

diff --git a/Python/legacy_tracing.c b/Python/legacy_tracing.c
index dbd19d7755c..4f08ed5c2af 100644
--- a/Python/legacy_tracing.c
+++ b/Python/legacy_tracing.c
@@ -439,12 +439,24 @@ is_tstate_valid(PyThreadState *tstate)
 #endif

 static Py_ssize_t
-setup_profile(PyThreadState *tstate, Py_tracefunc func, PyObject *arg, PyObject **old_profileobj)
+setup_profile(PyThreadState *tstate, Py_tracefunc func, PyObject *arg, PyObject **old_profileobj, int different_tstate)
 {
 *old_profileobj = NULL;
+
+ if (different_tstate) {
+ /* Stop the world: we're modifying another thread's thread state. */
+ _PyEval_StopTheWorld(tstate->interp);
+ }
+
 /* Setup PEP 669 monitoring callbacks and events. */
 if (!tstate->interp->sys_profile_initialized) {
 tstate->interp->sys_profile_initialized = true;
+
+ if (different_tstate) {
+ /* set_callbacks can't be called with the world stopped. */
+ _PyEval_StartTheWorld(tstate->interp);
+ }
+
 if (set_callbacks(PY_MONITORING_SYS_PROFILE_ID,
 sys_profile_start, PyTrace_CALL,
 PY_MONITORING_EVENT_PY_START,
@@ -482,6 +494,11 @@ setup_profile(PyThreadState *tstate, Py_tracefunc func, PyObject *arg, PyObject
 PY_MONITORING_EVENT_C_RAISE, -1)) {
 return -1;
 }
+
+ if (different_tstate) {
+ /* re-stop the world after set_callbacks. */
+ _PyEval_StopTheWorld(tstate->interp);
+ }
 }

 int delta = (func != NULL) - (tstate->c_profilefunc != NULL);
@@ -490,7 +507,13 @@ setup_profile(PyThreadState *tstate, Py_tracefunc func, PyObject *arg, PyObject
 tstate->c_profileobj = Py_XNewRef(arg);
 tstate->interp->sys_profiling_threads += delta;
 assert(tstate->interp->sys_profiling_threads >= 0);
- return tstate->interp->sys_profiling_threads;
+ Py_ssize_t ret = tstate->interp->sys_profiling_threads;
+
+ if (different_tstate) {
+ _PyEval_StartTheWorld(tstate->interp);
+ }
+
+ return ret;
 }

 int
@@ -510,7 +533,8 @@ _PyEval_SetProfile(PyThreadState *tstate, Py_tracefunc func, PyObject *arg)
 // needs to be decref'd outside of the lock
 PyObject *old_profileobj;
 LOCK_SETUP();
- Py_ssize_t profiling_threads = setup_profile(tstate, func, arg, &old_profileobj);
+ Py_ssize_t profiling_threads = setup_profile(
+ tstate, func, arg, &old_profileobj, tstate != current_tstate);
 UNLOCK_SETUP();
 Py_XDECREF(old_profileobj);

[colesbury]

I think the simpler change is probably okay for now, even at the cost of an extra stop-the-world pause.

Later on, I'll refactor it so that PyEval_SetProfileAllThreads stops the world once instead of 1xNTHREADS or 2xNTHREADS.

... and still accesses tstate->interp->sys_profile_initialized from a different thread without holding a lock

It's currently within a LOCK_SETUP() UNLOCK_SETUP() call, so I think it's okay.

[pablogsal]

I think the simpler change is probably okay for now, even at the cost of an extra stop-the-world pause.

Yeah I think this is fine as this happens only on setting/unsetting and is simpler to reason about. Maybe a bit trickier at finalization....