Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

circleci: failed tests: TestSplitSnapshotRace_SplitWins #9204

Closed
tbg opened this issue Sep 8, 2016 · 14 comments
Closed

circleci: failed tests: TestSplitSnapshotRace_SplitWins #9204

tbg opened this issue Sep 8, 2016 · 14 comments
Assignees
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Milestone

Comments

@tbg
Copy link
Member

tbg commented Sep 8, 2016

The following test appears to have failed:

#22431:

W160908 14:00:09.206445 17103 storage/store.go:2483  [s5] got error from range 11, replica {4 4 1}: storage/raft_transport.go:233: unable to accept Raft message from {NodeID:5 StoreID:5 ReplicaID:4}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W160908 14:00:09.272849 17045 storage/store.go:2483  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:233: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
I160908 14:00:09.275526 16664 storage/replica.go:1976  [s3,r11{"m"-/Max}] pending commands: refurbished 1, reproposing 0 (at 23.8); reasonTicks
W160908 14:00:09.306328 17103 storage/store.go:2483  [s5] got error from range 11, replica {4 4 1}: storage/raft_transport.go:233: unable to accept Raft message from {NodeID:5 StoreID:5 ReplicaID:4}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W160908 14:00:09.372699 17045 storage/store.go:2483  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:233: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
panic: test timed out after 2m0s

goroutine 17405 [running]:
panic(0x155c000, 0xc4205e3350)
    /usr/local/go/src/runtime/panic.go:500 +0x1a1
testing.startAlarm.func1()
    /usr/local/go/src/testing/testing.go:918 +0x10b
created by time.goFunc
    /usr/local/go/src/time/sleep.go:154 +0x44

goroutine 1 [chan receive, 1 minutes]:
testing.(*T).Run(0xc420164240, 0x171a8f5, 0x1f, 0x187c878, 0xc420275a01)
    /usr/local/go/src/testing/testing.go:647 +0x316
testing.RunTests.func1(0xc420164240)
    /usr/local/go/src/testing/testing.go:793 +0x6d
testing.tRunner(0xc420164240, 0xc420049bc0)
    /usr/local/go/src/testing/testing.go:610 +0x81
testing.RunTests(0x187db10, 0x209d4a0, 0x13e, 0x13e, 0xc4202840b0)
    /usr/local/go/src/testing/testing.go:799 +0x2f5
testing.(*M).Run(0xc420049ee8, 0xc420275d30)
    /usr/local/go/src/testing/testing.go:743 +0x85
github.com/cockroachdb/cockroach/storage_test.TestMain(0xc420049ee8)
    /go/src/github.com/cockroachdb/cockroach/storage/main_test.go:57 +0x1ff
main.main()
    github.com/cockroachdb/cockroach/storage/_test/_testmain.go:698 +0xc6

goroutine 17 [syscall, 2 minutes, locked to thread]:
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:2086 +0x1

goroutine 16634 [select]:
github.com/cockroachdb/cockroach/storage.(*Store).startGossip.func2()
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:1048 +0x314
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc420a60630, 0xc420013960)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 19 [chan receive]:
github.com/cockroachdb/cockroach/util/log.(*loggingT).flushDaemon(0x23e4ea0)
    /go/src/github.com/cockroachdb/cockroach/util/log/clog.go:1032 +0x77
created by github.com/cockroachdb/cockroach/util/log.init.1
    /go/src/github.com/cockroachdb/cockroach/util/log/clog.go:613 +0x95

goroutine 16664 [select]:
github.com/cockroachdb/cockroach/storage.(*Store).processRaft.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2604 +0xf50
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2990, 0xc4200e12d0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16540 [select]:
github.com/cockroachdb/cockroach/storage.NewRaftTransport.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/raft_transport.go:167 +0xe03
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420012b20)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16711 [IO wait]:
net.runtime_pollWait(0x7ff865ffbb90, 0x72, 0x10)
    /usr/local/go/src/runtime/netpoll.go:160 +0x59
net.(*pollDesc).wait(0xc420f5ae60, 0x72, 0xc420ad88e8, 0xc4200120a8)
    /usr/local/go/src/net/fd_poll_runtime.go:73 +0x38
net.(*pollDesc).waitRead(0xc420f5ae60, 0x20a8fc0, 0xc4200120a8)
    /usr/local/go/src/net/fd_poll_runtime.go:78 +0x34
net.(*netFD).Read(0xc420f5ae00, 0xc420ebc000, 0x8000, 0x8000, 0x0, 0x20a8fc0, 0xc4200120a8)
    /usr/local/go/src/net/fd_unix.go:243 +0x1a1
net.(*conn).Read(0xc4201302e8, 0xc420ebc000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/net.go:173 +0x70
--
google.golang.org/grpc.(*Server).handleRawConn(0xc42068efa0, 0x20bba00, 0xc4201302e8)
    /go/src/google.golang.org/grpc/server.go:388 +0x470
created by google.golang.org/grpc.(*Server).Serve
    /go/src/google.golang.org/grpc/server.go:357 +0x1a9

goroutine 16537 [select]:
github.com/cockroachdb/cockroach/kv.(*DistSender).sendToReplicas(0xc4200e23f0, 0x7ff866021178, 0xc4201da1e0, 0x2540be400, 0xb2d05e00, 0xc420e821a0, 0x2, 0xc420509e00, 0x3, 0x3, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:1043 +0x9e9
github.com/cockroachdb/cockroach/kv.(*DistSender).sendRPC(0xc4200e23f0, 0x7ff866021178, 0xc4201da1e0, 0x2, 0xc420509e00, 0x3, 0x3, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:379 +0x1c6
github.com/cockroachdb/cockroach/kv.(*DistSender).sendSingleRange(0xc4200e23f0, 0x7ff866021178, 0xc4201da1e0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:495 +0x19f
github.com/cockroachdb/cockroach/kv.(*DistSender).sendChunk.func2(0xc420858d78, 0xc420858c38, 0xc4208592a0, 0xc4200e23f0, 0xc420859290, 0x8, 0xc4200e0c70)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:787 +0x18e
github.com/cockroachdb/cockroach/kv.(*DistSender).sendChunk(0xc4200e23f0, 0x7ff866021178, 0xc4201da1e0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:788 +0x6af
--
testing.tRunner(0xc420de0300, 0x187c878)
    /usr/local/go/src/testing/testing.go:610 +0x81
created by testing.(*T).Run
    /usr/local/go/src/testing/testing.go:646 +0x2ec

goroutine 16927 [select, 1 minutes]:
google.golang.org/grpc/transport.(*recvBufferReader).Read(0xc420db6e00, 0xc4202e5c10, 0x5, 0x5, 0x0, 0x0, 0x0)
    /go/src/google.golang.org/grpc/transport/transport.go:141 +0x69a
google.golang.org/grpc/transport.(*Stream).Read(0xc4200c01e0, 0xc4202e5c10, 0x5, 0x5, 0xc420e37908, 0x60018b, 0x70)
    /go/src/google.golang.org/grpc/transport/transport.go:314 +0x59
io.ReadAtLeast(0x20a5440, 0xc4200c01e0, 0xc4202e5c10, 0x5, 0x5, 0x5, 0xc420f0a050, 0x0, 0xc42007b0a0)
    /usr/local/go/src/io/io.go:307 +0xa4
io.ReadFull(0x20a5440, 0xc4200c01e0, 0xc4202e5c10, 0x5, 0x5, 0xc400000001, 0x0, 0x5ce3f9)
    /usr/local/go/src/io/io.go:325 +0x58
google.golang.org/grpc.(*parser).recvMsg(0xc4202e5c00, 0x7fffffff, 0x0, 0x38, 0x1876efa, 0x1876ef9, 0xc41ff92453, 0x0)
    /go/src/google.golang.org/grpc/rpc_util.go:231 +0x6f
--
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420db73c0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16630 [select]:
github.com/cockroachdb/cockroach/storage.(*Store).processRaft.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2604 +0xf50
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc420a60630, 0xc420013740)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16686 [chan receive, 1 minutes]:
github.com/cockroachdb/cockroach/storage/engine.(*RocksDB).Open.func1(0xc420d9e600)
    /go/src/github.com/cockroachdb/cockroach/storage/engine/rocksdb.go:390 +0x44
created by github.com/cockroachdb/cockroach/storage/engine.(*RocksDB).Open
    /go/src/github.com/cockroachdb/cockroach/storage/engine/rocksdb.go:391 +0x6eb

goroutine 16604 [IO wait]:
net.runtime_pollWait(0x7ff865ffbad0, 0x72, 0xa)
    /usr/local/go/src/runtime/netpoll.go:160 +0x59
net.(*pollDesc).wait(0xc420f38ed0, 0x72, 0xc42066e8e8, 0xc4200120a8)
    /usr/local/go/src/net/fd_poll_runtime.go:73 +0x38
net.(*pollDesc).waitRead(0xc420f38ed0, 0x20a8fc0, 0xc4200120a8)
    /usr/local/go/src/net/fd_poll_runtime.go:78 +0x34
net.(*netFD).Read(0xc420f38e70, 0xc420cb2000, 0x8000, 0x8000, 0x0, 0x20a8fc0, 0xc4200120a8)
    /usr/local/go/src/net/fd_unix.go:243 +0x1a1
net.(*conn).Read(0xc420028430, 0xc420cb2000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/net.go:173 +0x70
--
google.golang.org/grpc.(*Server).handleRawConn(0xc42068e820, 0x20bba00, 0xc420028430)
    /go/src/google.golang.org/grpc/server.go:388 +0x470
created by google.golang.org/grpc.(*Server).Serve
    /go/src/google.golang.org/grpc/server.go:357 +0x1a9

goroutine 16649 [select]:
github.com/cockroachdb/cockroach/kv.(*TxnCoordSender).startStats(0xc420794630)
    /go/src/github.com/cockroachdb/cockroach/kv/txn_coord_sender.go:208 +0xa63
github.com/cockroachdb/cockroach/kv.(*TxnCoordSender).(github.com/cockroachdb/cockroach/kv.startStats)-fm()
    /go/src/github.com/cockroachdb/cockroach/kv/txn_coord_sender.go:193 +0x2a
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2990, 0xc4200e09a0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16798 [select]:
github.com/cockroachdb/cockroach/gossip.(*client).gossip(0xc420f56b60, 0x7ff8660211b8, 0xc420f24600, 0xc420335800, 0x20bb820, 0xc420d196e0, 0xc4200e2090, 0xc420d196a0, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/gossip/client.go:299 +0x3c4
github.com/cockroachdb/cockroach/gossip.(*client).start.func1()
    /go/src/github.com/cockroachdb/cockroach/gossip/client.go:126 +0x52d
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420f245c0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16633 [select]:
github.com/cockroachdb/cockroach/storage.(*Store).startGossip.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:1029 +0x314
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc420a60630, 0xc4200137c0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16810 [select, 1 minutes]:
google.golang.org/grpc/transport.(*recvBufferReader).Read(0xc420f24d40, 0xc420f6d1b0, 0x5, 0x5, 0x0, 0x0, 0x0)
    /go/src/google.golang.org/grpc/transport/transport.go:141 +0x69a
google.golang.org/grpc/transport.(*Stream).Read(0xc420ce0b40, 0xc420f6d1b0, 0x5, 0x5, 0xc420a05908, 0x60018b, 0x70)
    /go/src/google.golang.org/grpc/transport/transport.go:314 +0x59
io.ReadAtLeast(0x20a5440, 0xc420ce0b40, 0xc420f6d1b0, 0x5, 0x5, 0x5, 0xc42024ca00, 0x0, 0xc420c0ec40)
    /usr/local/go/src/io/io.go:307 +0xa4
io.ReadFull(0x20a5440, 0xc420ce0b40, 0xc420f6d1b0, 0x5, 0x5, 0xc400000001, 0x0, 0x5ce3f9)
    /usr/local/go/src/io/io.go:325 +0x58
google.golang.org/grpc.(*parser).recvMsg(0xc420f6d1a0, 0x7fffffff, 0x0, 0x38, 0x1876efa, 0x1876ef9, 0xc41ffe2849, 0x0)
    /go/src/google.golang.org/grpc/rpc_util.go:231 +0x6f
--
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420f25b00)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16847 [chan receive]:
github.com/cockroachdb/cockroach/storage.(*Store).processRaft.func1.1(0xc42049cba0)
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2523 +0x4a
created by github.com/cockroachdb/cockroach/storage.(*Store).processRaft.func1
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2526 +0xa7

goroutine 16629 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*bookie).start.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/reservation.go:274 +0x217
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc420a60630, 0xc420f265e0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16612 [chan receive, 1 minutes]:
github.com/cockroachdb/cockroach/storage/engine.(*RocksDB).Open.func1(0xc420ac6c00)
    /go/src/github.com/cockroachdb/cockroach/storage/engine/rocksdb.go:390 +0x44
created by github.com/cockroachdb/cockroach/storage/engine.(*RocksDB).Open
    /go/src/github.com/cockroachdb/cockroach/storage/engine/rocksdb.go:391 +0x6eb

goroutine 16622 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*baseQueue).processLoop.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/queue.go:418 +0x2cc
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc420a60630, 0xc420f6c520)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16884 [select]:
github.com/cockroachdb/cockroach/gossip.(*client).gossip(0xc420f56d20, 0x7ff8660211b8, 0xc420332180, 0xc42000e300, 0x20bb820, 0xc420deedd0, 0xc4200e2090, 0xc420deed80, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/gossip/client.go:299 +0x3c4
github.com/cockroachdb/cockroach/gossip.(*client).start.func1()
    /go/src/github.com/cockroachdb/cockroach/gossip/client.go:126 +0x52d
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420332140)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16719 [select, 1 minutes]:
google.golang.org/grpc.NewClientStream.func2(0x20bb460, 0xc420806600, 0xc4201bc780, 0xc4201e87e0)
    /go/src/google.golang.org/grpc/stream.go:197 +0x426
created by google.golang.org/grpc.NewClientStream
    /go/src/google.golang.org/grpc/stream.go:217 +0xb5f

goroutine 17049 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*idAllocator).start.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/id_alloc.go:124 +0x7ef
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc420a60630, 0xc4203b1960)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16835 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*baseQueue).processLoop.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/queue.go:418 +0x2cc
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e3830, 0xc420f50920)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16744 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*StorePool).start.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/store_pool.go:340 +0x3da
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e3830, 0xc420f3bb80)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16647 [select]:
github.com/cockroachdb/cockroach/storage.NewRaftTransport.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/raft_transport.go:167 +0xe03
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc4200e03a0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16834 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*baseQueue).processLoop.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/queue.go:418 +0x2cc
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e3830, 0xc420f507e0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16541 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*StorePool).start.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/store_pool.go:340 +0x3da
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e21b0, 0xc420f6d7e0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16567 [chan receive, 1 minutes]:
github.com/cockroachdb/cockroach/gossip.(*server).start.func3()
    /go/src/github.com/cockroachdb/cockroach/gossip/server.go:370 +0x66
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420f3b000)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16607 [select]:
google.golang.org/grpc/transport.(*http2Client).controller(0xc42000b000)
    /go/src/google.golang.org/grpc/transport/http2_client.go:999 +0x59d
created by google.golang.org/grpc/transport.newHTTP2Client
    /go/src/google.golang.org/grpc/transport/http2_client.go:233 +0xe78

goroutine 16655 [select]:
google.golang.org/grpc/transport.(*http2Server).controller(0xc4200e2bd0)
    /go/src/google.golang.org/grpc/transport/http2_server.go:673 +0x69c
created by google.golang.org/grpc/transport.newHTTP2Server
    /go/src/google.golang.org/grpc/transport/http2_server.go:139 +0x767

goroutine 16819 [select]:
github.com/cockroachdb/cockroach/storage.(*Store).startGossip.func2()
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:1048 +0x314
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e3830, 0xc420e82700)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16568 [select, 1 minutes]:
github.com/cockroachdb/cockroach/gossip.(*Gossip).bootstrap.func1()
    /go/src/github.com/cockroachdb/cockroach/gossip/gossip.go:920 +0x420
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420e83010)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16808 [select]:
google.golang.org/grpc/transport.(*recvBufferReader).Read(0xc420f24840, 0xc420f6c4d0, 0x5, 0x5, 0x0, 0x0, 0x0)
    /go/src/google.golang.org/grpc/transport/transport.go:141 +0x69a
google.golang.org/grpc/transport.(*Stream).Read(0xc420ce0a50, 0xc420f6c4d0, 0x5, 0x5, 0x5c8791, 0x1595d80, 0xc420f20b38)
    /go/src/google.golang.org/grpc/transport/transport.go:314 +0x59
io.ReadAtLeast(0x20a5440, 0xc420ce0a50, 0xc420f6c4d0, 0x5, 0x5, 0x5, 0x9e64fc, 0x7ff866021178, 0x620ce2150)
    /usr/local/go/src/io/io.go:307 +0xa4
io.ReadFull(0x20a5440, 0xc420ce0a50, 0xc420f6c4d0, 0x5, 0x5, 0x5ea8ac, 0xc42091cce0, 0xc42091cce0)
    /usr/local/go/src/io/io.go:325 +0x58
google.golang.org/grpc.(*parser).recvMsg(0xc420f6c4c0, 0x7fffffff, 0x4, 0x4, 0x1661720, 0x3, 0x3, 0x3)
    /go/src/google.golang.org/grpc/rpc_util.go:231 +0x6f
--
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420f24980)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16986 [select]:
google.golang.org/grpc/transport.(*recvBufferReader).Read(0xc4201b53c0, 0xc420713070, 0x5, 0x5, 0x0, 0x0, 0x0)
    /go/src/google.golang.org/grpc/transport/transport.go:141 +0x69a
google.golang.org/grpc/transport.(*Stream).Read(0xc420b544b0, 0xc420713070, 0x5, 0x5, 0x0, 0xc420849600, 0xc42044bb90)
    /go/src/google.golang.org/grpc/transport/transport.go:314 +0x59
io.ReadAtLeast(0x20a5440, 0xc420b544b0, 0xc420713070, 0x5, 0x5, 0x5, 0xc420794f78, 0x0, 0x1)
    /usr/local/go/src/io/io.go:307 +0xa4
io.ReadFull(0x20a5440, 0xc420b544b0, 0xc420713070, 0x5, 0x5, 0xc420794f78, 0xc4207e0c20, 0x4000000000000000)
    /usr/local/go/src/io/io.go:325 +0x58
google.golang.org/grpc.(*parser).recvMsg(0xc420713060, 0x7fffffff, 0xc420076820, 0x0, 0xc420849540, 0xc42044bce8, 0x614680, 0xc420849600)
    /go/src/google.golang.org/grpc/rpc_util.go:231 +0x6f
--
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420b7ede0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 17156 [select]:
github.com/cockroachdb/cockroach/kv.(*DistSender).sendToReplicas(0xc4200e23f0, 0x7ff866021178, 0xc4201db920, 0x2540be400, 0xb2d05e00, 0xc420e821a0, 0x2, 0xc420528c80, 0x3, 0x3, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:1043 +0x9e9
github.com/cockroachdb/cockroach/kv.(*DistSender).sendRPC(0xc4200e23f0, 0x7ff866021178, 0xc4201db920, 0x2, 0xc420528c80, 0x3, 0x3, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:379 +0x1c6
github.com/cockroachdb/cockroach/kv.(*DistSender).sendSingleRange(0xc4200e23f0, 0x7ff866021178, 0xc4201db920, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:495 +0x19f
github.com/cockroachdb/cockroach/kv.(*DistSender).sendChunk.func2(0xc42098ba00, 0xc42098b8c0, 0xc42098bf28, 0xc4200e23f0, 0xc42098bf18, 0xd, 0xc4203b9ad3)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:787 +0x18e
github.com/cockroachdb/cockroach/kv.(*DistSender).sendChunk(0xc4200e23f0, 0x7ff866021178, 0xc4201db920, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/kv/dist_sender.go:788 +0x6af
--
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunAsyncTask.func1(0xc4200e21b0, 0x1daf8d2, 0x16, 0x1c2, 0xc4207e0160)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:231 +0x95
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunAsyncTask
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:232 +0xbc

goroutine 16662 [select]:
github.com/cockroachdb/cockroach/gossip.(*Gossip).manage.func1()
    /go/src/github.com/cockroachdb/cockroach/gossip/gossip.go:948 +0x2fb
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc4200e11c0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16566 [select]:
github.com/cockroachdb/cockroach/rpc.(*Context).runHeartbeat(0xc420a42a80, 0xc420806000, 0xc420e82ee0, 0xf, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/rpc/context.go:294 +0x645
github.com/cockroachdb/cockroach/rpc.(*Context).GRPCDial.func1.1.1()
    /go/src/github.com/cockroachdb/cockroach/rpc/context.go:217 +0x69
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e2090, 0xc420cd6930)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16573 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*Store).Start.func3()
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:954 +0x165
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e21b0, 0xc420f3b880)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16586 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*baseQueue).processLoop.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/queue.go:418 +0x2cc
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e21b0, 0xc420f50c00)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 17149 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*Replica).redirectOnOrAcquireLease(0xc420a57200, 0x7ff866021178, 0xc420b6f770, 0xc420904b00)
    /go/src/github.com/cockroachdb/cockroach/storage/replica.go:742 +0x4ec
github.com/cockroachdb/cockroach/storage.(*Replica).addWriteCmd(0xc420a57200, 0x7ff866021178, 0xc420b6f770, 0x35a4e9000, 0x0, 0x300000003, 0x3, 0xb, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/storage/replica.go:1432 +0x18a
github.com/cockroachdb/cockroach/storage.(*Replica).Send(0xc420a57200, 0x7ff866021178, 0xc420b6f770, 0x35a4e9000, 0x0, 0x300000003, 0x3, 0xb, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/storage/replica.go:1016 +0x277
github.com/cockroachdb/cockroach/storage.(*Store).Send(0xc420650280, 0x7ff866021178, 0xc420b6f710, 0x35a4e9000, 0x0, 0x300000003, 0x3, 0xb, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2099 +0x75e
github.com/cockroachdb/cockroach/storage.(*Stores).Send(0xc420e900c0, 0x7ff8660211b8, 0xc420685a80, 0x0, 0x0, 0x300000003, 0x3, 0xb, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/storage/stores.go:182 +0x202
--
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunAsyncTask.func1(0xc4200e2990, 0x1daf8d2, 0x16, 0x1c2, 0xc4209049a0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:231 +0x95
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunAsyncTask
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:232 +0xbc

goroutine 16809 [select]:
github.com/cockroachdb/cockroach/gossip.(*server).Gossip(0xc420f562a0, 0x20baf80, 0xc420d19a30, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/gossip/server.go:180 +0x53c
github.com/cockroachdb/cockroach/gossip._Gossip_Gossip_Handler(0x16528e0, 0xc420f562a0, 0x20b7560, 0xc4200e3b90, 0x1b, 0x20aeac0)
    /go/src/github.com/cockroachdb/cockroach/gossip/gossip.pb.go:209 +0xbb
google.golang.org/grpc.(*Server).processStreamingRPC(0xc420526c80, 0x20bb4c0, 0xc4200e2bd0, 0xc420ce0b40, 0xc420e75980, 0x208c300, 0x0, 0x0, 0x0)
    /go/src/google.golang.org/grpc/server.go:689 +0x702
google.golang.org/grpc.(*Server).handleStream(0xc420526c80, 0x20bb4c0, 0xc4200e2bd0, 0xc420ce0b40, 0x0)
    /go/src/google.golang.org/grpc/server.go:773 +0xc36
google.golang.org/grpc.(*Server).serveStreams.func1.1(0xc4200e1130, 0xc420526c80, 0x20bb4c0, 0xc4200e2bd0, 0xc420ce0b40)
    /go/src/google.golang.org/grpc/server.go:422 +0xab
created by google.golang.org/grpc.(*Server).serveStreams.func1
    /go/src/google.golang.org/grpc/server.go:423 +0xa3

goroutine 16783 [select]:
github.com/cockroachdb/cockroach/storage.(*Store).processRaft.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2604 +0xf50
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e3830, 0xc420e826b0)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16579 [chan receive]:
github.com/cockroachdb/cockroach/storage.(*Store).processRaft.func1.1(0xc420e9f1a0)
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2523 +0x4a
created by github.com/cockroachdb/cockroach/storage.(*Store).processRaft.func1
    /go/src/github.com/cockroachdb/cockroach/storage/store.go:2526 +0xa7

goroutine 16588 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*baseQueue).processLoop.func1()
    /go/src/github.com/cockroachdb/cockroach/storage/queue.go:418 +0x2cc
github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker.func1(0xc4200e21b0, 0xc420f50c60)
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:187 +0x7d
created by github.com/cockroachdb/cockroach/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/util/stop/stopper.go:188 +0x66

goroutine 16817 [select, 1 minutes]:
github.com/cockroachdb/cockroach/storage.(*baseQueue).processLoop.func1()

Please assign, take a look and update the issue accordingly.

@tbg tbg added this to the Q2 milestone Sep 8, 2016
@tbg tbg added O-robot Originated from a bot. C-test-failure Broken test (automatically or manually discovered). labels Sep 8, 2016
@tamird
Copy link
Contributor

tamird commented Sep 8, 2016

Timeout during shutdown. Relevant stacks: https://gist.github.com/3b1ed2aa474014205d79fc7518374fe2

Lots of tasks stuck in dist sender. @tschottdorf?

@tamird
Copy link
Contributor

tamird commented Sep 8, 2016

Reassigning given that @spencerkimball was recently deep in DistSender.

@tamird tamird assigned spencerkimball and unassigned tbg Sep 8, 2016
mrtracy pushed a commit to mrtracy/cockroach that referenced this issue Sep 13, 2016
TestStoreMetrics had become flaky at some point due to a change in the way
intents are resolved. The change to resolution did not introduce the issue, it
simply exacerbated an existing problem in the test.

The issue occurred because intent resolution is asynchronous for "remote"
intents (not on the same range as the transaction record). This test does create
a few such intents; this test also stops stores before verifying metrics. With
the new resolution strategy, stopping a store was likely to create an unresolved
intent, meaning the intent count was 1.

This was incompatible with an existing "sanity check" that the intent count was
zero, a regression check for cockroachdb#4624. In order to keep the sanity check, I have
moved it into a succeedsSoon block *before* the stores are stopped.

This fixes cockroachdb#8437; however, the test now appears to be broken due to the same
underlying issue as cockroachdb#9204 (an infinite retry in distSender that prevents servers
from stopping). The test remains skipped, but the skip message has been
modified.
@mrtracy
Copy link
Contributor

mrtracy commented Sep 13, 2016

TestStoreMetrics is also failing with this reliably: https://circleci.com/gh/cockroachdb/cockroach/22634

That test stops and restarts stores (using multiTestContext); this issue occurs when one of the stores is unable to close. The stuck task does appear to be in DistSender.

TestStoreMetrics is currently skipped; #9311 is fixing another issue specific to that test, but leaves the test skipped with a new skip message.

@knz
Copy link
Contributor

knz commented Sep 30, 2016

@tamird
Copy link
Contributor

tamird commented Oct 4, 2016

Reproduces in 15 seconds on GCE with

make stress PKG=./storage STRESSFLAGS='-p 100 -stderr -maxfails 1' TESTTIMEOUT=15s TESTS=TestSplitSnapshotRace_SplitWins

The logs are full of:

W161004 14:56:10.102521 922 storage/store.go:2615  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
W161004 14:56:10.102558 922 storage/store.go:2615  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
W161004 14:56:10.102581 922 storage/store.go:2615  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
...
W161004 14:56:24.161683 922 storage/store.go:2615  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}

@jordanlewis
Copy link
Member

Even TeamCity knows this test is flaky: image

@tbg
Copy link
Member Author

tbg commented Oct 21, 2016

@tamird the above invocation

make stress PKG=./storage STRESSFLAGS='-p 100 -stderr -maxfails 1' TESTTIMEOUT=15s TESTS=TestSplitSnapshotRace_SplitWins

times out in mtc.replicateRange(rightRangeID, 4, 5), not at shutdown.

@tbg
Copy link
Member Author

tbg commented Oct 21, 2016

I'll take a look at this test.

@tbg tbg assigned tbg and unassigned spencerkimball Oct 21, 2016
@tbg
Copy link
Member Author

tbg commented Oct 21, 2016

# We try to replicate the range which currently lives on StoreID=2,3,4 (which is down and has missed a split) and we are in the process of replicating it up to node 4.
W161021 14:49:41.812482 22 storage/client_split_test.go:955  BEGIN REPLICATE
I161021 14:49:41.812852 22 storage/client_test.go:907  [add_replica=node_id:5 store_id:5 replica_id:0 ] change replicas


# Preemptive snapshot is generated (by Store 2) and applied by Store 5.
I161021 14:49:41.812985 22 storage/replica_raftstorage.go:446  [add_replica=node_id:5 store_id:5 replica_id:0 ,s2,r11/2:{"m"-/Max}] generated snapshot 9c59af22 for range 11 at index 10 in 76.699µs.
I161021 14:49:41.814831 22 storage/store.go:2965  [add_replica=node_id:5 store_id:5 replica_id:0 ] streamed snapshot: kv pairs: 29, log entries: 0
I161021 14:49:41.815016 1181 raft/raft.go:542  [s5] ffffffffffffffff became follower at term 0
I161021 14:49:41.815096 1181 raft/raft.go:302  [s5] newRaft ffffffffffffffff [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I161021 14:49:41.815111 1181 raft/raft.go:542  [s5] ffffffffffffffff became follower at term 1
I161021 14:49:41.815126 1181 raft/raft.go:661  [s5] ffffffffffffffff [term: 1] received a MsgSnap message with higher term from 2 [term: 5]
I161021 14:49:41.815139 1181 raft/raft.go:542  [s5] ffffffffffffffff became follower at term 5
I161021 14:49:41.815183 1181 raft/raft.go:1026  [s5] ffffffffffffffff [commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 10, term: 5]
I161021 14:49:41.815198 1181 raft/log.go:288  [s5] log [committed=0, applied=0, unstable.offset=1, len(unstable.Entries)=0] starts to restore snapshot [index: 10, term: 5]
I161021 14:49:41.815216 1181 raft/raft.go:1036  [s5] ffffffffffffffff restored progress of 1 [next = 11, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I161021 14:49:41.815232 1181 raft/raft.go:1036  [s5] ffffffffffffffff restored progress of 2 [next = 11, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I161021 14:49:41.815247 1181 raft/raft.go:1036  [s5] ffffffffffffffff restored progress of 3 [next = 11, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I161021 14:49:41.815259 1181 raft/raft.go:1003  [s5] ffffffffffffffff [commit: 10] restored snapshot [index: 10, term: 5]
I161021 14:49:41.815279 1181 storage/replica_raftstorage.go:577  [s5] [n5,s5,r11/?:{-}]: with replicaID [?], applying preemptive snapshot at index 10 (id=9c59af22, encoded size=16, 1 rocksdb batches, 0 log entries)
I161021 14:49:41.815588 1181 storage/replica_raftstorage.go:580  [s5] [n5,s5,r11/?:{"m"-/Max}]: with replicaID [?], applied preemptive snapshot in 0.000s
I161021 14:49:41.815940 22 storage/replica_command.go:3236  [add_replica=node_id:5 store_id:5 replica_id:0 ] change replicas: read existing descriptor range_id:11 start_key:"m" end_key:"\377\377" replicas:<node_id:4 store_id:4 replica_id:1 > replicas:<node_id:2 store_id:2 replica_id:2 > replicas:<node_id:3 store_id:3 replica_id:3 > next_replica_id:4 

# ChangeReplicas on Store 2 next proposes the batch which updates the RangeDescriptor. This will
# never return.
W161021 14:49:41.816094 1183 storage/replica.go:1525  [s2,r11/2:{"m"-/Max}] propose [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)

# Raft (Store 2) was probably quiesced, in any case it's coming up now and
# campaigns, but nobody responds. The proposal is dropped, so we're already
# going to have to wait for a tick-based reproposal.
# I haven't looked what happens below and I've got to run, but maybe someone sees right away.
I161021 14:49:41.816181 1183 raft/raft.go:542  [s2,r11/2:{"m"-/Max}] 2 became follower at term 5
I161021 14:49:41.816222 1183 raft/raft.go:302  [s2,r11/2:{"m"-/Max}] newRaft 2 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
I161021 14:49:41.816232 1183 raft/raft.go:635  [s2,r11/2:{"m"-/Max}] 2 is starting a new election at term 5
I161021 14:49:41.816241 1183 raft/raft.go:555  [s2,r11/2:{"m"-/Max}] 2 became candidate at term 6
I161021 14:49:41.816248 1183 raft/raft.go:608  [s2,r11/2:{"m"-/Max}] 2 received vote from 2 at term 6
I161021 14:49:41.816277 1183 raft/raft.go:596  [s2,r11/2:{"m"-/Max}] 2 [logterm: 5, index: 10] sent vote request to 3 at term 6
I161021 14:49:41.816319 1183 raft/raft.go:596  [s2,r11/2:{"m"-/Max}] 2 [logterm: 5, index: 10] sent vote request to 1 at term 6
I161021 14:49:41.816348 1183 raft/raft.go:890  [s2,r11/2:{"m"-/Max}] 2 no leader at term 6; dropping proposal
I161021 14:49:41.816387 231 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  SoftState updated: {Lead:0 RaftState:StateCandidate}
  HardState updated: {Term:6 Vote:2 Commit:10 XXX_unrecognized:[]}
  Outgoing Message[0]: 2->3 MsgVote Term:6 Log:5/10
  Outgoing Message[1]: 2->1 MsgVote Term:6 Log:5/10
I161021 14:49:41.817268 392 storage/raft.go:140  [s3,r2/3:/{System/Max-Max}] raft ready
  HardState updated: {Term:7 Vote:2 Commit:32 XXX_unrecognized:[]}
  New Entry[0]: 7/33 EntryNormal [11e8548d6bfe3373] GC [/System/Max,"\x05\x00")
  Committed Entry[0]: 7/32 EntryNormal [1382f3f4d5300f5e] [txn: 579030f0], EndTransaction [/Local/Range/"\x05"/RangeDescriptor,/Min)
  Outgoing Message[0]: 3->2 MsgAppResp Term:7 Log:0/32
  Outgoing Message[1]: 3->2 MsgAppResp Term:7 Log:0/33
  Outgoing Message[2]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:41.817517 233 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  HardState updated: {Term:7 Vote:2 Commit:33 XXX_unrecognized:[]}
  Committed Entry[0]: 7/33 EntryNormal [11e8548d6bfe3373] GC [/System/Max,"\x05\x00")
  Outgoing Message[0]: 2->3 MsgApp Term:7 Log:7/33 Commit:33
  Outgoing Message[1]: 2->4 MsgApp Term:7 Log:7/33 Commit:33
I161021 14:49:41.817985 338 raft/raft.go:542  [s3,r11/3:{-}] 3 became follower at term 0
I161021 14:49:41.818041 338 raft/raft.go:302  [s3,r11/3:{-}] newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I161021 14:49:41.818050 338 raft/raft.go:542  [s3,r11/3:{-}] 3 became follower at term 1
I161021 14:49:41.818062 338 raft/raft.go:661  [s3,r11/3:{-}] 3 [term: 1] received a MsgVote message with higher term from 2 [term: 6]
I161021 14:49:41.818068 338 raft/raft.go:542  [s3,r11/3:{-}] 3 became follower at term 6
I161021 14:49:41.818146 338 raft/raft.go:945  [s3,r11/3:{-}] 3 [logterm: 0, index: 0, vote: 0] voted for 2 [logterm: 5, index: 10] at term 6
I161021 14:49:41.818176 338 storage/raft.go:140  [s3,r11/3:{-}] raft ready
  HardState updated: {Term:6 Vote:2 Commit:0 XXX_unrecognized:[]}
  Outgoing Message[0]: 3->2 MsgVoteResp Term:6 Log:0/0
I161021 14:49:41.818329 235 raft/raft.go:608  [s2,r11/2:{"m"-/Max}] 2 received vote from 3 at term 6
I161021 14:49:41.818341 235 raft/raft.go:907  [s2,r11/2:{"m"-/Max}] 2 [quorum:2] has received 2 votes and 0 vote rejections
I161021 14:49:41.818353 235 raft/raft.go:582  [s2,r11/2:{"m"-/Max}] 2 became leader at term 6
I161021 14:49:41.818442 235 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  SoftState updated: {Lead:2 RaftState:StateLeader}
  New Entry[0]: 6/11 EntryNormal [empty]
  Outgoing Message[0]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty]]
  Outgoing Message[1]: 2->3 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty]]
W161021 14:49:41.818513 235 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonNewLeader
I161021 14:49:41.818593 235 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
I161021 14:49:41.818766 337 raft/raft.go:989  [s3,r11/3:{-}] 3 [logterm: 0, index: 10] rejected msgApp [logterm: 5, index: 10] from 2
I161021 14:49:41.818803 337 storage/raft.go:140  [s3,r11/3:{-}] raft ready
  SoftState updated: {Lead:2 RaftState:StateFollower}
  Outgoing Message[0]: 3->2 MsgAppResp Term:6 Log:0/10 Rejected
I161021 14:49:41.819847 392 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  HardState updated: {Term:7 Vote:2 Commit:33 XXX_unrecognized:[]}
  Committed Entry[0]: 7/33 EntryNormal [11e8548d6bfe3373] GC [/System/Max,"\x05\x00")
  Outgoing Message[0]: 3->2 MsgAppResp Term:7 Log:0/33
I161021 14:49:41.820252 239 raft/raft.go:770  [s2,r11/2:{"m"-/Max}] 2 received msgApp rejection(lastindex: 0) from 3 for index 10
I161021 14:49:41.820281 239 raft/raft.go:772  [s2,r11/2:{"m"-/Max}] 2 decreased progress of 3 to [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I161021 14:49:41.820307 239 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:41.821631 975 storage/store.go:2830  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
W161021 14:49:41.821654 975 storage/store.go:2830  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
W161021 14:49:41.821668 975 storage/store.go:2830  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
W161021 14:49:41.821795 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:41.821826 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:41.821849 975 storage/store.go:2830  [s2] got error from range 2, replica {4 4 4}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:4}
W161021 14:49:41.821992 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
I161021 14:49:41.863370 245 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:41.863433 245 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:41.863752 331 raft/raft.go:542  [s3,r11/3:{"m"-/Max}] 3 became follower at term 6
I161021 14:49:41.863803 331 raft/raft.go:302  [s3,r11/3:{"m"-/Max}] newRaft 3 [peers: [1,2,3], term: 6, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
I161021 14:49:41.863829 331 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:41.863864 331 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  SoftState updated: {Lead:2 RaftState:StateFollower}
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:41.863975 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:41.872958 938 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: a6c89c05], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:41.873155 122 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:56 XXX_unrecognized:[]}
  New Entry[0]: 6/56 EntryNormal [6900c542c8b5ab55] [txn: a6c89c05], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/56 EntryNormal [6900c542c8b5ab55] [txn: a6c89c05], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:41.883033 247 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:41.889543 1184 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d1685cf5], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:41.889873 123 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:57 XXX_unrecognized:[]}
  New Entry[0]: 6/57 EntryNormal [6f240468b0b3fc26] [txn: d1685cf5], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/57 EntryNormal [6f240468b0b3fc26] [txn: d1685cf5], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:41.902369 1113 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: b2512503], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:41.902612 124 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:58 XXX_unrecognized:[]}
  New Entry[0]: 6/58 EntryNormal [74d69727bc7a01a8] [txn: b2512503], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/58 EntryNormal [74d69727bc7a01a8] [txn: b2512503], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:41.962730 251 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:41.962834 251 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:41.968015 1061 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 5f421b96], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:41.968298 127 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:59 XXX_unrecognized:[]}
  New Entry[0]: 6/59 EntryNormal [00aefce6953fbc11] [txn: 5f421b96], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/59 EntryNormal [00aefce6953fbc11] [txn: 5f421b96], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:41.981173 1066 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d3e42ed6], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:41.981460 125 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:60 XXX_unrecognized:[]}
  New Entry[0]: 6/60 EntryNormal [48b9a3a5ef803a43] [txn: d3e42ed6], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/60 EntryNormal [48b9a3a5ef803a43] [txn: d3e42ed6], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.012462 346 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:42.012559 346 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.012744 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:42.027342 253 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.050872 1073 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: fc5fafdd], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.051037 128 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:61 XXX_unrecognized:[]}
  New Entry[0]: 6/61 EntryNormal [612de29911393e67] [txn: fc5fafdd], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/61 EntryNormal [612de29911393e67] [txn: fc5fafdd], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.062624 257 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:42.062691 257 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:42.062801 257 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:42.062918 257 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/13 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:42.063336 1191 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: bdb327ef], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.063528 131 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:62 XXX_unrecognized:[]}
  New Entry[0]: 6/62 EntryNormal [056a857aa8cb0876] [txn: bdb327ef], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/62 EntryNormal [056a857aa8cb0876] [txn: bdb327ef], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:42.064516 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:42.087328 1194 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 08ec3cbe], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.087491 132 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:63 XXX_unrecognized:[]}
  New Entry[0]: 6/63 EntryNormal [06578749881e796e] [txn: 08ec3cbe], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/63 EntryNormal [06578749881e796e] [txn: 08ec3cbe], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.111385 357 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:42.111494 357 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.111708 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:42.127458 261 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.149258 1236 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 8f936726], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.149547 130 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:64 XXX_unrecognized:[]}
  New Entry[0]: 6/64 EntryNormal [41c7b2d812544eba] [txn: 8f936726], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/64 EntryNormal [41c7b2d812544eba] [txn: 8f936726], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:42.162535 1224 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: cc1a4ac2], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.162821 134 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:65 XXX_unrecognized:[]}
  New Entry[0]: 6/65 EntryNormal [6eb4b2e9ecae9aaa] [txn: cc1a4ac2], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/65 EntryNormal [6eb4b2e9ecae9aaa] [txn: cc1a4ac2], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.163805 265 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:42.163891 265 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:42.211345 359 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:42.211420 359 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.211594 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:42.227342 266 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.230242 1243 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 9b3101c6], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.230547 135 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:66 XXX_unrecognized:[]}
  New Entry[0]: 6/66 EntryNormal [24fa91a6cdcda031] [txn: 9b3101c6], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/66 EntryNormal [24fa91a6cdcda031] [txn: 9b3101c6], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:42.242448 1231 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 0fdd9da2], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.242738 136 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:67 XXX_unrecognized:[]}
  New Entry[0]: 6/67 EntryNormal [477a1dee1ce59a6d] [txn: 0fdd9da2], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/67 EntryNormal [477a1dee1ce59a6d] [txn: 0fdd9da2], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:42.261226 1254 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: bad8c2ef], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.261487 74 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:68 XXX_unrecognized:[]}
  New Entry[0]: 6/68 EntryNormal [5660dc7c2bee4f95] [txn: bad8c2ef], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/68 EntryNormal [5660dc7c2bee4f95] [txn: bad8c2ef], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.281145 270 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:42.281264 270 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
I161021 14:49:42.312861 367 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
I161021 14:49:42.312931 367 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:42.313009 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:42.332186 1132 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 4424ad70], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.332461 76 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:69 XXX_unrecognized:[]}
  New Entry[0]: 6/69 EntryNormal [7884348387fcc6fb] [txn: 4424ad70], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/69 EntryNormal [7884348387fcc6fb] [txn: 4424ad70], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.334294 281 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.337195 1209 storage/replica.go:1525  [s3,r11/3:{"m"-/Max}] propose [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
W161021 14:49:42.352282 1134 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: e82e283a], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.352614 75 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:70 XXX_unrecognized:[]}
  New Entry[0]: 6/70 EntryNormal [0706802235a054f9] [txn: e82e283a], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/70 EntryNormal [0706802235a054f9] [txn: e82e283a], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.361191 276 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:42.361337 275 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:42.361486 275 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:42.361691 275 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/14 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:42.361999 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:42.410633 1136 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 0145fb52], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.411026 78 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:71 XXX_unrecognized:[]}
  New Entry[0]: 6/71 EntryNormal [3f77f45bd4439c2b] [txn: 0145fb52], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/71 EntryNormal [3f77f45bd4439c2b] [txn: 0145fb52], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.413000 372 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:42.414296 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:42.414349 373 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.422297 1256 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 971e508c], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.422585 79 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:72 XXX_unrecognized:[]}
  New Entry[0]: 6/72 EntryNormal [3caf12e5e119f404] [txn: 971e508c], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/72 EntryNormal [3caf12e5e119f404] [txn: 971e508c], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.427434 280 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.444525 1298 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: fb8da387], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.444805 80 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:73 XXX_unrecognized:[]}
  New Entry[0]: 6/73 EntryNormal [7b65850565c88138] [txn: fb8da387], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/73 EntryNormal [7b65850565c88138] [txn: fb8da387], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.466412 188 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:42.466507 188 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:42.508366 1287 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: e2454c1d], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.508663 82 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:74 XXX_unrecognized:[]}
  New Entry[0]: 6/74 EntryNormal [5943d0abbfebb553] [txn: e2454c1d], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/74 EntryNormal [5943d0abbfebb553] [txn: e2454c1d], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.516978 378 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:42.517057 378 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.517239 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:42.523180 1263 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 671b8f79], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.523456 85 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:75 XXX_unrecognized:[]}
  New Entry[0]: 6/75 EntryNormal [41dc2f60199601f0] [txn: 671b8f79], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/75 EntryNormal [41dc2f60199601f0] [txn: 671b8f79], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.527387 190 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:42.561228 193 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:42.561329 193 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:42.592958 1294 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 43b4beb5], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.604926 84 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:76 XXX_unrecognized:[]}
  New Entry[0]: 6/76 EntryNormal [4353ec4bbcdf6f50] [txn: 43b4beb5], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/76 EntryNormal [4353ec4bbcdf6f50] [txn: 43b4beb5], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:42.606896 1210 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 05eeba3e], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.607388 87 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:77 XXX_unrecognized:[]}
  New Entry[0]: 6/77 EntryNormal [36644be160e4b251] [txn: 05eeba3e], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/77 EntryNormal [36644be160e4b251] [txn: 05eeba3e], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.618219 382 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:42.618287 382 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.618445 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:42.620093 1213 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 6694468a], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.620373 89 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:78 XXX_unrecognized:[]}
  New Entry[0]: 6/78 EntryNormal [358b69080ea96add] [txn: 6694468a], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/78 EntryNormal [358b69080ea96add] [txn: 6694468a], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.627408 227 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:42.661949 231 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
W161021 14:49:42.662053 231 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:42.662225 231 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:42.662440 231 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/15 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
I161021 14:49:42.662949 386 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:42.663004 386 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.663098 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:42.663127 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:42.677881 234 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.688071 1362 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 13e50316], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.688352 91 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:79 XXX_unrecognized:[]}
  New Entry[0]: 6/79 EntryNormal [51bba1246fc41c84] [txn: 13e50316], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/79 EntryNormal [51bba1246fc41c84] [txn: 13e50316], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:42.701092 1340 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 7219b072], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.701324 90 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:80 XXX_unrecognized:[]}
  New Entry[0]: 6/80 EntryNormal [592b8219678c5f58] [txn: 7219b072], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/80 EntryNormal [592b8219678c5f58] [txn: 7219b072], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.761162 239 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:42.761937 239 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:42.762305 329 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:42.762374 329 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:42.762519 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:42.768773 1379 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: cac2ccbf], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.769034 92 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:81 XXX_unrecognized:[]}
  New Entry[0]: 6/81 EntryNormal [4dc097ea0f89a9fd] [txn: cac2ccbf], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/81 EntryNormal [4dc097ea0f89a9fd] [txn: cac2ccbf], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.777496 238 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.783030 1369 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: fc228da0], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.783321 93 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:82 XXX_unrecognized:[]}
  New Entry[0]: 6/82 EntryNormal [4f997957adfc0daf] [txn: fc228da0], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/82 EntryNormal [4f997957adfc0daf] [txn: fc228da0], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:42.800130 1371 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: a7e9024f], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.800431 94 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:83 XXX_unrecognized:[]}
  New Entry[0]: 6/83 EntryNormal [02f030a398a2070e] [txn: a7e9024f], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/83 EntryNormal [02f030a398a2070e] [txn: a7e9024f], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.863277 245 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:42.863377 245 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
I161021 14:49:42.863834 341 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
I161021 14:49:42.863892 341 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:42.863972 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:42.873255 1348 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 247c2b06], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.873563 95 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:84 XXX_unrecognized:[]}
  New Entry[0]: 6/84 EntryNormal [6afe193ee4ef8cb7] [txn: 247c2b06], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/84 EntryNormal [6afe193ee4ef8cb7] [txn: 247c2b06], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:42.879897 247 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:42.881178 1350 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 335c3221], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:42.881485 97 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:85 XXX_unrecognized:[]}
  New Entry[0]: 6/85 EntryNormal [710fb8f3e0320fdf] [txn: 335c3221], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/85 EntryNormal [710fb8f3e0320fdf] [txn: 335c3221], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
W161021 14:49:42.949337 1399 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 3a9e154b], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:42.949605 100 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:86 XXX_unrecognized:[]}
  New Entry[0]: 6/86 EntryNormal [493c15168a532275] [txn: 3a9e154b], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/86 EntryNormal [493c15168a532275] [txn: 3a9e154b], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:42.965142 1406 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: de6a9133], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.965425 99 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:87 XXX_unrecognized:[]}
  New Entry[0]: 6/87 EntryNormal [2679bbf7f080e158] [txn: de6a9133], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/87 EntryNormal [2679bbf7f080e158] [txn: de6a9133], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:42.966681 251 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
W161021 14:49:42.966764 251 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:42.966825 251 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:42.967151 251 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/16 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:42.968384 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:42.985218 1305 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 7dd10131], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:42.985507 101 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:88 XXX_unrecognized:[]}
  New Entry[0]: 6/88 EntryNormal [74a03150aa67eaa9] [txn: 7dd10131], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/88 EntryNormal [74a03150aa67eaa9] [txn: 7dd10131], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.011526 362 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.011592 362 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.011669 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.027683 272 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:43.048644 1426 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 6235c937], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:43.048921 104 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:89 XXX_unrecognized:[]}
  New Entry[0]: 6/89 EntryNormal [2ea4bc34fce37712] [txn: 6235c937], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/89 EntryNormal [2ea4bc34fce37712] [txn: 6235c937], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:43.061277 1445 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 9c22f127], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.061568 103 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:90 XXX_unrecognized:[]}
  New Entry[0]: 6/90 EntryNormal [2419818796e3ea33] [txn: 9c22f127], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/90 EntryNormal [2419818796e3ea33] [txn: 9c22f127], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.063272 259 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:43.063366 259 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:43.063736 348 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.063796 348 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.063942 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.077502 261 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:43.128735 1307 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: bebb9c16], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:43.129002 105 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:91 XXX_unrecognized:[]}
  New Entry[0]: 6/91 EntryNormal [5f399dc9934df394] [txn: bebb9c16], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/91 EntryNormal [5f399dc9934df394] [txn: bebb9c16], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:43.144223 1458 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 22f5a11d], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:43.144501 106 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:92 XXX_unrecognized:[]}
  New Entry[0]: 6/92 EntryNormal [77514114283e4df0] [txn: 22f5a11d], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/92 EntryNormal [77514114283e4df0] [txn: 22f5a11d], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:43.161351 265 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:43.161450 265 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:43.161805 1460 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: c91900f5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.162086 109 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:93 XXX_unrecognized:[]}
  New Entry[0]: 6/93 EntryNormal [404989a488053292] [txn: c91900f5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/93 EntryNormal [404989a488053292] [txn: c91900f5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.163416 354 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.163484 354 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.164065 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.179002 266 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:43.230128 1433 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: dd94b4f3], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:43.230456 108 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:94 XXX_unrecognized:[]}
  New Entry[0]: 6/94 EntryNormal [33020200261dddb8] [txn: dd94b4f3], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/94 EntryNormal [33020200261dddb8] [txn: dd94b4f3], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:43.241727 1412 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 3a7fe5f9], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.242006 110 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:95 XXX_unrecognized:[]}
  New Entry[0]: 6/95 EntryNormal [70228752c1e368e8] [txn: 3a7fe5f9], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/95 EntryNormal [70228752c1e368e8] [txn: 3a7fe5f9], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.263545 270 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:43.263636 270 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:43.263797 270 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:43.264064 270 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/17 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
I161021 14:49:43.264653 363 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.264716 363 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.264802 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:43.264824 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.278994 274 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:43.309252 1467 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: a634c655], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:43.309504 112 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:96 XXX_unrecognized:[]}
  New Entry[0]: 6/96 EntryNormal [6e4fca88987db0a6] [txn: a634c655], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/96 EntryNormal [6e4fca88987db0a6] [txn: a634c655], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:43.322224 1440 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d43e5caf], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:43.322487 114 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:97 XXX_unrecognized:[]}
  New Entry[0]: 6/97 EntryNormal [212f01d205bad08c] [txn: d43e5caf], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/97 EntryNormal [212f01d205bad08c] [txn: d43e5caf], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:43.342157 1490 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 83d23141], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.342416 113 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:98 XXX_unrecognized:[]}
  New Entry[0]: 6/98 EntryNormal [5825a1080db9dfd9] [txn: 83d23141], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/98 EntryNormal [5825a1080db9dfd9] [txn: 83d23141], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.362675 275 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:43.362769 275 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:43.408062 1457 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 71ed1330], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:43.408384 116 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:99 XXX_unrecognized:[]}
  New Entry[0]: 6/99 EntryNormal [19843c12f0d63d12] [txn: 71ed1330], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/99 EntryNormal [19843c12f0d63d12] [txn: 71ed1330], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:43.411333 369 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.411405 369 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.411558 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:43.423672 1419 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 7392c385], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.423915 117 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:100 XXX_unrecognized:[]}
  New Entry[0]: 6/100 EntryNormal [74d4797dacc37fad] [txn: 7392c385], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/100 EntryNormal [74d4797dacc37fad] [txn: 7392c385], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.428922 278 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:43.461186 188 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:43.461299 188 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:43.488826 1522 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: dfe84a01], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:43.489105 119 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:101 XXX_unrecognized:[]}
  New Entry[0]: 6/101 EntryNormal [687804ed2fc56e02] [txn: dfe84a01], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/101 EntryNormal [687804ed2fc56e02] [txn: dfe84a01], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:43.502265 1512 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 9f6cf92b], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:43.502503 120 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:102 XXX_unrecognized:[]}
  New Entry[0]: 6/102 EntryNormal [081efed180aef874] [txn: 9f6cf92b], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/102 EntryNormal [081efed180aef874] [txn: 9f6cf92b], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:43.511386 373 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.511453 373 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.511606 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:43.520165 1492 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 054b8512], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.520479 121 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:103 XXX_unrecognized:[]}
  New Entry[0]: 6/103 EntryNormal [4d2feceb8d6ce52b] [txn: 054b8512], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/103 EntryNormal [4d2feceb8d6ce52b] [txn: 054b8512], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.533095 190 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:43.561196 193 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:43.561301 193 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:43.561455 193 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:43.561736 193 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/18 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:43.562121 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:43.588556 1529 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: c9d149b0], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:43.588850 123 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:104 XXX_unrecognized:[]}
  New Entry[0]: 6/104 EntryNormal [4a79c83e27aab66b] [txn: c9d149b0], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/104 EntryNormal [4a79c83e27aab66b] [txn: c9d149b0], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:43.605472 1533 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 9f5806c5], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.605736 124 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:105 XXX_unrecognized:[]}
  New Entry[0]: 6/105 EntryNormal [6986c70a16085d2c] [txn: 9f5806c5], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/105 EntryNormal [6986c70a16085d2c] [txn: 9f5806c5], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.611281 380 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.611363 380 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.611528 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.628716 230 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:43.666484 228 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:43.666584 228 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:43.682285 1519 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 3b9dfd1c], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:43.682549 127 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:106 XXX_unrecognized:[]}
  New Entry[0]: 6/106 EntryNormal [37f870050028b9a2] [txn: 3b9dfd1c], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/106 EntryNormal [37f870050028b9a2] [txn: 3b9dfd1c], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:43.683770 1521 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 526698d3], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:43.684020 125 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:107 XXX_unrecognized:[]}
  New Entry[0]: 6/107 EntryNormal [1929ec93626b347c] [txn: 526698d3], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/107 EntryNormal [1929ec93626b347c] [txn: 526698d3], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:43.700714 1561 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: ebbf1e88], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.700987 129 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:108 XXX_unrecognized:[]}
  New Entry[0]: 6/108 EntryNormal [54e48c90f9f3cf91] [txn: ebbf1e88], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/108 EntryNormal [54e48c90f9f3cf91] [txn: ebbf1e88], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.719228 383 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.719299 383 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.719455 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.728913 234 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:43.765673 239 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:43.765804 239 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:43.768112 1563 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 02fc019e], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:43.768367 131 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:109 XXX_unrecognized:[]}
  New Entry[0]: 6/109 EntryNormal [651857746cf67de3] [txn: 02fc019e], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/109 EntryNormal [651857746cf67de3] [txn: 02fc019e], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:43.781202 1578 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: c8398722], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.781488 132 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:110 XXX_unrecognized:[]}
  New Entry[0]: 6/110 EntryNormal [15b65a1d737aba6e] [txn: c8398722], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/110 EntryNormal [15b65a1d737aba6e] [txn: c8398722], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.811293 389 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.811362 389 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.811512 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.828881 238 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:43.848886 1585 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: ff77936d], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:43.849130 130 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:111 XXX_unrecognized:[]}
  New Entry[0]: 6/111 EntryNormal [7a08e3a83380f37d] [txn: ff77936d], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/111 EntryNormal [7a08e3a83380f37d] [txn: ff77936d], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:43.862026 245 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:43.862121 245 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:43.862281 245 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:43.862589 245 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/19 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:43.863090 1482 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 7e4ee27e], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:43.863346 134 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:112 XXX_unrecognized:[]}
  New Entry[0]: 6/112 EntryNormal [4bcf1cafa564f20f] [txn: 7e4ee27e], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/112 EntryNormal [4bcf1cafa564f20f] [txn: 7e4ee27e], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:43.864349 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:43.884781 1156 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 75558755], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.885720 135 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:113 XXX_unrecognized:[]}
  New Entry[0]: 6/113 EntryNormal [5360ce25037403d2] [txn: 75558755], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/113 EntryNormal [5360ce25037403d2] [txn: 75558755], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:43.911501 337 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:43.911602 337 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:43.911836 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.966418 246 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:43.967077 246 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:43.984515 1593 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: fe4a2d82], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.992490 73 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:114 XXX_unrecognized:[]}
  New Entry[0]: 6/114 EntryNormal [5a9fa450e06d6970] [txn: fe4a2d82], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/114 EntryNormal [5a9fa450e06d6970] [txn: fe4a2d82], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:43.992932 246 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:43.993183 1539 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 5fe6d824], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:43.993243 342 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:43.993354 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:43.993435 74 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:115 XXX_unrecognized:[]}
  New Entry[0]: 6/115 EntryNormal [57b737a262e15fb4] [txn: 5fe6d824], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/115 EntryNormal [57b737a262e15fb4] [txn: 5fe6d824], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.012958 333 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.013060 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.027839 272 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.033032 1295 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d5b48d1d], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:44.033310 76 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:116 XXX_unrecognized:[]}
  New Entry[0]: 6/116 EntryNormal [5afd2e8dd4e79733] [txn: d5b48d1d], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/116 EntryNormal [5afd2e8dd4e79733] [txn: d5b48d1d], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:44.042373 1597 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 62a347df], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.042672 77 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:117 XXX_unrecognized:[]}
  New Entry[0]: 6/117 EntryNormal [4617589a57de4e24] [txn: 62a347df], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/117 EntryNormal [4617589a57de4e24] [txn: 62a347df], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.061183 259 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:44.061282 259 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:44.061625 1636 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: eaff7d4f], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.061896 78 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:118 XXX_unrecognized:[]}
  New Entry[0]: 6/118 EntryNormal [09f18b78493f21bb] [txn: eaff7d4f], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/118 EntryNormal [09f18b78493f21bb] [txn: eaff7d4f], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.062956 344 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:44.063014 344 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.063582 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.077489 261 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.127945 1606 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: ec3cf951], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.128237 79 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:119 XXX_unrecognized:[]}
  New Entry[0]: 6/119 EntryNormal [230c6fb1ef5a7256] [txn: ec3cf951], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/119 EntryNormal [230c6fb1ef5a7256] [txn: ec3cf951], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:44.141267 1650 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: bea9430e], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.141575 80 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:120 XXX_unrecognized:[]}
  New Entry[0]: 6/120 EntryNormal [237165c97fbcc1f0] [txn: bea9430e], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/120 EntryNormal [237165c97fbcc1f0] [txn: bea9430e], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.162133 265 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:44.162247 265 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:44.162408 265 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:44.162769 265 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/20 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
I161021 14:49:44.166577 345 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:44.166641 345 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.166734 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:44.166757 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.184368 264 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.216700 1652 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 47926af0], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:44.216968 82 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:121 XXX_unrecognized:[]}
  New Entry[0]: 6/121 EntryNormal [33ff1d651d267971] [txn: 47926af0], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/121 EntryNormal [33ff1d651d267971] [txn: 47926af0], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:44.223481 1623 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 66021732], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.223764 85 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:122 XXX_unrecognized:[]}
  New Entry[0]: 6/122 EntryNormal [35a329e8ef1ff02a] [txn: 66021732], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/122 EntryNormal [35a329e8ef1ff02a] [txn: 66021732], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:44.244766 1631 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: ec555875], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.245046 86 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:123 XXX_unrecognized:[]}
  New Entry[0]: 6/123 EntryNormal [5235c5c24391b0ba] [txn: ec555875], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/123 EntryNormal [5235c5c24391b0ba] [txn: ec555875], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.264004 269 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:44.264100 269 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:44.265407 351 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:44.265472 351 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.265638 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.285488 274 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.308102 1656 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 3cd318a9], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.308399 87 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:124 XXX_unrecognized:[]}
  New Entry[0]: 6/124 EntryNormal [3490693816e2f483] [txn: 3cd318a9], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/124 EntryNormal [3490693816e2f483] [txn: 3cd318a9], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:44.326089 1643 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d04d753f], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.326349 89 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:125 XXX_unrecognized:[]}
  New Entry[0]: 6/125 EntryNormal [2658664547c3379a] [txn: d04d753f], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/125 EntryNormal [2658664547c3379a] [txn: d04d753f], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.364836 275 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:44.364937 275 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:44.365470 358 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
I161021 14:49:44.365527 358 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:44.365602 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.381867 278 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.394472 1675 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 8ee6c915], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:44.394720 91 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:126 XXX_unrecognized:[]}
  New Entry[0]: 6/126 EntryNormal [59fcec4ce719b140] [txn: 8ee6c915], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/126 EntryNormal [59fcec4ce719b140] [txn: 8ee6c915], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:44.402223 1677 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 273df0d9], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.402456 90 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:127 XXX_unrecognized:[]}
  New Entry[0]: 6/127 EntryNormal [3c0c4fb543290389] [txn: 273df0d9], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/127 EntryNormal [3c0c4fb543290389] [txn: 273df0d9], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:44.420293 1273 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: b4a523f5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.420602 88 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:128 XXX_unrecognized:[]}
  New Entry[0]: 6/128 EntryNormal [394e8b715c1de86e] [txn: b4a523f5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/128 EntryNormal [394e8b715c1de86e] [txn: b4a523f5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.461147 188 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:44.461251 188 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:44.461439 188 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:44.461850 188 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/21 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:44.462173 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:44.487952 1647 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 1679fc97], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.488208 93 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:129 XXX_unrecognized:[]}
  New Entry[0]: 6/129 EntryNormal [4f8a5d47fe3adb40] [txn: 1679fc97], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/129 EntryNormal [4f8a5d47fe3adb40] [txn: 1679fc97], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:44.501170 1278 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 08d0ce5b], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.501430 94 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:130 XXX_unrecognized:[]}
  New Entry[0]: 6/130 EntryNormal [403376a989f17a2c] [txn: 08d0ce5b], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/130 EntryNormal [403376a989f17a2c] [txn: 08d0ce5b], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
W161021 14:49:44.502438 1280 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose TruncateLog [/Min,/Min)
I161021 14:49:44.502585 96 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:131 XXX_unrecognized:[]}
  New Entry[0]: 6/131 EntryNormal [5fe3d4ccd33e5a03] TruncateLog [/Min,/Min)
  Committed Entry[0]: 6/131 EntryNormal [5fe3d4ccd33e5a03] TruncateLog [/Min,/Min)
I161021 14:49:44.511335 370 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:44.511413 370 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.511569 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.527445 254 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:44.563158 191 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
I161021 14:49:44.563253 191 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
W161021 14:49:44.568881 1281 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 10a1f75e], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:44.569129 97 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:132 XXX_unrecognized:[]}
  New Entry[0]: 6/132 EntryNormal [7de1309b021d51d4] [txn: 10a1f75e], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/132 EntryNormal [7de1309b021d51d4] [txn: 10a1f75e], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:44.582231 1747 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: a6b6de07], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.582557 98 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:133 XXX_unrecognized:[]}
  New Entry[0]: 6/133 EntryNormal [781ae69422787fe8] [txn: a6b6de07], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/133 EntryNormal [781ae69422787fe8] [txn: a6b6de07], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:44.601294 1726 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d20965e1], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.601551 100 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:134 XXX_unrecognized:[]}
  New Entry[0]: 6/134 EntryNormal [0de7ebb162dbe1f4] [txn: d20965e1], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/134 EntryNormal [0de7ebb162dbe1f4] [txn: d20965e1], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.612913 376 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
I161021 14:49:44.612985 376 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:44.613056 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.630740 230 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.669740 1765 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 65c1afae], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.670000 101 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:135 XXX_unrecognized:[]}
  New Entry[0]: 6/135 EntryNormal [7c36229a14f2f90a] [txn: 65c1afae], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/135 EntryNormal [7c36229a14f2f90a] [txn: 65c1afae], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.670623 228 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:44.670702 228 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:44.681291 1733 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 1b27974f], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.681615 102 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:136 XXX_unrecognized:[]}
  New Entry[0]: 6/136 EntryNormal [65ba40966b3a5777] [txn: 1b27974f], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/136 EntryNormal [65ba40966b3a5777] [txn: 1b27974f], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.712070 334 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:44.712142 334 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.712295 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.727517 231 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.757169 1759 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 9299373b], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:44.757426 103 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:137 XXX_unrecognized:[]}
  New Entry[0]: 6/137 EntryNormal [69cd7cb1f6eb7394] [txn: 9299373b], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/137 EntryNormal [69cd7cb1f6eb7394] [txn: 9299373b], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:44.771990 1700 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 6bd65d26], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.772267 105 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:138 XXX_unrecognized:[]}
  New Entry[0]: 6/138 EntryNormal [3fbd67816ca9f6cc] [txn: 6bd65d26], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/138 EntryNormal [3fbd67816ca9f6cc] [txn: 6bd65d26], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:44.772998 239 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:44.773067 239 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:44.773613 239 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/22 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
I161021 14:49:44.773799 239 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
W161021 14:49:44.781150 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:44.781579 1768 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 1f7531df], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.781794 106 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:139 XXX_unrecognized:[]}
  New Entry[0]: 6/139 EntryNormal [2c35df2e5ccc327e] [txn: 1f7531df], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/139 EntryNormal [2c35df2e5ccc327e] [txn: 1f7531df], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.811532 386 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
I161021 14:49:44.811611 386 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:44.811696 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.827438 241 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.847987 1761 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: b65c554f], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.848263 109 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:140 XXX_unrecognized:[]}
  New Entry[0]: 6/140 EntryNormal [1671a90253e48b35] [txn: b65c554f], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/140 EntryNormal [1671a90253e48b35] [txn: b65c554f], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:44.864555 244 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:44.864667 244 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:44.865001 1784 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: e699b212], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.865264 108 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:141 XXX_unrecognized:[]}
  New Entry[0]: 6/141 EntryNormal [6cd29b11339cd181] [txn: e699b212], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/141 EntryNormal [6cd29b11339cd181] [txn: e699b212], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:44.866399 338 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:44.866457 338 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.867025 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.877364 247 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:44.928751 1772 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 244d9b3f], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:44.928992 110 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:142 XXX_unrecognized:[]}
  New Entry[0]: 6/142 EntryNormal [640234b8dd3a5d70] [txn: 244d9b3f], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/142 EntryNormal [640234b8dd3a5d70] [txn: 244d9b3f], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:44.942182 1776 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 95b86bb1], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.942498 111 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:143 XXX_unrecognized:[]}
  New Entry[0]: 6/143 EntryNormal [4392fe5f5f594ed3] [txn: 95b86bb1], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/143 EntryNormal [4392fe5f5f594ed3] [txn: 95b86bb1], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:44.962569 250 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:44.962679 250 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:44.963021 1743 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 48e3e3e7], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.963265 114 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:144 XXX_unrecognized:[]}
  New Entry[0]: 6/144 EntryNormal [02b7cb1fc3d0f881] [txn: 48e3e3e7], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/144 EntryNormal [02b7cb1fc3d0f881] [txn: 48e3e3e7], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:44.964099 336 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:44.964177 336 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:44.964354 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:44.978626 272 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:45.027967 1800 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 9739b650], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.028219 113 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:145 XXX_unrecognized:[]}
  New Entry[0]: 6/145 EntryNormal [365df4c9c9122653] [txn: 9739b650], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/145 EntryNormal [365df4c9c9122653] [txn: 9739b650], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:45.043991 1705 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 903accbe], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.044270 115 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:146 XXX_unrecognized:[]}
  New Entry[0]: 6/146 EntryNormal [2408656ad766df2b] [txn: 903accbe], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/146 EntryNormal [2408656ad766df2b] [txn: 903accbe], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
W161021 14:49:45.069407 259 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:45.069658 255 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:45.069678 259 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:45.070544 259 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/23 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:45.071007 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:45.108938 1826 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d1fe84ad], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:45.109236 117 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:147 XXX_unrecognized:[]}
  New Entry[0]: 6/147 EntryNormal [321e470d331e531b] [txn: d1fe84ad], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/147 EntryNormal [321e470d331e531b] [txn: d1fe84ad], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:45.116917 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:45.116971 332 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:45.117034 333 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:45.122630 1833 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 4e610327], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.122923 118 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:148 XXX_unrecognized:[]}
  New Entry[0]: 6/148 EntryNormal [75f6a8b71f4c813f] [txn: 4e610327], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/148 EntryNormal [75f6a8b71f4c813f] [txn: 4e610327], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.128001 256 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:45.140134 1540 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 881265b5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.140413 119 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:149 XXX_unrecognized:[]}
  New Entry[0]: 6/149 EntryNormal [494d58ea41a695cd] [txn: 881265b5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/149 EntryNormal [494d58ea41a695cd] [txn: 881265b5], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.161173 260 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:45.161275 265 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:45.208638 1840 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: c1572858], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.208930 121 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:150 XXX_unrecognized:[]}
  New Entry[0]: 6/150 EntryNormal [540f47d5435722a1] [txn: c1572858], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/150 EntryNormal [540f47d5435722a1] [txn: c1572858], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.213792 348 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
I161021 14:49:45.213868 348 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:45.214052 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:45.221324 1546 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 0c9cb89c], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.221661 122 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:151 XXX_unrecognized:[]}
  New Entry[0]: 6/151 EntryNormal [3ebf5350fed5e62d] [txn: 0c9cb89c], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/151 EntryNormal [3ebf5350fed5e62d] [txn: 0c9cb89c], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.227436 264 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:45.261191 269 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:45.261291 269 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:45.289436 1553 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 891871c0], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:45.289700 124 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:152 XXX_unrecognized:[]}
  New Entry[0]: 6/152 EntryNormal [526ad0d14a8ca331] [txn: 891871c0], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/152 EntryNormal [526ad0d14a8ca331] [txn: 891871c0], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:45.302259 1806 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 67d16811], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.302550 126 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:153 XXX_unrecognized:[]}
  New Entry[0]: 6/153 EntryNormal [79f680dacdbf6b0f] [txn: 67d16811], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/153 EntryNormal [79f680dacdbf6b0f] [txn: 67d16811], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.312822 354 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:45.312893 354 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:45.313053 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:45.320073 1808 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 58c2bd83], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.320356 127 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:154 XXX_unrecognized:[]}
  New Entry[0]: 6/154 EntryNormal [128ebc7dc834efd4] [txn: 58c2bd83], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/154 EntryNormal [128ebc7dc834efd4] [txn: 58c2bd83], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.330595 274 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:45.362961 275 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:45.363059 275 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:45.363243 275 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:45.363723 275 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/24 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
I161021 14:49:45.364362 355 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:45.364421 355 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:45.364529 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:45.364555 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:45.377872 277 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:45.388017 1707 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: a1646614], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.388317 129 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:155 XXX_unrecognized:[]}
  New Entry[0]: 6/155 EntryNormal [7a5d9d2b3143df44] [txn: a1646614], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/155 EntryNormal [7a5d9d2b3143df44] [txn: a1646614], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:45.405779 1890 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 30763816], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.406081 128 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:156 XXX_unrecognized:[]}
  New Entry[0]: 6/156 EntryNormal [66208dc0372020a8] [txn: 30763816], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/156 EntryNormal [66208dc0372020a8] [txn: 30763816], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
W161021 14:49:45.476926 1876 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: ba3abd2c], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:45.477236 132 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:157 XXX_unrecognized:[]}
  New Entry[0]: 6/157 EntryNormal [20c04caf7fdf2256] [txn: ba3abd2c], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/157 EntryNormal [20c04caf7fdf2256] [txn: ba3abd2c], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:45.483890 282 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:45.484032 188 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:45.484297 1878 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 19c65728], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.484592 133 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:158 XXX_unrecognized:[]}
  New Entry[0]: 6/158 EntryNormal [093a45a26f929c33] [txn: 19c65728], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/158 EntryNormal [093a45a26f929c33] [txn: 19c65728], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:45.500708 1709 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: c632478d], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.511767 130 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:159 XXX_unrecognized:[]}
  New Entry[0]: 6/159 EntryNormal [53432adb81f63064] [txn: c632478d], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/159 EntryNormal [53432adb81f63064] [txn: c632478d], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.512943 368 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:45.513003 368 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:45.513602 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:45.527463 254 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
I161021 14:49:45.561441 191 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:45.561548 191 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:45.568550 1886 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 20f74456], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.568904 135 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:160 XXX_unrecognized:[]}
  New Entry[0]: 6/160 EntryNormal [6e7e46800519490e] [txn: 20f74456], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/160 EntryNormal [6e7e46800519490e] [txn: 20f74456], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:45.585894 1903 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: b321185e], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.586183 136 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:161 XXX_unrecognized:[]}
  New Entry[0]: 6/161 EntryNormal [0096a7295226fe73] [txn: b321185e], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/161 EntryNormal [0096a7295226fe73] [txn: b321185e], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.614035 374 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:45.614128 374 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:45.614283 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:45.631908 230 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:45.654203 1913 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 28eb6f22], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:45.654478 74 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:162 XXX_unrecognized:[]}
  New Entry[0]: 6/162 EntryNormal [30842d06d7f46c5a] [txn: 28eb6f22], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/162 EntryNormal [30842d06d7f46c5a] [txn: 28eb6f22], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:45.662524 228 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
W161021 14:49:45.668197 229 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:45.668372 229 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:45.668879 229 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/25 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:45.669220 1712 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: eef8f43d], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.669455 76 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:163 XXX_unrecognized:[]}
  New Entry[0]: 6/163 EntryNormal [059a46fe22618c21] [txn: eef8f43d], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/163 EntryNormal [059a46fe22618c21] [txn: eef8f43d], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
W161021 14:49:45.670328 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:45.682600 1917 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: e23e505b], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.682848 77 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:164 XXX_unrecognized:[]}
  New Entry[0]: 6/164 EntryNormal [7da0fcedd0b29cd7] [txn: e23e505b], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/164 EntryNormal [7da0fcedd0b29cd7] [txn: e23e505b], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.720228 360 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:45.720309 360 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:45.720384 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:45.731050 233 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:45.747940 1925 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: bd8b278f], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.748189 78 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:165 XXX_unrecognized:[]}
  New Entry[0]: 6/165 EntryNormal [121a06a7cd6d36fa] [txn: bd8b278f], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/165 EntryNormal [121a06a7cd6d36fa] [txn: bd8b278f], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.767009 235 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:45.767115 235 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:45.767520 1919 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: dc3d0993], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.767763 79 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:166 XXX_unrecognized:[]}
  New Entry[0]: 6/166 EntryNormal [3d139b7eac108e48] [txn: dc3d0993], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/166 EntryNormal [3d139b7eac108e48] [txn: dc3d0993], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.771636 382 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:45.771705 382 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:45.771881 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:45.779325 241 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:45.829486 1943 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 8f673fce], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:45.829759 80 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:167 XXX_unrecognized:[]}
  New Entry[0]: 6/167 EntryNormal [436425bbc7f601b3] [txn: 8f673fce], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/167 EntryNormal [436425bbc7f601b3] [txn: 8f673fce], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
W161021 14:49:45.842804 1927 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 14d4754b], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.843111 81 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:168 XXX_unrecognized:[]}
  New Entry[0]: 6/168 EntryNormal [165613185784972d] [txn: 14d4754b], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/168 EntryNormal [165613185784972d] [txn: 14d4754b], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:45.861895 244 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
I161021 14:49:45.861995 244 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  Outgoing Message[0]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->3 MsgHeartbeat Term:6 Log:0/0
W161021 14:49:45.862385 1962 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: d567746a], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.862635 85 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:169 XXX_unrecognized:[]}
  New Entry[0]: 6/169 EntryNormal [4aa45b5bea517ed8] [txn: d567746a], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
  Committed Entry[0]: 6/169 EntryNormal [4aa45b5bea517ed8] [txn: d567746a], BeginTransaction [/System/NodeLiveness/3,/Min), ConditionalPut [/System/NodeLiveness/3,/Min), EndTransaction [/System/NodeLiveness/3,/Min)
I161021 14:49:45.863806 385 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
W161021 14:49:45.869405 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
I161021 14:49:45.869460 386 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
I161021 14:49:45.877371 247 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable
W161021 14:49:45.927785 1929 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 40a263d8], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
I161021 14:49:45.927964 86 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:170 XXX_unrecognized:[]}
  New Entry[0]: 6/170 EntryNormal [7a40fa6df135ee32] [txn: 40a263d8], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
  Committed Entry[0]: 6/170 EntryNormal [7a40fa6df135ee32] [txn: 40a263d8], BeginTransaction [/System/NodeLiveness/5,/Min), ConditionalPut [/System/NodeLiveness/5,/Min), EndTransaction [/System/NodeLiveness/5,/Min)
W161021 14:49:45.942467 1936 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 28d833c2], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.942748 84 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:171 XXX_unrecognized:[]}
  New Entry[0]: 6/171 EntryNormal [7c89991edd13485f] [txn: 28d833c2], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
  Committed Entry[0]: 6/171 EntryNormal [7c89991edd13485f] [txn: 28d833c2], BeginTransaction [/System/NodeLiveness/6,/Min), ConditionalPut [/System/NodeLiveness/6,/Min), EndTransaction [/System/NodeLiveness/6,/Min)
I161021 14:49:45.961919 250 storage/raft.go:140  [s2,r2/2:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:7 Log:0/0 Commit:33
  Outgoing Message[1]: 2->4 MsgHeartbeat Term:7 Log:0/0 Commit:28
W161021 14:49:45.961939 243 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonTicks
I161021 14:49:45.962012 243 raft/raft.go:355  [s2,r11/2:{"m"-/Max}] ignore sending snapshot to 3 since it is not recently active
I161021 14:49:45.962689 243 storage/raft.go:140  [s2,r11/2:{"m"-/Max}] raft ready
  New Entry[0]: 6/26 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [/Local/Range/"m"/RangeDescriptor,/Min)
  Outgoing Message[0]: 2->3 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[1]: 2->1 MsgHeartbeat Term:6 Log:0/0
  Outgoing Message[2]: 2->1 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal [empty], 6/12 EntryNormal [1dec217d05b39d4d] [txn: 571db887], BeginTransaction [/Local/Range/"m"/RangeDescriptor,/Min), ConditionalPut [
W161021 14:49:45.965256 975 storage/store.go:2830  [s2] got error from range 11, replica {4 4 1}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:2}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:1}
W161021 14:49:46.009128 1966 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: 83e96cda], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:46.009401 89 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:172 XXX_unrecognized:[]}
  New Entry[0]: 6/172 EntryNormal [0fa63d551b136952] [txn: 83e96cda], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
  Committed Entry[0]: 6/172 EntryNormal [0fa63d551b136952] [txn: 83e96cda], BeginTransaction [/System/NodeLiveness/1,/Min), ConditionalPut [/System/NodeLiveness/1,/Min), EndTransaction [/System/NodeLiveness/1,/Min)
I161021 14:49:46.011481 330 storage/raft.go:140  [s3,r2/3:{/System/Max-"m"}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:7 Log:0/0
I161021 14:49:46.011545 330 storage/raft.go:140  [s3,r11/3:{"m"-/Max}] raft ready
  Outgoing Message[0]: 3->2 MsgHeartbeatResp Term:6 Log:0/0
W161021 14:49:46.011698 975 storage/store.go:2830  [s2] got error from range 0, replica {4 4 0}: storage/raft_transport.go:247: unable to accept Raft message from {NodeID:2 StoreID:2 ReplicaID:0}: no handler registered for {NodeID:4 StoreID:4 ReplicaID:0}
W161021 14:49:46.031810 1994 storage/replica.go:1525  [s1,r1/1:/{Min-System/Max}] propose [txn: a3752594], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
I161021 14:49:46.032108 83 storage/raft.go:140  [s1,r1/1:/{Min-System/Max}] raft ready
  HardState updated: {Term:6 Vote:1 Commit:173 XXX_unrecognized:[]}
  New Entry[0]: 6/173 EntryNormal [7f28caf8f1cee183] [txn: a3752594], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
  Committed Entry[0]: 6/173 EntryNormal [7f28caf8f1cee183] [txn: a3752594], BeginTransaction [/System/NodeLiveness/2,/Min), ConditionalPut [/System/NodeLiveness/2,/Min), EndTransaction [/System/NodeLiveness/2,/Min)
panic: test timed out after 5s

@bdarnell
Copy link
Contributor

Raft (Store 2) was probably quiesced, in any case it's coming up now and
campaigns, but nobody responds. The proposal is dropped, so we're already
going to have to wait for a tick-based reproposal.

But it does get a response and become leader. This triggers a reproposal without waiting for ticks.

I161021 14:49:41.818353 235 raft/raft.go:582  [s2,r11/2:{"m"-/Max}] 2 became leader at term 6

W161021 14:49:41.818513 235 storage/replica.go:2397  [s2,r11/2:{"m"-/Max}] reproposing command 1dec217d05b39d4d; reasonNewLeader

The reproposal is rejected, which tries to trigger a snapshot send but it can't, probably because there's already a pending snapshot to the downed node:

I161021 14:49:41.820252 239 raft/raft.go:770  [s2,r11/2:{"m"-/Max}] 2 received msgApp rejection(lastindex: 0) from 3 for index 10
I161021 14:49:41.820281 239 raft/raft.go:772  [s2,r11/2:{"m"-/Max}] 2 decreased progress of 3 to [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]
I161021 14:49:41.820307 239 raft/raft.go:363  [s2,r11/2:{"m"-/Max}] 2 failed to send snapshot to 3 because snapshot is temporarily unavailable

It looks like what's happening here is that we're starting the snapshot process to a node that is stopped (either just before or just after we start snapshotting), and when the target node stops, the sending node is not able to fail-fast and release the snapshot so it can proceed to talk to other nodes.

@tbg
Copy link
Member Author

tbg commented Nov 1, 2016

Wanted to look into this more, but realistically won't be able to. Unassigning.

@tbg tbg assigned bdarnell and unassigned tbg Nov 1, 2016
@tbg
Copy link
Member Author

tbg commented Nov 1, 2016

@bdarnell, assigning you since you've already dug into it a fair bit.

@bdarnell
Copy link
Contributor

bdarnell commented Nov 7, 2016

The first step for both of these tests is deflaking the setup function itself (many but not all of the failures we see appear to be in the setup function). I first managed to deflake it by dropping in a few random calls to mtc.expireLeases() (which advances the manual clock used in this test), but it took a while to figure out why that worked.

The reason is this TODO. All of those actions are performed on the proposer (i.e. lease holder), except for addToReplicaGCQueue, which should be performed on the node that set it. This test passes most of the time because, surprisingly, the node we're removing is normally the lease holder (everything in this setup function operates in increasing store ID order, so the store with the lowest ID holds the lease except when some rare event causes another node to grab the lease first, and it's always the lowest store ID that we remove). Expiring the leases allows the to-be-removed node to grab the lease and propose its own removal.


That won't actually work when we move to real proposer-evaluated KV. Instead, this needs to come from the replicated data. I'll move this logic from changeReplicasTrigger into handleReplicatedProposalData.

bdarnell added a commit to bdarnell/cockroach that referenced this issue Nov 7, 2016
LocalProposalData is processed only on the proposer, which is unlikely in
practice to be the node being removed (but was apparently the case in
all of our tests except in rare cases).

This deflakes the SplitSnapshotRace tests, which would occasionally end
up with the lease on a different store and miss the automatic GC (and
because the test uses a manual clock, the background replicaGCQueue scan
wouldn't GC them either).

Fixes cockroachdb#8416
Fixes cockroachdb#9204
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Development

No branches or pull requests

7 participants