From e1c081aa9a0afb9af64f4a386d2013cfe2dae4e0 Mon Sep 17 00:00:00 2001 From: Nathan VanBenschoten Date: Tue, 12 Nov 2024 00:41:03 -0500 Subject: [PATCH] raft: don't step down to newer term while fortifying Informs #132762. This commit fixes a bug where a peer would step down to a newer term while fortifying a leader. This would break the leader fortification promise, which is critical for the leader lease disjointness property. Instead, we now ignore the message as a follower and let the leader handle the process of stepping down, safely defortifying, and eventually stepping back up leader in the new term. A subsequent commit will combine this logic with the other leader lease check for votes and pre-votes. Release note: None --- pkg/raft/raft.go | 61 +++-- pkg/raft/raft_test.go | 120 ++++++++-- pkg/raft/rawnode_test.go | 13 +- .../async_storage_writes_append_aba_race.txt | 2 +- .../confchange_fortification_safety.txt | 2 +- .../testdata/confchange_v1_add_single.txt | 2 +- .../confchange_v2_add_double_auto.txt | 4 +- .../confchange_v2_add_single_auto.txt | 2 +- .../confchange_v2_add_single_explicit.txt | 2 +- .../confchange_v2_add_single_implicit.txt | 2 +- pkg/raft/testdata/de_fortification_basic.txt | 4 +- .../testdata/de_fortification_checkquorum.txt | 2 +- .../fortification_followers_dont_prevote.txt | 2 +- .../fortification_followers_dont_vote.txt | 2 +- .../fortification_support_tracking.txt | 2 +- .../leader_step_down_stranded_peer.txt | 213 ++++++++++++------ ...leader_step_down_stranded_peer_prevote.txt | 55 ++++- .../testdata/mixedversions/checkquorum.txt | 2 +- .../snapshot_succeed_via_app_resp.txt | 2 +- pkg/raft/testdata/prevote_checkquorum.txt | 4 +- pkg/raft/testdata/snapshot_new_term.txt | 2 +- .../snapshot_succeed_via_app_resp.txt | 2 +- 22 files changed, 371 insertions(+), 131 deletions(-) diff --git a/pkg/raft/raft.go b/pkg/raft/raft.go index 4fe48b6e91e8..e5e94aa5801c 100644 --- a/pkg/raft/raft.go +++ b/pkg/raft/raft.go @@ -1029,8 +1029,8 @@ func (r *raft) reset(term uint64) { // // [*] this case, and other cases where a state transition implies // de-fortification. - assertTrue(!r.supportingFortifiedLeader() || r.lead == r.id, - "should not be changing terms when supporting a fortified leader; leader exempted") + assertTrue(!r.supportingFortifiedLeader(), + "should not be changing terms when supporting a fortified leader") r.setTerm(term) } @@ -1542,33 +1542,49 @@ func (r *raft) Step(m pb.Message) error { switch { case m.Type == pb.MsgPreVote: - // Never change our term in response to a PreVote + // Never change our term in response to a PreVote. case m.Type == pb.MsgPreVoteResp && !m.Reject: // We send pre-vote requests with a term in our future. If the // pre-vote is granted, we will increment our term when we get a // quorum. If it is not, the term comes from the node that // rejected our vote so we should become a follower at the new // term. + case IsMsgIndicatingLeader(m.Type): + // We've just received a message that indicates that a new leader + // was elected at a higher term, but the message may not be from the + // leader itself. Either way, the old leader is no longer fortified, + // so it's safe to de-fortify at this point. + r.deFortify(m.From, m.Term) + var lead pb.PeerID + if IsMsgFromLeader(m.Type) { + lead = m.From + } + r.logMsgHigherTerm(m, "new leader indicated, advancing term") + r.becomeFollower(m.Term, lead) default: - r.logger.Infof("%x [term: %d] received a %s message with higher term from %x [term: %d], advancing term", - r.id, r.Term, m.Type, m.From, m.Term) - if IsMsgIndicatingLeader(m.Type) { - // We've just received a message that indicates that a new leader - // was elected at a higher term, but the message may not be from the - // leader itself. Either way, the old leader is no longer fortified, - // so it's safe to de-fortify at this point. - r.deFortify(m.From, m.Term) - var lead pb.PeerID - if IsMsgFromLeader(m.Type) { - lead = m.From + // We've just received a message that does not indicate that a new + // leader was elected at a higher term. All it means is that some + // other peer has this term. + if r.supportingFortifiedLeader() { + // If we are supporting a fortified leader, we can't just jump to the + // larger term. Instead, we need to wait for the leader to learn about + // the stranded peer, step down, and defortify. The only thing to do + // here is check whether we are that leader, in which case we should + // step down to kick off this process of catching up to the term of the + // stranded peer. + if r.state == pb.StateLeader { + r.logMsgHigherTerm(m, "stepping down as leader to recover stranded peer") + r.becomeFollower(r.Term, r.id) + } else { + r.logMsgHigherTerm(m, "ignoring and still supporting fortified leader") } - r.becomeFollower(m.Term, lead) - } else { - // We've just received a message that does not indicate that a new - // leader was elected at a higher term. All it means is that some - // other peer has this term. - r.becomeFollower(m.Term, None) + return nil } + + // If we're not supporting a fortified leader, we can just jump to the + // term communicated by the peer. + r.logMsgHigherTerm(m, "advancing term") + r.becomeFollower(m.Term, None) } case m.Term < r.Term: @@ -1726,6 +1742,11 @@ func (r *raft) Step(m pb.Message) error { return nil } +func (r *raft) logMsgHigherTerm(m pb.Message, suffix redact.SafeString) { + r.logger.Infof("%x [term: %d] received a %s message with higher term from %x [term: %d], %s", + r.id, r.Term, m.Type, m.From, m.Term, suffix) +} + type stepFunc func(r *raft, m pb.Message) error func stepLeader(r *raft, m pb.Message) error { diff --git a/pkg/raft/raft_test.go b/pkg/raft/raft_test.go index 72571c0aaa87..903e0db24bdc 100644 --- a/pkg/raft/raft_test.go +++ b/pkg/raft/raft_test.go @@ -30,6 +30,7 @@ import ( "github.com/cockroachdb/cockroach/pkg/raft/tracker" "github.com/cockroachdb/cockroach/pkg/settings/cluster" "github.com/cockroachdb/cockroach/pkg/testutils" + "github.com/cockroachdb/cockroach/pkg/util/hlc" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) @@ -2137,7 +2138,7 @@ func testLeaderElectionWithCheckQuorum(t *testing.T, storeLivenessEnabled bool) // TestFreeStuckCandidateWithCheckQuorum ensures that a candidate with a higher term // can disrupt the leader even if the leader still "officially" holds the lease, The -// leader is expected to step down and adopt the candidate's term +// leader is expected to step down and adopt the candidate's term. func TestFreeStuckCandidateWithCheckQuorum(t *testing.T) { testutils.RunTrueAndFalse(t, "store-liveness-enabled", func(t *testing.T, storeLivenessEnabled bool) { @@ -2172,10 +2173,12 @@ func testFreeStuckCandidateWithCheckQuorum(t *testing.T, storeLivenessEnabled bo nt := newNetworkWithConfigAndLivenessFabric(nil, fabric, a, b, c) - for i := int64(0); i < b.electionTimeout; i++ { - b.tick() - } + // Elect node 1 as leader. nt.send(pb.Message{From: 1, To: 1, Type: pb.MsgHup}) + assert.Equal(t, pb.StateLeader, a.state) + if storeLivenessEnabled { + assert.Equal(t, hlc.MaxTimestamp, getLeadSupportStatus(a).LeadSupportUntil) + } nt.isolate(1) if storeLivenessEnabled { @@ -2193,7 +2196,7 @@ func testFreeStuckCandidateWithCheckQuorum(t *testing.T, storeLivenessEnabled bo assert.Equal(t, pb.StateCandidate, c.state) assert.Equal(t, b.Term+1, c.Term) - // Vote again for safety + // Vote again for safety. nt.send(pb.Message{From: 3, To: 3, Type: pb.MsgHup}) assert.Equal(t, pb.StateFollower, b.state) @@ -2206,19 +2209,52 @@ func testFreeStuckCandidateWithCheckQuorum(t *testing.T, storeLivenessEnabled bo nt.livenessFabric.GrantSupportForPeerFromAllPeers(1) } - nt.send(pb.Message{From: 1, To: 3, Type: pb.MsgHeartbeat, Term: a.Term}) + // If the stuck candidate were to talk to the follower, it may be ignored, + // depending on whether the follower is fortified by the leader. + nt.send(pb.Message{From: 3, To: 2, Type: pb.MsgAppResp, Term: c.Term}) + if storeLivenessEnabled { + assert.Equal(t, c.Term-2, b.Term) + } else { + assert.Equal(t, c.Term, b.Term) + } - // Disrupt the leader so that the stuck peer is freed + // Disrupt the leader so that the stuck peer is freed. The leader steps down + // immediately, but only changes its term if it was not fortified. If it was, + // it waits for defortification. + hbType := pb.MsgHeartbeat + if storeLivenessEnabled { + hbType = pb.MsgFortifyLeader + } + nt.send(pb.Message{From: 1, To: 3, Type: hbType, Term: a.Term}) assert.Equal(t, pb.StateFollower, a.state) - assert.Equal(t, a.Term, c.Term) - - // Vote again, should become leader this time if storeLivenessEnabled { - // We need to withdraw from 1 to allow 3 to campaign and get elected. - nt.livenessFabric.WithdrawSupportForPeerFromAllPeers(1) + // Node 1 still remembers that it was the leader. + assert.Equal(t, c.Term-2, a.Term) + assert.Equal(t, a.id, a.lead) + + // The ex-leader still hasn't defortified, so the stranded peer still can't + // win an election. + nt.send(pb.Message{From: 3, To: 3, Type: pb.MsgHup}) + assert.Equal(t, pb.StateCandidate, c.state) + assert.Equal(t, pb.StateFollower, a.state) + assert.Equal(t, c.Term-3, a.Term) + assert.Equal(t, a.id, a.lead) + + // The ex-leader defortifies itself and its followers once its remaining + // support has expired. + require.False(t, a.shouldBcastDeFortify()) + fabric.SetSupportExpired(1, true) + require.True(t, a.shouldBcastDeFortify()) + for range a.heartbeatTimeout { + nt.tick(a) + } + } else { + assert.Equal(t, c.Term, a.Term) + assert.Equal(t, None, a.lead) } - nt.send(pb.Message{From: 3, To: 3, Type: pb.MsgHup}) + // Vote again, should become leader this time. + nt.send(pb.Message{From: 3, To: 3, Type: pb.MsgHup}) assert.Equal(t, pb.StateLeader, c.state) } @@ -4436,6 +4472,11 @@ func testPreVoteMigrationWithFreeStuckPreCandidate(t *testing.T, storeLivenessEn n2 := nt.peers[2].(*raft) n3 := nt.peers[3].(*raft) + assert.Equal(t, pb.StateLeader, n1.state) + if storeLivenessEnabled { + assert.Equal(t, hlc.MaxTimestamp, getLeadSupportStatus(n1).LeadSupportUntil) + } + if storeLivenessEnabled { // 1 needs to withdraw support for 3 before it can become a preCandidate. nt.livenessFabric.WithdrawSupport(1, 3) @@ -4447,19 +4488,66 @@ func testPreVoteMigrationWithFreeStuckPreCandidate(t *testing.T, storeLivenessEn assert.Equal(t, pb.StateFollower, n2.state) assert.Equal(t, pb.StatePreCandidate, n3.state) - // Pre-Vote again for safety + // Pre-Vote again for safety. nt.send(pb.Message{From: 3, To: 3, Type: pb.MsgHup}) assert.Equal(t, pb.StateLeader, n1.state) assert.Equal(t, pb.StateFollower, n2.state) assert.Equal(t, pb.StatePreCandidate, n3.state) - nt.send(pb.Message{From: 1, To: 3, Type: pb.MsgHeartbeat, Term: n1.Term}) + // If the stuck candidate were to talk to the follower, it may be ignored, + // depending on whether the follower is fortified by the leader. + nt.send(pb.Message{From: 3, To: 2, Type: pb.MsgAppResp, Term: n3.Term}) + if storeLivenessEnabled { + assert.Equal(t, n3.Term-2, n2.Term) + } else { + assert.Equal(t, n3.Term, n2.Term) + } - // Disrupt the leader so that the stuck peer is freed + // Disrupt the leader so that the stuck peer is freed. The leader steps down + // immediately, but only changes its term if it was not fortified. If it was, + // it waits for defortification. + hbType := pb.MsgHeartbeat + if storeLivenessEnabled { + hbType = pb.MsgFortifyLeader + } + nt.send(pb.Message{From: 1, To: 3, Type: hbType, Term: n1.Term}) assert.Equal(t, pb.StateFollower, n1.state) + if storeLivenessEnabled { + // Node 1 still remembers that it was the leader. + assert.Equal(t, n3.Term-2, n1.Term) + assert.Equal(t, n1.id, n1.lead) + + // The ex-leader still hasn't defortified, so the stranded peer still can't + // win an election. + nt.send(pb.Message{From: 3, To: 3, Type: pb.MsgHup}) + assert.Equal(t, pb.StatePreCandidate, n3.state) + assert.Equal(t, pb.StateFollower, n1.state) + assert.Equal(t, n3.Term-2, n1.Term) + assert.Equal(t, n1.id, n1.lead) + + // The ex-leader defortifies itself and its followers once its remaining + // support has expired. + require.False(t, n1.shouldBcastDeFortify()) + fabric.SetSupportExpired(1, true) + require.True(t, n1.shouldBcastDeFortify()) + for range n1.heartbeatTimeout { + nt.tick(n1) + } + + // The ex-leader calls an election, which it loses and through which it + // learns about the larger term. + fabric.SetSupportExpired(1, false) + nt.send(pb.Message{From: 1, To: 1, Type: pb.MsgHup}) + assert.Equal(t, pb.StateFollower, n1.state) + } + assert.Equal(t, n1.Term, n3.Term) + assert.Equal(t, None, n1.lead) + // The ex-leader calls an election, which it wins. + nt.send(pb.Message{From: 1, To: 1, Type: pb.MsgHup}) + assert.Equal(t, pb.StateLeader, n1.state) } func testConfChangeCheckBeforeCampaign(t *testing.T, v2 bool, storeLivenessEnabled bool) { diff --git a/pkg/raft/rawnode_test.go b/pkg/raft/rawnode_test.go index 14f3ab146cd1..0c6d8fc3cdd8 100644 --- a/pkg/raft/rawnode_test.go +++ b/pkg/raft/rawnode_test.go @@ -351,18 +351,25 @@ func testRawNodeJointAutoLeave(t *testing.T, storeLivenessEnabled bool) { cc = &ccc } if cc != nil { - // Force it step down. + // Force it to step down. rawNode.Step(pb.Message{Type: pb.MsgHeartbeatResp, From: 1, Term: rawNode.raft.Term + 1}) + require.Equal(t, pb.StateFollower, rawNode.raft.state) + if storeLivenessEnabled { + // And also wait for defortification. + for range rawNode.raft.heartbeatTimeout { + rawNode.Tick() + } + } cs = rawNode.ApplyConfChange(cc) } } rawNode.Advance(rd) // Once we are the leader, propose a command and a ConfChange. - if !proposed && rd.HardState.Lead == rawNode.raft.id { + if !proposed && rawNode.raft.state == pb.StateLeader { require.NoError(t, rawNode.Propose([]byte("somedata"))) ccdata, err = testCc.Marshal() require.NoError(t, err) - rawNode.ProposeConfChange(testCc) + require.NoError(t, rawNode.ProposeConfChange(testCc)) proposed = true } } diff --git a/pkg/raft/testdata/async_storage_writes_append_aba_race.txt b/pkg/raft/testdata/async_storage_writes_append_aba_race.txt index ae85597d3dce..0db5f93f6aae 100644 --- a/pkg/raft/testdata/async_storage_writes_append_aba_race.txt +++ b/pkg/raft/testdata/async_storage_writes_append_aba_race.txt @@ -427,7 +427,7 @@ Messages: deliver-msgs 1 ---- 4->1 MsgFortifyLeader Term:3 Log:0/0 -INFO 1 [term: 2] received a MsgFortifyLeader message with higher term from 4 [term: 3], advancing term +INFO 1 [term: 2] received a MsgFortifyLeader message with higher term from 4 [term: 3], new leader indicated, advancing term INFO 1 became follower at term 3 4->1 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] INFO found conflict at index 12 [existing term: 2, conflicting term: 3] diff --git a/pkg/raft/testdata/confchange_fortification_safety.txt b/pkg/raft/testdata/confchange_fortification_safety.txt index fa44bf486bf0..7f9bc831e93b 100644 --- a/pkg/raft/testdata/confchange_fortification_safety.txt +++ b/pkg/raft/testdata/confchange_fortification_safety.txt @@ -143,7 +143,7 @@ stabilize 1 4 1->3 MsgApp Term:1 Log:1/4 Commit:4 Entries:[1/5 EntryNormal ""] > 4 receiving messages 1->4 MsgFortifyLeader Term:1 Log:0/0 - INFO 4 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 4 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 4 became follower at term 1 1->4 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v4] DEBUG 4 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 diff --git a/pkg/raft/testdata/confchange_v1_add_single.txt b/pkg/raft/testdata/confchange_v1_add_single.txt index 14750286c63a..77022ff5645d 100644 --- a/pkg/raft/testdata/confchange_v1_add_single.txt +++ b/pkg/raft/testdata/confchange_v1_add_single.txt @@ -60,7 +60,7 @@ stabilize 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChange v2] > 2 receiving messages 1->2 MsgFortifyLeader Term:1 Log:0/0 - INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 2 became follower at term 1 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChange v2] DEBUG 2 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 diff --git a/pkg/raft/testdata/confchange_v2_add_double_auto.txt b/pkg/raft/testdata/confchange_v2_add_double_auto.txt index c803215c1768..f1a78f5e7215 100644 --- a/pkg/raft/testdata/confchange_v2_add_double_auto.txt +++ b/pkg/raft/testdata/confchange_v2_add_double_auto.txt @@ -84,7 +84,7 @@ stabilize 1 2 ---- > 2 receiving messages 1->2 MsgFortifyLeader Term:1 Log:0/0 - INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 2 became follower at term 1 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2 v3] DEBUG 2 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 @@ -178,7 +178,7 @@ stabilize 1 3 ---- > 3 receiving messages 1->3 MsgFortifyLeader Term:1 Log:0/0 - INFO 3 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 3 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 3 became follower at term 1 1->3 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2 v3] DEBUG 3 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 diff --git a/pkg/raft/testdata/confchange_v2_add_single_auto.txt b/pkg/raft/testdata/confchange_v2_add_single_auto.txt index ba419aa183de..3fa6ae90fc26 100644 --- a/pkg/raft/testdata/confchange_v2_add_single_auto.txt +++ b/pkg/raft/testdata/confchange_v2_add_single_auto.txt @@ -61,7 +61,7 @@ stabilize 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2] > 2 receiving messages 1->2 MsgFortifyLeader Term:1 Log:0/0 - INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 2 became follower at term 1 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2] DEBUG 2 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 diff --git a/pkg/raft/testdata/confchange_v2_add_single_explicit.txt b/pkg/raft/testdata/confchange_v2_add_single_explicit.txt index f8cc663bf43d..85c2e308f1a4 100644 --- a/pkg/raft/testdata/confchange_v2_add_single_explicit.txt +++ b/pkg/raft/testdata/confchange_v2_add_single_explicit.txt @@ -61,7 +61,7 @@ stabilize 1 2 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2] > 2 receiving messages 1->2 MsgFortifyLeader Term:1 Log:0/0 - INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 2 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 2 became follower at term 1 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2] DEBUG 2 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 diff --git a/pkg/raft/testdata/confchange_v2_add_single_implicit.txt b/pkg/raft/testdata/confchange_v2_add_single_implicit.txt index fb5fc1527bae..2ef2021a965d 100644 --- a/pkg/raft/testdata/confchange_v2_add_single_implicit.txt +++ b/pkg/raft/testdata/confchange_v2_add_single_implicit.txt @@ -93,7 +93,7 @@ stabilize 1->2 MsgApp Term:1 Log:1/4 Commit:4 Entries:[1/5 EntryConfChangeV2] > 3 receiving messages 1->3 MsgFortifyLeader Term:1 Log:0/0 - INFO 3 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 3 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 3 became follower at term 1 1->3 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v3] DEBUG 3 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 diff --git a/pkg/raft/testdata/de_fortification_basic.txt b/pkg/raft/testdata/de_fortification_basic.txt index fcd1858b898c..aab57e40e046 100644 --- a/pkg/raft/testdata/de_fortification_basic.txt +++ b/pkg/raft/testdata/de_fortification_basic.txt @@ -807,8 +807,8 @@ stabilize 3->1 MsgApp Term:4 Log:2/4 Commit:4 Entries:[4/5 EntryNormal ""] > 2 receiving messages 3->2 MsgFortifyLeader Term:4 Log:0/0 - INFO 2 [term: 2] received a MsgFortifyLeader message with higher term from 3 [term: 4], advancing term DEBUG 2 setting election elapsed to start from 3 ticks after store liveness support expired + INFO 2 [term: 2] received a MsgFortifyLeader message with higher term from 3 [term: 4], new leader indicated, advancing term INFO 2 became follower at term 4 3->2 MsgApp Term:4 Log:2/4 Commit:4 Entries:[4/5 EntryNormal ""] > 3 processing append thread @@ -1369,8 +1369,8 @@ stabilize 1->2 MsgApp Term:6 Log:5/6 Commit:6 Entries:[6/7 EntryNormal ""] > 3 receiving messages 1->3 MsgApp Term:6 Log:5/6 Commit:6 Entries:[6/7 EntryNormal ""] - INFO 3 [term: 5] received a MsgApp message with higher term from 1 [term: 6], advancing term DEBUG 3 setting election elapsed to start from 3 ticks after store liveness support expired + INFO 3 [term: 5] received a MsgApp message with higher term from 1 [term: 6], new leader indicated, advancing term INFO 3 became follower at term 6 > 1 processing append thread Processing: diff --git a/pkg/raft/testdata/de_fortification_checkquorum.txt b/pkg/raft/testdata/de_fortification_checkquorum.txt index f1b3ea262d0a..4d677b1e6afd 100644 --- a/pkg/raft/testdata/de_fortification_checkquorum.txt +++ b/pkg/raft/testdata/de_fortification_checkquorum.txt @@ -415,7 +415,7 @@ stabilize 3->2 MsgApp Term:3 Log:2/12 Commit:13 Entries:[3/13 EntryNormal ""] > 2 receiving messages 3->2 MsgFortifyLeader Term:3 Log:0/0 - INFO 2 [term: 2] received a MsgFortifyLeader message with higher term from 3 [term: 3], advancing term + INFO 2 [term: 2] received a MsgFortifyLeader message with higher term from 3 [term: 3], new leader indicated, advancing term INFO 2 became follower at term 3 3->2 MsgApp Term:3 Log:2/12 Commit:13 Entries:[3/13 EntryNormal ""] > 2 handling Ready diff --git a/pkg/raft/testdata/fortification_followers_dont_prevote.txt b/pkg/raft/testdata/fortification_followers_dont_prevote.txt index 87a53dd818a8..1eb312ccc307 100644 --- a/pkg/raft/testdata/fortification_followers_dont_prevote.txt +++ b/pkg/raft/testdata/fortification_followers_dont_prevote.txt @@ -291,7 +291,7 @@ stabilize 2->3 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] > 1 receiving messages 2->1 MsgFortifyLeader Term:2 Log:0/0 - INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 2 [term: 2], advancing term + INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 2 [term: 2], new leader indicated, advancing term INFO 1 became follower at term 2 2->1 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] > 3 receiving messages diff --git a/pkg/raft/testdata/fortification_followers_dont_vote.txt b/pkg/raft/testdata/fortification_followers_dont_vote.txt index ea2a389eaa3e..0d74f98382c4 100644 --- a/pkg/raft/testdata/fortification_followers_dont_vote.txt +++ b/pkg/raft/testdata/fortification_followers_dont_vote.txt @@ -237,7 +237,7 @@ stabilize 2->3 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] > 1 receiving messages 2->1 MsgFortifyLeader Term:3 Log:0/0 - INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 2 [term: 3], advancing term + INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 2 [term: 3], new leader indicated, advancing term INFO 1 became follower at term 3 2->1 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] > 3 receiving messages diff --git a/pkg/raft/testdata/fortification_support_tracking.txt b/pkg/raft/testdata/fortification_support_tracking.txt index f8111c92fca1..938ee22ff660 100644 --- a/pkg/raft/testdata/fortification_support_tracking.txt +++ b/pkg/raft/testdata/fortification_support_tracking.txt @@ -218,7 +218,7 @@ stabilize 2->3 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] > 1 receiving messages 2->1 MsgFortifyLeader Term:2 Log:0/0 - INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 2 [term: 2], advancing term + INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 2 [term: 2], new leader indicated, advancing term INFO 1 became follower at term 2 2->1 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] > 3 receiving messages diff --git a/pkg/raft/testdata/leader_step_down_stranded_peer.txt b/pkg/raft/testdata/leader_step_down_stranded_peer.txt index 265aa71a5b5a..eba4b8b89421 100644 --- a/pkg/raft/testdata/leader_step_down_stranded_peer.txt +++ b/pkg/raft/testdata/leader_step_down_stranded_peer.txt @@ -220,139 +220,214 @@ stabilize 1 3 3->1 MsgAppResp Term:3 Log:0/0 > 1 receiving messages 3->1 MsgAppResp Term:3 Log:0/0 - INFO 1 [term: 1] received a MsgAppResp message with higher term from 3 [term: 3], advancing term - INFO 1 became follower at term 3 + INFO 1 [term: 1] received a MsgAppResp message with higher term from 3 [term: 3], stepping down as leader to recover stranded peer + INFO 1 became follower at term 1 3->1 MsgAppResp Term:3 Log:0/0 + INFO 1 [term: 1] received a MsgAppResp message with higher term from 3 [term: 3], ignoring and still supporting fortified leader +> 1 handling Ready + Ready MustSync=false: + State:StateFollower + +# Wait until the ex-leader can be safely defortified. +campaign 1 +---- +DEBUG 1 ignoring MsgHup due to leader fortification + +send-de-fortify 1 1 +---- +DEBUG 1 setting election elapsed to start from 3 ticks after store liveness support expired + +# Without pre-vote, the process through which the ex-leader learns about the +# higher term of the stranded peer is sub-optimal, but still works. Because +# the stranded peer does not respond when rejecting the MsgVote, we must wait +# for the stranded peer to campaign for the ex-leader (and next leader) to +# learn about the higher term and campaign with it. +campaign 1 +---- +INFO 1 is starting a new election at term 1 +INFO 1 became candidate at term 2 +INFO 1 [logterm: 1, index: 11] sent MsgVote request to 2 at term 2 +INFO 1 [logterm: 1, index: 11] sent MsgVote request to 3 at term 2 + +stabilize +---- +> 1 handling Ready + Ready MustSync=true: + State:StateCandidate + HardState Term:2 Vote:1 Commit:11 Lead:0 LeadEpoch:0 + Messages: + 1->2 MsgVote Term:2 Log:1/11 + 1->3 MsgVote Term:2 Log:1/11 + INFO 1 received MsgVoteResp from 1 at term 2 + INFO 1 has received 1 MsgVoteResp votes and 0 vote rejections +> 2 receiving messages + 1->2 MsgVote Term:2 Log:1/11 + INFO 2 [logterm: 1, index: 11, vote: 1] ignored MsgVote from 1 [logterm: 1, index: 11] at term 1: supporting fortified leader 1 at epoch 1 +> 3 receiving messages + 1->3 MsgVote Term:2 Log:1/11 + INFO 3 [term: 3] ignored a MsgVote message with lower term from 1 [term: 2] + +campaign 3 +---- +INFO 3 is starting a new election at term 3 +INFO 3 became candidate at term 4 +INFO 3 [logterm: 1, index: 10] sent MsgVote request to 1 at term 4 +INFO 3 [logterm: 1, index: 10] sent MsgVote request to 2 at term 4 + +stabilize +---- +> 3 handling Ready + Ready MustSync=true: + HardState Term:4 Vote:3 Commit:10 Lead:0 LeadEpoch:0 + Messages: + 3->1 MsgVote Term:4 Log:1/10 + 3->2 MsgVote Term:4 Log:1/10 + INFO 3 received MsgVoteResp from 3 at term 4 + INFO 3 has received 1 MsgVoteResp votes and 0 vote rejections +> 1 receiving messages + 3->1 MsgVote Term:4 Log:1/10 + INFO 1 [term: 2] received a MsgVote message with higher term from 3 [term: 4], advancing term + INFO 1 became follower at term 4 + INFO 1 [logterm: 1, index: 11, vote: 0] rejected MsgVote from 3 [logterm: 1, index: 10] at term 4 +> 2 receiving messages + 3->2 MsgVote Term:4 Log:1/10 + INFO 2 [logterm: 1, index: 11, vote: 1] ignored MsgVote from 3 [logterm: 1, index: 10] at term 1: supporting fortified leader 1 at epoch 1 > 1 handling Ready Ready MustSync=true: State:StateFollower - HardState Term:3 Commit:11 Lead:0 LeadEpoch:0 + HardState Term:4 Commit:11 Lead:0 LeadEpoch:0 + Messages: + 1->3 MsgVoteResp Term:4 Log:0/0 Rejected (Hint: 0) +> 3 receiving messages + 1->3 MsgVoteResp Term:4 Log:0/0 Rejected (Hint: 0) + INFO 3 received MsgVoteResp rejection from 1 at term 4 + INFO 3 has received 1 MsgVoteResp votes and 1 vote rejections campaign 1 ---- -INFO 1 is starting a new election at term 3 -INFO 1 became candidate at term 4 -INFO 1 [logterm: 1, index: 11] sent MsgVote request to 2 at term 4 -INFO 1 [logterm: 1, index: 11] sent MsgVote request to 3 at term 4 +INFO 1 is starting a new election at term 4 +INFO 1 became candidate at term 5 +INFO 1 [logterm: 1, index: 11] sent MsgVote request to 2 at term 5 +INFO 1 [logterm: 1, index: 11] sent MsgVote request to 3 at term 5 stabilize ---- > 1 handling Ready Ready MustSync=true: State:StateCandidate - HardState Term:4 Vote:1 Commit:11 Lead:0 LeadEpoch:0 + HardState Term:5 Vote:1 Commit:11 Lead:0 LeadEpoch:0 Messages: - 1->2 MsgVote Term:4 Log:1/11 - 1->3 MsgVote Term:4 Log:1/11 - INFO 1 received MsgVoteResp from 1 at term 4 + 1->2 MsgVote Term:5 Log:1/11 + 1->3 MsgVote Term:5 Log:1/11 + INFO 1 received MsgVoteResp from 1 at term 5 INFO 1 has received 1 MsgVoteResp votes and 0 vote rejections > 2 receiving messages - 1->2 MsgVote Term:4 Log:1/11 + 1->2 MsgVote Term:5 Log:1/11 INFO 2 [logterm: 1, index: 11, vote: 1] ignored MsgVote from 1 [logterm: 1, index: 11] at term 1: supporting fortified leader 1 at epoch 1 > 3 receiving messages - 1->3 MsgVote Term:4 Log:1/11 - INFO 3 [term: 3] received a MsgVote message with higher term from 1 [term: 4], advancing term - INFO 3 became follower at term 4 - INFO 3 [logterm: 1, index: 10, vote: 0] cast MsgVote for 1 [logterm: 1, index: 11] at term 4 + 1->3 MsgVote Term:5 Log:1/11 + INFO 3 [term: 4] received a MsgVote message with higher term from 1 [term: 5], advancing term + INFO 3 became follower at term 5 + INFO 3 [logterm: 1, index: 10, vote: 0] cast MsgVote for 1 [logterm: 1, index: 11] at term 5 > 3 handling Ready Ready MustSync=true: State:StateFollower - HardState Term:4 Vote:1 Commit:10 Lead:0 LeadEpoch:0 + HardState Term:5 Vote:1 Commit:10 Lead:0 LeadEpoch:0 Messages: - 3->1 MsgVoteResp Term:4 Log:0/0 + 3->1 MsgVoteResp Term:5 Log:0/0 > 1 receiving messages - 3->1 MsgVoteResp Term:4 Log:0/0 - INFO 1 received MsgVoteResp from 3 at term 4 + 3->1 MsgVoteResp Term:5 Log:0/0 + INFO 1 received MsgVoteResp from 3 at term 5 INFO 1 has received 2 MsgVoteResp votes and 0 vote rejections - INFO 1 became leader at term 4 + INFO 1 became leader at term 5 > 1 handling Ready Ready MustSync=true: State:StateLeader - HardState Term:4 Vote:1 Commit:11 Lead:1 LeadEpoch:1 + HardState Term:5 Vote:1 Commit:11 Lead:1 LeadEpoch:1 Entries: - 4/12 EntryNormal "" + 5/12 EntryNormal "" Messages: - 1->2 MsgFortifyLeader Term:4 Log:0/0 - 1->3 MsgFortifyLeader Term:4 Log:0/0 - 1->2 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] - 1->3 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] + 1->2 MsgFortifyLeader Term:5 Log:0/0 + 1->3 MsgFortifyLeader Term:5 Log:0/0 + 1->2 MsgApp Term:5 Log:1/11 Commit:11 Entries:[5/12 EntryNormal ""] + 1->3 MsgApp Term:5 Log:1/11 Commit:11 Entries:[5/12 EntryNormal ""] > 2 receiving messages - 1->2 MsgFortifyLeader Term:4 Log:0/0 - INFO 2 [term: 1] received a MsgFortifyLeader message with higher term from 1 [term: 4], advancing term + 1->2 MsgFortifyLeader Term:5 Log:0/0 DEBUG 2 setting election elapsed to start from 3 ticks after store liveness support expired - INFO 2 became follower at term 4 - 1->2 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] + INFO 2 [term: 1] received a MsgFortifyLeader message with higher term from 1 [term: 5], new leader indicated, advancing term + INFO 2 became follower at term 5 + 1->2 MsgApp Term:5 Log:1/11 Commit:11 Entries:[5/12 EntryNormal ""] > 3 receiving messages - 1->3 MsgFortifyLeader Term:4 Log:0/0 - 1->3 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] + 1->3 MsgFortifyLeader Term:5 Log:0/0 + 1->3 MsgApp Term:5 Log:1/11 Commit:11 Entries:[5/12 EntryNormal ""] DEBUG 3 [logterm: 0, index: 11] rejected MsgApp [logterm: 1, index: 11] from 1 > 2 handling Ready Ready MustSync=true: - HardState Term:4 Commit:11 Lead:1 LeadEpoch:1 + HardState Term:5 Commit:11 Lead:1 LeadEpoch:1 Entries: - 4/12 EntryNormal "" + 5/12 EntryNormal "" Messages: - 2->1 MsgFortifyLeaderResp Term:4 Log:0/0 LeadEpoch:1 - 2->1 MsgAppResp Term:4 Log:0/12 Commit:11 + 2->1 MsgFortifyLeaderResp Term:5 Log:0/0 LeadEpoch:1 + 2->1 MsgAppResp Term:5 Log:0/12 Commit:11 > 3 handling Ready Ready MustSync=true: - HardState Term:4 Vote:1 Commit:10 Lead:1 LeadEpoch:1 + HardState Term:5 Vote:1 Commit:10 Lead:1 LeadEpoch:1 Messages: - 3->1 MsgFortifyLeaderResp Term:4 Log:0/0 LeadEpoch:1 - 3->1 MsgAppResp Term:4 Log:1/11 Rejected (Hint: 10) Commit:10 + 3->1 MsgFortifyLeaderResp Term:5 Log:0/0 LeadEpoch:1 + 3->1 MsgAppResp Term:5 Log:1/11 Rejected (Hint: 10) Commit:10 > 1 receiving messages - 2->1 MsgFortifyLeaderResp Term:4 Log:0/0 LeadEpoch:1 - 2->1 MsgAppResp Term:4 Log:0/12 Commit:11 - 3->1 MsgFortifyLeaderResp Term:4 Log:0/0 LeadEpoch:1 - 3->1 MsgAppResp Term:4 Log:1/11 Rejected (Hint: 10) Commit:10 + 2->1 MsgFortifyLeaderResp Term:5 Log:0/0 LeadEpoch:1 + 2->1 MsgAppResp Term:5 Log:0/12 Commit:11 + 3->1 MsgFortifyLeaderResp Term:5 Log:0/0 LeadEpoch:1 + 3->1 MsgAppResp Term:5 Log:1/11 Rejected (Hint: 10) Commit:10 DEBUG 1 received MsgAppResp(rejected, hint: (index 10, term 1)) from 3 for index 11 DEBUG 1 decreased progress of 3 to [StateProbe match=0 next=11 sentCommit=10 matchCommit=10] > 1 handling Ready Ready MustSync=true: - HardState Term:4 Vote:1 Commit:12 Lead:1 LeadEpoch:1 + HardState Term:5 Vote:1 Commit:12 Lead:1 LeadEpoch:1 CommittedEntries: - 4/12 EntryNormal "" + 5/12 EntryNormal "" Messages: - 1->2 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] - 1->2 MsgApp Term:4 Log:4/12 Commit:12 - 1->3 MsgApp Term:4 Log:1/11 Commit:12 Entries:[4/12 EntryNormal ""] - 1->3 MsgApp Term:4 Log:1/10 Commit:12 Entries:[ + 1->2 MsgApp Term:5 Log:1/11 Commit:11 Entries:[5/12 EntryNormal ""] + 1->2 MsgApp Term:5 Log:5/12 Commit:12 + 1->3 MsgApp Term:5 Log:1/11 Commit:12 Entries:[5/12 EntryNormal ""] + 1->3 MsgApp Term:5 Log:1/10 Commit:12 Entries:[ 1/11 EntryNormal "" - 4/12 EntryNormal "" + 5/12 EntryNormal "" ] > 2 receiving messages - 1->2 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] - 1->2 MsgApp Term:4 Log:4/12 Commit:12 + 1->2 MsgApp Term:5 Log:1/11 Commit:11 Entries:[5/12 EntryNormal ""] + 1->2 MsgApp Term:5 Log:5/12 Commit:12 > 3 receiving messages - 1->3 MsgApp Term:4 Log:1/11 Commit:12 Entries:[4/12 EntryNormal ""] + 1->3 MsgApp Term:5 Log:1/11 Commit:12 Entries:[5/12 EntryNormal ""] DEBUG 3 [logterm: 0, index: 11] rejected MsgApp [logterm: 1, index: 11] from 1 - 1->3 MsgApp Term:4 Log:1/10 Commit:12 Entries:[ + 1->3 MsgApp Term:5 Log:1/10 Commit:12 Entries:[ 1/11 EntryNormal "" - 4/12 EntryNormal "" + 5/12 EntryNormal "" ] > 2 handling Ready Ready MustSync=true: - HardState Term:4 Commit:12 Lead:1 LeadEpoch:1 + HardState Term:5 Commit:12 Lead:1 LeadEpoch:1 CommittedEntries: - 4/12 EntryNormal "" + 5/12 EntryNormal "" Messages: - 2->1 MsgAppResp Term:4 Log:0/12 Commit:11 - 2->1 MsgAppResp Term:4 Log:0/12 Commit:12 + 2->1 MsgAppResp Term:5 Log:0/12 Commit:11 + 2->1 MsgAppResp Term:5 Log:0/12 Commit:12 > 3 handling Ready Ready MustSync=true: - HardState Term:4 Vote:1 Commit:12 Lead:1 LeadEpoch:1 + HardState Term:5 Vote:1 Commit:12 Lead:1 LeadEpoch:1 Entries: 1/11 EntryNormal "" - 4/12 EntryNormal "" + 5/12 EntryNormal "" CommittedEntries: 1/11 EntryNormal "" - 4/12 EntryNormal "" + 5/12 EntryNormal "" Messages: - 3->1 MsgAppResp Term:4 Log:1/11 Rejected (Hint: 10) Commit:10 - 3->1 MsgAppResp Term:4 Log:0/12 Commit:12 + 3->1 MsgAppResp Term:5 Log:1/11 Rejected (Hint: 10) Commit:10 + 3->1 MsgAppResp Term:5 Log:0/12 Commit:12 > 1 receiving messages - 2->1 MsgAppResp Term:4 Log:0/12 Commit:11 - 2->1 MsgAppResp Term:4 Log:0/12 Commit:12 - 3->1 MsgAppResp Term:4 Log:1/11 Rejected (Hint: 10) Commit:10 + 2->1 MsgAppResp Term:5 Log:0/12 Commit:11 + 2->1 MsgAppResp Term:5 Log:0/12 Commit:12 + 3->1 MsgAppResp Term:5 Log:1/11 Rejected (Hint: 10) Commit:10 DEBUG 1 received MsgAppResp(rejected, hint: (index 10, term 1)) from 3 for index 11 - 3->1 MsgAppResp Term:4 Log:0/12 Commit:12 + 3->1 MsgAppResp Term:5 Log:0/12 Commit:12 diff --git a/pkg/raft/testdata/leader_step_down_stranded_peer_prevote.txt b/pkg/raft/testdata/leader_step_down_stranded_peer_prevote.txt index 9d11a1ffb350..b829abea2710 100644 --- a/pkg/raft/testdata/leader_step_down_stranded_peer_prevote.txt +++ b/pkg/raft/testdata/leader_step_down_stranded_peer_prevote.txt @@ -339,9 +339,58 @@ stabilize 1 3 3->1 MsgAppResp Term:3 Log:0/0 > 1 receiving messages 3->1 MsgAppResp Term:3 Log:0/0 - INFO 1 [term: 1] received a MsgAppResp message with higher term from 3 [term: 3], advancing term - INFO 1 became follower at term 3 + INFO 1 [term: 1] received a MsgAppResp message with higher term from 3 [term: 3], stepping down as leader to recover stranded peer + INFO 1 became follower at term 1 3->1 MsgAppResp Term:3 Log:0/0 + INFO 1 [term: 1] received a MsgAppResp message with higher term from 3 [term: 3], ignoring and still supporting fortified leader +> 1 handling Ready + Ready MustSync=false: + State:StateFollower + +# Wait until the ex-leader can be safely defortified. +campaign 1 +---- +DEBUG 1 ignoring MsgHup due to leader fortification + +send-de-fortify 1 1 +---- +DEBUG 1 setting election elapsed to start from 3 ticks after store liveness support expired + +# With pre-vote, the ex-leader will learn about the higher term from the stranded +# peer during the first time that it campaigns. When it campaigns again, it will +# do so at the higher term and will be able to win the election. +campaign 1 +---- +INFO 1 is starting a new election at term 1 +INFO 1 became pre-candidate at term 1 +INFO 1 [logterm: 1, index: 11] sent MsgPreVote request to 2 at term 1 +INFO 1 [logterm: 1, index: 11] sent MsgPreVote request to 3 at term 1 + +stabilize +---- +> 1 handling Ready + Ready MustSync=true: + State:StatePreCandidate + HardState Term:1 Vote:1 Commit:11 Lead:0 LeadEpoch:0 + Messages: + 1->2 MsgPreVote Term:2 Log:1/11 + 1->3 MsgPreVote Term:2 Log:1/11 + INFO 1 received MsgPreVoteResp from 1 at term 1 + INFO 1 has received 1 MsgPreVoteResp votes and 0 vote rejections +> 2 receiving messages + 1->2 MsgPreVote Term:2 Log:1/11 + INFO 2 [logterm: 1, index: 11, vote: 1] ignored MsgPreVote from 1 [logterm: 1, index: 11] at term 1: supporting fortified leader 1 at epoch 1 +> 3 receiving messages + 1->3 MsgPreVote Term:2 Log:1/11 + INFO 3 [logterm: 1, index: 10, vote: 3] rejected MsgPreVote from 1 [logterm: 1, index: 11] at term 3 +> 3 handling Ready + Ready MustSync=false: + Messages: + 3->1 MsgPreVoteResp Term:3 Log:0/0 Rejected (Hint: 0) +> 1 receiving messages + 3->1 MsgPreVoteResp Term:3 Log:0/0 Rejected (Hint: 0) + INFO 1 [term: 1] received a MsgPreVoteResp message with higher term from 3 [term: 3], advancing term + INFO 1 became follower at term 3 > 1 handling Ready Ready MustSync=true: State:StateFollower @@ -422,8 +471,8 @@ stabilize 1->3 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] > 2 receiving messages 1->2 MsgFortifyLeader Term:4 Log:0/0 - INFO 2 [term: 1] received a MsgFortifyLeader message with higher term from 1 [term: 4], advancing term DEBUG 2 setting election elapsed to start from 3 ticks after store liveness support expired + INFO 2 [term: 1] received a MsgFortifyLeader message with higher term from 1 [term: 4], new leader indicated, advancing term INFO 2 became follower at term 4 1->2 MsgApp Term:4 Log:1/11 Commit:11 Entries:[4/12 EntryNormal ""] > 3 receiving messages diff --git a/pkg/raft/testdata/mixedversions/checkquorum.txt b/pkg/raft/testdata/mixedversions/checkquorum.txt index cdab21a68043..a06460c13db4 100644 --- a/pkg/raft/testdata/mixedversions/checkquorum.txt +++ b/pkg/raft/testdata/mixedversions/checkquorum.txt @@ -202,7 +202,7 @@ stabilize 2->1 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] > 3 receiving messages 2->3 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] - INFO 3 [term: 1] received a MsgApp message with higher term from 2 [term: 3], advancing term + INFO 3 [term: 1] received a MsgApp message with higher term from 2 [term: 3], new leader indicated, advancing term INFO 3 became follower at term 3 > 1 handling Ready Ready MustSync=true: diff --git a/pkg/raft/testdata/mixedversions/snapshot_succeed_via_app_resp.txt b/pkg/raft/testdata/mixedversions/snapshot_succeed_via_app_resp.txt index 587178db12bb..8698fff33b5c 100644 --- a/pkg/raft/testdata/mixedversions/snapshot_succeed_via_app_resp.txt +++ b/pkg/raft/testdata/mixedversions/snapshot_succeed_via_app_resp.txt @@ -76,7 +76,7 @@ stabilize 3 ---- > 3 receiving messages 1->3 MsgHeartbeat Term:1 Log:0/0 - INFO 3 [term: 0] received a MsgHeartbeat message with higher term from 1 [term: 1], advancing term + INFO 3 [term: 0] received a MsgHeartbeat message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 3 became follower at term 1 > 3 handling Ready Ready MustSync=true: diff --git a/pkg/raft/testdata/prevote_checkquorum.txt b/pkg/raft/testdata/prevote_checkquorum.txt index 883710aded24..64cb487c82ab 100644 --- a/pkg/raft/testdata/prevote_checkquorum.txt +++ b/pkg/raft/testdata/prevote_checkquorum.txt @@ -155,7 +155,7 @@ stabilize 3->2 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] > 1 receiving messages 3->1 MsgFortifyLeader Term:2 Log:0/0 - INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 3 [term: 2], advancing term + INFO 1 [term: 1] received a MsgFortifyLeader message with higher term from 3 [term: 2], new leader indicated, advancing term INFO 1 became follower at term 2 3->1 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] > 2 receiving messages @@ -359,7 +359,7 @@ stabilize 2->1 MsgApp Term:3 Log:2/12 Commit:12 Entries:[3/13 EntryNormal ""] > 3 receiving messages 2->3 MsgFortifyLeader Term:3 Log:0/0 - INFO 3 [term: 2] received a MsgFortifyLeader message with higher term from 2 [term: 3], advancing term + INFO 3 [term: 2] received a MsgFortifyLeader message with higher term from 2 [term: 3], new leader indicated, advancing term INFO 3 became follower at term 3 2->3 MsgApp Term:3 Log:2/12 Commit:12 Entries:[3/13 EntryNormal ""] > 1 handling Ready diff --git a/pkg/raft/testdata/snapshot_new_term.txt b/pkg/raft/testdata/snapshot_new_term.txt index 44f422311645..20abc2cead52 100644 --- a/pkg/raft/testdata/snapshot_new_term.txt +++ b/pkg/raft/testdata/snapshot_new_term.txt @@ -140,8 +140,8 @@ stabilize > 3 receiving messages 2->3 MsgSnap Term:2 Log:0/0 Snapshot: Index:12 Term:2 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false - INFO 3 [term: 1] received a MsgSnap message with higher term from 2 [term: 2], advancing term DEBUG 3 setting election elapsed to start from 3 ticks after store liveness support expired + INFO 3 [term: 1] received a MsgSnap message with higher term from 2 [term: 2], new leader indicated, advancing term INFO 3 became follower at term 2 INFO log [committed=11, applied=11, applying=11, unstable.offset=12, unstable.offsetInProgress=12, len(unstable.Entries)=0] starts to restore snapshot [index: 12, term: 2] INFO 3 switched to configuration voters=(1 2 3) diff --git a/pkg/raft/testdata/snapshot_succeed_via_app_resp.txt b/pkg/raft/testdata/snapshot_succeed_via_app_resp.txt index f3e03a3d80dd..52f6b35b3b32 100644 --- a/pkg/raft/testdata/snapshot_succeed_via_app_resp.txt +++ b/pkg/raft/testdata/snapshot_succeed_via_app_resp.txt @@ -72,7 +72,7 @@ stabilize 3 ---- > 3 receiving messages 1->3 MsgFortifyLeader Term:1 Log:0/0 - INFO 3 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], advancing term + INFO 3 [term: 0] received a MsgFortifyLeader message with higher term from 1 [term: 1], new leader indicated, advancing term INFO 3 became follower at term 1 > 3 handling Ready Ready MustSync=true: