Hello, ThreadSanitizer found a data race between the commit thread and the blocking
client-request callback. Could you take a look?
Commit hash: 9de4522beccaa1901d49488fcbb01447a9335ea9 (v2.1.0-58-g9de4522), return
method raft_params::blocking (the default). Related to #644 (also a TSAN race in the
commit path, but a different field/site).
==================
WARNING: ThreadSanitizer: data race (pid=7)
Write of size 4 at 0x723c00040180 by thread T38 (mutexes: write M0, write M1):
Previous read of size 4 at 0x723c00040180 by thread T65:
Location is heap block of size 240 at 0x723c000400b0 allocated by thread T65:
Mutex M0 (0x727000000cb0) created at:
Mutex M1 (0x727000000d18) created at:
Thread T38 'nuraft_commit' (tid=48, running) created by main thread at:
Thread T65 'ReqAccumulator' (tid=75, running) created by main thread at:
SUMMARY: ThreadSanitizer: data race
==================
(The frames are unsymbolized in our CI — the external symbolizer was unavailable — but the
size-4 field on the 240-byte commit_ret_elem block, the nuraft_commit writer thread,
and the reader thread blocked in the client-request callback identify the site
unambiguously. T65 is our own thread that calls append_entries and waits for the
result; in stock NuRaft this is whatever thread invokes the blocking client request.)
Where
Writer — commit thread, src/handle_commit.cxx (commit_in_bg_exec), writes
result_code_ under commit_ret_elems_lock_:
std::unique_lock<std::mutex> cre_lock(commit_ret_elems_lock_);
...
if (elem->idx_ == sm_idx) {
elem->result_code_ = cmd_result_code::OK; // write, under lock
elem->ret_value_ = ret_value;
...
elem->awaiter_.invoke();
Reader — blocking client callback, src/handle_client_request.cxx
(handle_cli_req_callback), reads result_code_ after releasing the lock:
elem->awaiter_.wait_ms(ctx_->get_params()->client_req_timeout_);
{ auto_lock(commit_ret_elems_lock_);
...
if (elem->result_code_ != cmd_result_code::TIMEOUT) // read under lock (ok)
commit_ret_elems_.erase(elem->idx_);
else
p_dv("Client timeout leave commit thread to remove commit_ret_elem %" PRIu64, idx);
...
} // lock released
if (elem->result_code_ == cmd_result_code::OK) { ... } // read, NO LOCK <-- race
...
resp->set_result_code(elem->result_code_); // read, NO LOCK <-- race
Why it happens
handle_cli_req_callback reaches these post-lock reads specifically on the timeout path
(wait_ms returns before the commit finishes — exactly when the commit thread is still in
flight). On that path the elem is intentionally left in commit_ret_elems_, so the
commit thread can write result_code_ for the same elem while the callback reads it
outside the lock. It reproduces reliably under TSAN with a short client_req_timeout_
(so slow, instrumented commits routinely exceed it).
With halt_on_error=1 this aborts the process. In our deployment the aborting node was the
only voting member, so the cluster could not elect a new leader until restart.
Suggested fix
Snapshot result_code_ into a local inside the existing critical section and use the local
afterwards:
cmd_result_code rc;
{ auto_lock(commit_ret_elems_lock_);
...
rc = elem->result_code_; // snapshot under lock
if (rc != cmd_result_code::TIMEOUT)
commit_ret_elems_.erase(elem->idx_);
else
p_dv("Client timeout leave commit thread to remove commit_ret_elem %" PRIu64, idx);
...
}
if (rc == cmd_result_code::OK) { ... }
resp->set_result_code(rc);
Making result_code_ a std::atomic<cmd_result_code> would also work, but snapshotting
under the lock is the smaller change and keeps all elem reads consistent with one point
in time.
Thanks!
Hello, ThreadSanitizer found a data race between the commit thread and the blocking
client-request callback. Could you take a look?
Commit hash:
9de4522beccaa1901d49488fcbb01447a9335ea9(v2.1.0-58-g9de4522), returnmethod
raft_params::blocking(the default). Related to #644 (also a TSAN race in thecommit path, but a different field/site).
(The frames are unsymbolized in our CI — the external symbolizer was unavailable — but the
size-4 field on the 240-byte
commit_ret_elemblock, thenuraft_commitwriter thread,and the reader thread blocked in the client-request callback identify the site
unambiguously.
T65is our own thread that callsappend_entriesand waits for theresult; in stock NuRaft this is whatever thread invokes the blocking client request.)
Where
Writer — commit thread,
src/handle_commit.cxx(commit_in_bg_exec), writesresult_code_undercommit_ret_elems_lock_:Reader — blocking client callback,
src/handle_client_request.cxx(
handle_cli_req_callback), readsresult_code_after releasing the lock:Why it happens
handle_cli_req_callbackreaches these post-lock reads specifically on the timeout path(
wait_msreturns before the commit finishes — exactly when the commit thread is still inflight). On that path the
elemis intentionally left incommit_ret_elems_, so thecommit thread can write
result_code_for the sameelemwhile the callback reads itoutside the lock. It reproduces reliably under TSAN with a short
client_req_timeout_(so slow, instrumented commits routinely exceed it).
With
halt_on_error=1this aborts the process. In our deployment the aborting node was theonly voting member, so the cluster could not elect a new leader until restart.
Suggested fix
Snapshot
result_code_into a local inside the existing critical section and use the localafterwards:
cmd_result_code rc; { auto_lock(commit_ret_elems_lock_); ... rc = elem->result_code_; // snapshot under lock if (rc != cmd_result_code::TIMEOUT) commit_ret_elems_.erase(elem->idx_); else p_dv("Client timeout leave commit thread to remove commit_ret_elem %" PRIu64, idx); ... } if (rc == cmd_result_code::OK) { ... } resp->set_result_code(rc);Making
result_code_astd::atomic<cmd_result_code>would also work, but snapshottingunder the lock is the smaller change and keeps all
elemreads consistent with one pointin time.
Thanks!