eBay / eBay/HomeStore

RaftReplDevDynamic-Epoll hangs permanently: OutMemberDown's replace_member() silently no-ops when caller isn't leader, then corrupts every later test's sync barrier

Open
#916 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
C++
Stars
29
Forks
30
Avg merge
2d 4h
Merged PRs (30d)
6

Description

Summary

RaftReplDevDynamic-Epoll hangs permanently (never completes; must be killed externally). Root-caused via live GDB on two independent occurrences: a local soak-test run and a real Jenkins CI job stuck for 38+ hours. Both show the identical mechanism, down to the exact function and line number.

Trigger: ReplDevDynamicTest.OutMemberDown calls replace_member() to add a spare replica to the raft group. If the calling replica (replica_0, hard-coded in the test) isn't the current raft leader at that exact instant, the test harness's run_on_leader() helper silently no-ops instead of erroring or retrying. The new member is never actually added to the raft config, so it never receives any data and spins forever in wait_for_commits().

Why it cascades into a total binary-wide hang, not just one test failure: the test harness's sync_for_* barriers (sync_for_test_start/sync_for_verify_start/sync_for_cleanup_start) share a single global counter + phase enum for the entire test binary, not scoped per test or per call site. Once one test's barrier is short an arrival (because the member that was supposed to arrive never joined), a later, unrelated test's call to the same barrier wrapper silently contributes toward the old, stranded count — confirmed live via GDB (see Evidence). This permanently desyncs every subsequent barrier in the run.

This is a test-harness bug, not a HomeStore library bug: the product code (RaftReplDev::start_replace_member) correctly rejects the request with NOT_LEADER when called on a non-leader — that's expected raft semantics, and other tests (LeaderReplace) already explicitly expect and handle it. OutMemberDown does not.

Root cause, step by step

  1. OutMemberDown's SetUp() creates a fresh 3-member raft group; register_listener() asserts replica_0 is elected leader at creation time.
  2. Sometime before OutMemberDown's body calls replace_member(), the raft group's leadership moves away from replica_0. Observed trigger: the previous test's raft group is torn down asynchronously and its raft server (and periodic checks) remain active for 15-20+ seconds after the next test has already created a new group in the same process — confirmed by log timestamps below. The two groups' raft servers compete for the same process's reactor/threads, tripping NuRaft's 5-second "peer not responding" leadership-yield safety check.
  3. OutMemberDown's test body only ever attempts replace_member() from replica_0's process:
    if (g_helper->replica_num() == 0) {
        replace_member(db, task_id, g_helper->replica_id(member_out), g_helper->replica_id(member_in));
    
    (src/tests/test_raft_repl_dev_dynamic.cpp:300-301)
  4. replace_member() routes through run_on_leader():
    void run_on_leader(std::shared_ptr<TestReplicatedDB> db, auto&& lambda) {
        ...
        auto leader_uuid = db->repl_dev()->get_leader_id();
        if (leader_uuid.is_nil()) { ...retry... }
        else if (leader_uuid == g_helper->my_replica_id()) { lambda(); break; }
        else { break; }   // <-- silently does nothing if the caller isn't the leader
    }
    
    (src/tests/test_common/raft_repl_test_base.hpp:604-623)
  5. Since replica_0 isn't leader at that moment, run_on_leader hits the silent breakdo_replace_member() (and therefore RaftReplDev::do_add_member/add_srv) is never invoked. No error, no assertion, no retry. The test proceeds as if nothing happened.
  6. The confirmed rejection at the raft layer (product code working correctly):
    [E] raft_repl_dev.cpp:235:start_replace_member [rdev4:<group>] Step1. Replace member, I am not leader, can not handle the request, task_id=task_id
    
  7. The spare replica (member_in) then calls wait_for_commits(300) (raft_repl_test_base.hpp:553-567) and spins forever — confirmed via a grep of the entire remaining log for that group_id: after the rejected replace_member attempt, there is zero further activity of any kind for that group_id for the rest of the run. The member was never added; there is nothing to wait for.
  8. Meanwhile, replica_1/replica_2 remain blocked at OutMemberDown's sync_for_verify_start(4) barrier (test_raft_repl_dev_dynamic.cpp:308), waiting for a 4th arrival (the spare) that can never come.
  9. Because sync_for_verify_start's underlying counter (verify_start_count_, phase VALIDATE) is a single global counter shared by every call to this wrapper in the binary (hs_repl_test_common.hpp:83-84,91-99), replica_0 — having silently no-op'd past the missing member and proceeded through TearDown()/SetUp() into the next test, LeaderReplace — calls the same wrapper from test_raft_repl_dev_dynamic.cpp:408. That call's arrival is counted toward the same stranded counter. GDB confirms all three live replicas simultaneously observing count=3, max_count=4 on the identical shared variable, despite being blocked at two different call sites in two different tests. No barrier can ever complete again for the remainder of the binary.

Why it's flaky rather than deterministic

The precondition (replica_0 not being leader at the exact instant it calls replace_member) is not something any test code arranges deliberately — under normal conditions replica_0 stays leader from group creation straight through to this call. It only flips due to the asynchronous-teardown/reactor-contention race in step 2, whose timing depends on real scheduling (machine load, thread contention), which varies run to run and machine to machine. That's why it reproduces intermittently (observed in soak testing, ~1-in-10-15 runs) rather than every time, even though the underlying harness bug (run_on_leader's silent no-op) is 100% deterministic once that precondition is hit.

Evidence

1. Local soak test (sdsbuild06), iteration hung at 351s (baseline ~200s)

Leader (replica_0) already inside the next test, blocked on the shared barrier:

#8  ...::IPCData::sync_for (count=@...: 3, new_phase=VALIDATE, max_count=4) at hs_repl_test_common.hpp:99
#9  ...::IPCData::sync_for_verify_start (num_members=4) at hs_repl_test_common.hpp:84
#10 ...::HSReplTestHelper::sync_for_verify_start (num_members=4) at hs_repl_test_common.hpp:378
#11 ReplDevDynamicTest_LeaderReplace_Test::TestBody at test_raft_repl_dev_dynamic.cpp:408

replica_1 and replica_2, blocked at the same counter from the previous test:

#8  ...::IPCData::sync_for (count=@...: 3, new_phase=VALIDATE, max_count=4) at hs_repl_test_common.hpp:99
#11 ReplDevDynamicTest_OutMemberDown_Test::TestBody at test_raft_repl_dev_dynamic.cpp:308

The spare replica (member_in), permanently spinning:

#3  RaftReplDevTestBase::wait_for_commits (exp_writes=300) at raft_repl_test_base.hpp:562
#4  ReplDevDynamicTest_OutMemberDown_Test::TestBody at test_raft_repl_dev_dynamic.cpp:305

Log confirmation (repeats unchanged for the entire hang, never increments):

[I] raft_repl_test_base.hpp:563:wait_for_commits Replica=3 received 0 commits but expected 300

The rejected replace_member call and the leadership-yield event that preceded it:

09:55:08 [E] raft_server.cxx:1243 check_leadership_validity — 2 nodes (out of 3, 3 including learners)
         are not responding longer than 5000 ms ... [group=<previous test's group>]
09:55:08 [E] raft_server.cxx:1279 check_leadership_validity — will yield the leadership of this node
09:55:29 [E] raft_repl_dev.cpp:235 start_replace_member [rdev4:<OutMemberDown's group>]
         Step1. Replace member, I am not leader, can not handle the request, task_id=task_id

Timing of the asynchronous-teardown overlap that triggers the leadership yield:

09:53:57  ReplaceMember test starts (group A)
09:55:00  TwoMemberDown test starts (new group B created) — group A not yet destroyed
09:55:08  group=A — "2 nodes not responding, will yield leadership"
09:55:18  group=A destroy_group finally logged — 18s after the next test already started
2. Independent confirmation: real Jenkins CI job, hung 38+ hours (build3, container 26fbd8c5f64f)

Same test, same exact functions and line numbers, captured via live gdb -p on the running processes:

  • Leader: ReplDevDynamicTest_LeaderReplace_Test::TestBody at test_raft_repl_dev_dynamic.cpp:408
  • Spare replica: RaftReplDevTestBase::wait_for_commits(exp_writes=300) at raft_repl_test_base.hpp:562, called from test_raft_repl_dev_dynamic.cpp:305
  • Log: start_replace_member"I am not leader, can not handle the request"

Host resources were confirmed healthy at the time (load average 0.39, 483GB RAM free) — this rules out simple resource exhaustion as an explanation; the mechanism above is the actual cause.

Ruled out

  • Not the pending_listeners_ data race fixed separately in hs_repl_test_common.hpp (register_listener()/get_listener()) — that was a different bug (a hard SIGABRT) that no longer reproduces after that fix. This hang is a distinct, subsequent issue found via continued soak testing after that fix.
  • Not a single-peer data-fetch failure (RaftReplDev::fetch_data_from_remote fetching from a dead originator with no peer fallback) — an earlier hypothesis, disproved by grepping the complete logs of both incidents: the associated log message ("probably originator is down") never appears in either occurrence.
  • Not resource exhaustion on the host — confirmed via uptime/free/fd counts on the 38-hour-hung CI container.

Proposed fix

  1. run_on_leader() (raft_repl_test_base.hpp:604-623): don't silently swallow the "I'm not the leader" case. Either loop with a bounded retry/timeout against a freshly-fetched leader id, or surface a clear failure (assert/log) when the lambda is skipped, so callers can't silently proceed as if the operation succeeded.
  2. Call sites like OutMemberDown: don't hard-code "only replica_0 attempts this." Have every replica's process attempt the call and rely on run_on_leader's per-process leader check to naturally select whichever one is actually leading (this is more robust to leadership changing between group creation and the call).
  3. sync_for_test_start/sync_for_verify_start/sync_for_cleanup_start (hs_repl_test_common.hpp:77-99): scope the counter/phase state per call site or per test generation, not globally per binary run. At minimum, add a bounded timeout with a diagnostic (current count vs. expected, which replicas have/haven't arrived) instead of blocking forever, so a stall in one test can't silently corrupt every subsequent barrier in the same run.

Happy to submit a PR for any/all of the above if that's useful.

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with run_on_leader() in src/tests/test_common/raft_repl_test_base.hpp and the OutMemberDown flow in src/tests/test_raft_repl_dev_dynamic.cpp, then inspect the shared barrier state in hs_repl_test_common.hpp. Reproduce or trace the non-leader path and the affected barriers. Done means a leadership change cannot silently skip replacement and a stalled test cannot permanently block later tests.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp
Domain
distributed-systems, testing-qa
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
48/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.