raft/rafttest: TestRestart failed

[cockroach-teamcity]

raft/rafttest.TestRestart failed with artifacts on master @ 46854026bc11b3870c8bbefc976f5550b18dd82c:

raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 2 not forwarding to itself at term 2; dropping proposal
raft2024/07/18 04:23:33 INFO: 5 is starting a new election at term 2
raft2024/07/18 04:23:33 INFO: 5 became candidate at term 3
raft2024/07/18 04:23:33 INFO: 5 [logterm: 2, index: 6] sent MsgVote request to 1 at term 3
raft2024/07/18 04:23:33 INFO: 5 [logterm: 2, index: 6] sent MsgVote request to 2 at term 3
raft2024/07/18 04:23:33 INFO: 5 [logterm: 2, index: 6] sent MsgVote request to 3 at term 3
raft2024/07/18 04:23:33 INFO: 5 [logterm: 2, index: 6] sent MsgVote request to 4 at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 5 lost leader 2 at term 3
raft2024/07/18 04:23:33 INFO: 5 received MsgVoteResp from 5 at term 3
raft2024/07/18 04:23:33 INFO: 5 has received 1 MsgVoteResp votes and 0 vote rejections
raft2024/07/18 04:23:33 INFO: 1 [term: 2] received a MsgVote message with higher term from 5 [term: 3]
raft2024/07/18 04:23:33 INFO: 1 became follower at term 3
raft2024/07/18 04:23:33 INFO: 1 [logterm: 2, index: 6, vote: 0] cast MsgVote for 5 [logterm: 2, index: 6] at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 1 lost leader 2 at term 3
raft2024/07/18 04:23:33 INFO: 4 [term: 2] received a MsgVote message with higher term from 5 [term: 3]
raft2024/07/18 04:23:33 INFO: 4 became follower at term 3
raft2024/07/18 04:23:33 INFO: 4 [logterm: 2, index: 6, vote: 0] cast MsgVote for 5 [logterm: 2, index: 6] at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 4 lost leader 2 at term 3
raft2024/07/18 04:23:33 INFO: 5 received MsgVoteResp from 1 at term 3
raft2024/07/18 04:23:33 INFO: 5 has received 2 MsgVoteResp votes and 0 vote rejections
raft2024/07/18 04:23:33 INFO: 3 [term: 2] received a MsgVote message with higher term from 5 [term: 3]
raft2024/07/18 04:23:33 INFO: 3 became follower at term 3
raft2024/07/18 04:23:33 INFO: 3 [logterm: 2, index: 6, vote: 0] cast MsgVote for 5 [logterm: 2, index: 6] at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 3 lost leader 2 at term 3
raft2024/07/18 04:23:33 INFO: 2 [term: 2] received a MsgVote message with higher term from 5 [term: 3]
raft2024/07/18 04:23:33 INFO: 2 became follower at term 3
raft2024/07/18 04:23:33 INFO: 2 [logterm: 2, index: 6, vote: 0] cast MsgVote for 5 [logterm: 2, index: 6] at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 2 lost leader 2 at term 3
raft2024/07/18 04:23:33 INFO: 5 received MsgVoteResp from 3 at term 3
raft2024/07/18 04:23:33 INFO: 5 has received 3 MsgVoteResp votes and 0 vote rejections
raft2024/07/18 04:23:33 INFO: 5 became leader at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 5 elected leader 5 at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 2 elected leader 5 at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 1 elected leader 5 at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 3 elected leader 5 at term 3
raft2024/07/18 04:23:33 INFO: raft.node: 4 elected leader 5 at term 3
    node_test.go:91: commits failed to converge!
I240718 04:23:38.520629 388 (gostd) node.go:100  [-] 8  raft.1: stop
I240718 04:23:38.520684 616 (gostd) node.go:100  [-] 9  raft.2: stop
I240718 04:23:38.520698 614 (gostd) node.go:100  [-] 10  raft.3: stop
I240718 04:23:38.520708 394 (gostd) node.go:100  [-] 11  raft.4: stop
I240718 04:23:38.521851 396 (gostd) node.go:100  [-] 12  raft.5: stop
--- FAIL: TestRestart (5.20s)

Help

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

/cc @cockroachdb/kv

This test on roachdash | Improve this report!

Jira issue: CRDB-40428

[nvb]

This is the same flake that was discussed in etcd-io/raft#181. It was later fixed upstream by etcd-io/raft#188.

We are in the process of picking this fix up over in #122133. @pav-kv do we want to revive that PR and get it merged so that we can close this? If not, I'll import just that one commit.

[cockroach-teamcity]

raft/rafttest.TestRestart failed with artifacts on master @ 4ae4a52772b4b6b2bf2c340e06919c090894dffb:

raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 3 not forwarding to itself at term 2; dropping proposal
raft2024/08/03 00:03:03 INFO: 4 is starting a new election at term 2
raft2024/08/03 00:03:03 INFO: 4 became candidate at term 3
raft2024/08/03 00:03:03 INFO: 4 [logterm: 2, index: 6] sent MsgVote request to 1 at term 3
raft2024/08/03 00:03:03 INFO: 4 [logterm: 2, index: 6] sent MsgVote request to 2 at term 3
raft2024/08/03 00:03:03 INFO: 4 [logterm: 2, index: 6] sent MsgVote request to 3 at term 3
raft2024/08/03 00:03:03 INFO: 4 [logterm: 2, index: 6] sent MsgVote request to 5 at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 4 lost leader 3 at term 3
raft2024/08/03 00:03:03 INFO: 4 received MsgVoteResp from 4 at term 3
raft2024/08/03 00:03:03 INFO: 4 has received 1 MsgVoteResp votes and 0 vote rejections
raft2024/08/03 00:03:03 INFO: 5 [term: 2] received a MsgVote message with higher term from 4 [term: 3]
raft2024/08/03 00:03:03 INFO: 5 became follower at term 3
raft2024/08/03 00:03:03 INFO: 5 [logterm: 2, index: 6, vote: 0] cast MsgVote for 4 [logterm: 2, index: 6] at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 5 lost leader 3 at term 3
raft2024/08/03 00:03:03 INFO: 3 [term: 2] received a MsgVote message with higher term from 4 [term: 3]
raft2024/08/03 00:03:03 INFO: 3 became follower at term 3
raft2024/08/03 00:03:03 INFO: 3 [logterm: 2, index: 6, vote: 0] cast MsgVote for 4 [logterm: 2, index: 6] at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 3 lost leader 3 at term 3
raft2024/08/03 00:03:03 INFO: 1 [term: 2] received a MsgVote message with higher term from 4 [term: 3]
raft2024/08/03 00:03:03 INFO: 1 became follower at term 3
raft2024/08/03 00:03:03 INFO: 1 [logterm: 2, index: 6, vote: 0] cast MsgVote for 4 [logterm: 2, index: 6] at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 1 lost leader 3 at term 3
raft2024/08/03 00:03:03 INFO: 2 [term: 2] received a MsgVote message with higher term from 4 [term: 3]
raft2024/08/03 00:03:03 INFO: 2 became follower at term 3
raft2024/08/03 00:03:03 INFO: 2 [logterm: 2, index: 6, vote: 0] cast MsgVote for 4 [logterm: 2, index: 6] at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 2 lost leader 3 at term 3
raft2024/08/03 00:03:03 INFO: 4 received MsgVoteResp from 3 at term 3
raft2024/08/03 00:03:03 INFO: 4 has received 2 MsgVoteResp votes and 0 vote rejections
raft2024/08/03 00:03:03 INFO: 4 received MsgVoteResp from 5 at term 3
raft2024/08/03 00:03:03 INFO: 4 has received 3 MsgVoteResp votes and 0 vote rejections
raft2024/08/03 00:03:03 INFO: 4 became leader at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 4 elected leader 4 at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 5 elected leader 4 at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 3 elected leader 4 at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 1 elected leader 4 at term 3
raft2024/08/03 00:03:03 INFO: raft.node: 2 elected leader 4 at term 3
    node_test.go:91: commits failed to converge!
I240803 00:03:08.972291 1723 (gostd) node.go:100  [-] 8  raft.1: stop
I240803 00:03:08.972370 1817 (gostd) node.go:100  [-] 9  raft.2: stop
I240803 00:03:08.972385 1815 (gostd) node.go:100  [-] 10  raft.3: stop
I240803 00:03:08.974438 1729 (gostd) node.go:100  [-] 11  raft.4: stop
I240803 00:03:08.975517 1731 (gostd) node.go:100  [-] 12  raft.5: stop
--- FAIL: TestRestart (5.21s)

Help

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

This test on roachdash | Improve this report!

[cockroach-teamcity]

raft/rafttest.TestRestart failed with artifacts on master @ 167a9af39d0c1fadb9de8ee3c40e616e6c98af78:

I240808 19:00:45.050083 1756 (gostd) node.go:100  [-] 9  raft.2: stop
I240808 19:00:45.050159 1754 (gostd) node.go:100  [-] 10  raft.3: stop
I240808 19:00:45.051214 1668 (gostd) node.go:100  [-] 11  raft.4: stop
I240808 19:00:45.051264 1670 (gostd) node.go:100  [-] 12  raft.5: stop
raft2024/08/08 19:00:45 INFO: 1 switched to configuration voters=()
raft2024/08/08 19:00:45 INFO: 1 became follower at term 0
raft2024/08/08 19:00:45 INFO: newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/08/08 19:00:45 INFO: 1 became follower at term 1
raft2024/08/08 19:00:45 INFO: 1 switched to configuration voters=(1)
raft2024/08/08 19:00:45 INFO: 1 switched to configuration voters=(1 2)
raft2024/08/08 19:00:45 INFO: 1 switched to configuration voters=(1 2 3)
raft2024/08/08 19:00:45 INFO: 1 switched to configuration voters=(1 2 3 4)
raft2024/08/08 19:00:45 INFO: 1 switched to configuration voters=(1 2 3 4 5)
raft2024/08/08 19:00:45 INFO: 2 switched to configuration voters=()
raft2024/08/08 19:00:45 INFO: 2 became follower at term 0
raft2024/08/08 19:00:45 INFO: newRaft 2 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/08/08 19:00:45 INFO: 2 became follower at term 1
raft2024/08/08 19:00:45 INFO: 2 switched to configuration voters=(1)
raft2024/08/08 19:00:45 INFO: 2 switched to configuration voters=(1 2)
raft2024/08/08 19:00:45 INFO: 2 switched to configuration voters=(1 2 3)
raft2024/08/08 19:00:45 INFO: 2 switched to configuration voters=(1 2 3 4)
raft2024/08/08 19:00:45 INFO: 2 switched to configuration voters=(1 2 3 4 5)
raft2024/08/08 19:00:45 INFO: 3 switched to configuration voters=()
raft2024/08/08 19:00:45 INFO: 3 became follower at term 0
raft2024/08/08 19:00:45 INFO: newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/08/08 19:00:45 INFO: 3 became follower at term 1
raft2024/08/08 19:00:45 INFO: 3 switched to configuration voters=(1)
raft2024/08/08 19:00:45 INFO: 3 switched to configuration voters=(1 2)
raft2024/08/08 19:00:45 INFO: 3 switched to configuration voters=(1 2 3)
raft2024/08/08 19:00:45 INFO: 3 switched to configuration voters=(1 2 3 4)
raft2024/08/08 19:00:45 INFO: 3 switched to configuration voters=(1 2 3 4 5)
raft2024/08/08 19:00:45 INFO: 4 switched to configuration voters=()
raft2024/08/08 19:00:45 INFO: 4 became follower at term 0
raft2024/08/08 19:00:45 INFO: newRaft 4 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/08/08 19:00:45 INFO: 4 became follower at term 1
raft2024/08/08 19:00:45 INFO: 4 switched to configuration voters=(1)
raft2024/08/08 19:00:45 INFO: 4 switched to configuration voters=(1 2)
raft2024/08/08 19:00:45 INFO: 4 switched to configuration voters=(1 2 3)
raft2024/08/08 19:00:45 INFO: 4 switched to configuration voters=(1 2 3 4)
raft2024/08/08 19:00:45 INFO: 4 switched to configuration voters=(1 2 3 4 5)
raft2024/08/08 19:00:45 INFO: 5 switched to configuration voters=()
raft2024/08/08 19:00:45 INFO: 5 became follower at term 0
raft2024/08/08 19:00:45 INFO: newRaft 5 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2024/08/08 19:00:45 INFO: 5 became follower at term 1
raft2024/08/08 19:00:45 INFO: 5 switched to configuration voters=(1)
raft2024/08/08 19:00:45 INFO: 5 switched to configuration voters=(1 2)
raft2024/08/08 19:00:45 INFO: 5 switched to configuration voters=(1 2 3)
raft2024/08/08 19:00:45 INFO: 5 switched to configuration voters=(1 2 3 4)
raft2024/08/08 19:00:45 INFO: 5 switched to configuration voters=(1 2 3 4 5)
--- FAIL: TestRestart (5.20s)

Help

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

This test on roachdash | Improve this report!