TSAN failure with free-threaded build, test_daemon_threads_fatal_error

[nascheme]

Bug report

Bug description:

It seems this unit test started failing after GH-140111. Build with the following configure options: ./configure --with-thread-sanitizer --with-pydebug --disable-gil.

Command to trigger the failure (doesn't happen every run).

./python -m test test_threading -m test_daemon_threads_fatal_error

The console output from a failed run:

./python -m test test_threading -m test_daemon_threads_fatal_error
Using random seed: 3327068419
0:00:00 load avg: 2.84 Run 1 test sequentially in a single process
0:00:00 load avg: 2.84 [1/1] test_threading
test test_threading failed -- Traceback (most recent call last):
  File "/home/nas/src/cpython/Lib/test/test_threading.py", line 1801, in test_daemon_threads_fatal_error
    self._inner()
    ~~~~~~~~~~~^^
  File "/home/nas/src/cpython/Lib/test/test_threading.py", line 1796, in _inner
    assert_python_ok("-c", script)
    ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^
  File "/home/nas/src/cpython/Lib/test/support/script_helper.py", line 182, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "/home/nas/src/cpython/Lib/test/support/script_helper.py", line 167, in _assert_python
    res.fail(cmd_line)
    ~~~~~~~~^^^^^^^^^^
  File "/home/nas/src/cpython/Lib/test/support/script_helper.py", line 80, in fail
    raise AssertionError(f"Process return code is {exitcode}\n"
    ...<10 lines>...
                         f"---")
AssertionError: Process return code is 66
command line: ['/home/nas/src/cpython/python', '-X', 'faulthandler', '-I', '-c', "if 1:\n            import _testcapi\n\n            _testcapi.run_in_subinterp('if 1:\\n            import os\\n            import threading\\n            import time\\n\\n            def f():\\n                # Make sure the daemon thread is still running when\\n                # Py_EndInterpreter is called.\\n                time.sleep(30.0)\\n            threading.Thread(target=f, daemon=True).start()\\n            ')\n            "]

stdout:
---

---

stderr:
---
==================
WARNING: ThreadSanitizer: data race (pid=2411975)
  Write of size 8 at 0x7f082bd42050 by main thread:
    #0 memset ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors_memintrinsics.inc:87 (libtsan.so.2+0x8412b) (BuildId: 4bf16ac194a27034832a03e77e518636fcad2b4e)
    #1 memset ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors_memintrinsics.inc:85 (libtsan.so.2+0x8412b)
    #2 fill_mem_debug Objects/obmalloc.c:2825 (python+0x2236e6) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #3 _PyMem_DebugRawFree Objects/obmalloc.c:2954 (python+0x223c17) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #4 PyMem_RawFree Objects/obmalloc.c:1023 (python+0x23eb48) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #5 free_interpreter Python/pystate.c:487 (python+0x4390e8) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #6 PyInterpreterState_Delete Python/pystate.c:965 (python+0x43bff6) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #7 finalize_interp_delete Python/pylifecycle.c:1963 (python+0x434511) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #8 Py_EndInterpreter Python/pylifecycle.c:2585 (python+0x436bb6) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #9 run_in_subinterp Modules/_testcapimodule.c:1224 (_testcapi.cpython-315td-x86_64-linux-gnu.so+0x1c63a) (BuildId: 4a8d5a43c74f1a1cbb285af9ec96499ca8113f97)
    #10 cfunction_call Objects/methodobject.c:575 (python+0x210755) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #11 _PyObject_MakeTpCall Objects/call.c:242 (python+0x189c96) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #12 _PyObject_VectorcallTstate Include/internal/pycore_call.h:167 (python+0x189eff) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #13 PyObject_Vectorcall Objects/call.c:327 (python+0x189fb2) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #14 _PyEval_EvalFrameDefault Python/generated_cases.c.h:1620 (python+0x35e501) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #15 _PyEval_EvalFrame Include/internal/pycore_ceval.h:121 (python+0x3909e1) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #16 _PyEval_Vector Python/ceval.c:2001 (python+0x390c3d) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #17 PyEval_EvalCode Python/ceval.c:884 (python+0x390d85) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #18 run_eval_code_obj Python/pythonrun.c:1365 (python+0x43fd2a) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #19 run_mod Python/pythonrun.c:1459 (python+0x43ffaf) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #20 _PyRun_StringFlagsWithName Python/pythonrun.c:1259 (python+0x440a78) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #21 _PyRun_SimpleStringFlagsWithName Python/pythonrun.c:578 (python+0x442b46) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #22 pymain_run_command Modules/main.c:261 (python+0x47a8aa) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #23 pymain_run_python Modules/main.c:682 (python+0x47b99c) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #24 Py_RunMain Modules/main.c:772 (python+0x47be56) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #25 pymain_main Modules/main.c:802 (python+0x47beea) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #26 Py_BytesMain Modules/main.c:826 (python+0x47bffb) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #27 main Programs/python.c:15 (python+0x97b87) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)

  Previous read of size 8 at 0x7f082bd42050 by thread T1:
    #0 drop_gil Python/ceval_gil.c:229 (python+0x3ea73c) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #1 _PyEval_ReleaseLock Python/ceval_gil.c:598 (python+0x3ebc38) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #2 detach_thread Python/pystate.c:2154 (python+0x43a264) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #3 _PyThreadState_Detach Python/pystate.c:2160 (python+0x43be92) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #4 PyEval_SaveThread Python/ceval_gil.c:642 (python+0x3ebe1b) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #5 pysleep Modules/timemodule.c:2255 (python+0x525e87) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #6 time_sleep Modules/timemodule.c:408 (python+0x525f93) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #7 cfunction_vectorcall_O Objects/methodobject.c:536 (python+0x20fbb5) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #8 _PyObject_VectorcallTstate Include/internal/pycore_call.h:169 (python+0x189e6c) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #9 PyObject_Vectorcall Objects/call.c:327 (python+0x189fb2) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #10 _PyEval_EvalFrameDefault Python/generated_cases.c.h:1620 (python+0x35e501) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #11 _PyEval_EvalFrame Include/internal/pycore_ceval.h:121 (python+0x3909e1) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #12 _PyEval_Vector Python/ceval.c:2001 (python+0x390c3d) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #13 _PyFunction_Vectorcall Objects/call.c:413 (python+0x189a3e) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #14 _PyObject_VectorcallTstate Include/internal/pycore_call.h:169 (python+0x18df70) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #15 method_vectorcall Objects/classobject.c:73 (python+0x18e263) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #16 _PyObject_VectorcallTstate Include/internal/pycore_call.h:169 (python+0x3bafb7) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #17 context_run Python/context.c:728 (python+0x3bb0cf) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #18 method_vectorcall_FASTCALL_KEYWORDS Objects/descrobject.c:421 (python+0x1a1b1e) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #19 _PyObject_VectorcallTstate Include/internal/pycore_call.h:169 (python+0x189e6c) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #20 PyObject_Vectorcall Objects/call.c:327 (python+0x189fb2) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #21 _PyEval_EvalFrameDefault Python/generated_cases.c.h:1620 (python+0x35e501) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #22 _PyEval_EvalFrame Include/internal/pycore_ceval.h:121 (python+0x3909e1) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #23 _PyEval_Vector Python/ceval.c:2001 (python+0x390c3d) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #24 _PyFunction_Vectorcall Objects/call.c:413 (python+0x189a3e) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #25 _PyObject_VectorcallTstate Include/internal/pycore_call.h:169 (python+0x18df70) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #26 method_vectorcall Objects/classobject.c:73 (python+0x18e263) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #27 _PyVectorcall_Call Objects/call.c:273 (python+0x18bc68) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #28 _PyObject_Call Objects/call.c:348 (python+0x18bfb1) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #29 PyObject_Call Objects/call.c:373 (python+0x18c011) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #30 thread_run Modules/_threadmodule.c:387 (python+0x522baa) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #31 pythread_wrapper Python/thread_pthread.h:234 (python+0x462551) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)

  Location is heap block of size 249119 at 0x7f082bd42000 allocated by main thread:
    #0 calloc ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:698 (libtsan.so.2+0x827ef) (BuildId: 4bf16ac194a27034832a03e77e518636fcad2b4e)
    #1 _PyMem_RawCalloc Objects/obmalloc.c:77 (python+0x2208a4) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #2 _PyMem_DebugRawAlloc Objects/obmalloc.c:2884 (python+0x2237e7) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #3 _PyMem_DebugRawCalloc Objects/obmalloc.c:2929 (python+0x22397d) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #4 PyMem_RawCalloc Objects/obmalloc.c:1009 (python+0x23dd8a) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #5 alloc_interpreter Python/pystate.c:465 (python+0x438b70) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #6 _PyInterpreterState_New Python/pystate.c:663 (python+0x43a900) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #7 new_interpreter Python/pylifecycle.c:2425 (python+0x437433) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #8 Py_NewInterpreter Python/pylifecycle.c:2530 (python+0x437b2b) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #9 run_in_subinterp Modules/_testcapimodule.c:1214 (_testcapi.cpython-315td-x86_64-linux-gnu.so+0x1c611) (BuildId: 4a8d5a43c74f1a1cbb285af9ec96499ca8113f97)
    #10 cfunction_call Objects/methodobject.c:575 (python+0x210755) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #11 _PyObject_MakeTpCall Objects/call.c:242 (python+0x189c96) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #12 _PyObject_VectorcallTstate Include/internal/pycore_call.h:167 (python+0x189eff) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #13 PyObject_Vectorcall Objects/call.c:327 (python+0x189fb2) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #14 _PyEval_EvalFrameDefault Python/generated_cases.c.h:1620 (python+0x35e501) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #15 _PyEval_EvalFrame Include/internal/pycore_ceval.h:121 (python+0x3909e1) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #16 _PyEval_Vector Python/ceval.c:2001 (python+0x390c3d) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #17 PyEval_EvalCode Python/ceval.c:884 (python+0x390d85) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #18 run_eval_code_obj Python/pythonrun.c:1365 (python+0x43fd2a) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #19 run_mod Python/pythonrun.c:1459 (python+0x43ffaf) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #20 _PyRun_StringFlagsWithName Python/pythonrun.c:1259 (python+0x440a78) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #21 _PyRun_SimpleStringFlagsWithName Python/pythonrun.c:578 (python+0x442b46) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #22 pymain_run_command Modules/main.c:261 (python+0x47a8aa) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #23 pymain_run_python Modules/main.c:682 (python+0x47b99c) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #24 Py_RunMain Modules/main.c:772 (python+0x47be56) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #25 pymain_main Modules/main.c:802 (python+0x47beea) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #26 Py_BytesMain Modules/main.c:826 (python+0x47bffb) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)
    #27 main Programs/python.c:15 (python+0x97b87) (BuildId: d60894373dd47029a049d3cae6ed7d163f468e09)

CPython versions tested on:

CPython main branch

Operating systems tested on:

Linux

[ZeroIntensity]

Let's revert #140111 in the meantime.

[kumaraditya303]

The issue is in the test itself, the tests runs a daemon thread with sleep() which releases the GIL however it is possible that by the time that runs the interpreter state is already freed so tsan reports it as data race with drop_gil and free_interpreter.

Currently the test works because the interpreter state is leaked, but that needs to be fixed. Also the test was recently changed in a648813 and previously a crash was expected.

[kumaraditya303]

I think this needs a similar fix as #130649 which is to add reference counting to interpreter states so that the interpreter state cannot be free prematurely before daemon threads are hung.

cc @colesbury

[ashm-dev]

@kumaraditya303 So, there's no need to look for ways to fix this data race, and my (our) fix is correct?

[kumaraditya303]

Yes, our fix was correct but it exposed another race at shutdown which needs to fixed first