[KUDU-2949] Thread collision in consensus current_term

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 1.12.0
• Code Review: https://gerrit.cloudera.org/c/14580/
• Assignee: Adar Dembo
• Reporter: Andrew Wong
• Created: 20/Sep/19 01:36
• Updated: 01/Nov/19 00:25
• Resolved: 01/Nov/19 00:25

Description

Saw a precommit failure of raft_consensus_quorum-test with the following stack trace:

roperty violated. Preceding OpId in replica: term: 0 index: 0. Preceding OpId from leader: term: 1 index: 2. (index mismatch)
I0920 01:06:49.326063   626 consensus_queue.cc:984] T TestTablet P 6fec94ba5fb343fbad900ca4ef38b251 [LEADER]: Connected to new peer: Peer: permanent_uuid: "938a40f5da7f4e62b2c317ecb1ba184c" member_type: VOTER last_known_addr { host: "peer-0.fake-domain-for-tests" port: 0 }, Status: LMP_MISMATCH, Last received: 0.0, Next index: 1, Last known committed idx: 0, Time since last communication: 0.000s
I0920 01:06:49.326789   624 consensus_queue.cc:984] T TestTablet P 6fec94ba5fb343fbad900ca4ef38b251 [LEADER]: Connected to new peer: Peer: permanent_uuid: "fa4335770e644e66a6ce962fb388c6f6" member_type: VOTER last_known_addr { host: "peer-1.fake-domain-for-tests" port: 0 }, Status: LMP_MISMATCH, Last received: 0.0, Next index: 1, Last known committed idx: 0, Time since last communication: 0.000s
I0920 01:06:49.357350   233 raft_consensus.cc:2311] T TestTablet P fa4335770e644e66a6ce962fb388c6f6 [term 1 FOLLOWER]: Leader election vote request: Denying vote to candidate 938a40f5da7f4e62b2c317ecb1ba184c for term 2 because replica is either leader or believes a valid leader to be alive.
I0920 01:06:49.357631   233 raft_consensus.cc:2890] T TestTablet P fa4335770e644e66a6ce962fb388c6f6 [term 1 FOLLOWER]: Advancing to term 2
W0920 01:06:50.192647   233 consensus_meta.cc:220] T TestTablet P fa4335770e644e66a6ce962fb388c6f6: Time spent flushing consensus metadata: real 0.835s	user 0.004s	sys 0.000s
I0920 01:06:50.192862   233 raft_consensus.cc:2350] T TestTablet P fa4335770e644e66a6ce962fb388c6f6 [term 2 FOLLOWER]: Leader election vote request: Granting yes vote for candidate 938a40f5da7f4e62b2c317ecb1ba184c in term 2.
F0920 01:06:50.193255   233 thread_collision_warner.cc:23] Thread Collision! Previous thread id: 635, current thread id: 233
*** Check failure stack trace: ***
I0920 01:06:50.193334   635 raft_consensus.cc:1149] T TestTablet P fa4335770e644e66a6ce962fb388c6f6 [term 2 FOLLOWER]: Rejecting Update request from peer 6fec94ba5fb343fbad900ca4ef38b251 for earlier term 1. Current term is 2. Ops: []
*** Aborted at 1568941610 (unix time) try "date -d @1568941610" if you are using GNU date ***
I0920 01:06:50.195124   634 consensus_queue.cc:995] T TestTablet P 6fec94ba5fb343fbad900ca4ef38b251 [LEADER]: Peer responded invalid term: Peer: permanent_uuid: "fa4335770e644e66a6ce962fb388c6f6" member_type: VOTER last_known_addr { host: "peer-1.fake-domain-for-tests" port: 0 }, Status: INVALID_TERM, Last received: 1.11, Next index: 12, Last known committed idx: 11, Time since last communication: 0.000s
I0920 01:06:50.197060   634 raft_consensus.cc:2885] T TestTablet P 6fec94ba5fb343fbad900ca4ef38b251 [term 1 LEADER]: Stepping down as leader of term 1
I0920 01:06:50.197245   634 raft_consensus.cc:705] T TestTablet P 6fec94ba5fb343fbad900ca4ef38b251 [term 1 LEADER]: Becoming Follower/Learner. State: Replica: 6fec94ba5fb343fbad900ca4ef38b251, State: Running, Role: LEADER
I0920 01:06:50.197593   634 consensus_queue.cc:229] T TestTablet P 6fec94ba5fb343fbad900ca4ef38b251 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 11, Committed index: 11, Last appended: 1.11, Last appended by leader: 11, Current term: 1, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 peers { permanent_uuid: "938a40f5da7f4e62b2c317ecb1ba184c" member_type: VOTER last_known_addr { host: "peer-0.fake-domain-for-tests" port: 0 } } peers { permanent_uuid: "fa4335770e644e66a6ce962fb388c6f6" member_type: VOTER last_known_addr { host: "peer-1.fake-domain-for-tests" port: 0 } } peers { permanent_uuid: "6fec94ba5fb343fbad900ca4ef38b251" member_type: VOTER last_known_addr { host: "peer-2.fake-domain-for-tests" port: 0 } }
PC: @     0x7ff647119c37 gsignal
I0920 01:06:50.198277   634 raft_consensus.cc:2890] T TestTablet P 6fec94ba5fb343fbad900ca4ef38b251 [term 1 FOLLOWER]: Advancing to term 2
*** SIGABRT (@0x3e8000000e9) received by PID 233 (TID 0x7ff653518bc0) from PID 233; stack trace: ***
    @           0x45b7bd __tsan::CallUserSignalHandler() at /home/jenkins-slave/workspace/kudu-master/1/thirdparty/src/llvm-6.0.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1908
    @           0x45c7ab rtl_sigaction() at /home/jenkins-slave/workspace/kudu-master/1/thirdparty/src/llvm-6.0.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1997
    @     0x7ff647f2b330 (unknown) at ??:0
    @     0x7ff647119c37 gsignal at ??:0
    @     0x7ff64711d028 abort at ??:0
    @           0x45e890 __interceptor_abort at /home/jenkins-slave/workspace/kudu-master/1/thirdparty/src/llvm-6.0.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1763
    @     0x7ff649bfdac2 google::logging_fail() at ??:0
    @     0x7ff649bfc905 google::LogMessage::SendToLog() at ??:0
    @     0x7ff649bfd3d2 google::LogMessage::Flush() at ??:0
    @     0x7ff649c01c0b google::LogMessageFatal::~LogMessageFatal() at ??:0
    @     0x7ff649e8ed25 base::DCheckAsserter::warn() at ??:0
    @     0x7ff649e8ed9e base::ThreadCollisionWarner::EnterSelf() at ??:0
    @     0x7ff6524ad7b9 base::ThreadCollisionWarner::ScopedRecursiveCheck::ScopedRecursiveCheck() at ??:0
    @     0x7ff6524ab582 kudu::consensus::ConsensusMetadata::current_term() at ??:0
    @           0x4ffcc1 kudu::consensus::RaftConsensusQuorumTest::AssertDurableTermAndVote() at /home/jenkins-slave/workspace/kudu-master/1/src/kudu/consensus/raft_consensus_quorum-test.cc:554
    @           0x4f6e9b kudu::consensus::RaftConsensusQuorumTest_TestRequestVote_Test::TestBody() at /home/jenkins-slave/workspace/kudu-master/1/src/kudu/consensus/raft_consensus_quorum-test.cc:?
    @     0x7ff6527c72f0 testing::internal::HandleExceptionsInMethodIfSupported<>() at ??:0
    @     0x7ff6527a64b9 testing::Test::Run() at ??:0
    @     0x7ff6527a774d testing::TestInfo::Run() at ??:0
    @     0x7ff6527a8227 testing::TestCase::Run() at ??:0
    @     0x7ff6527b45fb testing::internal::UnitTestImpl::RunAllTests() at ??:0
    @     0x7ff6527c8260 testing::internal::HandleExceptionsInMethodIfSupported<>() at ??:0
    @     0x7ff6527b3ee3 testing::UnitTest::Run() at ??:0
    @     0x7ff65311c51c RUN_ALL_TESTS() at ??:0
    @     0x7ff65311bcc7 main at ??:0
    @     0x7ff647104f45 __libc_start_main at ??:0
    @           0x4540f6 (unknown) at ??:?