test_threading.test_4_daemon_threads() crash randomly

[vstinner]

On Linux, when I stress test test_threading.test_4_daemon_threads(), it does crash randomly:

./python -m test test_threading -m test_4_daemon_threads -j50 -F --fail-env-changed 

gdb traceback:

Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00000000006e02f4 in PyInterpreterState_ThreadHead (interp=0xdddddddddddddddd) at Python/pystate.c:1961

warning: Source file is more recent than executable.
1961	 return interp->threads.head;
[Current thread is 1 (Thread 0x7fcbb8ff96c0 (LWP 510515))]
Missing separate debuginfos, use: dnf debuginfo-install bzip2-libs-1.0.8-13.fc38.x86_64 glibc-2.37-5.fc38.x86_64 libffi-3.4.4-2.fc38.x86_64 libgcc-13.2.1-1.fc38.x86_64 openssl-libs-3.0.9-2.fc38.x86_64 xz-libs-5.4.1-1.fc38.x86_64 zlib-1.2.13-3.fc38.x86_64
(gdb) where
#0 0x00000000006e02f4 in PyInterpreterState_ThreadHead (interp=0xdddddddddddddddd) at Python/pystate.c:1961
#1 0x0000000000703090 in _Py_DumpTracebackThreads (fd=2, interp=0xdddddddddddddddd, current_tstate=0x24a34e0) at Python/traceback.c:1331
#2 0x000000000071bcef in faulthandler_dump_traceback (fd=2, all_threads=1, interp=0xa53688 <_PyRuntime+92712>) at ./Modules/faulthandler.c:195
#3 0x000000000071bfed in faulthandler_fatal_error (signum=11) at ./Modules/faulthandler.c:313
#4 <signal handler called>
#5 0x000000000069f808 in take_gil (tstate=0x24a34e0) at Python/ceval_gil.c:360
#6 0x00000000006a03ab in PyEval_RestoreThread (tstate=0x24a34e0) at Python/ceval_gil.c:714
#7 0x000000000074dd93 in portable_lseek (self=0x7fcc186c3590, posobj=0x0, whence=1, suppress_pipe_error=false) at ./Modules/_io/fileio.c:934
#8 0x000000000074de88 in _io_FileIO_tell_impl (self=0x7fcc186c3590) at ./Modules/_io/fileio.c:997
#9 0x000000000074ea4c in _io_FileIO_tell (self=0x7fcc186c3590, _unused_ignored=0x0) at ./Modules/_io/clinic/fileio.c.h:460
(...)

gdb debug:

(gdb) frame 5
#5 0x000000000069f808 in take_gil (tstate=0x24a34e0) at Python/ceval_gil.c:360
360	 struct _gil_runtime_state *gil = ceval->gil;
(gdb) l
355	 }
356	
357	 assert(_PyThreadState_CheckConsistency(tstate));
358	 PyInterpreterState *interp = tstate->interp;
359	 struct _ceval_state *ceval = &interp->ceval;
360	 struct _gil_runtime_state *gil = ceval->gil;
361	
362	 /* Check that _PyEval_InitThreads() was called to create the lock */
363	 assert(gil_created(gil));
364	

(gdb) p /x ceval
$1 = 0xdddddddddddddddd

(gdb) p /x tstate->interp
$2 = 0xdddddddddddddddd


(gdb) p /x tstate
$5 = 0x24a34e0

(gdb) p /x _PyRuntime._finalizing._value 
$3 = 0xab8fa8

(gdb) p /x _PyRuntime._finalizing_id 
$4 = 0x7fcc49fce740

I don't understand why the test didn't exit: _PyThreadState_MustExit() should return, no?

I don't understand why assert(_PyThreadState_CheckConsistency(tstate)); didn't fail.

Maybe Py_Finalize() was called between the pre-check:

 if (_PyThreadState_MustExit(tstate)){
 /* bpo-39877: If Py_Finalize() has been called and tstate is not the
 thread which called Py_Finalize(), exit immediately the thread.

 This code path can be reached by a daemon thread after Py_Finalize()
 completes. In this case, tstate is a dangling pointer: points to
 PyThreadState freed memory. */
 PyThread_exit_thread();
 }

 assert(_PyThreadState_CheckConsistency(tstate));

and the code:

 PyInterpreterState *interp = tstate->interp;
 struct _ceval_state *ceval = &interp->ceval;
 struct _gil_runtime_state *gil = ceval->gil;

Linked PRs

• gh-110052: Fix faulthandler for freed tstate #110069
• [3.12] gh-110052: Fix faulthandler for freed tstate (#110069) #110071
• [3.11] gh-110052: Fix faulthandler for freed tstate (#110069) #110072

[vstinner]

See also issue gh-110031 which looks similar.

[vstinner]

The regression was introduced by PR gh-109794: #109794 (comment)

[ericsnowcurrently]

I'm looking into this.

./python -m test test_threading -m test_4_daemon_threads -j50 -F --fail-env-changed

I haven't been able to get a crash in over 16 minutes (but I certainly believe you).

[vstinner]

I haven't been able to get a crash in over 16 minutes (but I certainly believe you).

What is your operating system? I reproduced the crash on Linux. I didn't try other operating systems.

If you want to make daemon threads crashes more likely, add sleep(1) at the end of PyInterpreterState_Delete(), after free_interpreter().

[ericsnowcurrently]

What is your operating system? I reproduced the crash on Linux. I didn't try other operating systems.

It's an 8-core, 24GB RAM Hyper-V Ubuntu VM running on a Windows laptop.

If you want to make daemon threads crashes more likely, add sleep(1) at the end of PyInterpreterState_Delete(), after free_interpreter().

I'll try it.

[ericsnowcurrently]

gdb traceback:
,,,
gdb debug:
...
I don't understand why the test didn't exit: _PyThreadState_MustExit() should return, no?

Yeah, that's the critical question.

[ericsnowcurrently]

Here's the critical part from gh-109794:

diff --git a/Python/pystate.c b/Python/pystate.c
index dcc6c112215b3..570b5242600c0 100644
--- a/Python/pystate.c
+++ b/Python/pystate.c
@@ -2964,11 +2964,26 @@ _PyThreadState_MustExit(PyThreadState *tstate)
 tstate->interp->runtime to support calls from Python daemon threads.
 After Py_Finalize() has been called, tstate can be a dangling pointer:
 point to PyThreadState freed memory. */
+ unsigned long finalizing_id = _PyRuntimeState_GetFinalizingID(&_PyRuntime);
 PyThreadState *finalizing = _PyRuntimeState_GetFinalizing(&_PyRuntime);
 if (finalizing == NULL){
+ // XXX This isn't completely safe from daemon thraeds,
+ // since tstate might be a dangling pointer.
 finalizing = _PyInterpreterState_GetFinalizing(tstate->interp);
+ finalizing_id = _PyInterpreterState_GetFinalizingID(tstate->interp);
 }
- return (finalizing != NULL && finalizing != tstate);
+ // XXX else check &_PyRuntime._main_interpreter._initial_thread
+ if (finalizing == NULL){
+ return 0;
+ }
+ else if (finalizing == tstate){
+ return 0;
+ }
+ else if (finalizing_id == PyThread_get_thread_ident()){
+ /* gh-109793: we must have switched interpreters. */
+ return 0;
+ }
+ return 1;
 }

The most obvious possibility is that we switched to a different thread state during finalization in the thread where finalization is happening and the thread state belongs to the same interpreter. However, that isn't an expected use case for PyThread_Swap() and I'm pretty sure we don't have any code that does that.

[ericsnowcurrently]

If you want to make daemon threads crashes more likely, add sleep(1) at the end of PyInterpreterState_Delete(), after free_interpreter().

I'll try it.

No failures in 13 minutes.

[vstinner]

No failures in 13 minutes.

How do you build Python? Which configure options?

I'm usually using ./configure --with-pydebug to get assertions.

[ericsnowcurrently]

Basically: ./configure --with-pydebug CFLAGS=-O0

[ericsnowcurrently]

Is this issue tied to any buildbot/CI failures?

[terryjreedy]

6/12 core Win 10, standard PCBuild/build.bat -d

...
0:00:31 load avg: 76.65 [ 87/1] test_threading failed (1 failure)
test test_threading failed -- Traceback (most recent call last):
 File "f:\dev\3x\Lib\test\test_threading.py", line 1172, in test_4_daemon_threads
 rc, out, err = assert_python_ok('-c', script)
 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
 File "f:\dev\3x\Lib\test\support\script_helper.py", line 166, in assert_python_ok
 return _assert_python(True, *args, **env_vars)
 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
 File "f:\dev\3x\Lib\test\support\script_helper.py", line 151, in _assert_python
 res.fail(cmd_line)
 File "f:\dev\3x\Lib\test\support\script_helper.py", line 76, in fail
 raise AssertionError("Process return code is %d\n"
AssertionError: Process return code is 3221225477
command line: ['f:\\dev\\3x\\PCbuild\\amd64\\python_d.exe', '-X', 'faulthandler', '-c', "if True:\n import os\n import random\n import sys\n import time\n import threading\n\n thread_has_run = set()\n\n def random_io():\n '''Loop for a while sleeping random tiny amounts and doing some I/O.'''\n import test.test_threading as mod\n while True:\n with open(mod.__file__, 'rb') as in_f:\n stuff = in_f.read(200)\n with open(os.devnull, 'wb') as null_f:\n null_f.write(stuff)\n time.sleep(random.random() / 1995)\n thread_has_run.add(threading.current_thread())\n\n def main():\n count = 0\n for _ in range(40):\n new_thread = threading.Thread(target=random_io)\n new_thread.daemon = True\n new_thread.start()\n count += 1\n while len(thread_has_run) < count:\n time.sleep(0.001)\n # Trigger process shutdown\n sys.exit(0)\n\n main()\n "]

stdout:
---

---

stderr:
---
Windows fatal exception: access violation