Skip to content

data race in TestRaft_ReplaceUpgrade back compat test #681

@tgross

Description

@tgross

#678 surfaced an unrelated data race in the backwards compatibility test. Documenting this here for investigation so that we don't lose track of that while trying to land #678

Read was at:

      /opt/hostedtoolcache/go/1.26.2/x64/src/runtime/iface.go:334 +0x0
  github.com/hashicorp/raft-previous-version.(*Raft).pipelineSend()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/replication.go:512 +0x1d5

Write was at:

  github.com/hashicorp/raft-previous-version.(*Raft).startStopReplication()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:576 +0x56d
full details
=== RUN   TestRaft_ReplaceUpgrade/shutdown_without_leave
2026-05-07T17:47:30.021Z [INFO]  raft: initial configuration: index=0 servers=[]
2026-05-07T17:47:30.021Z [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:35499 [Follower]" leader-address= leader-id=
2026-05-07T17:47:30.021Z [INFO]  raft: initial configuration: index=0 servers=[]
2026-05-07T17:47:30.022Z [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:38851 [Follower]" leader-address= leader-id=
2026-05-07T17:47:30.022Z [INFO]  raft: initial configuration: index=0 servers=[]
2026-05-07T17:47:30.022Z [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:38119 [Follower]" leader-address= leader-id=
2026-05-07T17:47:30.096Z [WARN]  raft: no known peers, aborting election
2026-05-07T17:47:30.104Z [WARN]  raft: heartbeat timeout reached, starting election: last-leader-addr= last-leader-id=
2026-05-07T17:47:30.104Z [INFO]  raft: entering candidate state: node="Node at 127.0.0.1:35499 [Candidate]" term=2
2026-05-07T17:47:30.104Z [DEBUG] raft: voting for self: term=2 id=raftNode-0
2026-05-07T17:47:30.104Z [DEBUG] raft: asking for vote: term=2 from=raftNode-1 address=127.0.0.1:38851
2026-05-07T17:47:30.104Z [DEBUG] raft: asking for vote: term=2 from=raftNode-2 address=127.0.0.1:38119
2026-05-07T17:47:30.104Z [DEBUG] raft: calculated votes needed: needed=2 term=2
2026-05-07T17:47:30.104Z [DEBUG] raft: vote granted: from=raftNode-0 term=2 tally=1
2026-05-07T17:47:30.106Z [DEBUG] raft: lost leadership because received a requestVote with a newer term
2026-05-07T17:47:30.106Z [DEBUG] raft: lost leadership because received a requestVote with a newer term
2026-05-07T17:47:30.106Z [DEBUG] raft: vote granted: from=raftNode-2 term=2 tally=2
2026-05-07T17:47:30.106Z [INFO]  raft: election won: term=2 tally=2
2026-05-07T17:47:30.106Z [INFO]  raft: entering leader state: leader="Node at 127.0.0.1:35499 [Leader]"
2026-05-07T17:47:30.106Z [INFO]  raft: added peer, starting replication: peer=raftNode-1
2026-05-07T17:47:30.106Z [INFO]  raft: added peer, starting replication: peer=raftNode-2
2026-05-07T17:47:30.107Z [WARN]  raft: failed to get previous log: previous-index=1 last-index=0 error="log not found"
2026-05-07T17:47:30.107Z [WARN]  raft: failed to get previous log: previous-index=1 last-index=0 error="log not found"
2026-05-07T17:47:30.107Z [WARN]  raft: appendEntries rejected, sending older logs: peer="{Voter raftNode-1 127.0.0.1:38851}" next=1
2026-05-07T17:47:30.107Z [WARN]  raft: appendEntries rejected, sending older logs: peer="{Voter raftNode-2 127.0.0.1:38119}" next=1
2026-05-07T17:47:30.108Z [INFO]  raft: pipelining replication: peer="{Voter raftNode-1 127.0.0.1:38851}"
2026-05-07T17:47:30.109Z [INFO]  raft: pipelining replication: peer="{Voter raftNode-2 127.0.0.1:38119}"
Error: -07T17:47:30.124Z [ERROR] raft-net: failed to decode incoming command: error="transport shutdown"
2026-05-07T17:47:30.125Z [INFO]  raft: initial configuration: index=1 servers="[{Suffrage:Voter ID:raftNode-0 Address:127.0.0.1:35499} {Suffrage:Voter ID:raftNode-1 Address:127.0.0.1:38851} {Suffrage:Voter ID:raftNode-2 Address:127.0.0.1:38119}]"
2026-05-07T17:47:30.125Z [INFO]  raft: updating configuration: command=AddVoter server-id=raftNode-1 server-addr=127.0.0.1:34035 servers="[{Suffrage:Voter ID:raftNode-0 Address:127.0.0.1:35499} {Suffrage:Voter ID:raftNode-1 Address:127.0.0.1:34035} {Suffrage:Voter ID:raftNode-2 Address:127.0.0.1:38119}]"
2026-05-07T17:47:30.125Z [INFO]  raft: updating peer: peer=raftNode-1
2026-05-07T17:47:30.125Z [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:34035 [Follower]" leader-address= leader-id=
==================
WARNING: DATA RACE
Read at 0x00c004215120 by goroutine 1998:
  runtime.convT()
      /opt/hostedtoolcache/go/1.26.2/x64/src/runtime/iface.go:334 +0x0
  github.com/hashicorp/raft-previous-version.(*Raft).pipelineSend()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/replication.go:512 +0x1d5
  github.com/hashicorp/raft-previous-version.(*Raft).pipelineReplicate()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/replication.go:485 +0xf7b
  github.com/hashicorp/raft-previous-version.(*Raft).replicate()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/replication.go:188 +0xac7
  github.com/hashicorp/raft-previous-version.(*Raft).startStopReplication.func1()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:564 +0x49
  github.com/hashicorp/raft-previous-version.(*raftState).goFunc.func1()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/state.go:149 +0x97

Previous write at 0x00c004215120 by goroutine 1980:
  github.com/hashicorp/raft-previous-version.(*Raft).startStopReplication()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:576 +0x56d
  github.com/hashicorp/raft-previous-version.(*Raft).appendConfigurationEntry()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:1178 +0xb64
  github.com/hashicorp/raft-previous-version.(*Raft).leaderLoop()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:838 +0x2e4a
  github.com/hashicorp/raft-previous-version.(*Raft).runLeader()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:527 +0x9a4
  github.com/hashicorp/raft-previous-version.(*Raft).run()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:150 +0x171
  github.com/hashicorp/raft-previous-version.(*Raft).run-fm()
      <autogenerated>:1 +0x2e
  github.com/hashicorp/raft-previous-version.(*raftState).goFunc.func1()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/state.go:149 +0x97

Goroutine 1998 (running) created at:
  github.com/hashicorp/raft-previous-version.(*raftState).goFunc()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/state.go:147 +0x139
  github.com/hashicorp/raft-previous-version.(*Raft).startStopReplication()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:564 +0xd44
  github.com/hashicorp/raft-previous-version.(*Raft).runLeader()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:515 +0x8b6
  github.com/hashicorp/raft-previous-version.(*Raft).run()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/raft.go:150 +0x171
  github.com/hashicorp/raft-previous-version.(*Raft).run-fm()
      <autogenerated>:1 +0x2e
  github.com/hashicorp/raft-previous-version.(*raftState).goFunc.func1()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/state.go:149 +0x97

Goroutine 1980 (running) created at:
  github.com/hashicorp/raft-previous-version.(*raftState).goFunc()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/state.go:147 +0x139
  github.com/hashicorp/raft-previous-version.NewRaft()
      /home/runner/work/raft/raft/raft-compat/raft-previous-version/api.go:604 +0x1ab0
  github.com/hashicorp/raft/compat/testcluster.InitPreviousWithStore()
      /home/runner/work/raft/raft/raft-compat/testcluster/cluster.go:221 +0x8cf
  github.com/hashicorp/raft/compat/testcluster.InitPrevious()
      /home/runner/work/raft/raft/raft-compat/testcluster/cluster.go:196 +0x98
  github.com/hashicorp/raft/compat/testcluster.NewRaftCluster()
      /home/runner/work/raft/raft/raft-compat/testcluster/cluster.go:118 +0x1cc
  github.com/hashicorp/raft/compat/testcluster.NewPreviousRaftCluster()
      /home/runner/work/raft/raft/raft-compat/testcluster/cluster.go:124 +0xb3
  github.com/hashicorp/raft/compat.TestRaft_ReplaceUpgrade.func4()
      /home/runner/work/raft/raft/raft-compat/rolling_upgrade_test.go:201 +0xb4
  testing.tRunner()
      /opt/hostedtoolcache/go/1.26.2/x64/src/testing/testing.go:2036 +0x21c
  testing.(*T).Run.gowrap1()
      /opt/hostedtoolcache/go/1.26.2/x64/src/testing/testing.go:2101 +0x38
==================
Error: -07T17:47:30.126Z [ERROR] raft: failed to pipeline appendEntries: peer="{Voter raftNode-1 127.0.0.1:34035}" error="write tcp 127.0.0.1:53652->127.0.0.1:38851: use of closed network connection"
2026-05-07T17:47:30.126Z [INFO]  raft: aborting pipeline replication: peer="{Voter raftNode-1 127.0.0.1:38851}"
2026-05-07T17:47:30.130Z [INFO]  raft: initial configuration: index=4 servers="[{Suffrage:Voter ID:raftNode-0 Address:127.0.0.1:35499} {Suffrage:Voter ID:raftNode-1 Address:127.0.0.1:34035} {Suffrage:Voter ID:raftNode-2 Address:127.0.0.1:38119}]"
2026-05-07T17:47:30.130Z [INFO]  raft: updating configuration: command=AddVoter server-id=raftNode-2 server-addr=127.0.0.1:43689 servers="[{Suffrage:Voter ID:raftNode-0 Address:127.0.0.1:35499} {Suffrage:Voter ID:raftNode-1 Address:127.0.0.1:34035} {Suffrage:Voter ID:raftNode-2 Address:127.0.0.1:43689}]"
2026-05-07T17:47:30.130Z [INFO]  raft: updating peer: peer=raftNode-2
2026-05-07T17:47:30.130Z [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:43689 [Follower]" leader-address= leader-id=
Error: -07T17:47:30.131Z [ERROR] raft-net: failed to decode incoming command: error="transport shutdown"
2026-05-07T17:47:30.132Z [INFO]  raft: aborting pipeline replication: peer="{Voter raftNode-2 127.0.0.1:38119}"
2026-05-07T17:47:30.132Z [INFO]  raft: pipelining replication: peer="{Voter raftNode-1 127.0.0.1:34035}"
2026-05-07T17:47:30.140Z [INFO]  raft: pipelining replication: peer="{Voter raftNode-2 127.0.0.1:43689}"
2026-05-07T17:47:31.135Z [INFO]  raft: aborting pipeline replication: peer="{Voter raftNode-1 127.0.0.1:34035}"
2026-05-07T17:47:31.135Z [INFO]  raft: aborting pipeline replication: peer="{Voter raftNode-2 127.0.0.1:43689}"
2026-05-07T17:47:31.233Z [WARN]  raft: heartbeat timeout reached, starting election: last-leader-addr=127.0.0.1:35499 last-leader-id=raftNode-0
2026-05-07T17:47:31.233Z [INFO]  raft: entering candidate state: node="Node at 127.0.0.1:43689 [Candidate]" term=3
2026-05-07T17:47:31.233Z [DEBUG] raft: asking for pre-vote: term=3 from=raftNode-0 address=127.0.0.1:35499
2026-05-07T17:47:31.233Z [DEBUG] raft: asking for pre-vote: term=3 from=raftNode-1 address=127.0.0.1:34035
2026-05-07T17:47:31.234Z [DEBUG] raft: pre-voting for self: term=3 id=raftNode-2
2026-05-07T17:47:31.234Z [DEBUG] raft: calculated votes needed: needed=2 term=3
2026-05-07T17:47:31.234Z [DEBUG] raft: pre-vote received: from=raftNode-2 term=3 tally=0
2026-05-07T17:47:31.234Z [DEBUG] raft: pre-vote granted: from=raftNode-2 term=3 tally=1
Error: -07T17:47:31.235Z [ERROR] raft: failed to make requestVote RPC: target="{Voter raftNode-0 127.0.0.1:35499}" error="dial tcp 127.0.0.1:35499: connect: connection refused" term=3
2026-05-07T17:47:31.235Z [WARN]  raft: rejecting pre-vote request since we have a leader: from=127.0.0.1:43689 leader=127.0.0.1:35499 leader-id=raftNode-0
2026-05-07T17:47:31.235Z [DEBUG] raft: pre-vote received: from=raftNode-0 term=3 tally=1
2026-05-07T17:47:31.235Z [DEBUG] raft: pre-vote denied: from=raftNode-0 term=3 tally=1
2026-05-07T17:47:31.235Z [DEBUG] raft: pre-vote received: from=raftNode-1 term=2 tally=1
2026-05-07T17:47:31.235Z [DEBUG] raft: pre-vote denied: from=raftNode-1 term=2 tally=1
2026-05-07T17:47:31.235Z [INFO]  raft: pre-vote campaign failed, waiting for election timeout: term=2 tally=1 refused=2 votesNeeded=2
2026-05-07T17:47:31.241Z [WARN]  raft: heartbeat timeout reached, starting election: last-leader-addr=127.0.0.1:35499 last-leader-id=raftNode-0
2026-05-07T17:47:31.241Z [INFO]  raft: entering candidate state: node="Node at 127.0.0.1:34035 [Candidate]" term=3
2026-05-07T17:47:31.241Z [DEBUG] raft: asking for pre-vote: term=3 from=raftNode-0 address=127.0.0.1:35499
2026-05-07T17:47:31.241Z [DEBUG] raft: pre-voting for self: term=3 id=raftNode-1
2026-05-07T17:47:31.241Z [DEBUG] raft: asking for pre-vote: term=3 from=raftNode-2 address=127.0.0.1:43689
2026-05-07T17:47:31.241Z [DEBUG] raft: calculated votes needed: needed=2 term=3
2026-05-07T17:47:31.241Z [DEBUG] raft: pre-vote received: from=raftNode-1 term=3 tally=0
2026-05-07T17:47:31.241Z [DEBUG] raft: pre-vote granted: from=raftNode-1 term=3 tally=1
Error: -07T17:47:31.242Z [ERROR] raft: failed to make requestVote RPC: target="{Voter raftNode-0 127.0.0.1:35499}" error="dial tcp 127.0.0.1:35499: connect: connection refused" term=3
2026-05-07T17:47:31.242Z [DEBUG] raft: received a requestPreVote with a newer term, grant the pre-vote
2026-05-07T17:47:31.243Z [DEBUG] raft: pre-vote received: from=raftNode-0 term=3 tally=1
2026-05-07T17:47:31.243Z [DEBUG] raft: pre-vote denied: from=raftNode-0 term=3 tally=1
2026-05-07T17:47:31.243Z [DEBUG] raft: pre-vote received: from=raftNode-2 term=3 tally=1
2026-05-07T17:47:31.243Z [DEBUG] raft: pre-vote granted: from=raftNode-2 term=3 tally=2
2026-05-07T17:47:31.243Z [INFO]  raft: pre-vote successful, starting election: term=3 tally=2 refused=1 votesNeeded=2
2026-05-07T17:47:31.243Z [DEBUG] raft: asking for vote: term=3 from=raftNode-0 address=127.0.0.1:35499
2026-05-07T17:47:31.243Z [DEBUG] raft: voting for self: term=3 id=raftNode-1
2026-05-07T17:47:31.243Z [DEBUG] raft: asking for vote: term=3 from=raftNode-2 address=127.0.0.1:43689
2026-05-07T17:47:31.243Z [DEBUG] raft: vote granted: from=raftNode-1 term=3 tally=1
2026-05-07T17:47:31.243Z [DEBUG] raft: lost leadership because received a requestVote with a newer term
2026-05-07T17:47:31.243Z [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:43689 [Follower]" leader-address= leader-id=
Error: -07T17:47:31.243Z [ERROR] raft: failed to make requestVote RPC: target="{Voter raftNode-0 127.0.0.1:35499}" error="dial tcp 127.0.0.1:35499: connect: connection refused" term=3
2026-05-07T17:47:31.244Z [DEBUG] raft: vote granted: from=raftNode-2 term=3 tally=2
2026-05-07T17:47:31.244Z [INFO]  raft: election won: term=3 tally=2
2026-05-07T17:47:31.244Z [INFO]  raft: entering leader state: leader="Node at 127.0.0.1:34035 [Leader]"
2026-05-07T17:47:31.244Z [INFO]  raft: added peer, starting replication: peer=raftNode-0
2026-05-07T17:47:31.244Z [INFO]  raft: added peer, starting replication: peer=raftNode-2
Error: -07T17:47:31.245Z [ERROR] raft: failed to appendEntries to: peer="{Voter raftNode-0 127.0.0.1:35499}" error="dial tcp 127.0.0.1:35499: connect: connection refused"
2026-05-07T17:47:31.246Z [INFO]  raft: pipelining replication: peer="{Voter raftNode-2 127.0.0.1:43689}"
Error: -07T17:47:31.254Z [ERROR] raft: failed to heartbeat to: peer=127.0.0.1:35499 backoff time=10ms error="dial tcp 127.0.0.1:35499: connect: connection refused"
Error: -07T17:47:31.263Z [ERROR] raft: failed to appendEntries to: peer="{Voter raftNode-0 127.0.0.1:35499}" error="dial tcp 127.0.0.1:35499: connect: connection refused"
Error: -07T17:47:31.270Z [ERROR] raft: failed to heartbeat to: peer=127.0.0.1:35499 backoff time=10ms error="dial tcp 127.0.0.1:35499: connect: connection refused"
Error: -07T17:47:31.282Z [ERROR] raft: failed to appendEntries to: peer="{Voter raftNode-0 127.0.0.1:35499}" error="dial tcp 127.0.0.1:35499: connect: connection refused"
Error: -07T17:47:31.287Z [ERROR] raft: failed to heartbeat to: peer=127.0.0.1:35499 backoff time=10ms error="dial tcp 127.0.0.1:35499: connect: connection refused"
2026-05-07T17:47:31.294Z [WARN]  raft: failed to contact: server-id=raftNode-0 time=50.526624ms
Error: -07T17:47:31.306Z [ERROR] raft: failed to heartbeat to: peer=127.0.0.1:35499 backoff time=20ms error="dial tcp 127.0.0.1:35499: connect: connection refused"
Error: -07T17:47:31.309Z [ERROR] raft: failed to appendEntries to: peer="{Voter raftNode-0 127.0.0.1:35499}" error="dial tcp 127.0.0.1:35499: connect: connection refused"
Error: -07T17:47:31.335Z [ERROR] raft: failed to heartbeat to: peer=127.0.0.1:35499 backoff time=25ms error="dial tcp 127.0.0.1:35499: connect: connection refused"
2026-05-07T17:47:31.337Z [INFO]  raft: initial configuration: index=5 servers="[{Suffrage:Voter ID:raftNode-0 Address:127.0.0.1:35499} {Suffrage:Voter ID:raftNode-1 Address:127.0.0.1:34035} {Suffrage:Voter ID:raftNode-2 Address:127.0.0.1:43689}]"
2026-05-07T17:47:31.337Z [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:33471 [Follower]" leader-address= leader-id=
2026-05-07T17:47:31.337Z [INFO]  raft: updating configuration: command=AddVoter server-id=raftNode-0 server-addr=127.0.0.1:33471 servers="[{Suffrage:Voter ID:raftNode-0 Address:127.0.0.1:33471} {Suffrage:Voter ID:raftNode-1 Address:127.0.0.1:34035} {Suffrage:Voter ID:raftNode-2 Address:127.0.0.1:43689}]"
2026-05-07T17:47:31.337Z [INFO]  raft: updating peer: peer=raftNode-0
2026-05-07T17:47:31.343Z [WARN]  raft: failed to contact: server-id=raftNode-0 time=98.703037ms
2026-05-07T17:47:31.356Z [INFO]  raft: pipelining replication: peer="{Voter raftNode-0 127.0.0.1:33471}"
    testing.go:1712: race detected during execution of test

Metadata

Metadata

Assignees

Type

No type
No fields configured for issues without a type.

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions