etcd/raft/testdata/snapshot_succeed_via_app_resp.txt
Tobias Schottdorf 078caccce5 raft: add a batch of interaction-driven conf change tests
Verifiy the behavior in various v1 and v2 conf change operations.
This also includes various fixups, notably it adds protection
against transitioning in and out of new configs when this is not
permissible.

There are more threads to pull, but those are left for future commits.
2019-08-16 08:09:44 -07:00

157 lines
4.7 KiB
Plaintext

# TestSnapshotSucceedViaAppResp regression tests the situation in which a snap-
# shot is sent to a follower at the most recent index (i.e. the snapshot index
# is the leader's last index is the committed index). In that situation, a bug
# in the past left the follower in probing status until the next log entry was
# committed.
#
# See https://github.com/etcd-io/etcd/pull/10308 for additional background.
# Turn off output during the setup of the test.
log-level none
----
ok
# Start with two nodes, but the config already has a third.
add-nodes 2 voters=(1,2,3) index=10
----
ok
campaign 1
----
ok
# Fully replicate everything, including the leader's empty index.
stabilize
----
ok (quiet)
compact 1 11
----
ok (quiet)
# Drop inflight messages to n3.
deliver-msgs drop=(3)
----
ok (quiet)
# Show the Raft log messages from now on.
log-level debug
----
ok
status 1
----
1: StateReplicate match=11 next=12 inactive
2: StateReplicate match=11 next=12
3: StateProbe match=0 next=11 paused inactive
# Add the node that will receive a snapshot (it has no state at all, does not
# even have a config).
add-nodes 1
----
INFO 3 switched to configuration voters=()
INFO 3 became follower at term 0
INFO newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
# Time passes on the leader so that it will try the previously missing follower
# again.
tick-heartbeat 1
----
ok
process-ready 1
----
Ready MustSync=false:
Messages:
1->2 MsgHeartbeat Term:1 Log:0/0 Commit:11
1->3 MsgHeartbeat Term:1 Log:0/0
# Iterate until no more work is done by the new peer. It receives the heartbeat
# and responds.
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]
INFO 3 became follower at term 1
> 3 handling Ready
Ready MustSync=true:
Lead:1 State:StateFollower
HardState Term:1 Commit:0
Messages:
3->1 MsgHeartbeatResp Term:1 Log:0/0
# The leader in turn will realize that n3 needs a snapshot, which it initiates.
stabilize 1
----
> 1 receiving messages
3->1 MsgHeartbeatResp Term:1 Log:0/0
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 Snapshot: Index:11 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
status 1
----
1: StateReplicate match=11 next=12 inactive
2: StateReplicate match=11 next=12
3: StateSnapshot match=0 next=11 paused pendingSnap=11
# Follower applies the snapshot. Note how it reacts with a MsgAppResp upon completion.
# The snapshot fully catches the follower up (i.e. there are no more log entries it
# needs to apply after). The bug was that the leader failed to realize that the follower
# was now fully caught up.
stabilize 3
----
> 3 receiving messages
1->3 MsgSnap Term:1 Log:0/0 Snapshot: Index:11 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
INFO log [committed=0, applied=0, unstable.offset=1, len(unstable.Entries)=0] starts to restore snapshot [index: 11, term: 1]
INFO 3 switched to configuration voters=(1 2 3)
INFO 3 [commit: 11, lastindex: 11, lastterm: 1] restored snapshot [index: 11, term: 1]
INFO 3 [commit: 11] restored snapshot [index: 11, term: 1]
> 3 handling Ready
Ready MustSync=false:
HardState Term:1 Commit:11
Snapshot Index:11 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
Messages:
3->1 MsgAppResp Term:1 Log:0/11
# The MsgAppResp lets the leader move the follower back to replicating state.
# Leader sends another MsgAppResp, to communicate the updated commit index.
stabilize 1
----
> 1 receiving messages
3->1 MsgAppResp Term:1 Log:0/11
DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 3 [StateSnapshot match=11 next=12 paused pendingSnap=11]
> 1 handling Ready
Ready MustSync=false:
Messages:
1->3 MsgApp Term:1 Log:1/11 Commit:11
status 1
----
1: StateReplicate match=11 next=12 inactive
2: StateReplicate match=11 next=12
3: StateReplicate match=11 next=12
# Let things settle.
stabilize
----
> 2 receiving messages
1->2 MsgHeartbeat Term:1 Log:0/0 Commit:11
> 3 receiving messages
1->3 MsgApp Term:1 Log:1/11 Commit:11
> 2 handling Ready
Ready MustSync=false:
Messages:
2->1 MsgHeartbeatResp Term:1 Log:0/0
> 3 handling Ready
Ready MustSync=false:
Messages:
3->1 MsgAppResp Term:1 Log:0/11
> 1 receiving messages
2->1 MsgHeartbeatResp Term:1 Log:0/0
3->1 MsgAppResp Term:1 Log:0/11