-
-
Save tbg/3380546a93f8851e5bbd to your computer and use it in GitHub Desktop.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
go test -tags '' -i ./storage | |
go test -tags '' -run TestRaftAfterRemoveRange -cpu 1 ./storage -timeout 10s -v --verbosity=1 | |
=== RUN TestRaftAfterRemoveRange | |
I0804 02:01:20.668546 93859 storage/engine/rocksdb.go:99 opening in-memory rocksdb instance | |
W0804 02:01:20.678905 93859 rpc/tls.go:41 listening via tcp to 127.0.0.1:0 without TLS | |
I0804 02:01:20.681252 93859 multiraft/multiraft.go:454 node 100000001 starting | |
I0804 02:01:20.682832 93859 storage/range.go:986 gossiping cluster id from store 1, range 1 | |
I0804 02:01:20.684805 93859 raft/raft.go:390 100000001 became follower at term 5 | |
I0804 02:01:20.684892 93859 raft/raft.go:207 newRaft 100000001 [peers: [100000001], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5] | |
I0804 02:01:20.684960 93859 raft/raft.go:464 100000001 is starting a new election at term 5 | |
I0804 02:01:20.684986 93859 raft/raft.go:403 100000001 became candidate at term 6 | |
I0804 02:01:20.685009 93859 raft/raft.go:447 100000001 received vote from 100000001 at term 6 | |
I0804 02:01:20.685044 93859 raft/raft.go:426 100000001 became leader at term 6 | |
I0804 02:01:20.688925 93859 storage/range_command.go:932 range 1: new leader lease replica 1:1 19:00:00.000 +1.000s | |
I0804 02:01:20.689051 93859 storage/range.go:1053 gossiping accounting config from store 1, range 1 | |
I0804 02:01:20.689114 93859 storage/range.go:1053 gossiping permissions config from store 1, range 1 | |
I0804 02:01:20.689158 93859 storage/range.go:1053 gossiping user config from store 1, range 1 | |
I0804 02:01:20.689204 93859 storage/range.go:1053 gossiping zones config from store 1, range 1 | |
I0804 02:01:20.689319 93859 storage/range.go:994 gossiping sentinel from store 1, range 1 | |
I0804 02:01:20.689353 93859 storage/range.go:998 gossiping first range from store 1, range 1 | |
I0804 02:01:20.689457 93859 storage/engine/rocksdb.go:99 opening in-memory rocksdb instance | |
W0804 02:01:20.689835 93859 rpc/tls.go:41 listening via tcp to 127.0.0.1:0 without TLS | |
I0804 02:01:20.690023 93859 multiraft/multiraft.go:454 node 200000002 starting | |
I0804 02:01:20.690092 93859 storage/engine/rocksdb.go:99 opening in-memory rocksdb instance | |
W0804 02:01:20.690358 93859 rpc/tls.go:41 listening via tcp to 127.0.0.1:0 without TLS | |
I0804 02:01:20.690537 93859 multiraft/multiraft.go:454 node 300000003 starting | |
I0804 02:01:20.692547 93859 storage/range_command.go:994 initiating a split of range=1 ["" - "\xff\xff") at key "b" | |
W0804 02:01:20.697198 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00k\x00\x01rdsc" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
W0804 02:01:20.697327 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00k\x00\x01rtn-" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
W0804 02:01:20.697399 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
W0804 02:01:20.697451 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rtn-" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
W0804 02:01:20.697498 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00meta1\xff\xff" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
W0804 02:01:20.697541 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00meta2b" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
W0804 02:01:20.697583 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00meta2\xff\xff" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
W0804 02:01:20.697623 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00range-tree-root" "" "range_command.go:1038" id=b18e3666 key="b" rw=false pri=93.43629810 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,20 orig=0.000000000,20 max=0.000000000,20 } | |
I0804 02:01:20.698557 93859 raft/raft.go:390 100000001 became follower at term 5 | |
I0804 02:01:20.698597 93859 raft/raft.go:207 newRaft 100000001 [peers: [100000001], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5] | |
I0804 02:01:20.698626 93859 raft/raft.go:464 100000001 is starting a new election at term 5 | |
I0804 02:01:20.698637 93859 raft/raft.go:403 100000001 became candidate at term 6 | |
I0804 02:01:20.698644 93859 raft/raft.go:447 100000001 received vote from 100000001 at term 6 | |
I0804 02:01:20.698661 93859 raft/raft.go:426 100000001 became leader at term 6 | |
I0804 02:01:20.698883 93859 storage/range_command.go:932 range 2: new leader lease replica 1:1 19:00:00.000 +1.000s | |
W0804 02:01:20.699630 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=ef8418cc key="b" rw=false pri=79.68131233 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,44 orig=0.000000000,44 max=0.000000000,44 } | |
W0804 02:01:20.699686 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:20.700971 93859 rpc/tls.go:57 connecting via tcp to 127.0.0.1:49283 without TLS | |
I0804 02:01:20.701694 93859 multiraft/multiraft.go:513 node 200000002: got message for unknown group 2; creating it | |
I0804 02:01:20.701800 93859 raft/raft.go:390 200000002 became follower at term 0 | |
I0804 02:01:20.701832 93859 raft/raft.go:207 newRaft 200000002 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] | |
I0804 02:01:20.701841 93859 raft/raft.go:390 200000002 became follower at term 1 | |
I0804 02:01:20.701885 93859 raft/raft.go:479 200000002 [term: 1] received a MsgApp message with higher term from 100000001 [term: 6] | |
I0804 02:01:20.701894 93859 raft/raft.go:390 200000002 became follower at term 6 | |
W0804 02:01:20.702009 93859 rpc/tls.go:57 connecting via tcp to 127.0.0.1:49282 without TLS | |
I0804 02:01:20.702611 93859 raft/raft.go:258 100000001 [firstindex: 11, commit: 14] sent snapshot[index: 14, term: 6] to 200000002 [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.702642 93859 raft/raft.go:260 100000001 paused sending replication messages to 200000002 [next = 1, match = 0, state = ProgressStateSnapshot, waiting = true, pendingSnapshot = 14] | |
I0804 02:01:20.702760 93859 raft/raft.go:565 100000001 snapshot succeeded, resumed sending replication messages to 200000002 [next = 15, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.702873 93859 raft/raft.go:698 200000002 [commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 14, term: 6] | |
I0804 02:01:20.702905 93859 raft/log.go:250 log [committed=0, applied=0, unstable.offset=1, len(unstable.Entries)=0] starts to restore snapshot [index: 14, term: 6] | |
I0804 02:01:20.702929 93859 raft/raft.go:710 200000002 restored progress of 100000001 [next = 15, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.702945 93859 raft/raft.go:710 200000002 restored progress of 200000002 [next = 15, match = 14, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.702964 93859 raft/raft.go:675 200000002 [commit: 0] restored snapshot [index: 14, term: 6] | |
W0804 02:01:20.707211 93859 storage/store.go:1291 conflicting intents on ["\x00\x00meta2\xff\xff"]: resolved? true | |
W0804 02:01:20.708573 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=b0331b2a key="b" rw=false pri=24.74269645 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,54 orig=0.000000000,54 max=0.000000000,54 } | |
W0804 02:01:20.708606 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:20.709064 93859 rpc/tls.go:57 connecting via tcp to 127.0.0.1:49284 without TLS | |
W0804 02:01:20.709429 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=b0331b2a key="b" rw=false pri=24.74269645 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,54 orig=0.000000000,54 max=0.000000000,54 } | |
W0804 02:01:20.709458 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
I0804 02:01:20.710340 93859 multiraft/multiraft.go:513 node 300000003: got message for unknown group 2; creating it | |
I0804 02:01:20.710435 93859 raft/raft.go:390 300000003 became follower at term 0 | |
I0804 02:01:20.710462 93859 raft/raft.go:207 newRaft 300000003 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] | |
I0804 02:01:20.710470 93859 raft/raft.go:390 300000003 became follower at term 1 | |
I0804 02:01:20.710491 93859 raft/raft.go:479 300000003 [term: 1] received a MsgApp message with higher term from 100000001 [term: 6] | |
I0804 02:01:20.710498 93859 raft/raft.go:390 300000003 became follower at term 6 | |
I0804 02:01:20.710783 93859 raft/raft.go:258 100000001 [firstindex: 11, commit: 19] sent snapshot[index: 19, term: 6] to 300000003 [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.710797 93859 raft/raft.go:260 100000001 paused sending replication messages to 300000003 [next = 1, match = 0, state = ProgressStateSnapshot, waiting = true, pendingSnapshot = 19] | |
I0804 02:01:20.710883 93859 raft/raft.go:565 100000001 snapshot succeeded, resumed sending replication messages to 300000003 [next = 20, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.711357 93859 raft/raft.go:698 300000003 [commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 19, term: 6] | |
I0804 02:01:20.711370 93859 raft/log.go:250 log [committed=0, applied=0, unstable.offset=1, len(unstable.Entries)=0] starts to restore snapshot [index: 19, term: 6] | |
I0804 02:01:20.711381 93859 raft/raft.go:710 300000003 restored progress of 100000001 [next = 20, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.711389 93859 raft/raft.go:710 300000003 restored progress of 200000002 [next = 20, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.711397 93859 raft/raft.go:710 300000003 restored progress of 300000003 [next = 20, match = 19, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0] | |
I0804 02:01:20.711403 93859 raft/raft.go:675 300000003 [commit: 0] restored snapshot [index: 19, term: 6] | |
W0804 02:01:20.713686 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=f6dabea4 key="b" rw=false pri=72.14923784 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,85 orig=0.000000000,85 max=0.000000000,85 } | |
W0804 02:01:20.713711 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:20.714424 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=f6dabea4 key="b" rw=false pri=72.14923784 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,85 orig=0.000000000,85 max=0.000000000,85 } | |
W0804 02:01:20.714448 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:20.715633 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=f6dabea4 key="b" rw=false pri=72.14923784 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,85 orig=0.000000000,85 max=0.000000000,85 } | |
W0804 02:01:20.715667 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:20.717333 93859 storage/store.go:1291 conflicting intents on ["\x00\x00meta2\xff\xff"]: resolved? true | |
W0804 02:01:20.718137 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=cf0e8d79 key="b" rw=false pri=21.13950850 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,94 orig=0.000000000,94 max=0.000000000,94 } | |
W0804 02:01:20.718172 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:20.718827 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00kb\x00\x01rdsc" "" "range_command.go:1344" id=cf0e8d79 key="b" rw=false pri=21.13950850 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,94 orig=0.000000000,94 max=0.000000000,94 } | |
W0804 02:01:20.718851 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:20.718971 93859 storage/client_raft_test.go:868 _______________________ | |
W0804 02:01:20.719706 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00\x00k\x00\x01rdsc" "" "range_command.go:1344" id=cd04a15b key="" rw=false pri=57.16429183 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,122 orig=0.000000000,122 max=0.000000000,122 } | |
W0804 02:01:20.719774 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00meta1\xff\xff" "" "range_command.go:1344" id=cd04a15b key="" rw=false pri=57.16429183 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,122 orig=0.000000000,122 max=0.000000000,122 } | |
W0804 02:01:20.719805 93859 storage/range_command.go:346 resolving on EndTransaction: {"\x00\x00meta2b" "" "range_command.go:1344" id=cd04a15b key="" rw=false pri=57.16429183 iso=SERIALIZABLE stat=PENDING epo=0 ts=0.000000000,122 orig=0.000000000,122 max=0.000000000,122 } | |
W0804 02:01:20.719832 93859 storage/range_command.go:1264 TODO(tschottdorf): changeReplicasTrigger | |
W0804 02:01:21.810561 93859 rpc/server.go:351 rpc: server cannot decode request: read tcp 127.0.0.1:49286: use of closed network connection | |
W0804 02:01:21.810623 93859 rpc/server.go:351 rpc: server cannot decode request: read tcp 127.0.0.1:49285: use of closed network connection | |
W0804 02:01:21.810682 93859 rpc/server.go:351 rpc: server cannot decode request: read tcp 127.0.0.1:49287: use of closed network connection | |
--- FAIL: TestRaftAfterRemoveRange (1.14s) | |
testing.go:150: storage/client_test.go:320: condition failed to evaluate within 1s: storage/client_test.go:316: range not found on store 1 | |
FAIL | |
exit status 1 | |
FAIL github.com/cockroachdb/cockroach/storage 1.257s | |
make: *** [test] Error 1 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment