TSan: data race in pending calls

[pitrou]

Bug report

Bug description:

Running test_capi with TSan enabled and the GIL enabled yields the following race condition:

test_isolated_subinterpreter (test.test_capi.test_misc.TestPendingCalls.test_isolated_subinterpreter) ... 
==================
WARNING: ThreadSanitizer: data race (pid=84714)
  Write of size 4 at 0x7f72e30d2038 by main thread:
    #0 _push_pending_call /home/antoine/cpython/default/Python/ceval_gil.c:674:25 (python+0x4b860b) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #1 _PyEval_AddPendingCall /home/antoine/cpython/default/Python/ceval_gil.c:746:18 (python+0x4b860b)
    #2 pending_identify /home/antoine/cpython/default/./Modules/_testinternalcapi.c:1135:13 (_testinternalcapi.cpython-313d-x86_64-linux-gnu.so+0x8d77) (BuildId: 0997eb086570be7275cd70cbfb0545cf77f5f79c)
    #3 cfunction_call /home/antoine/cpython/default/Objects/methodobject.c:551:18 (python+0x2cf92c) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)

[...]
  Previous atomic read of size 4 at 0x7f72e30d2038 by thread T1 (mutexes: write M0):
    #0 _Py_atomic_load_int32_relaxed /home/antoine/cpython/default/./Include/cpython/pyatomic_gcc.h:319:10 (python+0x4b7cfc) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #1 update_eval_breaker_for_thread /home/antoine/cpython/default/Python/ceval_gil.c:87:27 (python+0x4b7cfc)
    #2 take_gil /home/antoine/cpython/default/Python/ceval_gil.c:385:5 (python+0x4b7cfc)
    #3 _PyEval_AcquireLock /home/antoine/cpython/default/Python/ceval_gil.c:555:5 (python+0x4b81be) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #4 _PyThreadState_Attach /home/antoine/cpython/default/Python/pystate.c:1878:5 (python+0x525943) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #5 PyEval_RestoreThread /home/antoine/cpython/default/Python/ceval_gil.c:623:5 (python+0x4b843e) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #6 _Py_write_impl /home/antoine/cpython/default/Python/fileutils.c:1970:13 (python+0x561f0e) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #7 _Py_write /home/antoine/cpython/default/Python/fileutils.c:2036:12 (python+0x561e1f) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #8 os_write_impl /home/antoine/cpython/default/./Modules/posixmodule.c:11495:12 (python+0x579d37) (BuildId: 80a378e5bf8e9a3b503d1ddb455283576a308db6)
    #9 os_write /home/antoine/cpython/default/./Modules/clinic/posixmodule.c.h:7369:21 (python+0x579d37)
[...]

CPython versions tested on:

CPython main branch

Operating systems tested on:

Linux

Linked PRs

• gh-116908: Only write to _pending_calls.calls_to_do with atomic operations #117044

[pitrou]

@colesbury @swtaarrs @corona10

[swtaarrs]

It looks like the root of the issue here is that tsan doesn't know about PyMutex, which is used to protect the data member being mutated here. I believe I've found the set of function calls used to annotate mutex implementations, so I'll work on adding those to PyMutex.

[colesbury]

@swtaarrs, I don't think you need to annotate PyMutex. I think it's more likely something like sem_clockwait not being supported by TSan.

colesbury/nogil-3.12@7507a77

[swtaarrs]

@colesbury That's already in main. Any other ideas? The annotations look pretty straightforward so I'll give them a try.

[colesbury]

Oh, I missed that. I'm curious if annotations for PyMutex fix this, but it looks to me like a data race:

T1: Writes pending->calls_to_do (nonatomic, but holding pending->mutex);
T2: Reads pending->calls_to_do (atomic, but not holding pending->mutex);

Either T1 needs an atomic write or T2 needs to hold pending->mutex.

[swtaarrs]

(heh, I saw your comment pop up as I clicked to post mine. sounds like we agree!)

TSAN still doesn't like the nonatomic increment even with PyMutex annotated (I verified that the annotations are working, since the error message now says that it holds the relevant PyMutex during the bad write).

I'm going back to my initial thought was that this is a real data race. We shouldn't be mixing nonatomic writes with atomic reads, even if it works out in practice. Changing the increment and decrement of pending->calls_to_do to atomic gets rid of the error, and I wouldn't expect it to be a performance issue.