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.
_______________________________________________ Pkg-go-maintainers mailing list Pkg-go-maintainers@alioth-lists.debian.net https://alioth-lists.debian.net/cgi-bin/mailman/listinfo/pkg-go-maintainers