raft/rafttest: TestBasicProgress failed

[cockroach-teamcity]

raft/rafttest.TestBasicProgress failed with artifacts on release-24.1 @ d2ac82658f68c96394a811a3eaecafcd808403f3:

2024/04/03 23:05:30 raft.3: stop
2024/04/03 23:05:30 raft.4: stop
2024/04/03 23:05:30 raft.5: stop
raft2024/04/03 23:05:30 INFO: 1 switched to configuration voters=()
raft2024/04/03 23:05:30 INFO: 1 became follower at term 0
raft2024/04/03 23:05:30 INFO: newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/04/03 23:05:30 INFO: 1 became follower at term 1
raft2024/04/03 23:05:30 INFO: 1 switched to configuration voters=(1)
raft2024/04/03 23:05:30 INFO: 1 switched to configuration voters=(1 2)
raft2024/04/03 23:05:30 INFO: 1 switched to configuration voters=(1 2 3)
raft2024/04/03 23:05:30 INFO: 1 switched to configuration voters=(1 2 3 4)
raft2024/04/03 23:05:30 INFO: 1 switched to configuration voters=(1 2 3 4 5)
raft2024/04/03 23:05:30 INFO: 2 switched to configuration voters=()
raft2024/04/03 23:05:30 INFO: 2 became follower at term 0
raft2024/04/03 23:05:30 INFO: newRaft 2 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/04/03 23:05:30 INFO: 2 became follower at term 1
raft2024/04/03 23:05:30 INFO: 2 switched to configuration voters=(1)
raft2024/04/03 23:05:30 INFO: 2 switched to configuration voters=(1 2)
raft2024/04/03 23:05:30 INFO: 2 switched to configuration voters=(1 2 3)
raft2024/04/03 23:05:30 INFO: 2 switched to configuration voters=(1 2 3 4)
raft2024/04/03 23:05:30 INFO: 2 switched to configuration voters=(1 2 3 4 5)
raft2024/04/03 23:05:30 INFO: 3 switched to configuration voters=()
raft2024/04/03 23:05:30 INFO: 3 became follower at term 0
raft2024/04/03 23:05:30 INFO: newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/04/03 23:05:30 INFO: 3 became follower at term 1
raft2024/04/03 23:05:30 INFO: 3 switched to configuration voters=(1)
raft2024/04/03 23:05:30 INFO: 3 switched to configuration voters=(1 2)
raft2024/04/03 23:05:30 INFO: 3 switched to configuration voters=(1 2 3)
raft2024/04/03 23:05:30 INFO: 3 switched to configuration voters=(1 2 3 4)
raft2024/04/03 23:05:30 INFO: 3 switched to configuration voters=(1 2 3 4 5)
raft2024/04/03 23:05:30 INFO: 4 switched to configuration voters=()
raft2024/04/03 23:05:30 INFO: 4 became follower at term 0
raft2024/04/03 23:05:30 INFO: newRaft 4 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/04/03 23:05:30 INFO: 4 became follower at term 1
raft2024/04/03 23:05:30 INFO: 4 switched to configuration voters=(1)
raft2024/04/03 23:05:30 INFO: 4 switched to configuration voters=(1 2)
raft2024/04/03 23:05:30 INFO: 4 switched to configuration voters=(1 2 3)
raft2024/04/03 23:05:30 INFO: 4 switched to configuration voters=(1 2 3 4)
raft2024/04/03 23:05:30 INFO: 4 switched to configuration voters=(1 2 3 4 5)
raft2024/04/03 23:05:30 INFO: 5 switched to configuration voters=()
raft2024/04/03 23:05:30 INFO: 5 became follower at term 0
raft2024/04/03 23:05:30 INFO: newRaft 5 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/04/03 23:05:30 INFO: 5 became follower at term 1
raft2024/04/03 23:05:30 INFO: 5 switched to configuration voters=(1)
raft2024/04/03 23:05:30 INFO: 5 switched to configuration voters=(1 2)
raft2024/04/03 23:05:30 INFO: 5 switched to configuration voters=(1 2 3)
raft2024/04/03 23:05:30 INFO: 5 switched to configuration voters=(1 2 3 4)
raft2024/04/03 23:05:30 INFO: 5 switched to configuration voters=(1 2 3 4 5)
    node_test.go:47: commits failed to converge!
