tracker: add commit index to debug output

Signed-off-by: Pavel Kalinnikov <[email protected]>
pav-kv · Jan 24, 2024 · 10feb2e · 10feb2e
1 parent da6ad00
commit 10feb2e
Show file tree

Hide file tree

Showing 13 changed files with 89 additions and 88 deletions.
diff --git a/testdata/campaign_learner_must_vote.txt b/testdata/campaign_learner_must_vote.txt
@@ -113,7 +113,7 @@ stabilize 2 3
 > 2 receiving messages
   3->2 MsgAppResp Term:2 Log:1/4 Rejected (Hint: 3)
   DEBUG 2 received MsgAppResp(rejected, hint: (index 3, term 1)) from 3 for index 4
-  DEBUG 2 decreased progress of 3 to [StateProbe match=0 next=4]
+  DEBUG 2 decreased progress of 3 to [StateProbe match=0 commit=0 next=4]
 > 2 handling Ready
   Ready MustSync=false:
   Messages:

diff --git a/testdata/confchange_v1_add_single.txt b/testdata/confchange_v1_add_single.txt
@@ -70,9 +70,9 @@ stabilize
 > 1 receiving messages
   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]
-  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]
+  DEBUG 1 decreased progress of 2 to [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 commit=0 next=1 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -91,7 +91,7 @@ stabilize
   2->1 MsgAppResp Term:1 Log:0/4
 > 1 receiving messages
   2->1 MsgAppResp Term:1 Log:0/4
-  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 next=5 paused pendingSnap=4]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 commit=0 next=5 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:

diff --git a/testdata/confchange_v2_add_double_auto.txt b/testdata/confchange_v2_add_double_auto.txt
@@ -93,9 +93,9 @@ stabilize 1 2
 > 1 receiving messages
   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]
-  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]
+  DEBUG 1 decreased progress of 2 to [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 commit=0 next=1 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -114,7 +114,7 @@ stabilize 1 2
   2->1 MsgAppResp Term:1 Log:0/4
 > 1 receiving messages
   2->1 MsgAppResp Term:1 Log:0/4
-  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 next=5 paused pendingSnap=4]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 commit=0 next=5 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -167,9 +167,9 @@ stabilize 1 3
 > 1 receiving messages
   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]
-  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]
+  DEBUG 1 decreased progress of 3 to [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 [firstindex: 3, commit: 5] sent snapshot[index: 5, term: 1] to 3 [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 paused sending replication messages to 3 [StateSnapshot match=0 commit=0 next=1 paused pendingSnap=5]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -188,7 +188,7 @@ stabilize 1 3
   3->1 MsgAppResp Term:1 Log:0/5
 > 1 receiving messages
   3->1 MsgAppResp Term:1 Log:0/5
-  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 3 [StateSnapshot match=5 next=6 paused pendingSnap=5]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 3 [StateSnapshot match=5 commit=0 next=6 paused pendingSnap=5]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:

diff --git a/testdata/confchange_v2_add_double_implicit.txt b/testdata/confchange_v2_add_double_implicit.txt
@@ -76,9 +76,9 @@ stabilize 1 2
 > 1 receiving messages
   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]
-  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]
+  DEBUG 1 decreased progress of 2 to [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 commit=0 next=1 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -97,7 +97,7 @@ stabilize 1 2
   2->1 MsgAppResp Term:1 Log:0/4
 > 1 receiving messages
   2->1 MsgAppResp Term:1 Log:0/4
-  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 next=5 paused pendingSnap=4]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 commit=0 next=5 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:

diff --git a/testdata/confchange_v2_add_single_auto.txt b/testdata/confchange_v2_add_single_auto.txt
@@ -71,9 +71,9 @@ stabilize
 > 1 receiving messages
   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]
-  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]
+  DEBUG 1 decreased progress of 2 to [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 commit=0 next=1 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -92,7 +92,7 @@ stabilize
   2->1 MsgAppResp Term:1 Log:0/4
 > 1 receiving messages
   2->1 MsgAppResp Term:1 Log:0/4
-  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 next=5 paused pendingSnap=4]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 commit=0 next=5 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:

diff --git a/testdata/confchange_v2_add_single_explicit.txt b/testdata/confchange_v2_add_single_explicit.txt
@@ -71,9 +71,9 @@ stabilize 1 2
 > 1 receiving messages
   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]
-  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]
+  DEBUG 1 decreased progress of 2 to [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 [firstindex: 3, commit: 4] sent snapshot[index: 4, term: 1] to 2 [StateProbe match=0 commit=0 next=1]
+  DEBUG 1 paused sending replication messages to 2 [StateSnapshot match=0 commit=0 next=1 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -92,7 +92,7 @@ stabilize 1 2
   2->1 MsgAppResp Term:1 Log:0/4
 > 1 receiving messages
   2->1 MsgAppResp Term:1 Log:0/4
-  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 next=5 paused pendingSnap=4]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 2 [StateSnapshot match=4 commit=0 next=5 paused pendingSnap=4]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:

diff --git a/testdata/heartbeat_resp_recovers_from_probing.txt b/testdata/heartbeat_resp_recovers_from_probing.txt
@@ -28,20 +28,20 @@ ok
 
 status 1
 ----
-1: StateReplicate match=11 next=12
-2: StateReplicate match=11 next=12
-3: StateReplicate match=11 next=12
+1: StateReplicate match=11 commit=10 next=12
+2: StateReplicate match=11 commit=11 next=12
+3: StateReplicate match=11 commit=11 next=12
 
 # On the first replica, report the second one as not reachable.
 report-unreachable 1 2
 ----
-DEBUG 1 failed to send message to 2 because it is unreachable [StateProbe match=11 next=12]
+DEBUG 1 failed to send message to 2 because it is unreachable [StateProbe match=11 commit=11 next=12]
 
 status 1
 ----
-1: StateReplicate match=11 next=12
-2: StateProbe match=11 next=12
-3: StateReplicate match=11 next=12
+1: StateReplicate match=11 commit=10 next=12
+2: StateProbe match=11 commit=11 next=12
+3: StateReplicate match=11 commit=11 next=12
 
 tick-heartbeat 1
 ----
@@ -85,6 +85,6 @@ stabilize
 
 status 1
 ----
-1: StateReplicate match=11 next=12
-2: StateReplicate match=11 next=12
-3: StateReplicate match=11 next=12
+1: StateReplicate match=11 commit=10 next=12
+2: StateReplicate match=11 commit=11 next=12
+3: StateReplicate match=11 commit=11 next=12
diff --git a/testdata/replicate_pause.txt b/testdata/replicate_pause.txt
@@ -46,9 +46,9 @@ ok
 # Expect that in-flight tracking to nodes 2 and 3 is saturated.
 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]
+1: StateReplicate match=14 commit=11 next=15
+2: StateReplicate match=11 commit=11 next=15 paused inflight=3[full]
+3: StateReplicate match=11 commit=11 next=15 paused inflight=3[full]
 
 log-level none
 ----
@@ -66,9 +66,9 @@ ok
 # Expect that the entries are committed and stored on nodes 1 and 2.
 status 1
 ----
-1: StateReplicate match=14 next=15
-2: StateReplicate match=14 next=15
-3: StateReplicate match=11 next=15 paused inflight=3[full]
+1: StateReplicate match=14 commit=11 next=15
+2: StateReplicate match=14 commit=14 next=15
+3: StateReplicate match=11 commit=11 next=15 paused inflight=3[full]
 
 # Drop append messages to node 3.
 deliver-msgs drop=3
@@ -94,9 +94,9 @@ ok
 # In-flight tracking to nodes 2 and 3 is saturated, but node 3 is behind.
 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]
+1: StateReplicate match=14 commit=11 next=15
+2: StateReplicate match=14 commit=14 next=18 paused inflight=3[full]
+3: StateReplicate match=11 commit=11 next=15 paused inflight=3[full]
 
 log-level none
 ----
@@ -114,9 +114,9 @@ ok
 # Expect that the entries are committed and stored only on nodes 1 and 2.
 status 1
 ----
-1: StateReplicate match=17 next=18
-2: StateReplicate match=17 next=18
-3: StateReplicate match=11 next=15 paused inflight=3[full]
+1: StateReplicate match=17 commit=14 next=18
+2: StateReplicate match=17 commit=17 next=18
+3: StateReplicate match=11 commit=11 next=15 paused inflight=3[full]
 
 # Make a heartbeat roundtrip.
 tick-heartbeat 1
@@ -185,6 +185,6 @@ ok
 # Eventually all nodes catch up on the committed state.
 status 1
 ----
-1: StateReplicate match=17 next=18
-2: StateReplicate match=17 next=18
-3: StateReplicate match=17 next=18
+1: StateReplicate match=17 commit=14 next=18
+2: StateReplicate match=17 commit=17 next=18
+3: StateReplicate match=17 commit=17 next=18
diff --git a/testdata/slow_follower_after_compaction.txt b/testdata/slow_follower_after_compaction.txt
@@ -43,9 +43,9 @@ ok
 # All nodes up-to-date.
 status 1
 ----
-1: StateReplicate match=14 next=15
-2: StateReplicate match=14 next=15
-3: StateReplicate match=14 next=15
+1: StateReplicate match=14 commit=11 next=15
+2: StateReplicate match=14 commit=14 next=15
+3: StateReplicate match=14 commit=14 next=15
 
 log-level none
 ----
@@ -79,9 +79,9 @@ ok
 # Nodes 1 and 2 up-to-date, 3 is behind and MsgApp flow is throttled.
 status 1
 ----
-1: StateReplicate match=18 next=19
-2: StateReplicate match=18 next=19
-3: StateReplicate match=14 next=17 paused inflight=2[full]
+1: StateReplicate match=18 commit=14 next=19
+2: StateReplicate match=18 commit=18 next=19
+3: StateReplicate match=14 commit=14 next=17 paused inflight=2[full]
 
 # Break the MsgApp flow from the leader to node 3.
 deliver-msgs drop=3
@@ -116,6 +116,6 @@ ok
 # All nodes caught up.
 status 1
 ----
-1: StateReplicate match=18 next=19
-2: StateReplicate match=18 next=19
-3: StateReplicate match=18 next=19
+1: StateReplicate match=18 commit=14 next=19
+2: StateReplicate match=18 commit=18 next=19
+3: StateReplicate match=18 commit=18 next=19
diff --git a/testdata/snapshot_succeed_via_app_resp.txt b/testdata/snapshot_succeed_via_app_resp.txt
@@ -41,9 +41,9 @@ ok
 
 status 1
 ----
-1: StateReplicate match=11 next=12
-2: StateReplicate match=11 next=12
-3: StateProbe match=0 next=11 paused inactive
+1: StateReplicate match=11 commit=10 next=12
+2: StateReplicate match=11 commit=11 next=12
+3: StateProbe match=0 commit=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).
@@ -86,18 +86,18 @@ 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]
+  DEBUG 1 [firstindex: 12, commit: 11] sent snapshot[index: 11, term: 1] to 3 [StateProbe match=0 commit=0 next=11]
+  DEBUG 1 paused sending replication messages to 3 [StateSnapshot match=0 commit=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
-2: StateReplicate match=11 next=12
-3: StateSnapshot match=0 next=11 paused pendingSnap=11
+1: StateReplicate match=11 commit=10 next=12
+2: StateReplicate match=11 commit=11 next=12
+3: StateSnapshot match=0 commit=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
@@ -124,17 +124,17 @@ 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]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 3 [StateSnapshot match=11 commit=0 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
-2: StateReplicate match=11 next=12
-3: StateReplicate match=11 next=12
+1: StateReplicate match=11 commit=10 next=12
+2: StateReplicate match=11 commit=11 next=12
+3: StateReplicate match=11 commit=0 next=12
 
 # Let things settle.
 stabilize

diff --git a/testdata/snapshot_succeed_via_app_resp_behind.txt b/testdata/snapshot_succeed_via_app_resp_behind.txt
@@ -48,9 +48,9 @@ raft-state
 
 status 1
 ----
-1: StateReplicate match=11 next=12
-2: StateReplicate match=11 next=12
-3: StateProbe match=0 next=11 paused inactive
+1: StateReplicate match=11 commit=10 next=12
+2: StateReplicate match=11 commit=11 next=12
+3: StateProbe match=0 commit=0 next=11 paused inactive
 
 raft-log 3
 ----
@@ -82,9 +82,9 @@ ok
 
 status 1
 ----
-1: StateReplicate match=12 next=13
-2: StateReplicate match=12 next=13
-3: StateProbe match=0 next=11 paused inactive
+1: StateReplicate match=12 commit=11 next=13
+2: StateReplicate match=12 commit=12 next=13
+3: StateProbe match=0 commit=0 next=11 paused inactive
 
 # 3 now gets the first MsgApp the leader originally sent, trying to append entry
 # 11 but this is rejected because the follower's log started at index 5.
@@ -120,9 +120,9 @@ stabilize 1
 > 1 receiving messages
   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]
-  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]
+  DEBUG 1 decreased progress of 3 to [StateProbe match=0 commit=0 next=6]
+  DEBUG 1 [firstindex: 11, commit: 12] sent snapshot[index: 12, term: 1] to 3 [StateProbe match=0 commit=0 next=6]
+  DEBUG 1 paused sending replication messages to 3 [StateSnapshot match=0 commit=0 next=6 paused pendingSnap=12]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -148,7 +148,7 @@ 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=12]
+  DEBUG 1 recovered from needing snapshot, resumed sending replication messages to 3 [StateSnapshot match=11 commit=0 next=12 paused pendingSnap=12]
 > 1 handling Ready
   Ready MustSync=false:
   Messages:
@@ -158,6 +158,6 @@ stabilize 1
 # This is despite its PendingSnapshot having been 12.
 status 1
 ----
-1: StateReplicate match=12 next=13
-2: StateReplicate match=12 next=13
-3: StateReplicate match=11 next=13 inflight=1
+1: StateReplicate match=12 commit=11 next=13
+2: StateReplicate match=12 commit=12 next=13
+3: StateReplicate match=11 commit=0 next=13 inflight=1