From 419efa1747cdd641f6491b9ba3a5a73744a678d4 Mon Sep 17 00:00:00 2001 From: Pavel Kalinnikov Date: Fri, 9 Feb 2024 12:04:10 +0000 Subject: [PATCH] demo: the effect of batched MsgApp ready Signed-off-by: Pavel Kalinnikov --- raft.go | 7 +- rafttest/interaction_env_handler_add_nodes.go | 1 + rawnode.go | 21 +++++- testdata/async_storage_writes.txt | 52 ++++--------- .../async_storage_writes_append_aba_race.txt | 24 +++--- testdata/confchange_disable_validation.txt | 4 +- testdata/confchange_v1_add_single.txt | 2 +- testdata/confchange_v1_remove_leader.txt | 36 ++++----- .../confchange_v1_remove_leader_stepdown.txt | 36 ++++----- testdata/confchange_v2_add_double_auto.txt | 72 +++++++++--------- .../confchange_v2_add_double_implicit.txt | 12 ++- testdata/confchange_v2_add_single_auto.txt | 2 +- .../confchange_v2_add_single_explicit.txt | 20 +++-- .../heartbeat_resp_recovers_from_probing.txt | 16 +--- testdata/lagging_commit.txt | 24 +++--- testdata/prevote.txt | 4 +- testdata/replicate_pause.txt | 75 +++++++++++++++---- testdata/slow_follower_after_compaction.txt | 13 ++-- testdata/snapshot_succeed_via_app_resp.txt | 2 +- .../snapshot_succeed_via_app_resp_behind.txt | 2 +- 20 files changed, 227 insertions(+), 198 deletions(-) diff --git a/raft.go b/raft.go index c5cfa98f..70c209f5 100644 --- a/raft.go +++ b/raft.go @@ -626,7 +626,8 @@ func (r *raft) getMessages(to uint64, fc FlowControl, buffer []pb.Message) []pb. } pr := r.trk.Progress[to] buf := msgBuf(buffer) - r.maybeSendAppendBuf(to, pr, &buf) + for r.maybeSendAppendBuf(to, pr, &buf) { + } return buf } @@ -650,6 +651,10 @@ func (r *raft) maybeSendAppend(to uint64, pr *tracker.Progress) bool { return r.maybeSendAppendBuf(to, pr, &r.msgs) } +func (r *raft) appendsReady(pr *tracker.Progress) bool { + return pr.ShouldSendMsgApp(r.raftLog.lastIndex(), r.raftLog.committed) +} + // maybeSendAppendBuf implements maybeSendAppend, and puts the messages into the // provided buffer. func (r *raft) maybeSendAppendBuf(to uint64, pr *tracker.Progress, buf *msgBuf) bool { diff --git a/rafttest/interaction_env_handler_add_nodes.go b/rafttest/interaction_env_handler_add_nodes.go index e68a295f..5c699eb5 100644 --- a/rafttest/interaction_env_handler_add_nodes.go +++ b/rafttest/interaction_env_handler_add_nodes.go @@ -144,6 +144,7 @@ func (env *InteractionEnv) AddNodes(n int, cfg raft.Config, snap pb.Snapshot) er } cfg.Logger = env.Output + cfg.DisableEagerAppends = true rn, err := raft.NewRawNode(&cfg) if err != nil { return err diff --git a/rawnode.go b/rawnode.go index e7a22f96..1be65ce1 100644 --- a/rawnode.go +++ b/rawnode.go @@ -16,7 +16,6 @@ package raft import ( "errors" - pb "go.etcd.io/raft/v3/raftpb" "go.etcd.io/raft/v3/tracker" ) @@ -208,6 +207,15 @@ func (rn *RawNode) readyWithoutAccept() Ready { } } + if r.disableEagerAppends && r.state == StateLeader { + r.trk.Visit(func(id uint64, pr *tracker.Progress) { + if id == r.id { + return + } + rd.Messages = r.getMessages(id, FlowControl{}, rd.Messages) + }) + } + return rd } @@ -486,6 +494,17 @@ func (rn *RawNode) HasReady() bool { if len(r.msgs) > 0 || len(r.msgsAfterAppend) > 0 { return true } + if rn.raft.state == StateLeader { + ready := false + rn.raft.trk.Visit(func(id uint64, pr *tracker.Progress) { + if id != rn.raft.id && !ready { + ready = rn.raft.appendsReady(pr) + } + }) + if ready { + return true + } + } if r.raftLog.hasNextUnstableEnts() || r.raftLog.hasNextCommittedEnts(rn.applyUnstableEntries()) { return true } diff --git a/testdata/async_storage_writes.txt b/testdata/async_storage_writes.txt index 02e59e5a..40330fb0 100644 --- a/testdata/async_storage_writes.txt +++ b/testdata/async_storage_writes.txt @@ -87,12 +87,12 @@ stabilize Entries: 1/11 EntryNormal "" Messages: - 1->2 MsgApp Term:1 Log:1/10 Commit:10 Entries:[1/11 EntryNormal ""] - 1->3 MsgApp Term:1 Log:1/10 Commit:10 Entries:[1/11 EntryNormal ""] 1->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[1/11 EntryNormal ""] Responses:[ 1->1 MsgAppResp Term:1 Log:0/11 AppendThread->1 MsgStorageAppendResp Term:1 Log:1/11 ] + 1->2 MsgApp Term:1 Log:1/10 Commit:10 Entries:[1/11 EntryNormal ""] + 1->3 MsgApp Term:1 Log:1/10 Commit:10 Entries:[1/11 EntryNormal ""] > 2 receiving messages 1->2 MsgApp Term:1 Log:1/10 Commit:10 Entries:[1/11 EntryNormal ""] > 3 receiving messages @@ -151,12 +151,12 @@ stabilize CommittedEntries: 1/11 EntryNormal "" Messages: - 1->2 MsgApp Term:1 Log:1/11 Commit:11 - 1->3 MsgApp Term:1 Log:1/11 Commit:11 1->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:11 Vote:1 1->ApplyThread MsgStorageApply Term:0 Log:0/0 Entries:[1/11 EntryNormal ""] Responses:[ ApplyThread->1 MsgStorageApplyResp Term:0 Log:0/0 Entries:[1/11 EntryNormal ""] ] + 1->2 MsgApp Term:1 Log:1/11 Commit:11 + 1->3 MsgApp Term:1 Log:1/11 Commit:11 > 2 receiving messages 1->2 MsgApp Term:1 Log:1/11 Commit:11 > 3 receiving messages @@ -235,12 +235,12 @@ process-ready 1 2 3 Entries: 1/12 EntryNormal "prop_1" Messages: - 1->2 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "prop_1"] - 1->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "prop_1"] 1->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[1/12 EntryNormal "prop_1"] Responses:[ 1->1 MsgAppResp Term:1 Log:0/12 AppendThread->1 MsgStorageAppendResp Term:1 Log:1/12 ] + 1->2 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "prop_1"] + 1->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "prop_1"] > 2 handling Ready > 3 handling Ready @@ -285,12 +285,12 @@ process-ready 1 2 3 Entries: 1/13 EntryNormal "prop_2" Messages: - 1->2 MsgApp Term:1 Log:1/12 Commit:11 Entries:[1/13 EntryNormal "prop_2"] - 1->3 MsgApp Term:1 Log:1/12 Commit:11 Entries:[1/13 EntryNormal "prop_2"] 1->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[1/13 EntryNormal "prop_2"] Responses:[ 1->1 MsgAppResp Term:1 Log:0/13 AppendThread->1 MsgStorageAppendResp Term:1 Log:1/13 ] + 1->2 MsgApp Term:1 Log:1/12 Commit:11 Entries:[1/13 EntryNormal "prop_2"] + 1->3 MsgApp Term:1 Log:1/12 Commit:11 Entries:[1/13 EntryNormal "prop_2"] > 2 handling Ready > 3 handling Ready @@ -368,10 +368,6 @@ process-ready 1 2 3 CommittedEntries: 1/12 EntryNormal "prop_1" Messages: - 1->2 MsgApp Term:1 Log:1/13 Commit:12 - 1->3 MsgApp Term:1 Log:1/13 Commit:12 - 1->2 MsgApp Term:1 Log:1/13 Commit:12 Entries:[1/14 EntryNormal "prop_3"] - 1->3 MsgApp Term:1 Log:1/13 Commit:12 Entries:[1/14 EntryNormal "prop_3"] 1->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:12 Vote:1 Entries:[1/14 EntryNormal "prop_3"] Responses:[ 1->1 MsgAppResp Term:1 Log:0/14 AppendThread->1 MsgStorageAppendResp Term:1 Log:1/14 @@ -379,6 +375,8 @@ process-ready 1 2 3 1->ApplyThread MsgStorageApply Term:0 Log:0/0 Entries:[1/12 EntryNormal "prop_1"] Responses:[ ApplyThread->1 MsgStorageApplyResp Term:0 Log:0/0 Entries:[1/12 EntryNormal "prop_1"] ] + 1->2 MsgApp Term:1 Log:1/13 Commit:12 Entries:[1/14 EntryNormal "prop_3"] + 1->3 MsgApp Term:1 Log:1/13 Commit:12 Entries:[1/14 EntryNormal "prop_3"] > 2 handling Ready > 3 handling Ready @@ -386,9 +384,7 @@ process-ready 1 2 3 deliver-msgs 1 2 3 ---- -1->2 MsgApp Term:1 Log:1/13 Commit:12 1->2 MsgApp Term:1 Log:1/13 Commit:12 Entries:[1/14 EntryNormal "prop_3"] -1->3 MsgApp Term:1 Log:1/13 Commit:12 1->3 MsgApp Term:1 Log:1/13 Commit:12 Entries:[1/14 EntryNormal "prop_3"] process-ready 1 2 3 @@ -404,7 +400,6 @@ process-ready 1 2 3 1/12 EntryNormal "prop_1" Messages: 2->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:12 Vote:1 Entries:[1/14 EntryNormal "prop_3"] Responses:[ - 2->1 MsgAppResp Term:1 Log:0/13 2->1 MsgAppResp Term:1 Log:0/14 AppendThread->2 MsgStorageAppendResp Term:1 Log:1/14 ] @@ -420,7 +415,6 @@ process-ready 1 2 3 1/12 EntryNormal "prop_1" Messages: 3->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:12 Vote:1 Entries:[1/14 EntryNormal "prop_3"] Responses:[ - 3->1 MsgAppResp Term:1 Log:0/13 3->1 MsgAppResp Term:1 Log:0/14 AppendThread->3 MsgStorageAppendResp Term:1 Log:1/14 ] @@ -472,10 +466,6 @@ process-ready 1 2 3 CommittedEntries: 1/13 EntryNormal "prop_2" Messages: - 1->2 MsgApp Term:1 Log:1/14 Commit:13 - 1->3 MsgApp Term:1 Log:1/14 Commit:13 - 1->2 MsgApp Term:1 Log:1/14 Commit:13 Entries:[1/15 EntryNormal "prop_4"] - 1->3 MsgApp Term:1 Log:1/14 Commit:13 Entries:[1/15 EntryNormal "prop_4"] 1->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:13 Vote:1 Entries:[1/15 EntryNormal "prop_4"] Responses:[ 1->1 MsgAppResp Term:1 Log:0/15 AppendThread->1 MsgStorageAppendResp Term:1 Log:1/15 @@ -483,6 +473,8 @@ process-ready 1 2 3 1->ApplyThread MsgStorageApply Term:0 Log:0/0 Entries:[1/13 EntryNormal "prop_2"] Responses:[ ApplyThread->1 MsgStorageApplyResp Term:0 Log:0/0 Entries:[1/13 EntryNormal "prop_2"] ] + 1->2 MsgApp Term:1 Log:1/14 Commit:13 Entries:[1/15 EntryNormal "prop_4"] + 1->3 MsgApp Term:1 Log:1/14 Commit:13 Entries:[1/15 EntryNormal "prop_4"] > 2 handling Ready > 3 handling Ready @@ -490,9 +482,7 @@ process-ready 1 2 3 deliver-msgs 1 2 3 ---- -1->2 MsgApp Term:1 Log:1/14 Commit:13 1->2 MsgApp Term:1 Log:1/14 Commit:13 Entries:[1/15 EntryNormal "prop_4"] -1->3 MsgApp Term:1 Log:1/14 Commit:13 1->3 MsgApp Term:1 Log:1/14 Commit:13 Entries:[1/15 EntryNormal "prop_4"] process-ready 1 2 3 @@ -508,7 +498,6 @@ process-ready 1 2 3 1/13 EntryNormal "prop_2" Messages: 2->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:13 Vote:1 Entries:[1/15 EntryNormal "prop_4"] Responses:[ - 2->1 MsgAppResp Term:1 Log:0/14 2->1 MsgAppResp Term:1 Log:0/15 AppendThread->2 MsgStorageAppendResp Term:1 Log:1/15 ] @@ -524,7 +513,6 @@ process-ready 1 2 3 1/13 EntryNormal "prop_2" Messages: 3->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:13 Vote:1 Entries:[1/15 EntryNormal "prop_4"] Responses:[ - 3->1 MsgAppResp Term:1 Log:0/14 3->1 MsgAppResp Term:1 Log:0/15 AppendThread->3 MsgStorageAppendResp Term:1 Log:1/15 ] @@ -544,14 +532,12 @@ process-append-thread 1 2 3 Processing: 2->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:12 Vote:1 Entries:[1/14 EntryNormal "prop_3"] Responses: - 2->1 MsgAppResp Term:1 Log:0/13 2->1 MsgAppResp Term:1 Log:0/14 AppendThread->2 MsgStorageAppendResp Term:1 Log:1/14 > 3 processing append thread Processing: 3->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:12 Vote:1 Entries:[1/14 EntryNormal "prop_3"] Responses: - 3->1 MsgAppResp Term:1 Log:0/13 3->1 MsgAppResp Term:1 Log:0/14 AppendThread->3 MsgStorageAppendResp Term:1 Log:1/14 @@ -577,9 +563,7 @@ deliver-msgs 1 2 3 ---- 1->1 MsgAppResp Term:1 Log:0/14 AppendThread->1 MsgStorageAppendResp Term:1 Log:1/14 -2->1 MsgAppResp Term:1 Log:0/13 2->1 MsgAppResp Term:1 Log:0/14 -3->1 MsgAppResp Term:1 Log:0/13 3->1 MsgAppResp Term:1 Log:0/14 ApplyThread->1 MsgStorageApplyResp Term:0 Log:0/0 Entries:[1/12 EntryNormal "prop_1"] AppendThread->2 MsgStorageAppendResp Term:1 Log:1/14 @@ -595,14 +579,14 @@ process-ready 1 2 3 CommittedEntries: 1/14 EntryNormal "prop_3" Messages: - 1->2 MsgApp Term:1 Log:1/15 Commit:14 - 1->3 MsgApp Term:1 Log:1/15 Commit:14 1->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:14 Vote:1 Responses:[ AppendThread->1 MsgStorageAppendResp Term:1 Log:1/15 ] 1->ApplyThread MsgStorageApply Term:0 Log:0/0 Entries:[1/14 EntryNormal "prop_3"] Responses:[ ApplyThread->1 MsgStorageApplyResp Term:0 Log:0/0 Entries:[1/14 EntryNormal "prop_3"] ] + 1->2 MsgApp Term:1 Log:1/15 Commit:14 + 1->3 MsgApp Term:1 Log:1/15 Commit:14 > 2 handling Ready > 3 handling Ready @@ -656,14 +640,12 @@ process-append-thread 1 2 3 Processing: 2->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:13 Vote:1 Entries:[1/15 EntryNormal "prop_4"] Responses: - 2->1 MsgAppResp Term:1 Log:0/14 2->1 MsgAppResp Term:1 Log:0/15 AppendThread->2 MsgStorageAppendResp Term:1 Log:1/15 > 3 processing append thread Processing: 3->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:13 Vote:1 Entries:[1/15 EntryNormal "prop_4"] Responses: - 3->1 MsgAppResp Term:1 Log:0/14 3->1 MsgAppResp Term:1 Log:0/15 AppendThread->3 MsgStorageAppendResp Term:1 Log:1/15 @@ -689,9 +671,7 @@ deliver-msgs 1 2 3 ---- 1->1 MsgAppResp Term:1 Log:0/15 AppendThread->1 MsgStorageAppendResp Term:1 Log:1/15 -2->1 MsgAppResp Term:1 Log:0/14 2->1 MsgAppResp Term:1 Log:0/15 -3->1 MsgAppResp Term:1 Log:0/14 3->1 MsgAppResp Term:1 Log:0/15 ApplyThread->1 MsgStorageApplyResp Term:0 Log:0/0 Entries:[1/13 EntryNormal "prop_2"] AppendThread->2 MsgStorageAppendResp Term:1 Log:1/15 @@ -707,12 +687,12 @@ process-ready 1 2 3 CommittedEntries: 1/15 EntryNormal "prop_4" Messages: - 1->2 MsgApp Term:1 Log:1/15 Commit:15 - 1->3 MsgApp Term:1 Log:1/15 Commit:15 1->AppendThread MsgStorageAppend Term:1 Log:0/0 Commit:15 Vote:1 1->ApplyThread MsgStorageApply Term:0 Log:0/0 Entries:[1/15 EntryNormal "prop_4"] Responses:[ ApplyThread->1 MsgStorageApplyResp Term:0 Log:0/0 Entries:[1/15 EntryNormal "prop_4"] ] + 1->2 MsgApp Term:1 Log:1/15 Commit:15 + 1->3 MsgApp Term:1 Log:1/15 Commit:15 > 2 handling Ready > 3 handling Ready diff --git a/testdata/async_storage_writes_append_aba_race.txt b/testdata/async_storage_writes_append_aba_race.txt index 83964fe7..2f5e3cd4 100644 --- a/testdata/async_storage_writes_append_aba_race.txt +++ b/testdata/async_storage_writes_append_aba_race.txt @@ -36,16 +36,16 @@ Ready MustSync=true: Entries: 1/12 EntryNormal "init_prop" Messages: +2->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[1/12 EntryNormal "init_prop"] Responses:[ + 2->2 MsgAppResp Term:1 Log:0/12 + AppendThread->2 MsgStorageAppendResp Term:1 Log:1/12 +] 2->1 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "init_prop"] 2->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "init_prop"] 2->4 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "init_prop"] 2->5 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "init_prop"] 2->6 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "init_prop"] 2->7 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "init_prop"] -2->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[1/12 EntryNormal "init_prop"] Responses:[ - 2->2 MsgAppResp Term:1 Log:0/12 - AppendThread->2 MsgStorageAppendResp Term:1 Log:1/12 -] deliver-msgs 1 drop=(3,4,5,6,7) ---- @@ -191,16 +191,16 @@ Lead:3 State:StateLeader Entries: 2/12 EntryNormal "" Messages: +3->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[2/12 EntryNormal ""] Responses:[ + 3->3 MsgAppResp Term:2 Log:0/12 + AppendThread->3 MsgStorageAppendResp Term:2 Log:2/12 +] 3->1 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] 3->2 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] 3->4 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] 3->5 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] 3->6 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] 3->7 MsgApp Term:2 Log:1/11 Commit:11 Entries:[2/12 EntryNormal ""] -3->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[2/12 EntryNormal ""] Responses:[ - 3->3 MsgAppResp Term:2 Log:0/12 - AppendThread->3 MsgStorageAppendResp Term:2 Log:2/12 -] deliver-msgs 1 drop=(2,4,5,6,7) ---- @@ -348,16 +348,16 @@ Lead:4 State:StateLeader Entries: 3/12 EntryNormal "" Messages: +4->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[3/12 EntryNormal ""] Responses:[ + 4->4 MsgAppResp Term:3 Log:0/12 + AppendThread->4 MsgStorageAppendResp Term:3 Log:3/12 +] 4->1 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] 4->2 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] 4->3 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] 4->5 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] 4->6 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] 4->7 MsgApp Term:3 Log:1/11 Commit:11 Entries:[3/12 EntryNormal ""] -4->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[3/12 EntryNormal ""] Responses:[ - 4->4 MsgAppResp Term:3 Log:0/12 - AppendThread->4 MsgStorageAppendResp Term:3 Log:3/12 -] # Step 7: before the new entries reach node 1, it hears of the term change # through a heartbeat and persists the new term. Node 1 then receives these diff --git a/testdata/confchange_disable_validation.txt b/testdata/confchange_disable_validation.txt index 1a2bc4fd..b0a131b9 100644 --- a/testdata/confchange_disable_validation.txt +++ b/testdata/confchange_disable_validation.txt @@ -71,6 +71,6 @@ stabilize CommittedEntries: 1/6 EntryConfChangeV2 Messages: - 1->2 MsgApp Term:1 Log:1/5 Commit:5 Entries:[1/6 EntryConfChangeV2] - 1->3 MsgApp Term:1 Log:1/5 Commit:5 Entries:[1/6 EntryConfChangeV2] + 1->2 MsgApp Term:1 Log:1/5 Commit:6 Entries:[1/6 EntryConfChangeV2] + 1->3 MsgApp Term:1 Log:1/5 Commit:6 Entries:[1/6 EntryConfChangeV2] INFO 1 switched to configuration voters=(1) learners=(2 3) diff --git a/testdata/confchange_v1_add_single.txt b/testdata/confchange_v1_add_single.txt index e54a183f..64a2c2b1 100644 --- a/testdata/confchange_v1_add_single.txt +++ b/testdata/confchange_v1_add_single.txt @@ -71,9 +71,9 @@ stabilize 2->1 MsgAppResp Term:1 Log:0/3 Rejected (Hint: 0) DEBUG 1 received MsgAppResp(rejected, hint: (index 0, term 0)) from 2 for index 3 DEBUG 1 decreased progress of 2 to [StateProbe match=0 next=1] +> 1 handling Ready DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 next=1] DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 next=1 paused pendingSnap=4] -> 1 handling Ready Ready MustSync=false: Messages: 1->2 MsgSnap Term:1 Log:0/0 diff --git a/testdata/confchange_v1_remove_leader.txt b/testdata/confchange_v1_remove_leader.txt index cc91508a..435b68a1 100644 --- a/testdata/confchange_v1_remove_leader.txt +++ b/testdata/confchange_v1_remove_leader.txt @@ -52,25 +52,30 @@ Entries: 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: -1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] -1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] -1->2 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] -1->3 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] +1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" +] +1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" +] # Send response from n2 (which is enough to commit the entries so far next time # n1 runs). stabilize 2 ---- > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] - 1->2 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] + 1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" + ] > 2 handling Ready Ready MustSync=true: Entries: 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: - 2->1 MsgAppResp Term:1 Log:0/4 2->1 MsgAppResp Term:1 Log:0/5 # Put another entry in n1's log. @@ -92,7 +97,6 @@ stabilize 1 1->2 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] 1->3 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] > 1 receiving messages - 2->1 MsgAppResp Term:1 Log:0/4 2->1 MsgAppResp Term:1 Log:0/5 > 1 handling Ready Ready MustSync=false: @@ -101,8 +105,6 @@ stabilize 1 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: - 1->2 MsgApp Term:1 Log:1/6 Commit:4 - 1->3 MsgApp Term:1 Log:1/6 Commit:4 1->2 MsgApp Term:1 Log:1/6 Commit:5 1->3 MsgApp Term:1 Log:1/6 Commit:5 INFO 1 switched to configuration voters=(2 3) @@ -118,7 +120,6 @@ stabilize 2 ---- > 2 receiving messages 1->2 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] - 1->2 MsgApp Term:1 Log:1/6 Commit:4 1->2 MsgApp Term:1 Log:1/6 Commit:5 > 2 handling Ready Ready MustSync=true: @@ -131,7 +132,6 @@ stabilize 2 Messages: 2->1 MsgAppResp Term:1 Log:0/6 2->1 MsgAppResp Term:1 Log:0/6 - 2->1 MsgAppResp Term:1 Log:0/6 INFO 2 switched to configuration voters=(2 3) # ... which thankfully is what we see on the leader. @@ -140,16 +140,16 @@ stabilize 1 > 1 receiving messages 2->1 MsgAppResp Term:1 Log:0/6 2->1 MsgAppResp Term:1 Log:0/6 - 2->1 MsgAppResp Term:1 Log:0/6 # When n3 responds, quorum is reached and everything falls into place. stabilize ---- > 3 receiving messages - 1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] - 1->3 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] + 1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" + ] 1->3 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] - 1->3 MsgApp Term:1 Log:1/6 Commit:4 1->3 MsgApp Term:1 Log:1/6 Commit:5 > 3 handling Ready Ready MustSync=true: @@ -162,18 +162,14 @@ stabilize 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: - 3->1 MsgAppResp Term:1 Log:0/4 3->1 MsgAppResp Term:1 Log:0/5 3->1 MsgAppResp Term:1 Log:0/6 3->1 MsgAppResp Term:1 Log:0/6 - 3->1 MsgAppResp Term:1 Log:0/6 INFO 3 switched to configuration voters=(2 3) > 1 receiving messages - 3->1 MsgAppResp Term:1 Log:0/4 3->1 MsgAppResp Term:1 Log:0/5 3->1 MsgAppResp Term:1 Log:0/6 3->1 MsgAppResp Term:1 Log:0/6 - 3->1 MsgAppResp Term:1 Log:0/6 > 1 handling Ready Ready MustSync=false: HardState Term:1 Vote:1 Commit:6 diff --git a/testdata/confchange_v1_remove_leader_stepdown.txt b/testdata/confchange_v1_remove_leader_stepdown.txt index fe397650..7c814598 100644 --- a/testdata/confchange_v1_remove_leader_stepdown.txt +++ b/testdata/confchange_v1_remove_leader_stepdown.txt @@ -53,25 +53,30 @@ Entries: 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: -1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] -1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] -1->2 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] -1->3 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] +1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" +] +1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" +] # Send response from n2 (which is enough to commit the entries so far next time # n1 runs). stabilize 2 ---- > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] - 1->2 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] + 1->2 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" + ] > 2 handling Ready Ready MustSync=true: Entries: 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: - 2->1 MsgAppResp Term:1 Log:0/4 2->1 MsgAppResp Term:1 Log:0/5 # Put another entry in n1's log. @@ -91,7 +96,6 @@ stabilize 1 1->2 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] 1->3 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] > 1 receiving messages - 2->1 MsgAppResp Term:1 Log:0/4 2->1 MsgAppResp Term:1 Log:0/5 > 1 handling Ready Ready MustSync=false: @@ -100,8 +104,6 @@ stabilize 1 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: - 1->2 MsgApp Term:1 Log:1/6 Commit:4 - 1->3 MsgApp Term:1 Log:1/6 Commit:4 1->2 MsgApp Term:1 Log:1/6 Commit:5 1->3 MsgApp Term:1 Log:1/6 Commit:5 INFO 1 switched to configuration voters=(2 3) @@ -121,7 +123,6 @@ stabilize 2 ---- > 2 receiving messages 1->2 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] - 1->2 MsgApp Term:1 Log:1/6 Commit:4 1->2 MsgApp Term:1 Log:1/6 Commit:5 > 2 handling Ready Ready MustSync=true: @@ -134,7 +135,6 @@ stabilize 2 Messages: 2->1 MsgAppResp Term:1 Log:0/6 2->1 MsgAppResp Term:1 Log:0/6 - 2->1 MsgAppResp Term:1 Log:0/6 INFO 2 switched to configuration voters=(2 3) # ...because the old leader n1 ignores the append responses. @@ -143,16 +143,16 @@ stabilize 1 > 1 receiving messages 2->1 MsgAppResp Term:1 Log:0/6 2->1 MsgAppResp Term:1 Log:0/6 - 2->1 MsgAppResp Term:1 Log:0/6 # When n3 responds, quorum is reached and everything falls into place. stabilize ---- > 3 receiving messages - 1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[1/4 EntryConfChange r1] - 1->3 MsgApp Term:1 Log:1/4 Commit:3 Entries:[1/5 EntryNormal "foo"] + 1->3 MsgApp Term:1 Log:1/3 Commit:3 Entries:[ + 1/4 EntryConfChange r1 + 1/5 EntryNormal "foo" + ] 1->3 MsgApp Term:1 Log:1/5 Commit:3 Entries:[1/6 EntryNormal "bar"] - 1->3 MsgApp Term:1 Log:1/6 Commit:4 1->3 MsgApp Term:1 Log:1/6 Commit:5 > 3 handling Ready Ready MustSync=true: @@ -165,18 +165,14 @@ stabilize 1/4 EntryConfChange r1 1/5 EntryNormal "foo" Messages: - 3->1 MsgAppResp Term:1 Log:0/4 3->1 MsgAppResp Term:1 Log:0/5 3->1 MsgAppResp Term:1 Log:0/6 3->1 MsgAppResp Term:1 Log:0/6 - 3->1 MsgAppResp Term:1 Log:0/6 INFO 3 switched to configuration voters=(2 3) > 1 receiving messages - 3->1 MsgAppResp Term:1 Log:0/4 3->1 MsgAppResp Term:1 Log:0/5 3->1 MsgAppResp Term:1 Log:0/6 3->1 MsgAppResp Term:1 Log:0/6 - 3->1 MsgAppResp Term:1 Log:0/6 # n1 can no longer propose. propose 1 baz diff --git a/testdata/confchange_v2_add_double_auto.txt b/testdata/confchange_v2_add_double_auto.txt index bf1dfcbe..81fa8388 100644 --- a/testdata/confchange_v2_add_double_auto.txt +++ b/testdata/confchange_v2_add_double_auto.txt @@ -69,8 +69,14 @@ stabilize 1 Entries: 1/5 EntryConfChangeV2 Messages: - 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2 v3] - 1->3 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2 v3] + 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[ + 1/4 EntryConfChangeV2 v2 v3 + 1/5 EntryConfChangeV2 + ] + 1->3 MsgApp Term:1 Log:1/3 Commit:4 Entries:[ + 1/4 EntryConfChangeV2 v2 v3 + 1/5 EntryConfChangeV2 + ] # First, play out the whole interaction between n1 and n2. We see n1's probe to # n2 get rejected (since n2 needs a snapshot); the snapshot is delivered at which @@ -80,7 +86,10 @@ stabilize 1 stabilize 1 2 ---- > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2 v3] + 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[ + 1/4 EntryConfChangeV2 v2 v3 + 1/5 EntryConfChangeV2 + ] INFO 2 [term: 0] received a MsgApp message with higher term from 1 [term: 1] INFO 2 became follower at term 1 DEBUG 2 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 @@ -94,9 +103,9 @@ stabilize 1 2 2->1 MsgAppResp Term:1 Log:0/3 Rejected (Hint: 0) DEBUG 1 received MsgAppResp(rejected, hint: (index 0, term 0)) from 2 for index 3 DEBUG 1 decreased progress of 2 to [StateProbe match=0 next=1] +> 1 handling Ready DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 next=1] DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 next=1 paused pendingSnap=4] -> 1 handling Ready Ready MustSync=false: Messages: 1->2 MsgSnap Term:1 Log:0/0 @@ -156,7 +165,10 @@ stabilize 1 2 stabilize 1 3 ---- > 3 receiving messages - 1->3 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2 v3] + 1->3 MsgApp Term:1 Log:1/3 Commit:4 Entries:[ + 1/4 EntryConfChangeV2 v2 v3 + 1/5 EntryConfChangeV2 + ] INFO 3 [term: 0] received a MsgApp message with higher term from 1 [term: 1] INFO 3 became follower at term 1 DEBUG 3 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 @@ -170,9 +182,9 @@ stabilize 1 3 3->1 MsgAppResp Term:1 Log:0/3 Rejected (Hint: 0) DEBUG 1 received MsgAppResp(rejected, hint: (index 0, term 0)) from 3 for index 3 DEBUG 1 decreased progress of 3 to [StateProbe match=0 next=1] +> 1 handling Ready DEBUG 1 [firstindex: 3, commit: 5] sent snapshot[index: 5, term: 1] to 3 [StateProbe match=0 next=1] DEBUG 1 paused sending replication messages to 3 [StateSnapshot match=0 next=1 paused pendingSnap=5] -> 1 handling Ready Ready MustSync=false: Messages: 1->3 MsgSnap Term:1 Log:0/0 @@ -271,10 +283,14 @@ stabilize 1 1/7 EntryNormal "foo" 1/8 EntryNormal "bar" Messages: - 1->2 MsgApp Term:1 Log:1/6 Commit:5 Entries:[1/7 EntryNormal "foo"] - 1->3 MsgApp Term:1 Log:1/6 Commit:5 Entries:[1/7 EntryNormal "foo"] - 1->2 MsgApp Term:1 Log:1/7 Commit:5 Entries:[1/8 EntryNormal "bar"] - 1->3 MsgApp Term:1 Log:1/7 Commit:5 Entries:[1/8 EntryNormal "bar"] + 1->2 MsgApp Term:1 Log:1/6 Commit:5 Entries:[ + 1/7 EntryNormal "foo" + 1/8 EntryNormal "bar" + ] + 1->3 MsgApp Term:1 Log:1/6 Commit:5 Entries:[ + 1/7 EntryNormal "foo" + 1/8 EntryNormal "bar" + ] > 1 receiving messages 2->1 MsgAppResp Term:1 Log:0/6 3->1 MsgAppResp Term:1 Log:0/6 @@ -300,13 +316,17 @@ stabilize 1 stabilize 2 3 ---- > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/6 Commit:5 Entries:[1/7 EntryNormal "foo"] - 1->2 MsgApp Term:1 Log:1/7 Commit:5 Entries:[1/8 EntryNormal "bar"] + 1->2 MsgApp Term:1 Log:1/6 Commit:5 Entries:[ + 1/7 EntryNormal "foo" + 1/8 EntryNormal "bar" + ] 1->2 MsgApp Term:1 Log:1/8 Commit:6 1->2 MsgApp Term:1 Log:1/8 Commit:6 Entries:[1/9 EntryConfChangeV2] > 3 receiving messages - 1->3 MsgApp Term:1 Log:1/6 Commit:5 Entries:[1/7 EntryNormal "foo"] - 1->3 MsgApp Term:1 Log:1/7 Commit:5 Entries:[1/8 EntryNormal "bar"] + 1->3 MsgApp Term:1 Log:1/6 Commit:5 Entries:[ + 1/7 EntryNormal "foo" + 1/8 EntryNormal "bar" + ] 1->3 MsgApp Term:1 Log:1/8 Commit:6 1->3 MsgApp Term:1 Log:1/8 Commit:6 Entries:[1/9 EntryConfChangeV2] > 2 handling Ready @@ -319,7 +339,6 @@ stabilize 2 3 CommittedEntries: 1/6 EntryConfChangeV2 r2 r3 Messages: - 2->1 MsgAppResp Term:1 Log:0/7 2->1 MsgAppResp Term:1 Log:0/8 2->1 MsgAppResp Term:1 Log:0/8 2->1 MsgAppResp Term:1 Log:0/9 @@ -334,7 +353,6 @@ stabilize 2 3 CommittedEntries: 1/6 EntryConfChangeV2 r2 r3 Messages: - 3->1 MsgAppResp Term:1 Log:0/7 3->1 MsgAppResp Term:1 Log:0/8 3->1 MsgAppResp Term:1 Log:0/8 3->1 MsgAppResp Term:1 Log:0/9 @@ -346,11 +364,9 @@ stabilize 2 3 stabilize ---- > 1 receiving messages - 2->1 MsgAppResp Term:1 Log:0/7 2->1 MsgAppResp Term:1 Log:0/8 2->1 MsgAppResp Term:1 Log:0/8 2->1 MsgAppResp Term:1 Log:0/9 - 3->1 MsgAppResp Term:1 Log:0/7 3->1 MsgAppResp Term:1 Log:0/8 3->1 MsgAppResp Term:1 Log:0/8 3->1 MsgAppResp Term:1 Log:0/9 @@ -362,20 +378,12 @@ stabilize 1/8 EntryNormal "bar" 1/9 EntryConfChangeV2 Messages: - 1->2 MsgApp Term:1 Log:1/9 Commit:7 - 1->3 MsgApp Term:1 Log:1/9 Commit:7 - 1->2 MsgApp Term:1 Log:1/9 Commit:8 - 1->3 MsgApp Term:1 Log:1/9 Commit:8 1->2 MsgApp Term:1 Log:1/9 Commit:9 1->3 MsgApp Term:1 Log:1/9 Commit:9 INFO 1 switched to configuration voters=(1) > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/9 Commit:7 - 1->2 MsgApp Term:1 Log:1/9 Commit:8 1->2 MsgApp Term:1 Log:1/9 Commit:9 > 3 receiving messages - 1->3 MsgApp Term:1 Log:1/9 Commit:7 - 1->3 MsgApp Term:1 Log:1/9 Commit:8 1->3 MsgApp Term:1 Log:1/9 Commit:9 > 2 handling Ready Ready MustSync=false: @@ -386,8 +394,6 @@ stabilize 1/9 EntryConfChangeV2 Messages: 2->1 MsgAppResp Term:1 Log:0/9 - 2->1 MsgAppResp Term:1 Log:0/9 - 2->1 MsgAppResp Term:1 Log:0/9 INFO 2 switched to configuration voters=(1) > 3 handling Ready Ready MustSync=false: @@ -398,19 +404,9 @@ stabilize 1/9 EntryConfChangeV2 Messages: 3->1 MsgAppResp Term:1 Log:0/9 - 3->1 MsgAppResp Term:1 Log:0/9 - 3->1 MsgAppResp Term:1 Log:0/9 INFO 3 switched to configuration voters=(1) > 1 receiving messages 2->1 MsgAppResp Term:1 Log:0/9 raft: cannot step as peer not found - 2->1 MsgAppResp Term:1 Log:0/9 - raft: cannot step as peer not found - 2->1 MsgAppResp Term:1 Log:0/9 - raft: cannot step as peer not found - 3->1 MsgAppResp Term:1 Log:0/9 - raft: cannot step as peer not found - 3->1 MsgAppResp Term:1 Log:0/9 - raft: cannot step as peer not found 3->1 MsgAppResp Term:1 Log:0/9 raft: cannot step as peer not found diff --git a/testdata/confchange_v2_add_double_implicit.txt b/testdata/confchange_v2_add_double_implicit.txt index 536d66b8..e523bc41 100644 --- a/testdata/confchange_v2_add_double_implicit.txt +++ b/testdata/confchange_v2_add_double_implicit.txt @@ -61,9 +61,15 @@ stabilize 1 2 Entries: 1/5 EntryConfChangeV2 Messages: - 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2] + 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[ + 1/4 EntryConfChangeV2 v2 + 1/5 EntryConfChangeV2 + ] > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v2] + 1->2 MsgApp Term:1 Log:1/3 Commit:4 Entries:[ + 1/4 EntryConfChangeV2 v2 + 1/5 EntryConfChangeV2 + ] INFO 2 [term: 0] received a MsgApp message with higher term from 1 [term: 1] INFO 2 became follower at term 1 DEBUG 2 [logterm: 0, index: 3] rejected MsgApp [logterm: 1, index: 3] from 1 @@ -77,9 +83,9 @@ stabilize 1 2 2->1 MsgAppResp Term:1 Log:0/3 Rejected (Hint: 0) DEBUG 1 received MsgAppResp(rejected, hint: (index 0, term 0)) from 2 for index 3 DEBUG 1 decreased progress of 2 to [StateProbe match=0 next=1] +> 1 handling Ready DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 next=1] DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 next=1 paused pendingSnap=4] -> 1 handling Ready Ready MustSync=false: Messages: 1->2 MsgSnap Term:1 Log:0/0 diff --git a/testdata/confchange_v2_add_single_auto.txt b/testdata/confchange_v2_add_single_auto.txt index 1c487da8..09a674e7 100644 --- a/testdata/confchange_v2_add_single_auto.txt +++ b/testdata/confchange_v2_add_single_auto.txt @@ -72,9 +72,9 @@ stabilize 2->1 MsgAppResp Term:1 Log:0/3 Rejected (Hint: 0) DEBUG 1 received MsgAppResp(rejected, hint: (index 0, term 0)) from 2 for index 3 DEBUG 1 decreased progress of 2 to [StateProbe match=0 next=1] +> 1 handling Ready DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 next=1] DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 next=1 paused pendingSnap=4] -> 1 handling Ready Ready MustSync=false: Messages: 1->2 MsgSnap Term:1 Log:0/0 diff --git a/testdata/confchange_v2_add_single_explicit.txt b/testdata/confchange_v2_add_single_explicit.txt index 123cd17a..65334f92 100644 --- a/testdata/confchange_v2_add_single_explicit.txt +++ b/testdata/confchange_v2_add_single_explicit.txt @@ -72,9 +72,9 @@ stabilize 1 2 2->1 MsgAppResp Term:1 Log:0/3 Rejected (Hint: 0) DEBUG 1 received MsgAppResp(rejected, hint: (index 0, term 0)) from 2 for index 3 DEBUG 1 decreased progress of 2 to [StateProbe match=0 next=1] +> 1 handling Ready DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 next=1] DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 next=1 paused pendingSnap=4] -> 1 handling Ready Ready MustSync=false: Messages: 1->2 MsgSnap Term:1 Log:0/0 @@ -130,21 +130,23 @@ stabilize 1/5 EntryNormal "" 1/6 EntryConfChangeV2 Messages: - 1->2 MsgApp Term:1 Log:1/4 Commit:4 Entries:[1/5 EntryNormal ""] - 1->2 MsgApp Term:1 Log:1/5 Commit:4 Entries:[1/6 EntryConfChangeV2] + 1->2 MsgApp Term:1 Log:1/4 Commit:4 Entries:[ + 1/5 EntryNormal "" + 1/6 EntryConfChangeV2 + ] > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/4 Commit:4 Entries:[1/5 EntryNormal ""] - 1->2 MsgApp Term:1 Log:1/5 Commit:4 Entries:[1/6 EntryConfChangeV2] + 1->2 MsgApp Term:1 Log:1/4 Commit:4 Entries:[ + 1/5 EntryNormal "" + 1/6 EntryConfChangeV2 + ] > 2 handling Ready Ready MustSync=true: Entries: 1/5 EntryNormal "" 1/6 EntryConfChangeV2 Messages: - 2->1 MsgAppResp Term:1 Log:0/5 2->1 MsgAppResp Term:1 Log:0/6 > 1 receiving messages - 2->1 MsgAppResp Term:1 Log:0/5 2->1 MsgAppResp Term:1 Log:0/6 > 1 handling Ready Ready MustSync=false: @@ -153,11 +155,9 @@ stabilize 1/5 EntryNormal "" 1/6 EntryConfChangeV2 Messages: - 1->2 MsgApp Term:1 Log:1/6 Commit:5 1->2 MsgApp Term:1 Log:1/6 Commit:6 INFO 1 switched to configuration voters=(1 2) > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/6 Commit:5 1->2 MsgApp Term:1 Log:1/6 Commit:6 > 2 handling Ready Ready MustSync=false: @@ -167,11 +167,9 @@ stabilize 1/6 EntryConfChangeV2 Messages: 2->1 MsgAppResp Term:1 Log:0/6 - 2->1 MsgAppResp Term:1 Log:0/6 INFO 2 switched to configuration voters=(1 2) > 1 receiving messages 2->1 MsgAppResp Term:1 Log:0/6 - 2->1 MsgAppResp Term:1 Log:0/6 # Check that trying to transition out again won't do anything. propose-conf-change 1 diff --git a/testdata/heartbeat_resp_recovers_from_probing.txt b/testdata/heartbeat_resp_recovers_from_probing.txt index e606a155..76d75a26 100644 --- a/testdata/heartbeat_resp_recovers_from_probing.txt +++ b/testdata/heartbeat_resp_recovers_from_probing.txt @@ -55,33 +55,25 @@ stabilize Messages: 1->2 MsgHeartbeat Term:1 Log:0/0 Commit:11 1->3 MsgHeartbeat Term:1 Log:0/0 Commit:11 + 1->2 MsgApp Term:1 Log:1/11 Commit:11 > 2 receiving messages 1->2 MsgHeartbeat Term:1 Log:0/0 Commit:11 + 1->2 MsgApp Term:1 Log:1/11 Commit:11 > 3 receiving messages 1->3 MsgHeartbeat Term:1 Log:0/0 Commit:11 > 2 handling Ready Ready MustSync=false: Messages: 2->1 MsgHeartbeatResp Term:1 Log:0/0 + 2->1 MsgAppResp Term:1 Log:0/11 > 3 handling Ready Ready MustSync=false: Messages: 3->1 MsgHeartbeatResp Term:1 Log:0/0 > 1 receiving messages 2->1 MsgHeartbeatResp Term:1 Log:0/0 - 3->1 MsgHeartbeatResp Term:1 Log:0/0 -> 1 handling Ready - Ready MustSync=false: - Messages: - 1->2 MsgApp Term:1 Log:1/11 Commit:11 -> 2 receiving messages - 1->2 MsgApp Term:1 Log:1/11 Commit:11 -> 2 handling Ready - Ready MustSync=false: - Messages: - 2->1 MsgAppResp Term:1 Log:0/11 -> 1 receiving messages 2->1 MsgAppResp Term:1 Log:0/11 + 3->1 MsgHeartbeatResp Term:1 Log:0/0 status 1 ---- diff --git a/testdata/lagging_commit.txt b/testdata/lagging_commit.txt index 8f8ba336..fe1bf413 100644 --- a/testdata/lagging_commit.txt +++ b/testdata/lagging_commit.txt @@ -39,10 +39,14 @@ ok deliver-msgs 2 3 ---- -1->2 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "data1"] -1->2 MsgApp Term:1 Log:1/12 Commit:11 Entries:[1/13 EntryNormal "data2"] -1->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "data1"] -1->3 MsgApp Term:1 Log:1/12 Commit:11 Entries:[1/13 EntryNormal "data2"] +1->2 MsgApp Term:1 Log:1/11 Commit:11 Entries:[ + 1/12 EntryNormal "data1" + 1/13 EntryNormal "data2" +] +1->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[ + 1/12 EntryNormal "data1" + 1/13 EntryNormal "data2" +] process-ready 3 ---- @@ -51,14 +55,12 @@ Entries: 1/12 EntryNormal "data1" 1/13 EntryNormal "data2" Messages: -3->1 MsgAppResp Term:1 Log:0/12 3->1 MsgAppResp Term:1 Log:0/13 # Suppose there is a network blip which prevents the leader learning that the # follower 3 has appended the proposed entries to the log. deliver-msgs drop=(1) ---- -dropped: 3->1 MsgAppResp Term:1 Log:0/12 dropped: 3->1 MsgAppResp Term:1 Log:0/13 # In the meantime, the entries are committed, and the leader sends the commit @@ -71,10 +73,8 @@ stabilize 1 2 1/12 EntryNormal "data1" 1/13 EntryNormal "data2" Messages: - 2->1 MsgAppResp Term:1 Log:0/12 2->1 MsgAppResp Term:1 Log:0/13 > 1 receiving messages - 2->1 MsgAppResp Term:1 Log:0/12 2->1 MsgAppResp Term:1 Log:0/13 > 1 handling Ready Ready MustSync=false: @@ -83,12 +83,9 @@ stabilize 1 2 1/12 EntryNormal "data1" 1/13 EntryNormal "data2" Messages: - 1->2 MsgApp Term:1 Log:1/13 Commit:12 - 1->3 MsgApp Term:1 Log:1/13 Commit:12 1->2 MsgApp Term:1 Log:1/13 Commit:13 1->3 MsgApp Term:1 Log:1/13 Commit:13 > 2 receiving messages - 1->2 MsgApp Term:1 Log:1/13 Commit:12 1->2 MsgApp Term:1 Log:1/13 Commit:13 > 2 handling Ready Ready MustSync=false: @@ -98,16 +95,13 @@ stabilize 1 2 1/13 EntryNormal "data2" Messages: 2->1 MsgAppResp Term:1 Log:0/13 - 2->1 MsgAppResp Term:1 Log:0/13 > 1 receiving messages 2->1 MsgAppResp Term:1 Log:0/13 - 2->1 MsgAppResp Term:1 Log:0/13 # The network blip prevents the follower 3 from learning that the previously # appended entries are now committed. deliver-msgs drop=(3) ---- -dropped: 1->3 MsgApp Term:1 Log:1/13 Commit:12 dropped: 1->3 MsgApp Term:1 Log:1/13 Commit:13 # The network blip ends here. @@ -116,7 +110,7 @@ status 1 ---- 1: StateReplicate match=13 next=14 2: StateReplicate match=13 next=14 -3: StateReplicate match=11 next=14 inflight=2 +3: StateReplicate match=11 next=14 inflight=1 # The leader still observes that the entries are in-flight to the follower 3, # since it hasn't heard from it. Nothing triggers updating the follower's diff --git a/testdata/prevote.txt b/testdata/prevote.txt index db763d35..a7a3fecf 100644 --- a/testdata/prevote.txt +++ b/testdata/prevote.txt @@ -90,9 +90,9 @@ stabilize CommittedEntries: 1/12 EntryNormal "prop_1" Messages: + 1->3 MsgPreVoteResp Term:1 Log:0/0 Rejected (Hint: 0) 1->2 MsgApp Term:1 Log:1/12 Commit:12 1->3 MsgApp Term:1 Log:1/12 Commit:12 - 1->3 MsgPreVoteResp Term:1 Log:0/0 Rejected (Hint: 0) > 2 handling Ready Ready MustSync=false: Messages: @@ -102,8 +102,8 @@ stabilize > 3 receiving messages 1->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "prop_1"] INFO 3 became follower at term 1 - 1->3 MsgApp Term:1 Log:1/12 Commit:12 1->3 MsgPreVoteResp Term:1 Log:0/0 Rejected (Hint: 0) + 1->3 MsgApp Term:1 Log:1/12 Commit:12 2->3 MsgPreVoteResp Term:1 Log:0/0 Rejected (Hint: 0) > 2 handling Ready Ready MustSync=false: diff --git a/testdata/replicate_pause.txt b/testdata/replicate_pause.txt index 4931480e..326f5c23 100644 --- a/testdata/replicate_pause.txt +++ b/testdata/replicate_pause.txt @@ -47,8 +47,8 @@ ok status 1 ---- 1: StateReplicate match=14 next=15 -2: StateReplicate match=11 next=15 paused inflight=3[full] -3: StateReplicate match=11 next=15 paused inflight=3[full] +2: StateReplicate match=11 next=15 inflight=1 +3: StateReplicate match=11 next=15 inflight=1 log-level none ---- @@ -68,16 +68,16 @@ status 1 ---- 1: StateReplicate match=14 next=15 2: StateReplicate match=14 next=15 -3: StateReplicate match=11 next=15 paused inflight=3[full] +3: StateReplicate match=11 next=15 inflight=1 # Drop append messages to node 3. deliver-msgs drop=3 ---- -dropped: 1->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[1/12 EntryNormal "prop_1_12"] -dropped: 1->3 MsgApp Term:1 Log:1/12 Commit:11 Entries:[1/13 EntryNormal "prop_1_13"] -dropped: 1->3 MsgApp Term:1 Log:1/13 Commit:11 Entries:[1/14 EntryNormal "prop_1_14"] -dropped: 1->3 MsgApp Term:1 Log:1/14 Commit:12 -dropped: 1->3 MsgApp Term:1 Log:1/14 Commit:13 +dropped: 1->3 MsgApp Term:1 Log:1/11 Commit:11 Entries:[ + 1/12 EntryNormal "prop_1_12" + 1/13 EntryNormal "prop_1_13" + 1/14 EntryNormal "prop_1_14" +] dropped: 1->3 MsgApp Term:1 Log:1/14 Commit:14 @@ -98,8 +98,8 @@ ok status 1 ---- 1: StateReplicate match=14 next=15 -2: StateReplicate match=14 next=18 paused inflight=3[full] -3: StateReplicate match=11 next=15 paused inflight=3[full] +2: StateReplicate match=14 next=15 +3: StateReplicate match=11 next=15 inflight=1 log-level none ---- @@ -119,7 +119,7 @@ status 1 ---- 1: StateReplicate match=17 next=18 2: StateReplicate match=17 next=18 -3: StateReplicate match=11 next=15 paused inflight=3[full] +3: StateReplicate match=11 next=18 inflight=2 # Make a heartbeat roundtrip. tick-heartbeat 1 @@ -139,6 +139,14 @@ stabilize 2 3 > 2 receiving messages 1->2 MsgHeartbeat Term:1 Log:0/0 Commit:17 > 3 receiving messages + 1->3 MsgApp Term:1 Log:1/14 Commit:14 Entries:[ + 1/15 EntryNormal "prop_1_15" + 1/16 EntryNormal "prop_1_16" + 1/17 EntryNormal "prop_1_17" + ] + DEBUG 3 [logterm: 0, index: 14] rejected MsgApp [logterm: 1, index: 14] from 1 + 1->3 MsgApp Term:1 Log:1/17 Commit:17 + DEBUG 3 [logterm: 0, index: 17] rejected MsgApp [logterm: 1, index: 17] from 1 1->3 MsgHeartbeat Term:1 Log:0/0 Commit:11 > 2 handling Ready Ready MustSync=false: @@ -148,6 +156,8 @@ stabilize 2 3 Ready MustSync=false: Messages: 3->1 MsgHeartbeatResp Term:1 Log:0/0 + 3->1 MsgAppResp Term:1 Log:1/14 Rejected (Hint: 11) + 3->1 MsgAppResp Term:1 Log:1/17 Rejected (Hint: 11) # After handling heartbeat responses, node 1 sends an empty MsgApp to a # throttled node 3 because it hasn't yet replied to a single MsgApp, and the @@ -157,21 +167,54 @@ stabilize 1 > 1 receiving messages 2->1 MsgHeartbeatResp Term:1 Log:0/0 3->1 MsgHeartbeatResp Term:1 Log:0/0 + 3->1 MsgAppResp Term:1 Log:1/14 Rejected (Hint: 11) + DEBUG 1 received MsgAppResp(rejected, hint: (index 11, term 1)) from 3 for index 14 + DEBUG 1 decreased progress of 3 to [StateReplicate match=11 next=12 inflight=2] + 3->1 MsgAppResp Term:1 Log:1/17 Rejected (Hint: 11) + DEBUG 1 received MsgAppResp(rejected, hint: (index 11, term 1)) from 3 for index 17 > 1 handling Ready Ready MustSync=false: Messages: - 1->3 MsgApp Term:1 Log:1/14 Commit:17 + 1->3 MsgApp Term:1 Log:1/11 Commit:17 Entries:[ + 1/12 EntryNormal "prop_1_12" + 1/13 EntryNormal "prop_1_13" + 1/14 EntryNormal "prop_1_14" + 1/15 EntryNormal "prop_1_15" + 1/16 EntryNormal "prop_1_16" + 1/17 EntryNormal "prop_1_17" + ] # Node 3 finally receives a MsgApp, but there was a gap, so it rejects it. stabilize 3 ---- > 3 receiving messages - 1->3 MsgApp Term:1 Log:1/14 Commit:17 - DEBUG 3 [logterm: 0, index: 14] rejected MsgApp [logterm: 1, index: 14] from 1 + 1->3 MsgApp Term:1 Log:1/11 Commit:17 Entries:[ + 1/12 EntryNormal "prop_1_12" + 1/13 EntryNormal "prop_1_13" + 1/14 EntryNormal "prop_1_14" + 1/15 EntryNormal "prop_1_15" + 1/16 EntryNormal "prop_1_16" + 1/17 EntryNormal "prop_1_17" + ] > 3 handling Ready - Ready MustSync=false: + Ready MustSync=true: + HardState Term:1 Vote:1 Commit:17 + Entries: + 1/12 EntryNormal "prop_1_12" + 1/13 EntryNormal "prop_1_13" + 1/14 EntryNormal "prop_1_14" + 1/15 EntryNormal "prop_1_15" + 1/16 EntryNormal "prop_1_16" + 1/17 EntryNormal "prop_1_17" + CommittedEntries: + 1/12 EntryNormal "prop_1_12" + 1/13 EntryNormal "prop_1_13" + 1/14 EntryNormal "prop_1_14" + 1/15 EntryNormal "prop_1_15" + 1/16 EntryNormal "prop_1_16" + 1/17 EntryNormal "prop_1_17" Messages: - 3->1 MsgAppResp Term:1 Log:1/14 Rejected (Hint: 11) + 3->1 MsgAppResp Term:1 Log:0/17 log-level none ---- diff --git a/testdata/slow_follower_after_compaction.txt b/testdata/slow_follower_after_compaction.txt index 2ce02ada..a033952d 100644 --- a/testdata/slow_follower_after_compaction.txt +++ b/testdata/slow_follower_after_compaction.txt @@ -81,15 +81,18 @@ status 1 ---- 1: StateReplicate match=18 next=19 2: StateReplicate match=18 next=19 -3: StateReplicate match=14 next=17 paused inflight=2[full] +3: StateReplicate match=14 next=19 inflight=1 # Break the MsgApp flow from the leader to node 3. deliver-msgs drop=3 ---- -dropped: 1->3 MsgApp Term:1 Log:1/14 Commit:14 Entries:[1/15 EntryNormal "prop_1_15"] -dropped: 1->3 MsgApp Term:1 Log:1/15 Commit:14 Entries:[1/16 EntryNormal "prop_1_16"] -dropped: 1->3 MsgApp Term:1 Log:1/16 Commit:15 -dropped: 1->3 MsgApp Term:1 Log:1/16 Commit:16 +dropped: 1->3 MsgApp Term:1 Log:1/14 Commit:14 Entries:[ + 1/15 EntryNormal "prop_1_15" + 1/16 EntryNormal "prop_1_16" + 1/17 EntryNormal "prop_1_17" + 1/18 EntryNormal "prop_1_18" +] +dropped: 1->3 MsgApp Term:1 Log:1/18 Commit:18 # Truncate the leader's log beyond node 3 log size. compact 1 17 diff --git a/testdata/snapshot_succeed_via_app_resp.txt b/testdata/snapshot_succeed_via_app_resp.txt index 5c4b0c61..ee4c8706 100644 --- a/testdata/snapshot_succeed_via_app_resp.txt +++ b/testdata/snapshot_succeed_via_app_resp.txt @@ -86,9 +86,9 @@ stabilize 1 ---- > 1 receiving messages 3->1 MsgHeartbeatResp Term:1 Log:0/0 +> 1 handling Ready DEBUG 1 [firstindex: 12, commit: 11] sent snapshot[index: 11, term: 1] to 3 [StateProbe match=0 next=11] DEBUG 1 paused sending replication messages to 3 [StateSnapshot match=0 next=11 paused pendingSnap=11] -> 1 handling Ready Ready MustSync=false: Messages: 1->3 MsgSnap Term:1 Log:0/0 diff --git a/testdata/snapshot_succeed_via_app_resp_behind.txt b/testdata/snapshot_succeed_via_app_resp_behind.txt index b0f5883b..beec45f3 100644 --- a/testdata/snapshot_succeed_via_app_resp_behind.txt +++ b/testdata/snapshot_succeed_via_app_resp_behind.txt @@ -123,9 +123,9 @@ stabilize 1 3->1 MsgAppResp Term:1 Log:1/10 Rejected (Hint: 5) DEBUG 1 received MsgAppResp(rejected, hint: (index 5, term 1)) from 3 for index 10 DEBUG 1 decreased progress of 3 to [StateProbe match=0 next=6] +> 1 handling Ready DEBUG 1 [firstindex: 11, commit: 12] sent snapshot[index: 12, term: 1] to 3 [StateProbe match=0 next=6] DEBUG 1 paused sending replication messages to 3 [StateSnapshot match=0 next=6 paused pendingSnap=12] -> 1 handling Ready Ready MustSync=false: Messages: 1->3 MsgSnap Term:1 Log:0/0