--- FAIL: TestBasicProgress (5.25s)

Help

See also: How To Investigate a Go Test Failure (internal)

/cc @cockroachdb/replication

This test on roachdash | Improve this report!

Jira issue: CRDB-37487

[kvoli]

I'm not able to reproduce this locally over 10k runs on 4a623b2. I'll pull a newer 24.1 SHA and try again.

dev test pkg/raft/rafttest -f TestBasicProgress --stress --count=10000 -v
...
Target //pkg/raft/rafttest:rafttest_test up-to-date:
  _bazel/bin/pkg/raft/rafttest/rafttest_test_/rafttest_test
INFO: Elapsed time: 101.234s, Critical Path: 0.48s
INFO: 10001 processes: 1 internal, 10000 linux-sandbox.
//pkg/raft/rafttest:rafttest_test                                        PASSED in 0.5s
  Stats over 10000 runs: max = 0.5s, min = 0.2s, avg = 0.2s, dev = 0.0s

Executed 1 out of 1 test: 1 test passes.

[kvoli]

No luck on d2ac826 either. This test was recently added when we embedded the up-stream etcd-io/raft lib in cockroach. I'm guessing this test was flaky before embedding. Moving to a GA-blocker.

Full test log

=== RUN   TestBasicProgress
23:05:24 INFO: 1 switched to configuration voters=()
23:05:24 INFO: 1 became follower at term 0
23:05:24 INFO: newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:24 INFO: 1 became follower at term 1
23:05:24 INFO: 1 switched to configuration voters=(1)
23:05:24 INFO: 1 switched to configuration voters=(1 2)
23:05:24 INFO: 1 switched to configuration voters=(1 2 3)
23:05:24 INFO: 1 switched to configuration voters=(1 2 3 4)
23:05:24 INFO: 1 switched to configuration voters=(1 2 3 4 5)
23:05:24 INFO: 2 switched to configuration voters=()
23:05:24 INFO: 2 became follower at term 0
23:05:24 INFO: newRaft 2 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:24 INFO: 2 became follower at term 1
23:05:24 INFO: 2 switched to configuration voters=(1)
23:05:24 INFO: 2 switched to configuration voters=(1 2)
23:05:24 INFO: 2 switched to configuration voters=(1 2 3)
23:05:24 INFO: 2 switched to configuration voters=(1 2 3 4)
23:05:24 INFO: 2 switched to configuration voters=(1 2 3 4 5)
23:05:24 INFO: 3 switched to configuration voters=()
23:05:24 INFO: 3 became follower at term 0
23:05:24 INFO: newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:24 INFO: 3 became follower at term 1
23:05:24 INFO: 3 switched to configuration voters=(1)
23:05:24 INFO: 3 switched to configuration voters=(1 2)
23:05:24 INFO: 3 switched to configuration voters=(1 2 3)
23:05:24 INFO: 3 switched to configuration voters=(1 2 3 4)
23:05:24 INFO: 3 switched to configuration voters=(1 2 3 4 5)
23:05:24 INFO: 4 switched to configuration voters=()
23:05:24 INFO: 4 became follower at term 0
23:05:24 INFO: newRaft 4 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:24 INFO: 4 became follower at term 1
23:05:24 INFO: 4 switched to configuration voters=(1)
23:05:24 INFO: 4 switched to configuration voters=(1 2)
23:05:24 INFO: 4 switched to configuration voters=(1 2 3)
23:05:24 INFO: 4 switched to configuration voters=(1 2 3 4)
23:05:24 INFO: 4 switched to configuration voters=(1 2 3 4 5)
23:05:24 INFO: 5 switched to configuration voters=()
23:05:24 INFO: 5 became follower at term 0
23:05:24 INFO: newRaft 5 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:24 INFO: 5 became follower at term 1
23:05:24 INFO: 5 switched to configuration voters=(1)
23:05:24 INFO: 5 switched to configuration voters=(1 2)
23:05:24 INFO: 5 switched to configuration voters=(1 2 3)
23:05:24 INFO: 5 switched to configuration voters=(1 2 3 4)
23:05:24 INFO: 5 switched to configuration voters=(1 2 3 4 5)
23:05:24 INFO: 3 is starting a new election at term 1
23:05:24 INFO: 3 became candidate at term 2
23:05:24 INFO: 3 [logterm: 1, index: 5] sent MsgVote request to 1 at term 2
23:05:24 INFO: 3 [logterm: 1, index: 5] sent MsgVote request to 2 at term 2
23:05:24 INFO: 3 [logterm: 1, index: 5] sent MsgVote request to 4 at term 2
23:05:24 INFO: 3 [logterm: 1, index: 5] sent MsgVote request to 5 at term 2
23:05:24 INFO: 3 received MsgVoteResp from 3 at term 2
23:05:24 INFO: 3 has received 1 MsgVoteResp votes and 0 vote rejections
23:05:24 INFO: 4 [term: 1] received a MsgVote message with higher term from 3 [term: 2]
23:05:24 INFO: 4 became follower at term 2
23:05:24 INFO: 4 [logterm: 1, index: 5, vote: 0] cast MsgVote for 3 [logterm: 1, index: 5] at term 2
23:05:24 INFO: 1 [term: 1] received a MsgVote message with higher term from 3 [term: 2]
23:05:24 INFO: 1 became follower at term 2
23:05:24 INFO: 1 [logterm: 1, index: 5, vote: 0] cast MsgVote for 3 [logterm: 1, index: 5] at term 2
23:05:24 INFO: 5 is starting a new election at term 1
23:05:24 INFO: 5 became candidate at term 2
23:05:24 INFO: 5 [logterm: 1, index: 5] sent MsgVote request to 1 at term 2
23:05:24 INFO: 5 [logterm: 1, index: 5] sent MsgVote request to 2 at term 2
23:05:24 INFO: 5 [logterm: 1, index: 5] sent MsgVote request to 3 at term 2
23:05:24 INFO: 5 [logterm: 1, index: 5] sent MsgVote request to 4 at term 2
23:05:24 INFO: 5 received MsgVoteResp from 5 at term 2
23:05:24 INFO: 5 has received 1 MsgVoteResp votes and 0 vote rejections
23:05:24 INFO: 5 [logterm: 1, index: 5, vote: 5] rejected MsgVote from 3 [logterm: 1, index: 5] at term 2
23:05:24 INFO: 3 received MsgVoteResp from 4 at term 2
23:05:24 INFO: 3 has received 2 MsgVoteResp votes and 0 vote rejections
23:05:24 INFO: 3 [logterm: 1, index: 5, vote: 3] rejected MsgVote from 5 [logterm: 1, index: 5] at term 2
23:05:24 INFO: 1 [logterm: 1, index: 5, vote: 3] rejected MsgVote from 5 [logterm: 1, index: 5] at term 2
23:05:24 INFO: 3 received MsgVoteResp from 1 at term 2
23:05:24 INFO: 3 has received 3 MsgVoteResp votes and 0 vote rejections
23:05:24 INFO: 3 became leader at term 2
23:05:24 INFO: raft.node: 3 elected leader 3 at term 2
23:05:24 INFO: 5 received MsgVoteResp rejection from 3 at term 2
23:05:24 INFO: 5 has received 1 MsgVoteResp votes and 1 vote rejections
23:05:24 INFO: 4 [logterm: 1, index: 5, vote: 3] rejected MsgVote from 5 [logterm: 1, index: 5] at term 2
23:05:24 INFO: raft.node: 4 elected leader 3 at term 2
23:05:24 INFO: 5 became follower at term 2
23:05:24 INFO: raft.node: 5 elected leader 3 at term 2
23:05:24 INFO: raft.node: 1 elected leader 3 at term 2
23:05:25 INFO: 2 [term: 1] received a MsgVote message with higher term from 3 [term: 2]
23:05:25 INFO: 2 became follower at term 2
23:05:25 INFO: 2 [logterm: 1, index: 5, vote: 0] cast MsgVote for 3 [logterm: 1, index: 5] at term 2
23:05:25 INFO: 2 [logterm: 1, index: 5, vote: 3] rejected MsgVote from 5 [logterm: 1, index: 5] at term 2
23:05:25 INFO: raft.node: 2 elected leader 3 at term 2
23:05:25 INFO: 2 is starting a new election at term 2
23:05:25 INFO: 2 became candidate at term 3
23:05:25 INFO: 2 [logterm: 2, index: 6] sent MsgVote request to 1 at term 3
23:05:25 INFO: 2 [logterm: 2, index: 6] sent MsgVote request to 3 at term 3
23:05:25 INFO: 2 [logterm: 2, index: 6] sent MsgVote request to 4 at term 3
23:05:25 INFO: 2 [logterm: 2, index: 6] sent MsgVote request to 5 at term 3
23:05:25 INFO: raft.node: 2 lost leader 3 at term 3
23:05:25 INFO: 2 received MsgVoteResp from 2 at term 3
23:05:25 INFO: 2 has received 1 MsgVoteResp votes and 0 vote rejections
23:05:25 INFO: 2 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 2] received a MsgVote message with higher term from 2 [term: 3]
23:05:25 INFO: 5 became follower at term 3
23:05:25 INFO: 5 [logterm: 2, index: 6, vote: 0] cast MsgVote for 2 [logterm: 2, index: 6] at term 3
23:05:25 INFO: raft.node: 5 lost leader 3 at term 3
23:05:25 INFO: 2 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgVoteResp message with lower term from 2 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 2] received a MsgVote message with higher term from 2 [term: 3]
23:05:25 INFO: 3 became follower at term 3
23:05:25 INFO: 3 [logterm: 2, index: 78, vote: 0] rejected MsgVote from 2 [logterm: 2, index: 6] at term 3
23:05:25 INFO: raft.node: 3 lost leader 3 at term 3
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 2] received a MsgVote message with higher term from 2 [term: 3]
23:05:25 INFO: 4 became follower at term 3
23:05:25 INFO: 4 [logterm: 2, index: 6, vote: 0] cast MsgVote for 2 [logterm: 2, index: 6] at term 3
23:05:25 INFO: raft.node: 4 lost leader 3 at term 3
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored entry appends from a MsgStorageAppendResp message with lower term [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 2] received a MsgVote message with higher term from 2 [term: 3]
23:05:25 INFO: 1 became follower at term 3
23:05:25 INFO: 1 [logterm: 2, index: 7, vote: 0] rejected MsgVote from 2 [logterm: 2, index: 6] at term 3
23:05:25 INFO: raft.node: 1 lost leader 3 at term 3
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 2 received MsgVoteResp from 5 at term 3
23:05:25 INFO: 2 has received 2 MsgVoteResp votes and 0 vote rejections
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgHeartbeatResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 received MsgVoteResp from 4 at term 3
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 has received 3 MsgVoteResp votes and 0 vote rejections
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 became leader at term 3
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: raft.node: 2 elected leader 2 at term 3
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 5 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 4 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 2 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgApp message with lower term from 3 [term: 2]
23:05:25 INFO: 1 [term: 3] ignored a MsgHeartbeat message with lower term from 3 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 4 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgHeartbeatResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: 3 [term: 3] ignored a MsgAppResp message with lower term from 1 [term: 2]
23:05:25 INFO: raft.node: 1 elected leader 2 at term 3
23:05:25 INFO: raft.node: 5 elected leader 2 at term 3
23:05:25 INFO: found conflict at index 7 [existing term: 2, conflicting term: 3]
23:05:25 INFO: replace the unstable entries from index 7
23:05:25 INFO: raft.node: 4 elected leader 2 at term 3
23:05:25 INFO: found conflict at index 7 [existing term: 2, conflicting term: 3]
23:05:25 INFO: replace the unstable entries from index 7
23:05:25 INFO: raft.node: 3 elected leader 2 at term 3
    node_test.go:47: commits failed to converge!
23:05:30 raft.1: stop
23:05:30 raft.2: stop
23:05:30 raft.3: stop
23:05:30 raft.4: stop
23:05:30 raft.5: stop
23:05:30 INFO: 1 switched to configuration voters=()
23:05:30 INFO: 1 became follower at term 0
23:05:30 INFO: newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:30 INFO: 1 became follower at term 1
23:05:30 INFO: 1 switched to configuration voters=(1)
23:05:30 INFO: 1 switched to configuration voters=(1 2)
23:05:30 INFO: 1 switched to configuration voters=(1 2 3)
23:05:30 INFO: 1 switched to configuration voters=(1 2 3 4)
23:05:30 INFO: 1 switched to configuration voters=(1 2 3 4 5)
23:05:30 INFO: 2 switched to configuration voters=()
23:05:30 INFO: 2 became follower at term 0
23:05:30 INFO: newRaft 2 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:30 INFO: 2 became follower at term 1
23:05:30 INFO: 2 switched to configuration voters=(1)
23:05:30 INFO: 2 switched to configuration voters=(1 2)
23:05:30 INFO: 2 switched to configuration voters=(1 2 3)
23:05:30 INFO: 2 switched to configuration voters=(1 2 3 4)
23:05:30 INFO: 2 switched to configuration voters=(1 2 3 4 5)
23:05:30 INFO: 3 switched to configuration voters=()
23:05:30 INFO: 3 became follower at term 0
23:05:30 INFO: newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:30 INFO: 3 became follower at term 1
23:05:30 INFO: 3 switched to configuration voters=(1)
23:05:30 INFO: 3 switched to configuration voters=(1 2)
23:05:30 INFO: 3 switched to configuration voters=(1 2 3)
23:05:30 INFO: 3 switched to configuration voters=(1 2 3 4)
23:05:30 INFO: 3 switched to configuration voters=(1 2 3 4 5)
23:05:30 INFO: 4 switched to configuration voters=()
23:05:30 INFO: 4 became follower at term 0
23:05:30 INFO: newRaft 4 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:30 INFO: 4 became follower at term 1
23:05:30 INFO: 4 switched to configuration voters=(1)
23:05:30 INFO: 4 switched to configuration voters=(1 2)
23:05:30 INFO: 4 switched to configuration voters=(1 2 3)
23:05:30 INFO: 4 switched to configuration voters=(1 2 3 4)
23:05:30 INFO: 4 switched to configuration voters=(1 2 3 4 5)
23:05:30 INFO: 5 switched to configuration voters=()
23:05:30 INFO: 5 became follower at term 0
23:05:30 INFO: newRaft 5 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
23:05:30 INFO: 5 became follower at term 1
23:05:30 INFO: 5 switched to configuration voters=(1)
23:05:30 INFO: 5 switched to configuration voters=(1 2)
23:05:30 INFO: 5 switched to configuration voters=(1 2 3)
23:05:30 INFO: 5 switched to configuration voters=(1 2 3 4)
23:05:30 INFO: 5 switched to configuration voters=(1 2 3 4 5)
--- FAIL: TestBasicProgress (5.25s)

[kvoli]

@andrewbaptist could you add more detail to why this is a bug? I wasn't able to determine either way based on the test output, but I'm not intimately familiar here.

[andrewbaptist]

I didn't dig into the detail on why this failed other than also trying to reproduce it. Based on the test and the set of conditions it needs deeper investigation to determine the cause. There aren't any network calls to induce flakiness, and the test normally passes within ~100-200ms, so the 5s to fail here doesn't seem likely to be fixed by a timing change.

I'm also a little confused about the teamcity UI that makes it hard to see trends on this test. The page showing the trend is here vs the default if you click the link

The test itself is quite simple, but there isn't a lot of debuggability as its written. So either it is not expected that we would have all 100 entries on all nodes, but that seems unlikely, or there is some bug that prevents it from happening. Without a repro, we might have to just observe this longer...