go1.5_TestReplicateAddAndRemove.log

[tamird:~/src/go/src/github.com/cockroachdb/cockroach] go1.5-testing(9)+ 2 ± make PKG=./storage TESTS=TestReplicateAddAndRemove TESTFLAGS='--vmodule=raft=5'
go build -tags ''  -ldflags '-X github.com/cockroachdb/cockroach/util.buildTag "alpha-3682-g9553af7" -X github.com/cockroachdb/cockroach/util.buildTime "2015/07/22 23:16:19" -X github.com/cockroachdb/cockroach/util.buildDeps "github.com/biogo/store:e1f74b3c58befe661feed7fa4cf52436de753128 github.com/cockroachdb/c-lz4:6e71f140a365017bbe0904710007f8725fd3f809 github.com/cockroachdb/c-protobuf:0f9ab7b988ca7474cf76b9a961ab03c0552abcb3 github.com/cockroachdb/c-rocksdb:e120ce0fb32f86b94188928743270ea11ff016b3 github.com/cockroachdb/c-snappy:618733f9e5bab8463b9049117a335a7a1bfc9fd5 github.com/cockroachdb/cockroach:9553af7961508128d50b78224d80a1e41e3e6234 github.com/coreos/etcd:3e455ed1049ab4a6152d8df32e58f014abafbc7f github.com/elazarl/go-bindata-assetfs:3dcc96556217539f50599357fb481ac0dc7439b9 github.com/gogo/protobuf:64f27bf06efee53589314a6e5a4af34cdd85adf6 github.com/google/btree:cc6329d4279e3f025a53a83c397d2339b5705c45 github.com/inconshreveable/mousetrap:76626ae9c91c4f2a10f34cad8ce83ea42c93bb75 github.com/julienschmidt/httprouter:70708e46004c7bcb09b70e685a8b74a690135387 github.com/montanaflynn/stats:44fb56da2a2a67d394dec0e18a82dd316f192529 github.com/spf13/cobra:66816bcd0378e248c613e3c443c020f544c28804 github.com/spf13/pflag:67cbc198fd11dab704b214c1e629a97af392c085 golang.org/x/crypto:cc04154d65fb9296747569b107cfd05380b1ea3e golang.org/x/net:8bfde94a845cb31000de3266ac83edbda58dab09 gopkg.in/yaml.v1:9f9df34309c04878acc86042b16630b0f696e1de"' -v -i -o cockroach
github.com/cockroachdb/cockroach
# github.com/cockroachdb/cockroach
link: warning: option -X github.com/cockroachdb/cockroach/util.buildTag alpha-3682-g9553af7 may not work in future releases; use -X github.com/cockroachdb/cockroach/util.buildTag=alpha-3682-g9553af7
link: warning: option -X github.com/cockroachdb/cockroach/util.buildTime 2015/07/22 23:16:19 may not work in future releases; use -X github.com/cockroachdb/cockroach/util.buildTime=2015/07/22 23:16:19
link: warning: option -X github.com/cockroachdb/cockroach/util.buildDeps github.com/biogo/store:e1f74b3c58befe661feed7fa4cf52436de753128 github.com/cockroachdb/c-lz4:6e71f140a365017bbe0904710007f8725fd3f809 github.com/cockroachdb/c-protobuf:0f9ab7b988ca7474cf76b9a961ab03c0552abcb3 github.com/cockroachdb/c-rocksdb:e120ce0fb32f86b94188928743270ea11ff016b3 github.com/cockroachdb/c-snappy:618733f9e5bab8463b9049117a335a7a1bfc9fd5 github.com/cockroachdb/cockroach:9553af7961508128d50b78224d80a1e41e3e6234 github.com/coreos/etcd:3e455ed1049ab4a6152d8df32e58f014abafbc7f github.com/elazarl/go-bindata-assetfs:3dcc96556217539f50599357fb481ac0dc7439b9 github.com/gogo/protobuf:64f27bf06efee53589314a6e5a4af34cdd85adf6 github.com/google/btree:cc6329d4279e3f025a53a83c397d2339b5705c45 github.com/inconshreveable/mousetrap:76626ae9c91c4f2a10f34cad8ce83ea42c93bb75 github.com/julienschmidt/httprouter:70708e46004c7bcb09b70e685a8b74a690135387 github.com/montanaflynn/stats:44fb56da2a2a67d394dec0e18a82dd316f192529 github.com/spf13/cobra:66816bcd0378e248c613e3c443c020f544c28804 github.com/spf13/pflag:67cbc198fd11dab704b214c1e629a97af392c085 golang.org/x/crypto:cc04154d65fb9296747569b107cfd05380b1ea3e golang.org/x/net:8bfde94a845cb31000de3266ac83edbda58dab09 gopkg.in/yaml.v1:9f9df34309c04878acc86042b16630b0f696e1de may not work in future releases; use -X github.com/cockroachdb/cockroach/util.buildDeps=github.com/biogo/store:e1f74b3c58befe661feed7fa4cf52436de753128 github.com/cockroachdb/c-lz4:6e71f140a365017bbe0904710007f8725fd3f809 github.com/cockroachdb/c-protobuf:0f9ab7b988ca7474cf76b9a961ab03c0552abcb3 github.com/cockroachdb/c-rocksdb:e120ce0fb32f86b94188928743270ea11ff016b3 github.com/cockroachdb/c-snappy:618733f9e5bab8463b9049117a335a7a1bfc9fd5 github.com/cockroachdb/cockroach:9553af7961508128d50b78224d80a1e41e3e6234 github.com/coreos/etcd:3e455ed1049ab4a6152d8df32e58f014abafbc7f github.com/elazarl/go-bindata-assetfs:3dcc96556217539f50599357fb481ac0dc7439b9 github.com/gogo/protobuf:64f27bf06efee53589314a6e5a4af34cdd85adf6 github.com/google/btree:cc6329d4279e3f025a53a83c397d2339b5705c45 github.com/inconshreveable/mousetrap:76626ae9c91c4f2a10f34cad8ce83ea42c93bb75 github.com/julienschmidt/httprouter:70708e46004c7bcb09b70e685a8b74a690135387 github.com/montanaflynn/stats:44fb56da2a2a67d394dec0e18a82dd316f192529 github.com/spf13/cobra:66816bcd0378e248c613e3c443c020f544c28804 github.com/spf13/pflag:67cbc198fd11dab704b214c1e629a97af392c085 golang.org/x/crypto:cc04154d65fb9296747569b107cfd05380b1ea3e golang.org/x/net:8bfde94a845cb31000de3266ac83edbda58dab09 gopkg.in/yaml.v1:9f9df34309c04878acc86042b16630b0f696e1de
go test -tags ''  -i ./storage
go test -tags ''  -run TestReplicateAddAndRemove -cpu 1 ./storage -timeout 30s --vmodule=raft=5
I0722 19:16:32.098840 97674 storage/engine/rocksdb.go:99  opening in-memory rocksdb instance
I0722 19:16:32.100083 97674 storage/range.go:996  gossiping cluster id  from store 1, range 1
I0722 19:16:32.100238 97674 raft/raft.go:390  100000001 became follower at term 5
I0722 19:16:32.100277 97674 raft/raft.go:207  newRaft 100000001 [peers: [100000001], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
I0722 19:16:32.100379 97674 raft/raft.go:464  100000001 is starting a new election at term 5
I0722 19:16:32.100389 97674 raft/raft.go:403  100000001 became candidate at term 6
I0722 19:16:32.100398 97674 raft/raft.go:447  100000001 received vote from 100000001 at term 6
I0722 19:16:32.100420 97674 raft/raft.go:426  100000001 became leader at term 6
I0722 19:16:32.100728 97674 storage/range_command.go:823  range 1: new leader lease replica 1:1 19:00:00.000 +1.000s
I0722 19:16:32.100786 97674 storage/range.go:1063  gossiping accounting config from store 1, range 1
I0722 19:16:32.100814 97674 storage/range.go:1063  gossiping permissions config from store 1, range 1
I0722 19:16:32.100840 97674 storage/range.go:1063  gossiping user config from store 1, range 1
I0722 19:16:32.100874 97674 storage/range.go:1063  gossiping zones config from store 1, range 1
I0722 19:16:32.100944 97674 storage/range.go:1004  gossiping sentinel from store 1, range 1
I0722 19:16:32.100962 97674 storage/range.go:1008  gossiping first range from store 1, range 1
I0722 19:16:32.101018 97674 storage/engine/rocksdb.go:99  opening in-memory rocksdb instance
I0722 19:16:32.101406 97674 storage/engine/rocksdb.go:99  opening in-memory rocksdb instance
I0722 19:16:32.101726 97674 storage/engine/rocksdb.go:99  opening in-memory rocksdb instance
I0722 19:16:32.104247 97674 multiraft/multiraft.go:511  node 400000004: got message for unknown group 1; creating it
I0722 19:16:32.104304 97674 raft/raft.go:390  400000004 became follower at term 0
I0722 19:16:32.104325 97674 raft/raft.go:207  newRaft 400000004 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0722 19:16:32.104332 97674 raft/raft.go:390  400000004 became follower at term 1
I0722 19:16:32.104355 97674 raft/raft.go:479  400000004 [term: 1] received a MsgApp message with higher term from 100000001 [term: 6]
I0722 19:16:32.104361 97674 raft/raft.go:390  400000004 became follower at term 6
I0722 19:16:32.104387 97674 raft/raft.go:661  400000004 [logterm: 0, index: 16] rejected msgApp [logterm: 6, index: 16] from 100000001
I0722 19:16:32.104965 97674 raft/raft.go:517  100000001 received msgApp rejection(lastindex: 0) from 400000004 for index 16
I0722 19:16:32.104987 97674 raft/raft.go:519  100000001 decreased progress of 400000004 to [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.105115 97674 raft/raft.go:258  100000001 [firstindex: 11, commit: 16] sent snapshot[index: 16, term: 6] to 400000004 [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.105129 97674 raft/raft.go:260  100000001 paused sending replication messages to 400000004 [next = 1, match = 0, state = ProgressStateSnapshot, waiting = true, pendingSnapshot = 16]
I0722 19:16:32.105186 97674 raft/raft.go:565  100000001 snapshot succeeded, resumed sending replication messages to 400000004 [next = 17, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.105264 97674 raft/raft.go:698  400000004 [commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 16, term: 6]
I0722 19:16:32.105283 97674 raft/log.go:250  log [committed=0, applied=0, unstable.offset=1, len(unstable.Entries)=0] starts to restore snapshot [index: 16, term: 6]
I0722 19:16:32.105301 97674 raft/raft.go:710  400000004 restored progress of 100000001 [next = 17, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.105310 97674 raft/raft.go:710  400000004 restored progress of 400000004 [next = 17, match = 16, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.105318 97674 raft/raft.go:675  400000004 [commit: 0] restored snapshot [index: 16, term: 6]
I0722 19:16:32.108943 97674 multiraft/multiraft.go:511  node 200000002: got message for unknown group 1; creating it
I0722 19:16:32.109014 97674 raft/raft.go:390  200000002 became follower at term 0
I0722 19:16:32.109041 97674 raft/raft.go:207  newRaft 200000002 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0722 19:16:32.109048 97674 raft/raft.go:390  200000002 became follower at term 1
I0722 19:16:32.109068 97674 raft/raft.go:479  200000002 [term: 1] received a MsgApp message with higher term from 100000001 [term: 6]
I0722 19:16:32.109074 97674 raft/raft.go:390  200000002 became follower at term 6
I0722 19:16:32.109085 97674 raft/raft.go:661  200000002 [logterm: 0, index: 22] rejected msgApp [logterm: 6, index: 22] from 100000001
I0722 19:16:32.110094 97674 raft/raft.go:517  100000001 received msgApp rejection(lastindex: 0) from 200000002 for index 22
I0722 19:16:32.110115 97674 raft/raft.go:519  100000001 decreased progress of 200000002 to [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.110281 97674 raft/raft.go:258  100000001 [firstindex: 11, commit: 23] sent snapshot[index: 22, term: 6] to 200000002 [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.110299 97674 raft/raft.go:260  100000001 paused sending replication messages to 200000002 [next = 1, match = 0, state = ProgressStateSnapshot, waiting = true, pendingSnapshot = 22]
I0722 19:16:32.110388 97674 raft/raft.go:565  100000001 snapshot succeeded, resumed sending replication messages to 200000002 [next = 23, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.110944 97674 raft/raft.go:698  200000002 [commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 22, term: 6]
I0722 19:16:32.110962 97674 raft/log.go:250  log [committed=0, applied=0, unstable.offset=1, len(unstable.Entries)=0] starts to restore snapshot [index: 22, term: 6]
I0722 19:16:32.110976 97674 raft/raft.go:710  200000002 restored progress of 100000001 [next = 23, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.110987 97674 raft/raft.go:710  200000002 restored progress of 400000004 [next = 23, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.111003 97674 raft/raft.go:710  200000002 restored progress of 200000002 [next = 23, match = 22, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I0722 19:16:32.111012 97674 raft/raft.go:675  200000002 [commit: 0] restored snapshot [index: 22, term: 6]
I0722 19:16:32.112675 97674 raft/raft.go:661  200000002 [logterm: 0, index: 25] rejected msgApp [logterm: 6, index: 25] from 100000001
I0722 19:16:32.113155 97674 raft/raft.go:517  100000001 received msgApp rejection(lastindex: 22) from 200000002 for index 25
--- FAIL: TestReplicateAddAndRemove (1.11s)
	testing.go:150: storage/client_raft_test.go:623: condition failed to evaluate within 1s: storage/client_raft_test.go:620: expected [5 5 0 5], got [5 0 0 5]
FAIL
FAIL	github.com/cockroachdb/cockroach/storage	1.129s
make: *** [test] Error 1
[tamird:~/src/go/src/github.com/cockroachdb/cockroach] go1.5-testing(9)+ 2 ±