Package: src:golang-github-hashicorp-raft
Version: 1.0.0+git20180118.077966db-1
Severity: serious
Tags: ftbfs
Dear maintainer:
I tried to build this package in buster but it failed:
--------------------------------------------------------------------------------
[...]
debian/rules build-indep
dh build-indep --buildsystem=golang --with=golang
dh_update_autotools_config -i -O--buildsystem=golang
dh_auto_configure -i -O--buildsystem=golang
dh_auto_build -i -O--buildsystem=golang
cd obj-x86_64-linux-gnu && go install
-gcflags=\"-trimpath=/<<BUILDDIR>>/golang-github-hashicorp-raft-1.0.0\+git20180118.077966db/obj-x86_64-linux-gnu/src\"
-asmflags=\"-trimpath=/<<BUILDDIR>>/golang-github-hashicorp-raft-1.0.0\+git20180118.077966db/obj-x86_64-linux-gnu/src\"
-v -p 1 github.com/hashicorp/raft github.com/hashicorp/raft/bench
github.com/hashicorp/golang-lru/simplelru
github.com/hashicorp/go-immutable-radix
github.com/armon/go-metrics
github.com/hashicorp/go-msgpack/codec
github.com/hashicorp/raft
github.com/hashicorp/raft/bench
dh_auto_test -i -O--buildsystem=golang
cd obj-x86_64-linux-gnu && go test -vet=off -v -p 1
github.com/hashicorp/raft github.com/hashicorp/raft/bench
=== RUN TestCommitment_setVoters
--- PASS: TestCommitment_setVoters (0.00s)
=== RUN TestCommitment_match_max
--- PASS: TestCommitment_match_max (0.00s)
=== RUN TestCommitment_match_nonVoting
--- PASS: TestCommitment_match_nonVoting (0.00s)
=== RUN TestCommitment_recalculate
--- PASS: TestCommitment_recalculate (0.00s)
=== RUN TestCommitment_recalculate_startIndex
--- PASS: TestCommitment_recalculate_startIndex (0.00s)
=== RUN TestCommitment_noVoterSanity
--- PASS: TestCommitment_noVoterSanity (0.00s)
=== RUN TestCommitment_singleVoter
--- PASS: TestCommitment_singleVoter (0.00s)
=== RUN TestConfiguration_Configuration_Clone
--- PASS: TestConfiguration_Configuration_Clone (0.00s)
=== RUN TestConfiguration_configurations_Clone
--- PASS: TestConfiguration_configurations_Clone (0.00s)
=== RUN TestConfiguration_hasVote
--- PASS: TestConfiguration_hasVote (0.00s)
=== RUN TestConfiguration_checkConfiguration
--- PASS: TestConfiguration_checkConfiguration (0.00s)
=== RUN TestConfiguration_nextConfiguration_table
--- PASS: TestConfiguration_nextConfiguration_table (0.00s)
=== RUN TestConfiguration_nextConfiguration_prevIndex
--- PASS: TestConfiguration_nextConfiguration_prevIndex (0.00s)
=== RUN TestConfiguration_nextConfiguration_checkConfiguration
--- PASS: TestConfiguration_nextConfiguration_checkConfiguration (0.00s)
=== RUN TestConfiguration_encodeDecodePeers
--- PASS: TestConfiguration_encodeDecodePeers (0.00s)
=== RUN TestConfiguration_encodeDecodeConfiguration
--- PASS: TestConfiguration_encodeDecodeConfiguration (0.00s)
=== RUN TestDiscardSnapshotStoreImpl
--- PASS: TestDiscardSnapshotStoreImpl (0.00s)
=== RUN TestDiscardSnapshotSinkImpl
--- PASS: TestDiscardSnapshotSinkImpl (0.00s)
=== RUN TestFileSnapshotStoreImpl
--- PASS: TestFileSnapshotStoreImpl (0.00s)
=== RUN TestFileSnapshotSinkImpl
--- PASS: TestFileSnapshotSinkImpl (0.00s)
=== RUN TestFileSS_CreateSnapshotMissingParentDir
--- PASS: TestFileSS_CreateSnapshotMissingParentDir (0.14s)
raft_test.go:101: 21:34:33.261773 [INFO] snapshot: Creating new
snapshot at /tmp/raft068757217/raft335529164/snapshots/3-10-1533504873261.tmp
=== RUN TestFileSS_CreateSnapshot
--- PASS: TestFileSS_CreateSnapshot (0.50s)
raft_test.go:101: 21:34:33.401289 [INFO] snapshot: Creating new
snapshot at /tmp/raft997309883/snapshots/3-10-1533504873401.tmp
raft_test.go:101: 21:34:33.534238 [WARN] snapshot: Found temporary
snapshot: 3-10-1533504873401.tmp
=== RUN TestFileSS_CancelSnapshot
--- PASS: TestFileSS_CancelSnapshot (0.13s)
raft_test.go:101: 21:34:33.899206 [INFO] snapshot: Creating new
snapshot at /tmp/raft437327838/snapshots/3-10-1533504873899.tmp
=== RUN TestFileSS_Retention
--- PASS: TestFileSS_Retention (2.67s)
raft_test.go:101: 21:34:34.032449 [INFO] snapshot: Creating new
snapshot at /tmp/raft011354021/snapshots/3-10-1533504874032.tmp
raft_test.go:101: 21:34:34.591751 [INFO] snapshot: Creating new
snapshot at /tmp/raft011354021/snapshots/3-11-1533504874591.tmp
raft_test.go:101: 21:34:35.192120 [INFO] snapshot: Creating new
snapshot at /tmp/raft011354021/snapshots/3-12-1533504875192.tmp
raft_test.go:101: 21:34:35.691391 [INFO] snapshot: reaping snapshot
/tmp/raft011354021/snapshots/3-10-1533504874032
raft_test.go:101: 21:34:35.691859 [INFO] snapshot: Creating new
snapshot at /tmp/raft011354021/snapshots/3-13-1533504875691.tmp
raft_test.go:101: 21:34:36.206487 [INFO] snapshot: reaping snapshot
/tmp/raft011354021/snapshots/3-11-1533504874591
raft_test.go:101: 21:34:36.206936 [INFO] snapshot: Creating new
snapshot at /tmp/raft011354021/snapshots/3-14-1533504876206.tmp
raft_test.go:101: 21:34:36.703417 [INFO] snapshot: reaping snapshot
/tmp/raft011354021/snapshots/3-12-1533504875192
=== RUN TestFileSS_BadPerm
--- PASS: TestFileSS_BadPerm (0.00s)
=== RUN TestFileSS_MissingParentDir
--- PASS: TestFileSS_MissingParentDir (0.00s)
=== RUN TestFileSS_Ordering
--- PASS: TestFileSS_Ordering (0.87s)
raft_test.go:101: 21:34:36.705125 [INFO] snapshot: Creating new
snapshot at /tmp/raft464535028/snapshots/5-130350-1533504876705.tmp
raft_test.go:101: 21:34:37.210217 [INFO] snapshot: Creating new
snapshot at /tmp/raft464535028/snapshots/36-204917-1533504877210.tmp
=== RUN TestDeferFutureSuccess
--- PASS: TestDeferFutureSuccess (0.00s)
=== RUN TestDeferFutureError
--- PASS: TestDeferFutureError (0.00s)
=== RUN TestDeferFutureConcurrent
--- PASS: TestDeferFutureConcurrent (0.00s)
=== RUN TestInmemSnapshotStoreImpl
--- PASS: TestInmemSnapshotStoreImpl (0.00s)
=== RUN TestInmemSnapshotSinkImpl
--- PASS: TestInmemSnapshotSinkImpl (0.00s)
=== RUN TestInmemSS_CreateSnapshot
--- PASS: TestInmemSS_CreateSnapshot (0.00s)
=== RUN TestInmemTransportImpl
--- PASS: TestInmemTransportImpl (0.00s)
=== RUN TestRaft_Integ
--- SKIP: TestRaft_Integ (0.00s)
=== RUN TestLogCache
--- PASS: TestLogCache (0.00s)
=== RUN TestNetworkTransport_CloseStreams
--- PASS: TestNetworkTransport_CloseStreams (0.01s)
raft_test.go:101: 21:34:37.585661 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45228
raft_test.go:101: 21:34:37.587586 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45230
raft_test.go:101: 21:34:37.587635 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45232
raft_test.go:101: 21:34:37.587679 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45234
raft_test.go:101: 21:34:37.587715 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45236
raft_test.go:101: 21:34:37.590433 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45238
raft_test.go:101: 21:34:37.590479 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45240
raft_test.go:101: 21:34:37.590522 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45242
raft_test.go:101: 21:34:37.590552 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45244
raft_test.go:101: 21:34:37.591003 [DEBUG] raft-net: 127.0.0.1:43803
accepted connection from: 127.0.0.1:45246
=== RUN TestNetworkTransport_StartStop
--- PASS: TestNetworkTransport_StartStop (0.00s)
=== RUN TestNetworkTransport_Heartbeat_FastPath
--- PASS: TestNetworkTransport_Heartbeat_FastPath (0.00s)
raft_test.go:101: 21:34:37.596801 [DEBUG] raft-net: 127.0.0.1:45387
accepted connection from: 127.0.0.1:42658
=== RUN TestNetworkTransport_AppendEntries
--- PASS: TestNetworkTransport_AppendEntries (0.00s)
raft_test.go:101: 21:34:37.599005 [DEBUG] raft-net: 127.0.0.1:37269
accepted connection from: 127.0.0.1:35250
raft_test.go:101: 21:34:37.599782 [DEBUG] raft-net: 127.0.0.1:39797
accepted connection from: 127.0.0.1:46418
=== RUN TestNetworkTransport_AppendEntriesPipeline
--- PASS: TestNetworkTransport_AppendEntriesPipeline (0.00s)
raft_test.go:101: 21:34:37.602850 [DEBUG] raft-net: 127.0.0.1:35029
accepted connection from: 127.0.0.1:51152
raft_test.go:101: 21:34:37.604563 [DEBUG] raft-net: 127.0.0.1:33943
accepted connection from: 127.0.0.1:42982
=== RUN TestNetworkTransport_AppendEntriesPipeline_CloseStreams
--- FAIL: TestNetworkTransport_AppendEntriesPipeline_CloseStreams (0.01s)
raft_test.go:101: 21:34:37.607625 [DEBUG] raft-net: 127.0.0.1:42603
accepted connection from: 127.0.0.1:54548
net_transport_test.go:430: expected an error due to the streams being
closed
=== RUN TestNetworkTransport_RequestVote
--- PASS: TestNetworkTransport_RequestVote (0.00s)
raft_test.go:101: 21:34:37.622810 [DEBUG] raft-net: 127.0.0.1:46533
accepted connection from: 127.0.0.1:49862
raft_test.go:101: 21:34:37.623203 [DEBUG] raft-net: 127.0.0.1:39871
accepted connection from: 127.0.0.1:41336
=== RUN TestNetworkTransport_InstallSnapshot
--- PASS: TestNetworkTransport_InstallSnapshot (0.00s)
raft_test.go:101: 21:34:37.624322 [DEBUG] raft-net: 127.0.0.1:38327
accepted connection from: 127.0.0.1:47078
raft_test.go:101: 21:34:37.624703 [DEBUG] raft-net: 127.0.0.1:38457
accepted connection from: 127.0.0.1:59188
=== RUN TestNetworkTransport_EncodeDecode
--- PASS: TestNetworkTransport_EncodeDecode (0.00s)
=== RUN TestNetworkTransport_EncodeDecode_AddressProvider
--- PASS: TestNetworkTransport_EncodeDecode_AddressProvider (0.00s)
=== RUN TestNetworkTransport_PooledConn
--- PASS: TestNetworkTransport_PooledConn (0.00s)
raft_test.go:101: 21:34:37.626694 [DEBUG] raft-net: 127.0.0.1:36083
accepted connection from: 127.0.0.1:53178
raft_test.go:101: 21:34:37.627528 [DEBUG] raft-net: 127.0.0.1:36083
accepted connection from: 127.0.0.1:53180
raft_test.go:101: 21:34:37.627570 [DEBUG] raft-net: 127.0.0.1:36083
accepted connection from: 127.0.0.1:53182
raft_test.go:101: 21:34:37.627594 [DEBUG] raft-net: 127.0.0.1:36083
accepted connection from: 127.0.0.1:53184
raft_test.go:101: 21:34:37.627610 [DEBUG] raft-net: 127.0.0.1:36083
accepted connection from: 127.0.0.1:53186
=== RUN TestPeersJSON_BadConfiguration
--- PASS: TestPeersJSON_BadConfiguration (0.00s)
=== RUN TestPeersJSON_ReadPeersJSON
--- PASS: TestPeersJSON_ReadPeersJSON (0.00s)
=== RUN TestPeersJSON_ReadConfigJSON
--- PASS: TestPeersJSON_ReadConfigJSON (0.00s)
=== RUN TestRaft_ProtocolVersion_RejectRPC
testLoggerAdapter verbose: cluster: 21:34:37.630973 [DEBUG] Fully Connecting
testLoggerAdapter verbose: server-7333363b-f44c-0ac4-5583-33011bff02e1:
21:34:37.631290 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:server-7333363b-f44c-0ac4-5583-33011bff02e1
Address:7333363b-f44c-0ac4-5583-33011bff02e1} {Suffrage:Voter
ID:server-a7bec59b-fd42-090d-6959-801a534d0671
Address:a7bec59b-fd42-090d-6959-801a534d0671} {Suffrage:Voter
ID:server-4173eaa8-dcef-283e-3345-6e663b2d5437
Address:4173eaa8-dcef-283e-3345-6e663b2d5437}]
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.631546 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:server-7333363b-f44c-0ac4-5583-33011bff02e1
Address:7333363b-f44c-0ac4-5583-33011bff02e1} {Suffrage:Voter
ID:server-a7bec59b-fd42-090d-6959-801a534d0671
Address:a7bec59b-fd42-090d-6959-801a534d0671} {Suffrage:Voter
ID:server-4173eaa8-dcef-283e-3345-6e663b2d5437
Address:4173eaa8-dcef-283e-3345-6e663b2d5437}]
testLoggerAdapter verbose: server-4173eaa8-dcef-283e-3345-6e663b2d5437:
21:34:37.631782 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:server-7333363b-f44c-0ac4-5583-33011bff02e1
Address:7333363b-f44c-0ac4-5583-33011bff02e1} {Suffrage:Voter
ID:server-a7bec59b-fd42-090d-6959-801a534d0671
Address:a7bec59b-fd42-090d-6959-801a534d0671} {Suffrage:Voter
ID:server-4173eaa8-dcef-283e-3345-6e663b2d5437
Address:4173eaa8-dcef-283e-3345-6e663b2d5437}]
testLoggerAdapter verbose: cluster: 21:34:37.631916 [INFO] Starting stability
test for raft state: Follower
testLoggerAdapter verbose: server-7333363b-f44c-0ac4-5583-33011bff02e1:
21:34:37.632074 [INFO] raft: Node at 7333363b-f44c-0ac4-5583-33011bff02e1
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.632096 [INFO] raft: Node at a7bec59b-fd42-090d-6959-801a534d0671
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: server-4173eaa8-dcef-283e-3345-6e663b2d5437:
21:34:37.632140 [INFO] raft: Node at 4173eaa8-dcef-283e-3345-6e663b2d5437
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690712 [WARN] raft: Heartbeat timeout from "" reached, starting
election
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690807 [INFO] raft: Node at a7bec59b-fd42-090d-6959-801a534d0671
[Candidate] entering Candidate state in term 2
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690883 [DEBUG] raft: Votes needed: 2
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690912 [DEBUG] raft: Vote granted from
server-a7bec59b-fd42-090d-6959-801a534d0671 in term 2. Tally: 1
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691010 [DEBUG] raft: Vote granted from
server-4173eaa8-dcef-283e-3345-6e663b2d5437 in term 2. Tally: 2
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691031 [INFO] raft: Election won. Tally: 2
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691053 [INFO] raft: Node at a7bec59b-fd42-090d-6959-801a534d0671
[Leader] entering Leader state
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691089 [INFO] raft: Added peer
server-7333363b-f44c-0ac4-5583-33011bff02e1, starting replication
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691110 [INFO] raft: Added peer
server-4173eaa8-dcef-283e-3345-6e663b2d5437, starting replication
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691235 [INFO] raft: pipelining replication to peer {Voter
server-4173eaa8-dcef-283e-3345-6e663b2d5437
4173eaa8-dcef-283e-3345-6e663b2d5437}
testLoggerAdapter verbose: cluster: 21:34:37.691334 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:37.691368 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:37.691388 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691497 [INFO] raft: pipelining replication to peer {Voter
server-7333363b-f44c-0ac4-5583-33011bff02e1
7333363b-f44c-0ac4-5583-33011bff02e1}
testLoggerAdapter verbose: cluster: 21:34:37.691582 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:37.796756 [INFO] Stable state for
Follower reached at 2018-08-05 21:34:37.691599967 +0000 UTC m=+4.431992423 (2
nodes), 59.41985ms from start of poll, 60.465526ms from cluster start. Timeout
at 2018-08-05 21:34:37.796658813 +0000 UTC m=+4.537051171, 105.058748ms after
stability
testLoggerAdapter verbose: cluster: 21:34:37.796820 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: cluster: 21:34:37.902153 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:37.796832499 +0000 UTC m=+4.537224859 (1
nodes), 1.845µs from start of poll, 165.697962ms from cluster start. Timeout
at 2018-08-05 21:34:37.902067048 +0000 UTC m=+4.642459569, 105.23471ms after
stability
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.902321 [INFO] raft: aborting pipeline replication to peer {Voter
server-4173eaa8-dcef-283e-3345-6e663b2d5437
4173eaa8-dcef-283e-3345-6e663b2d5437}
testLoggerAdapter verbose: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.902369 [INFO] raft: aborting pipeline replication to peer {Voter
server-7333363b-f44c-0ac4-5583-33011bff02e1
7333363b-f44c-0ac4-5583-33011bff02e1}
--- PASS: TestRaft_ProtocolVersion_RejectRPC (0.27s)
raft_test.go:97: cluster: 21:34:37.630973 [DEBUG] Fully Connecting
raft_test.go:97: server-7333363b-f44c-0ac4-5583-33011bff02e1:
21:34:37.631290 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:server-7333363b-f44c-0ac4-5583-33011bff02e1
Address:7333363b-f44c-0ac4-5583-33011bff02e1} {Suffrage:Voter
ID:server-a7bec59b-fd42-090d-6959-801a534d0671
Address:a7bec59b-fd42-090d-6959-801a534d0671} {Suffrage:Voter
ID:server-4173eaa8-dcef-283e-3345-6e663b2d5437
Address:4173eaa8-dcef-283e-3345-6e663b2d5437}]
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.631546 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:server-7333363b-f44c-0ac4-5583-33011bff02e1
Address:7333363b-f44c-0ac4-5583-33011bff02e1} {Suffrage:Voter
ID:server-a7bec59b-fd42-090d-6959-801a534d0671
Address:a7bec59b-fd42-090d-6959-801a534d0671} {Suffrage:Voter
ID:server-4173eaa8-dcef-283e-3345-6e663b2d5437
Address:4173eaa8-dcef-283e-3345-6e663b2d5437}]
raft_test.go:97: server-4173eaa8-dcef-283e-3345-6e663b2d5437:
21:34:37.631782 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:server-7333363b-f44c-0ac4-5583-33011bff02e1
Address:7333363b-f44c-0ac4-5583-33011bff02e1} {Suffrage:Voter
ID:server-a7bec59b-fd42-090d-6959-801a534d0671
Address:a7bec59b-fd42-090d-6959-801a534d0671} {Suffrage:Voter
ID:server-4173eaa8-dcef-283e-3345-6e663b2d5437
Address:4173eaa8-dcef-283e-3345-6e663b2d5437}]
raft_test.go:97: cluster: 21:34:37.631916 [INFO] Starting stability
test for raft state: Follower
raft_test.go:97: server-7333363b-f44c-0ac4-5583-33011bff02e1:
21:34:37.632074 [INFO] raft: Node at 7333363b-f44c-0ac4-5583-33011bff02e1
[Follower] entering Follower state (Leader: "")
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.632096 [INFO] raft: Node at a7bec59b-fd42-090d-6959-801a534d0671
[Follower] entering Follower state (Leader: "")
raft_test.go:97: server-4173eaa8-dcef-283e-3345-6e663b2d5437:
21:34:37.632140 [INFO] raft: Node at 4173eaa8-dcef-283e-3345-6e663b2d5437
[Follower] entering Follower state (Leader: "")
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690712 [WARN] raft: Heartbeat timeout from "" reached, starting
election
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690807 [INFO] raft: Node at a7bec59b-fd42-090d-6959-801a534d0671
[Candidate] entering Candidate state in term 2
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690883 [DEBUG] raft: Votes needed: 2
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.690912 [DEBUG] raft: Vote granted from
server-a7bec59b-fd42-090d-6959-801a534d0671 in term 2. Tally: 1
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691010 [DEBUG] raft: Vote granted from
server-4173eaa8-dcef-283e-3345-6e663b2d5437 in term 2. Tally: 2
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691031 [INFO] raft: Election won. Tally: 2
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691053 [INFO] raft: Node at a7bec59b-fd42-090d-6959-801a534d0671
[Leader] entering Leader state
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691089 [INFO] raft: Added peer
server-7333363b-f44c-0ac4-5583-33011bff02e1, starting replication
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691110 [INFO] raft: Added peer
server-4173eaa8-dcef-283e-3345-6e663b2d5437, starting replication
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691235 [INFO] raft: pipelining replication to peer {Voter
server-4173eaa8-dcef-283e-3345-6e663b2d5437
4173eaa8-dcef-283e-3345-6e663b2d5437}
raft_test.go:97: cluster: 21:34:37.691334 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:37.691368 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:37.691388 [DEBUG] Resetting stability
timeout
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.691497 [INFO] raft: pipelining replication to peer {Voter
server-7333363b-f44c-0ac4-5583-33011bff02e1
7333363b-f44c-0ac4-5583-33011bff02e1}
raft_test.go:97: cluster: 21:34:37.691582 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:37.796756 [INFO] Stable state for
Follower reached at 2018-08-05 21:34:37.691599967 +0000 UTC m=+4.431992423 (2
nodes), 59.41985ms from start of poll, 60.465526ms from cluster start. Timeout
at 2018-08-05 21:34:37.796658813 +0000 UTC m=+4.537051171, 105.058748ms after
stability
raft_test.go:97: cluster: 21:34:37.796820 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: cluster: 21:34:37.902153 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:37.796832499 +0000 UTC m=+4.537224859 (1
nodes), 1.845µs from start of poll, 165.697962ms from cluster start. Timeout
at 2018-08-05 21:34:37.902067048 +0000 UTC m=+4.642459569, 105.23471ms after
stability
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.902321 [INFO] raft: aborting pipeline replication to peer {Voter
server-4173eaa8-dcef-283e-3345-6e663b2d5437
4173eaa8-dcef-283e-3345-6e663b2d5437}
raft_test.go:97: server-a7bec59b-fd42-090d-6959-801a534d0671:
21:34:37.902369 [INFO] raft: aborting pipeline replication to peer {Voter
server-7333363b-f44c-0ac4-5583-33011bff02e1
7333363b-f44c-0ac4-5583-33011bff02e1}
=== RUN TestRaft_ProtocolVersion_Upgrade_1_2
testLoggerAdapter verbose: cluster: 21:34:37.903769 [DEBUG] Fully Connecting
testLoggerAdapter verbose: e2d7d56f-5c15-9fda-8f5c-58649d49e7a2:
21:34:37.904016 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d}]
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.904188 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d}]
testLoggerAdapter verbose: cluster: 21:34:37.904493 [DEBUG] Fully Connecting
testLoggerAdapter verbose: 5e697909-978f-4783-0601-42a9c3a56df9:
21:34:37.904575 [INFO] raft: Initial configuration (index=0): []
testLoggerAdapter verbose: cluster: 21:34:37.904644 [DEBUG] Fully Connecting
testLoggerAdapter verbose: cluster: 21:34:37.904670 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: e2d7d56f-5c15-9fda-8f5c-58649d49e7a2:
21:34:37.904722 [INFO] raft: Node at e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.904768 [INFO] raft: Node at e6a27847-1561-0356-4b8e-83d498cf019d
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: 5e697909-978f-4783-0601-42a9c3a56df9:
21:34:37.904813 [INFO] raft: Node at 5e697909-978f-4783-0601-42a9c3a56df9
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961367 [WARN] raft: Heartbeat timeout from "" reached, starting
election
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961476 [INFO] raft: Node at e6a27847-1561-0356-4b8e-83d498cf019d
[Candidate] entering Candidate state in term 2
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961521 [DEBUG] raft: Votes needed: 2
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961546 [DEBUG] raft: Vote granted from
e6a27847-1561-0356-4b8e-83d498cf019d in term 2. Tally: 1
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961693 [DEBUG] raft: Vote granted from
e2d7d56f-5c15-9fda-8f5c-58649d49e7a2 in term 2. Tally: 2
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961720 [INFO] raft: Election won. Tally: 2
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961745 [INFO] raft: Node at e6a27847-1561-0356-4b8e-83d498cf019d
[Leader] entering Leader state
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961768 [INFO] raft: Added peer e2d7d56f-5c15-9fda-8f5c-58649d49e7a2,
starting replication
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:37.961897 [INFO] raft: pipelining replication to peer {Voter
e2d7d56f-5c15-9fda-8f5c-58649d49e7a2 e2d7d56f-5c15-9fda-8f5c-58649d49e7a2}
testLoggerAdapter verbose: cluster: 21:34:37.961938 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:37.961971 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:37.962001 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: 5e697909-978f-4783-0601-42a9c3a56df9:
21:34:37.998468 [WARN] raft: no known peers, aborting election
testLoggerAdapter verbose: cluster: 21:34:38.067227 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:37.962046175 +0000 UTC m=+4.702438631 (1
nodes), 57.357732ms from start of poll, 58.239831ms from cluster start. Timeout
at 2018-08-05 21:34:38.067178511 +0000 UTC m=+4.807570929, 105.132298ms after
stability
testLoggerAdapter verbose: cluster: 21:34:38.067515 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: cluster: 21:34:38.173010 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.067696606 +0000 UTC m=+4.808088989 (1
nodes), 865ns from start of poll, 163.890189ms from cluster start. Timeout at
2018-08-05 21:34:38.172913591 +0000 UTC m=+4.913306110, 105.217121ms after
stability
testLoggerAdapter verbose: cluster: 21:34:38.173450 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: cluster: 21:34:38.278925 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.173837282 +0000 UTC m=+4.914229710 (1
nodes), 1.543µs from start of poll, 270.03091ms from cluster start. Timeout at
2018-08-05 21:34:38.278906342 +0000 UTC m=+5.019298694, 105.068984ms after
stability
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.279139 [INFO] raft: Updating configuration with AddStaging
(5e697909-978f-4783-0601-42a9c3a56df9, 5e697909-978f-4783-0601-42a9c3a56df9) to
[{Suffrage:Voter ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d} {Suffrage:Voter
ID:5e697909-978f-4783-0601-42a9c3a56df9
Address:5e697909-978f-4783-0601-42a9c3a56df9}]
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.279261 [INFO] raft: Added peer 5e697909-978f-4783-0601-42a9c3a56df9,
starting replication
testLoggerAdapter verbose: 5e697909-978f-4783-0601-42a9c3a56df9:
21:34:38.279377 [WARN] raft: Failed to get previous log: 3 log not found (last:
0)
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.279466 [WARN] raft: AppendEntries to {Voter
5e697909-978f-4783-0601-42a9c3a56df9 5e697909-978f-4783-0601-42a9c3a56df9}
rejected, sending older logs (next: 1)
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.279573 [INFO] raft: pipelining replication to peer {Voter
5e697909-978f-4783-0601-42a9c3a56df9 5e697909-978f-4783-0601-42a9c3a56df9}
testLoggerAdapter verbose: cluster: 21:34:38.279707 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: cluster: 21:34:38.385043 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.279781244 +0000 UTC m=+5.020173593 (1
nodes), 421ns from start of poll, 375.974793ms from cluster start. Timeout at
2018-08-05 21:34:38.384952813 +0000 UTC m=+5.125345252, 105.171659ms after
stability
testLoggerAdapter verbose: cluster: 21:34:38.385538 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: cluster: 21:34:38.491049 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.385881068 +0000 UTC m=+5.126273496 (1
nodes), 1.388µs from start of poll, 482.074696ms from cluster start. Timeout
at 2018-08-05 21:34:38.491029942 +0000 UTC m=+5.231422315, 105.148819ms after
stability
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.491277 [INFO] raft: Updating configuration with RemoveServer
(5e697909-978f-4783-0601-42a9c3a56df9, ) to [{Suffrage:Voter
ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d}]
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.491398 [INFO] raft: Removed peer 5e697909-978f-4783-0601-42a9c3a56df9,
stopping replication after 4
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.491499 [INFO] raft: aborting pipeline replication to peer {Voter
5e697909-978f-4783-0601-42a9c3a56df9 5e697909-978f-4783-0601-42a9c3a56df9}
testLoggerAdapter verbose: e6a27847-1561-0356-4b8e-83d498cf019d:
21:34:38.491637 [INFO] raft: aborting pipeline replication to peer {Voter
e2d7d56f-5c15-9fda-8f5c-58649d49e7a2 e2d7d56f-5c15-9fda-8f5c-58649d49e7a2}
--- PASS: TestRaft_ProtocolVersion_Upgrade_1_2 (0.59s)
raft_test.go:97: cluster: 21:34:37.903769 [DEBUG] Fully Connecting
raft_test.go:97: e2d7d56f-5c15-9fda-8f5c-58649d49e7a2: 21:34:37.904016
[INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d}]
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.904188
[INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d}]
raft_test.go:97: cluster: 21:34:37.904493 [DEBUG] Fully Connecting
raft_test.go:97: 5e697909-978f-4783-0601-42a9c3a56df9: 21:34:37.904575
[INFO] raft: Initial configuration (index=0): []
raft_test.go:97: cluster: 21:34:37.904644 [DEBUG] Fully Connecting
raft_test.go:97: cluster: 21:34:37.904670 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: e2d7d56f-5c15-9fda-8f5c-58649d49e7a2: 21:34:37.904722
[INFO] raft: Node at e2d7d56f-5c15-9fda-8f5c-58649d49e7a2 [Follower] entering
Follower state (Leader: "")
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.904768
[INFO] raft: Node at e6a27847-1561-0356-4b8e-83d498cf019d [Follower] entering
Follower state (Leader: "")
raft_test.go:97: 5e697909-978f-4783-0601-42a9c3a56df9: 21:34:37.904813
[INFO] raft: Node at 5e697909-978f-4783-0601-42a9c3a56df9 [Follower] entering
Follower state (Leader: "")
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961367
[WARN] raft: Heartbeat timeout from "" reached, starting election
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961476
[INFO] raft: Node at e6a27847-1561-0356-4b8e-83d498cf019d [Candidate] entering
Candidate state in term 2
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961521
[DEBUG] raft: Votes needed: 2
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961546
[DEBUG] raft: Vote granted from e6a27847-1561-0356-4b8e-83d498cf019d in term 2.
Tally: 1
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961693
[DEBUG] raft: Vote granted from e2d7d56f-5c15-9fda-8f5c-58649d49e7a2 in term 2.
Tally: 2
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961720
[INFO] raft: Election won. Tally: 2
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961745
[INFO] raft: Node at e6a27847-1561-0356-4b8e-83d498cf019d [Leader] entering
Leader state
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961768
[INFO] raft: Added peer e2d7d56f-5c15-9fda-8f5c-58649d49e7a2, starting
replication
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:37.961897
[INFO] raft: pipelining replication to peer {Voter
e2d7d56f-5c15-9fda-8f5c-58649d49e7a2 e2d7d56f-5c15-9fda-8f5c-58649d49e7a2}
raft_test.go:97: cluster: 21:34:37.961938 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:37.961971 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:37.962001 [DEBUG] Resetting stability
timeout
raft_test.go:97: 5e697909-978f-4783-0601-42a9c3a56df9: 21:34:37.998468
[WARN] raft: no known peers, aborting election
raft_test.go:97: cluster: 21:34:38.067227 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:37.962046175 +0000 UTC m=+4.702438631 (1
nodes), 57.357732ms from start of poll, 58.239831ms from cluster start. Timeout
at 2018-08-05 21:34:38.067178511 +0000 UTC m=+4.807570929, 105.132298ms after
stability
raft_test.go:97: cluster: 21:34:38.067515 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: cluster: 21:34:38.173010 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.067696606 +0000 UTC m=+4.808088989 (1
nodes), 865ns from start of poll, 163.890189ms from cluster start. Timeout at
2018-08-05 21:34:38.172913591 +0000 UTC m=+4.913306110, 105.217121ms after
stability
raft_test.go:97: cluster: 21:34:38.173450 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: cluster: 21:34:38.278925 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.173837282 +0000 UTC m=+4.914229710 (1
nodes), 1.543µs from start of poll, 270.03091ms from cluster start. Timeout at
2018-08-05 21:34:38.278906342 +0000 UTC m=+5.019298694, 105.068984ms after
stability
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.279139
[INFO] raft: Updating configuration with AddStaging
(5e697909-978f-4783-0601-42a9c3a56df9, 5e697909-978f-4783-0601-42a9c3a56df9) to
[{Suffrage:Voter ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d} {Suffrage:Voter
ID:5e697909-978f-4783-0601-42a9c3a56df9
Address:5e697909-978f-4783-0601-42a9c3a56df9}]
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.279261
[INFO] raft: Added peer 5e697909-978f-4783-0601-42a9c3a56df9, starting
replication
raft_test.go:97: 5e697909-978f-4783-0601-42a9c3a56df9: 21:34:38.279377
[WARN] raft: Failed to get previous log: 3 log not found (last: 0)
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.279466
[WARN] raft: AppendEntries to {Voter 5e697909-978f-4783-0601-42a9c3a56df9
5e697909-978f-4783-0601-42a9c3a56df9} rejected, sending older logs (next: 1)
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.279573
[INFO] raft: pipelining replication to peer {Voter
5e697909-978f-4783-0601-42a9c3a56df9 5e697909-978f-4783-0601-42a9c3a56df9}
raft_test.go:97: cluster: 21:34:38.279707 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: cluster: 21:34:38.385043 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.279781244 +0000 UTC m=+5.020173593 (1
nodes), 421ns from start of poll, 375.974793ms from cluster start. Timeout at
2018-08-05 21:34:38.384952813 +0000 UTC m=+5.125345252, 105.171659ms after
stability
raft_test.go:97: cluster: 21:34:38.385538 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: cluster: 21:34:38.491049 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.385881068 +0000 UTC m=+5.126273496 (1
nodes), 1.388µs from start of poll, 482.074696ms from cluster start. Timeout
at 2018-08-05 21:34:38.491029942 +0000 UTC m=+5.231422315, 105.148819ms after
stability
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.491277
[INFO] raft: Updating configuration with RemoveServer
(5e697909-978f-4783-0601-42a9c3a56df9, ) to [{Suffrage:Voter
ID:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2
Address:e2d7d56f-5c15-9fda-8f5c-58649d49e7a2} {Suffrage:Voter
ID:e6a27847-1561-0356-4b8e-83d498cf019d
Address:e6a27847-1561-0356-4b8e-83d498cf019d}]
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.491398
[INFO] raft: Removed peer 5e697909-978f-4783-0601-42a9c3a56df9, stopping
replication after 4
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.491499
[INFO] raft: aborting pipeline replication to peer {Voter
5e697909-978f-4783-0601-42a9c3a56df9 5e697909-978f-4783-0601-42a9c3a56df9}
raft_test.go:97: e6a27847-1561-0356-4b8e-83d498cf019d: 21:34:38.491637
[INFO] raft: aborting pipeline replication to peer {Voter
e2d7d56f-5c15-9fda-8f5c-58649d49e7a2 e2d7d56f-5c15-9fda-8f5c-58649d49e7a2}
=== RUN TestRaft_ProtocolVersion_Upgrade_2_3
testLoggerAdapter verbose: cluster: 21:34:38.493007 [DEBUG] Fully Connecting
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.493189 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:b428a04a-5ed2-ff80-71d1-f2b3e96972c5
Address:b428a04a-5ed2-ff80-71d1-f2b3e96972c5}]
testLoggerAdapter verbose: b428a04a-5ed2-ff80-71d1-f2b3e96972c5:
21:34:38.493324 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:b428a04a-5ed2-ff80-71d1-f2b3e96972c5
Address:b428a04a-5ed2-ff80-71d1-f2b3e96972c5}]
testLoggerAdapter verbose: cluster: 21:34:38.493418 [INFO] Starting stability
test for raft state: Follower
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.493524 [INFO] raft: Node at bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: b428a04a-5ed2-ff80-71d1-f2b3e96972c5:
21:34:38.493665 [INFO] raft: Node at b428a04a-5ed2-ff80-71d1-f2b3e96972c5
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.554394 [WARN] raft: Heartbeat timeout from "" reached, starting
election
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.554836 [INFO] raft: Node at bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
[Candidate] entering Candidate state in term 2
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.555044 [DEBUG] raft: Votes needed: 2
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.555246 [DEBUG] raft: Vote granted from
bc2e52a2-c0f6-421c-e3be-a73b04a27cf3 in term 2. Tally: 1
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.555516 [DEBUG] raft: Vote granted from
b428a04a-5ed2-ff80-71d1-f2b3e96972c5 in term 2. Tally: 2
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.555711 [INFO] raft: Election won. Tally: 2
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.555904 [INFO] raft: Node at bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
[Leader] entering Leader state
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.556092 [INFO] raft: Added peer b428a04a-5ed2-ff80-71d1-f2b3e96972c5,
starting replication
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.556380 [INFO] raft: pipelining replication to peer {Voter
b428a04a-5ed2-ff80-71d1-f2b3e96972c5 b428a04a-5ed2-ff80-71d1-f2b3e96972c5}
testLoggerAdapter verbose: cluster: 21:34:38.556590 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:38.556786 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:38.556989 [DEBUG] Resetting stability
timeout
testLoggerAdapter verbose: cluster: 21:34:38.662314 [INFO] Stable state for
Follower reached at 2018-08-05 21:34:38.557174987 +0000 UTC m=+5.297567395 (1
nodes), 63.67302ms from start of poll, 64.086991ms from cluster start. Timeout
at 2018-08-05 21:34:38.662286461 +0000 UTC m=+5.402678833, 105.111438ms after
stability
testLoggerAdapter verbose: cluster: 21:34:38.662663 [DEBUG] Fully Connecting
testLoggerAdapter verbose: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.662787 [INFO] raft: Initial configuration (index=0): []
testLoggerAdapter verbose: cluster: 21:34:38.662866 [DEBUG] Fully Connecting
testLoggerAdapter verbose: cluster: 21:34:38.662937 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.663029 [INFO] raft: Node at f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
[Follower] entering Follower state (Leader: "")
testLoggerAdapter verbose: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.737871 [WARN] raft: no known peers, aborting election
testLoggerAdapter verbose: cluster: 21:34:38.768139 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.663007668 +0000 UTC m=+5.403400023 (1
nodes), 13.461µs from start of poll, 169.919619ms from cluster start. Timeout
at 2018-08-05 21:34:38.768118469 +0000 UTC m=+5.508510840, 105.110817ms after
stability
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.768360 [INFO] raft: Updating configuration with AddStaging
(server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2,
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2) to [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:b428a04a-5ed2-ff80-71d1-f2b3e96972c5
Address:b428a04a-5ed2-ff80-71d1-f2b3e96972c5} {Suffrage:Voter
ID:server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
Address:f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}]
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.768519 [INFO] raft: Added peer
server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2, starting replication
testLoggerAdapter verbose: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.768632 [WARN] raft: Failed to get previous log: 3 log not found (last:
0)
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.768723 [WARN] raft: AppendEntries to {Voter
server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2} rejected, sending older logs (next: 1)
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.768829 [INFO] raft: pipelining replication to peer {Voter
server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}
testLoggerAdapter verbose: cluster: 21:34:38.768975 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: cluster: 21:34:38.874139 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.769049289 +0000 UTC m=+5.509441638 (1
nodes), 407ns from start of poll, 275.961234ms from cluster start. Timeout at
2018-08-05 21:34:38.874117273 +0000 UTC m=+5.614509626, 105.067988ms after
stability
testLoggerAdapter verbose: cluster: 21:34:38.874324 [INFO] Starting stability
test for raft state: Leader
testLoggerAdapter verbose: cluster: 21:34:38.979542 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.874408976 +0000 UTC m=+5.614801325 (1
nodes), 443ns from start of poll, 381.320921ms from cluster start. Timeout at
2018-08-05 21:34:38.979511588 +0000 UTC m=+5.719903959, 105.102634ms after
stability
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.979581 [INFO] raft: Updating configuration with RemoveServer
(b428a04a-5ed2-ff80-71d1-f2b3e96972c5, ) to [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
Address:f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}]
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.979612 [INFO] raft: Removed peer b428a04a-5ed2-ff80-71d1-f2b3e96972c5,
stopping replication after 4
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.979639 [INFO] raft: aborting pipeline replication to peer {Voter
b428a04a-5ed2-ff80-71d1-f2b3e96972c5 b428a04a-5ed2-ff80-71d1-f2b3e96972c5}
testLoggerAdapter verbose: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3:
21:34:38.979700 [INFO] raft: aborting pipeline replication to peer {Voter
server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}
--- PASS: TestRaft_ProtocolVersion_Upgrade_2_3 (0.49s)
raft_test.go:97: cluster: 21:34:38.493007 [DEBUG] Fully Connecting
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.493189
[INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:b428a04a-5ed2-ff80-71d1-f2b3e96972c5
Address:b428a04a-5ed2-ff80-71d1-f2b3e96972c5}]
raft_test.go:97: b428a04a-5ed2-ff80-71d1-f2b3e96972c5: 21:34:38.493324
[INFO] raft: Initial configuration (index=1): [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:b428a04a-5ed2-ff80-71d1-f2b3e96972c5
Address:b428a04a-5ed2-ff80-71d1-f2b3e96972c5}]
raft_test.go:97: cluster: 21:34:38.493418 [INFO] Starting stability
test for raft state: Follower
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.493524
[INFO] raft: Node at bc2e52a2-c0f6-421c-e3be-a73b04a27cf3 [Follower] entering
Follower state (Leader: "")
raft_test.go:97: b428a04a-5ed2-ff80-71d1-f2b3e96972c5: 21:34:38.493665
[INFO] raft: Node at b428a04a-5ed2-ff80-71d1-f2b3e96972c5 [Follower] entering
Follower state (Leader: "")
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.554394
[WARN] raft: Heartbeat timeout from "" reached, starting election
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.554836
[INFO] raft: Node at bc2e52a2-c0f6-421c-e3be-a73b04a27cf3 [Candidate] entering
Candidate state in term 2
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.555044
[DEBUG] raft: Votes needed: 2
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.555246
[DEBUG] raft: Vote granted from bc2e52a2-c0f6-421c-e3be-a73b04a27cf3 in term 2.
Tally: 1
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.555516
[DEBUG] raft: Vote granted from b428a04a-5ed2-ff80-71d1-f2b3e96972c5 in term 2.
Tally: 2
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.555711
[INFO] raft: Election won. Tally: 2
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.555904
[INFO] raft: Node at bc2e52a2-c0f6-421c-e3be-a73b04a27cf3 [Leader] entering
Leader state
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.556092
[INFO] raft: Added peer b428a04a-5ed2-ff80-71d1-f2b3e96972c5, starting
replication
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.556380
[INFO] raft: pipelining replication to peer {Voter
b428a04a-5ed2-ff80-71d1-f2b3e96972c5 b428a04a-5ed2-ff80-71d1-f2b3e96972c5}
raft_test.go:97: cluster: 21:34:38.556590 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:38.556786 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:38.556989 [DEBUG] Resetting stability
timeout
raft_test.go:97: cluster: 21:34:38.662314 [INFO] Stable state for
Follower reached at 2018-08-05 21:34:38.557174987 +0000 UTC m=+5.297567395 (1
nodes), 63.67302ms from start of poll, 64.086991ms from cluster start. Timeout
at 2018-08-05 21:34:38.662286461 +0000 UTC m=+5.402678833, 105.111438ms after
stability
raft_test.go:97: cluster: 21:34:38.662663 [DEBUG] Fully Connecting
raft_test.go:97: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.662787 [INFO] raft: Initial configuration (index=0): []
raft_test.go:97: cluster: 21:34:38.662866 [DEBUG] Fully Connecting
raft_test.go:97: cluster: 21:34:38.662937 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.663029 [INFO] raft: Node at f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
[Follower] entering Follower state (Leader: "")
raft_test.go:97: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.737871 [WARN] raft: no known peers, aborting election
raft_test.go:97: cluster: 21:34:38.768139 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.663007668 +0000 UTC m=+5.403400023 (1
nodes), 13.461µs from start of poll, 169.919619ms from cluster start. Timeout
at 2018-08-05 21:34:38.768118469 +0000 UTC m=+5.508510840, 105.110817ms after
stability
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.768360
[INFO] raft: Updating configuration with AddStaging
(server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2,
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2) to [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:b428a04a-5ed2-ff80-71d1-f2b3e96972c5
Address:b428a04a-5ed2-ff80-71d1-f2b3e96972c5} {Suffrage:Voter
ID:server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
Address:f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}]
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.768519
[INFO] raft: Added peer server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2, starting
replication
raft_test.go:97: server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2:
21:34:38.768632 [WARN] raft: Failed to get previous log: 3 log not found (last:
0)
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.768723
[WARN] raft: AppendEntries to {Voter
server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2} rejected, sending older logs (next: 1)
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.768829
[INFO] raft: pipelining replication to peer {Voter
server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}
raft_test.go:97: cluster: 21:34:38.768975 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: cluster: 21:34:38.874139 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.769049289 +0000 UTC m=+5.509441638 (1
nodes), 407ns from start of poll, 275.961234ms from cluster start. Timeout at
2018-08-05 21:34:38.874117273 +0000 UTC m=+5.614509626, 105.067988ms after
stability
raft_test.go:97: cluster: 21:34:38.874324 [INFO] Starting stability
test for raft state: Leader
raft_test.go:97: cluster: 21:34:38.979542 [INFO] Stable state for
Leader reached at 2018-08-05 21:34:38.874408976 +0000 UTC m=+5.614801325 (1
nodes), 443ns from start of poll, 381.320921ms from cluster start. Timeout at
2018-08-05 21:34:38.979511588 +0000 UTC m=+5.719903959, 105.102634ms after
stability
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.979581
[INFO] raft: Updating configuration with RemoveServer
(b428a04a-5ed2-ff80-71d1-f2b3e96972c5, ) to [{Suffrage:Voter
ID:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3
Address:bc2e52a2-c0f6-421c-e3be-a73b04a27cf3} {Suffrage:Voter
ID:server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
Address:f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}]
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.979612
[INFO] raft: Removed peer b428a04a-5ed2-ff80-71d1-f2b3e96972c5, stopping
replication after 4
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.979639
[INFO] raft: aborting pipeline replication to peer {Voter
b428a04a-5ed2-ff80-71d1-f2b3e96972c5 b428a04a-5ed2-ff80-71d1-f2b3e96972c5}
raft_test.go:97: bc2e52a2-c0f6-421c-e3be-a73b04a27cf3: 21:34:38.979700
[INFO] raft: aborting pipeline replication to peer {Voter
server-f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2
f6cd9dec-cfb5-2f1b-d901-144b6e1f57d2}
=== RUN TestTCPTransport_BadAddr
--- PASS: TestTCPTransport_BadAddr (0.00s)
=== RUN TestTCPTransport_WithAdvertise
--- PASS: TestTCPTransport_WithAdvertise (0.00s)
=== RUN TestTransport_StartStop
--- PASS: TestTransport_StartStop (0.00s)
=== RUN TestTransport_AppendEntries
--- PASS: TestTransport_AppendEntries (0.00s)
=== RUN TestTransport_AppendEntriesPipeline
--- PASS: TestTransport_AppendEntriesPipeline (0.00s)
=== RUN TestTransport_RequestVote
--- PASS: TestTransport_RequestVote (0.00s)
=== RUN TestTransport_InstallSnapshot
--- PASS: TestTransport_InstallSnapshot (0.00s)
=== RUN TestTransport_EncodeDecode
--- PASS: TestTransport_EncodeDecode (0.00s)
=== RUN TestRandomTimeout
--- PASS: TestRandomTimeout (0.00s)
=== RUN TestNewSeed
--- PASS: TestNewSeed (0.00s)
=== RUN TestRandomTimeout_NoTime
--- PASS: TestRandomTimeout_NoTime (0.00s)
=== RUN TestMin
--- PASS: TestMin (0.00s)
=== RUN TestMax
--- PASS: TestMax (0.00s)
=== RUN TestGenerateUUID
--- PASS: TestGenerateUUID (0.00s)
=== RUN TestBackoff
--- PASS: TestBackoff (0.00s)
FAIL
FAIL github.com/hashicorp/raft 5.730s
? github.com/hashicorp/raft/bench [no test files]
dh_auto_test: cd obj-x86_64-linux-gnu && go test -vet=off -v -p 1
github.com/hashicorp/raft github.com/hashicorp/raft/bench returned exit code 1
make: *** [debian/rules:9: build-indep] Error 1
dpkg-buildpackage: error: debian/rules build-indep subprocess returned exit
status 2
--------------------------------------------------------------------------------
I suspect of a race condition or something alike, because this failure
does not seem to happen in reproducible builds. However, it fails
for me approximately half of the time, so if you could not reproduce it,
I would gladly offer a test machine where this happens (please contact
me privately for details).
If this is really a bug in one of the build-depends, please use reassign and
affects,
so that this is still visible in the BTS web page for this package.
Thanks.
