Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

rafttest: improve message formatting #162

Merged
merged 1 commit into from
Feb 9, 2024
Merged

rafttest: improve message formatting #162

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
181 changes: 141 additions & 40 deletions testdata/async_storage_writes.txt
View file
Open in desktop

Large diffs are not rendered by default.

67 changes: 52 additions & 15 deletions testdata/async_storage_writes_append_aba_race.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,10 @@ Messages:
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]
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)
----
Expand All @@ -61,7 +64,10 @@ Ready MustSync=true:
Entries:
1/12 EntryNormal "init_prop"
Messages:
1->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[1/12 EntryNormal "init_prop"] Responses:[1->2 MsgAppResp Term:1 Log:0/12, AppendThread->1 MsgStorageAppendResp Term:1 Log:1/12]
1->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[1/12 EntryNormal "init_prop"] Responses:[
1->2 MsgAppResp Term:1 Log:0/12
AppendThread->1 MsgStorageAppendResp Term:1 Log:1/12
]

# Step 4: node 3 becomes the leader after getting a vote from nodes 4, 5, and 6.

Expand All @@ -88,7 +94,9 @@ Messages:
3->5 MsgVote Term:2 Log:1/11
3->6 MsgVote Term:2 Log:1/11
3->7 MsgVote Term:2 Log:1/11
3->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[3->3 MsgVoteResp Term:2 Log:0/0]
3->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[
3->3 MsgVoteResp Term:2 Log:0/0
]

deliver-msgs 4 5 6
----
Expand All @@ -112,19 +120,25 @@ process-ready 4 5 6
Lead:0 State:StateFollower
HardState Term:2 Vote:3 Commit:11
Messages:
4->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[4->3 MsgVoteResp Term:2 Log:0/0]
4->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[
4->3 MsgVoteResp Term:2 Log:0/0
]
> 5 handling Ready
Ready MustSync=true:
Lead:0 State:StateFollower
HardState Term:2 Vote:3 Commit:11
Messages:
5->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[5->3 MsgVoteResp Term:2 Log:0/0]
5->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[
5->3 MsgVoteResp Term:2 Log:0/0
]
> 6 handling Ready
Ready MustSync=true:
Lead:0 State:StateFollower
HardState Term:2 Vote:3 Commit:11
Messages:
6->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[6->3 MsgVoteResp Term:2 Log:0/0]
6->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Vote:3 Responses:[
6->3 MsgVoteResp Term:2 Log:0/0
]

process-append-thread 3 4 5 6
----
Expand Down Expand Up @@ -183,7 +197,10 @@ Messages:
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]
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)
----
Expand All @@ -210,7 +227,11 @@ HardState Term:2 Commit:11
Entries:
2/12 EntryNormal ""
Messages:
1->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Entries:[2/12 EntryNormal ""] Responses:[1->3 MsgVoteResp Term:2 Log:0/0 Rejected (Hint: 0), 1->3 MsgAppResp Term:2 Log:0/12, AppendThread->1 MsgStorageAppendResp Term:2 Log:2/12]
1->AppendThread MsgStorageAppend Term:2 Log:0/0 Commit:11 Entries:[2/12 EntryNormal ""] Responses:[
1->3 MsgVoteResp Term:2 Log:0/0 Rejected (Hint: 0)
1->3 MsgAppResp Term:2 Log:0/12
AppendThread->1 MsgStorageAppendResp Term:2 Log:2/12
]

# Step 6: node 3 crashes and node 4 becomes leader getting the vote from 5, 6, and 7.

Expand All @@ -237,7 +258,9 @@ Messages:
4->5 MsgVote Term:3 Log:1/11
4->6 MsgVote Term:3 Log:1/11
4->7 MsgVote Term:3 Log:1/11
4->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[4->4 MsgVoteResp Term:3 Log:0/0]
4->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[
4->4 MsgVoteResp Term:3 Log:0/0
]

deliver-msgs 5 6 7
----
Expand All @@ -260,18 +283,24 @@ process-ready 5 6 7
Ready MustSync=true:
HardState Term:3 Vote:4 Commit:11
Messages:
5->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[5->4 MsgVoteResp Term:3 Log:0/0]
5->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[
5->4 MsgVoteResp Term:3 Log:0/0
]
> 6 handling Ready
Ready MustSync=true:
HardState Term:3 Vote:4 Commit:11
Messages:
6->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[6->4 MsgVoteResp Term:3 Log:0/0]
6->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[
6->4 MsgVoteResp Term:3 Log:0/0
]
> 7 handling Ready
Ready MustSync=true:
Lead:0 State:StateFollower
HardState Term:3 Vote:4 Commit:11
Messages:
7->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[7->4 MsgVoteResp Term:3 Log:0/0]
7->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Vote:4 Responses:[
7->4 MsgVoteResp Term:3 Log:0/0
]

process-append-thread 4 5 6 7
----
Expand Down Expand Up @@ -325,7 +354,10 @@ Messages:
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]
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
Expand Down Expand Up @@ -366,7 +398,9 @@ Lead:4 State:StateFollower
HardState Term:3 Commit:11
Messages:
1->4 MsgHeartbeatResp Term:3 Log:0/0
1->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Responses:[AppendThread->1 MsgStorageAppendResp Term:3 Log:2/12]
1->AppendThread MsgStorageAppend Term:3 Log:0/0 Commit:11 Responses:[
AppendThread->1 MsgStorageAppendResp Term:3 Log:2/12
]

deliver-msgs 4
----
Expand All @@ -390,7 +424,10 @@ Ready MustSync=true:
Entries:
3/12 EntryNormal ""
Messages:
1->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[3/12 EntryNormal ""] Responses:[1->4 MsgAppResp Term:3 Log:0/12, AppendThread->1 MsgStorageAppendResp Term:3 Log:3/12]
1->AppendThread MsgStorageAppend Term:0 Log:0/0 Entries:[3/12 EntryNormal ""] Responses:[
1->4 MsgAppResp Term:3 Log:0/12
AppendThread->1 MsgStorageAppendResp Term:3 Log:3/12
]

# Step 8: The asynchronous log appends from the first Ready complete and the
# MsgStorageAppendResp is returned to the raft node state machine. A decision
Expand Down
10 changes: 8 additions & 2 deletions testdata/campaign_learner_must_vote.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -117,9 +117,15 @@ stabilize 2 3
> 2 handling Ready
Ready MustSync=false:
Messages:
2->3 MsgApp Term:2 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v3, 2/5 EntryNormal ""]
2->3 MsgApp Term:2 Log:1/3 Commit:4 Entries:[
1/4 EntryConfChangeV2 v3
2/5 EntryNormal ""
]
> 3 receiving messages
2->3 MsgApp Term:2 Log:1/3 Commit:4 Entries:[1/4 EntryConfChangeV2 v3, 2/5 EntryNormal ""]
2->3 MsgApp Term:2 Log:1/3 Commit:4 Entries:[
1/4 EntryConfChangeV2 v3
2/5 EntryNormal ""
]
> 3 handling Ready
Ready MustSync=true:
HardState Term:2 Vote:2 Commit:4
Expand Down
6 changes: 4 additions & 2 deletions testdata/confchange_v1_add_single.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -76,9 +76,11 @@ stabilize
> 1 handling Ready
Ready MustSync=false:
Messages:
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
> 2 receiving messages
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
INFO log [committed=0, applied=0, applying=0, unstable.offset=1, unstable.offsetInProgress=1, len(unstable.Entries)=0] starts to restore snapshot [index: 4, term: 1]
INFO 2 switched to configuration voters=(1 2)
INFO 2 [commit: 4, lastindex: 4, lastterm: 1] restored snapshot [index: 4, term: 1]
Expand Down
12 changes: 8 additions & 4 deletions testdata/confchange_v2_add_double_auto.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -99,9 +99,11 @@ stabilize 1 2
> 1 handling Ready
Ready MustSync=false:
Messages:
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
> 2 receiving messages
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
INFO log [committed=0, applied=0, applying=0, unstable.offset=1, unstable.offsetInProgress=1, len(unstable.Entries)=0] starts to restore snapshot [index: 4, term: 1]
INFO 2 switched to configuration voters=(1 2 3)&&(1) autoleave
INFO 2 [commit: 4, lastindex: 4, lastterm: 1] restored snapshot [index: 4, term: 1]
Expand Down Expand Up @@ -173,9 +175,11 @@ stabilize 1 3
> 1 handling Ready
Ready MustSync=false:
Messages:
1->3 MsgSnap Term:1 Log:0/0 Snapshot: Index:5 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
1->3 MsgSnap Term:1 Log:0/0
Snapshot: Index:5 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
> 3 receiving messages
1->3 MsgSnap Term:1 Log:0/0 Snapshot: Index:5 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
1->3 MsgSnap Term:1 Log:0/0
Snapshot: Index:5 Term:1 ConfState:Voters:[1 2 3] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
INFO log [committed=0, applied=0, applying=0, unstable.offset=1, unstable.offsetInProgress=1, len(unstable.Entries)=0] starts to restore snapshot [index: 5, term: 1]
INFO 3 switched to configuration voters=(1 2 3)
INFO 3 [commit: 5, lastindex: 5, lastterm: 1] restored snapshot [index: 5, term: 1]
Expand Down
6 changes: 4 additions & 2 deletions testdata/confchange_v2_add_double_implicit.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -82,9 +82,11 @@ stabilize 1 2
> 1 handling Ready
Ready MustSync=false:
Messages:
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
> 2 receiving messages
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:true
INFO log [committed=0, applied=0, applying=0, unstable.offset=1, unstable.offsetInProgress=1, len(unstable.Entries)=0] starts to restore snapshot [index: 4, term: 1]
INFO 2 switched to configuration voters=(1 2)&&(1) autoleave
INFO 2 [commit: 4, lastindex: 4, lastterm: 1] restored snapshot [index: 4, term: 1]
Expand Down
6 changes: 4 additions & 2 deletions testdata/confchange_v2_add_single_auto.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -77,9 +77,11 @@ stabilize
> 1 handling Ready
Ready MustSync=false:
Messages:
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
> 2 receiving messages
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[] Learners:[] LearnersNext:[] AutoLeave:false
INFO log [committed=0, applied=0, applying=0, unstable.offset=1, unstable.offsetInProgress=1, len(unstable.Entries)=0] starts to restore snapshot [index: 4, term: 1]
INFO 2 switched to configuration voters=(1 2)
INFO 2 [commit: 4, lastindex: 4, lastterm: 1] restored snapshot [index: 4, term: 1]
Expand Down
6 changes: 4 additions & 2 deletions testdata/confchange_v2_add_single_explicit.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -77,9 +77,11 @@ stabilize 1 2
> 1 handling Ready
Ready MustSync=false:
Messages:
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:false
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:false
> 2 receiving messages
1->2 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:false
1->2 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[1 2] VotersOutgoing:[1] Learners:[] LearnersNext:[] AutoLeave:false
INFO log [committed=0, applied=0, applying=0, unstable.offset=1, unstable.offsetInProgress=1, len(unstable.Entries)=0] starts to restore snapshot [index: 4, term: 1]
INFO 2 switched to configuration voters=(1 2)&&(1)
INFO 2 [commit: 4, lastindex: 4, lastterm: 1] restored snapshot [index: 4, term: 1]
Expand Down
6 changes: 4 additions & 2 deletions testdata/confchange_v2_replace_leader.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -126,9 +126,11 @@ stabilize
> 1 handling Ready
Ready MustSync=false:
Messages:
1->4 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[2 3 4] VotersOutgoing:[1 2 3] Learners:[] LearnersNext:[] AutoLeave:false
1->4 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[2 3 4] VotersOutgoing:[1 2 3] Learners:[] LearnersNext:[] AutoLeave:false
> 4 receiving messages
1->4 MsgSnap Term:1 Log:0/0 Snapshot: Index:4 Term:1 ConfState:Voters:[2 3 4] VotersOutgoing:[1 2 3] Learners:[] LearnersNext:[] AutoLeave:false
1->4 MsgSnap Term:1 Log:0/0
Snapshot: Index:4 Term:1 ConfState:Voters:[2 3 4] VotersOutgoing:[1 2 3] Learners:[] LearnersNext:[] AutoLeave:false
INFO log [committed=0, applied=0, applying=0, unstable.offset=1, unstable.offsetInProgress=1, len(unstable.Entries)=0] starts to restore snapshot [index: 4, term: 1]
INFO 4 switched to configuration voters=(2 3 4)&&(1 2 3)
INFO 4 [commit: 4, lastindex: 4, lastterm: 1] restored snapshot [index: 4, term: 1]
Expand Down
Loading
Loading