Predicate is being moved, please retry later

jzhu077 · October 31, 2017, 2:19am

Retrying req: 23214. Error: rpc error: code = Unknown desc = failed to apply mutations error: internal error: rpc error: code = Unknown desc = Predicate is being moved, please retry later

I try to use a dgraph cluster, however, I noticed that after predicate balancing (approx 10mins into the ingestion) I often get the above error. Much appreciated if someone can share some light on this issue.

I thought the dgraph instances are able to communicate with each other about where the new location of the predicate, even though certain predicates have been moved from nodeA to nodeB.

The expected behavior:

node A serves predicate x
after 10 mins predicate x is moved to node B
ingestion still works when I try to ingest triples related to predicate x via grpc address of node A

peter · October 31, 2017, 3:02am

Does the error message “Predicate is being moved, please retry later” get returned consistently even after retrying later?

The dgraph cluster won’t accept updates to that predicate while the move is in progress, but once the move has finished it should accept updates as normal. Depending on how large the data being moved is, this could take some minutes.

jzhu077 · October 31, 2017, 3:07am

Retrying req: 23191. Error: rpc error: code = Unknown desc = failed to apply mutations error: internal error: rpc error: code = Unknown desc = Predicate is being moved, please retry later
Retrying req: 23214. Error: rpc error: code = Unknown desc = failed to apply mutations error: internal error: rpc error: code = Unknown desc = Predicate is being moved, please retry later
Retrying req: 1. Error: rpc error: code = Unavailable desc = grpc: the connection is unavailable

After a lot of retries, the grpc connection is closed.
Is there a configuration I can set to disable to predicate balancing? Or a workaround to this problem?

peter · October 31, 2017, 3:19am

That’s odd that the connection becomes unavailable. Did the dgraph instance crash? Do you have the output from the dgraph it is trying to connect to?

jzhu077 · October 31, 2017, 3:26am

all dgraph nodes have similar logs after the nomal logs i.e ask to serve certain predicates

2017/10/31 02:11:57 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:235454 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:12:07 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:12:17 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:12:34 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:12:36 groups.go:441: Error while updating tablets size rpc error: code = Canceled desc = context canceled
2017/10/31 02:12:45 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:12:58 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:13:10 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:13:34 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:13:57 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:14:26 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:14:51 groups.go:408: Unable to sync memberships. Error: rpc error: code = Unknown desc = cannot get linerized read (time expired or no configured leader)
2017/10/31 02:15:02 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:236145 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:15:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:238926 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:16:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240517 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:18:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240519 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:19:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240520 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:26:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240521 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:27:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240522 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:34:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240523 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:35:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240524 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:42:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240526 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:42:35 predicate_move.go:44: Writing 400443 keys
2017/10/31 02:42:38 predicate_move.go:44: Writing 206462 keys
2017/10/31 02:42:39 predicate_move.go:211: received 606906 number of keys, error <nil>
2017/10/31 02:43:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240529 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:50:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240531 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 02:58:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240533 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:06:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240535 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:14:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240536 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:15:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240537 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:22:34 wal.go:84: Writing snapshot to WAL: {Data:[9 2 0 0 0 0 0 0 0 16 7 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 54] Metadata:{ConfState:{Nodes:[2] XXX_unrecognized:[]} Index:240538 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}

peter · October 31, 2017, 3:37am

I don’t see anything too strange in the logs near the predicate move. It doesn’t look like the dgraph instance crashed. What happens if you retry (with backoff) after getting the “unavailable” error code? According to the grpc standard, “unavailable” is transient. Perhaps the client/server implementations are putting the error in.

There’s not any way to tell the cluster not to try to balance predicates.

mrjn · October 31, 2017, 3:39am

We could easily add it so that Zero won’t try to rebalance the predicates, but that would just mean that the servers would be unbalanced – which would mean worse cache usage and overall slowness in running queries.

It’s better to understand if what you’re seeing is some sort of temporary error or a persistent one; and what is causing it.

peter · October 31, 2017, 3:41am

Can you post the dgraphzero logs as well? Any additional information you have would be useful.

jzhu077 · October 31, 2017, 3:54am

The dgraphzero looks pretty normal to me

dgraphzero 1:

2017/10/31 03:38:32 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:39:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:39:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:39:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:39:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:39:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:39:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:39:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:39:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:39:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:39:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:40:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:40:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:40:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:40:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:40:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:40:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:40:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:40:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:40:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:40:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:41:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:41:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:41:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:41:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:41:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:41:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:41:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:41:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:41:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:41:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:42:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:42:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:42:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:42:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:42:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:42:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:42:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:42:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:42:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:42:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:43:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:43:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:43:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:43:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:43:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:43:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:43:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:43:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:43:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:43:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:44:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:44:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:44:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:44:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:44:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:44:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:44:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:44:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:44:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:44:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:45:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:45:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:45:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:45:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:45:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:45:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:45:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:45:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:45:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:45:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgApp 2-->1
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgAppResp 1-->2
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgApp 2-->1
2017/10/31 03:46:30 raft.go:253: Applied proposal: {Id:253216214 Member:<nil> Tablet:group_id:9 predicate:"host" force:true read_only:true space:208  MaxLeaseId:0}
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgAppResp 1-->2
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgApp 2-->1
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgAppResp 1-->2
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgApp 2-->1
2017/10/31 03:46:32 raft.go:253: Applied proposal: {Id:3439473179 Member:<nil> Tablet:group_id:7 predicate:"host" force:true space:208  MaxLeaseId:0}
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgAppResp 1-->2
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:47:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:47:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:47:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:47:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:47:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:47:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:47:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:47:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:47:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:47:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:48:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:48:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:48:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:48:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:48:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:48:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:48:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:48:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:48:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:48:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:49:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:49:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:49:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:49:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:49:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:49:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:49:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:49:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:49:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:49:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:50:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:50:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:50:05 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:50:05 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:50:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:50:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:50:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:50:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 03:50:07 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 03:50:07 node.go:554: RECEIVED: MsgReadIndexResp 2-->1

dgraphzero-2

2017/10/31 03:45:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:45:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:45:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:45:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:30 tablet.go:161: 

Groups sorted by size: [{gid:7 size:252512777} {gid:2 size:257355041} {gid:5 size:263780800} {gid:1 size:269899653} {gid:6 size:270787415} {gid:3 size:272753576} {gid:9 size:329978776} {gid:4 size:366610362} {gid:8 size:419436687} {gid:10 size:957726659}]

2017/10/31 03:46:30 tablet.go:166: size_diff 705213882
2017/10/31 03:46:30 tablet.go:166: size_diff 166923910
2017/10/31 03:46:30 tablet.go:166: size_diff 114097585
2017/10/31 03:46:30 tablet.go:166: size_diff 77465999
2017/10/31 03:46:30 tablet.go:83: Going to move predicate host from 9 to 7
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgApp 2-->1
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgAppResp 1-->2
2017/10/31 03:46:30 raft.go:253: Applied proposal: {Id:253216214 Member:<nil> Tablet:group_id:9 predicate:"host" force:true read_only:true space:208  MaxLeaseId:0}
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgApp 2-->1
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgAppResp 1-->2
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:30 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:30 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgApp 2-->1
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgAppResp 1-->2
2017/10/31 03:46:32 raft.go:253: Applied proposal: {Id:3439473179 Member:<nil> Tablet:group_id:7 predicate:"host" force:true space:208  MaxLeaseId:0}
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgApp 2-->1
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgAppResp 1-->2
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:46:32 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:46:32 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:47:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:47:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:47:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:47:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:47:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:47:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:47:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:47:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:47:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:47:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:48:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:48:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:48:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:48:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:48:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:48:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:48:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:48:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:48:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:48:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:49:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:49:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:49:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:49:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:49:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:49:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:49:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:49:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:49:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:49:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:50:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:50:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:50:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:50:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:50:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:50:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:50:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:50:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:50:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:50:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:51:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:51:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:51:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:51:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:51:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:51:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:51:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:51:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:51:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:51:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:52:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:52:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:52:05 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:52:05 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:52:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:52:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:52:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:52:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1
2017/10/31 03:52:07 node.go:554: RECEIVED: MsgReadIndex 1-->2
2017/10/31 03:52:07 node.go:177: 		SENDING: MsgReadIndexResp 2-->1

dgraphzero 3: (somehow it didn’t start properly, shouldn’t matter I think)

Setting up listener at: 0.0.0.0:8892
Setting up listener at: 0.0.0.0:8893
2017/10/31 02:02:30 node.go:234: Found hardstate: {Term:1 Vote:0 Commit:0 XXX_unrecognized:[]}
2017/10/31 02:02:30 node.go:246: Group 0 found 0 entries
2017/10/31 02:02:30 raft.go:292: Restarting node for dgraphzero
2017/10/31 02:02:30 raft.go:567: INFO: 3 became follower at term 1
2017/10/31 02:02:30 raft.go:316: INFO: newRaft 3 [peers: [], term: 1, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
Running Dgraph zero...

peter · October 31, 2017, 4:00am

I agree, the drgaphzero logs look normal.

What’s happening with the timestamps though? Are these the dgraphzero logs that correspond with the dgraph log? The timestamps don’t match.

jzhu077 · October 31, 2017, 4:07am

I only grab the last section of the very long logs. Oh I forgot to mention there are 10 dgraph instances in the cluster, and I’ve implemented the evenly distributed client-side routing.

2017/10/31 03:54:34 in dgraph

2017/10/31 03:52:07in dgraphzero

I think they are matching

this is the dgraph log now

2017/10/31 03:22:37 predicate_move.go:211: received 262276 number of keys, error <nil>
2017/10/31 03:23:34 wal.go:84: Writing snapshot to WAL: {Data:[9 3 0 0 0 0 0 0 0 16 1 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 55] Metadata:{ConfState:{Nodes:[3] XXX_unrecognized:[]} Index:240704 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:30:34 wal.go:84: Writing snapshot to WAL: {Data:[9 3 0 0 0 0 0 0 0 16 1 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 55] Metadata:{ConfState:{Nodes:[3] XXX_unrecognized:[]} Index:240706 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:38:34 wal.go:84: Writing snapshot to WAL: {Data:[9 3 0 0 0 0 0 0 0 16 1 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 55] Metadata:{ConfState:{Nodes:[3] XXX_unrecognized:[]} Index:240708 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:46:34 wal.go:84: Writing snapshot to WAL: {Data:[9 3 0 0 0 0 0 0 0 16 1 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 55] Metadata:{ConfState:{Nodes:[3] XXX_unrecognized:[]} Index:240710 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}
2017/10/31 03:54:34 wal.go:84: Writing snapshot to WAL: {Data:[9 3 0 0 0 0 0 0 0 16 1 26 15 108 111 99 97 108 104 111 115 116 58 49 50 51 52 55] Metadata:{ConfState:{Nodes:[3] XXX_unrecognized:[]} Index:240712 Term:3 XXX_unrecognized:[]} XXX_unrecognized:[]}

peter · October 31, 2017, 4:24am

What would be really useful would be to see the dgraph and dgraphzero logs when the “connection is unavailable” and “predicate is being moved, please retry later” errors are received. When you do a mutation and receive either error, you should retry the mutation again later (for example, once every 10 seconds for the next 10 minutes). Seeing the what the logs look like when these events occur will help determine what’s going wrong (and if the problem is transient or persistent).

jzhu077 · October 31, 2017, 4:30am

here is the log at the time of error

2017/10/31 02:09:35 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:09:35 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:09:35 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:31 node.go:554: RECEIVED: MsgApp 2-->1
2017/10/31 02:10:31 node.go:177: 		SENDING: MsgAppResp 1-->2
2017/10/31 02:10:31 node.go:554: RECEIVED: MsgApp 2-->1
2017/10/31 02:10:31 raft.go:253: Applied proposal: {Id:3580691170 Member:<nil> Tablet:group_id:10 predicate:"___commonkind" force:true read_only:true space:78750688  MaxLeaseId:0}
2017/10/31 02:10:31 node.go:177: 		SENDING: MsgAppResp 1-->2
2017/10/31 02:10:31 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:31 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:31 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:31 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:34 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:34 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:34 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:34 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:34 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:34 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:35 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:35 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:35 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:35 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:10:35 node.go:177: 		SENDING: MsgReadIndex 1-->2
2017/10/31 02:10:35 node.go:554: RECEIVED: MsgReadIndexResp 2-->1
2017/10/31 02:11:04 raft.go:749: INFO: 1 is starting a new election at term 3
2017/10/31 02:11:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:06 raft.go:580: INFO: 1 became candidate at term 4
2017/10/31 02:11:10 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:11 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 4
2017/10/31 02:11:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:14 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 4
2017/10/31 02:11:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:18 node.go:307: INFO: raft.node: 1 lost leader 2 at term 4
2017/10/31 02:11:20 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:22 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:42 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:11:46 raft.go:749: INFO: 1 is starting a new election at term 4
2017/10/31 02:11:51 raft.go:580: INFO: 1 became candidate at term 5
2017/10/31 02:11:52 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:56 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:56 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 5
2017/10/31 02:11:56 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:57 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 5
2017/10/31 02:12:07 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:12:08 raft.go:749: INFO: 1 is starting a new election at term 5
2017/10/31 02:12:10 raft.go:580: INFO: 1 became candidate at term 6
2017/10/31 02:12:10 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:11 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 6
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 6
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:12:18 raft.go:749: INFO: 1 is starting a new election at term 6
2017/10/31 02:12:20 raft.go:580: INFO: 1 became candidate at term 7
2017/10/31 02:12:21 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 7
2017/10/31 02:12:21 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:23 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:24 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 7
2017/10/31 02:12:25 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:35 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:12:37 raft.go:749: INFO: 1 is starting a new election at term 7
2017/10/31 02:12:40 raft.go:580: INFO: 1 became candidate at term 8
2017/10/31 02:12:41 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 8
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:41 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:42 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:44 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 8
2017/10/31 02:12:43 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:44 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:12:57 raft.go:749: INFO: 1 is starting a new election at term 8
2017/10/31 02:12:59 raft.go:580: INFO: 1 became candidate at term 9
2017/10/31 02:12:59 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:00 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:00 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 9
2017/10/31 02:13:01 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:01 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:01 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:01 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:01 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 9
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:03 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:03 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:03 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:13:09 raft.go:749: INFO: 1 is starting a new election at term 9
2017/10/31 02:13:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:13 raft.go:580: INFO: 1 became candidate at term 10
2017/10/31 02:13:15 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 10
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:16 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 10
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:25 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:13:33 raft.go:749: INFO: 1 is starting a new election at term 10
2017/10/31 02:13:38 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:40 raft.go:580: INFO: 1 became candidate at term 11
2017/10/31 02:13:47 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:50 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:52 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 11
2017/10/31 02:13:57 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 11
2017/10/31 02:13:56 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:57 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:14:17 raft.go:749: INFO: 1 is starting a new election at term 11
2017/10/31 02:14:24 raft.go:580: INFO: 1 became candidate at term 12
2017/10/31 02:14:24 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:26 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:26 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 12
2017/10/31 02:14:26 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:26 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 12
2017/10/31 02:14:35 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:14:44 raft.go:749: INFO: 1 is starting a new election at term 12
2017/10/31 02:14:47 raft.go:580: INFO: 1 became candidate at term 13
2017/10/31 02:14:52 raft.go:664: INFO: 1 received MsgVoteResp from 1 at term 13
2017/10/31 02:14:49 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:15:00 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:15:00 raft.go:652: INFO: 1 [logterm: 3, index: 177] sent MsgVote request to 2 at term 13
2017/10/31 02:15:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:15:06 node.go:177: 		SENDING: MsgVote 1-->2
2017/10/31 02:15:06 node.go:554: RECEIVED: MsgVote 2-->1
2017/10/31 02:15:06 raft.go:709: INFO: 1 [term: 13] received a MsgVote message with higher term from 2 [term: 15]
2017/10/31 02:15:06 raft.go:567: INFO: 1 became follower at term 15
2017/10/31 02:15:06 raft.go:764: INFO: 1 [logterm: 3, index: 177, vote: 0] cast MsgVote for 2 [logterm: 3, index: 177] at term 15
2017/10/31 02:15:06 node.go:177: 		SENDING: MsgVoteResp 1-->2
2017/10/31 02:15:06 node.go:554: RECEIVED: MsgApp 2-->1
2017/10/31 02:15:06 node.go:301: INFO: raft.node: 1 elected leader 2 at term 15

jzhu077 · October 31, 2017, 4:32am

another dgraph zero

2017/10/31 02:11:22 raft.go:793: WARN: 2 stepped down to follower since quorum is not active
2017/10/31 02:11:28 raft.go:567: INFO: 2 became follower at term 3
2017/10/31 02:11:32 node.go:307: INFO: raft.node: 2 lost leader 2 at term 3
2017/10/31 02:11:38 raft.go:1070: INFO: 2 no leader at term 3; dropping index reading msg
2017/10/31 02:11:40 raft.go:1070: INFO: 2 no leader at term 3; dropping index reading msg
2017/10/31 02:11:45 raft.go:749: INFO: 2 is starting a new election at term 3
2017/10/31 02:11:51 raft.go:580: INFO: 2 became candidate at term 4
2017/10/31 02:11:50 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:53 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:54 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 4
2017/10/31 02:11:56 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 4
2017/10/31 02:11:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:56 raft.go:749: INFO: 2 is starting a new election at term 4
2017/10/31 02:11:56 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:11:58 raft.go:580: INFO: 2 became candidate at term 5
2017/10/31 02:12:05 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 5
2017/10/31 02:12:05 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:06 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:07 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 5
2017/10/31 02:12:12 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:12:12 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:12:14 raft.go:749: INFO: 2 is starting a new election at term 5
2017/10/31 02:12:16 raft.go:580: INFO: 2 became candidate at term 6
2017/10/31 02:12:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 6
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 6
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:18 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:21 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:12:23 raft.go:749: INFO: 2 is starting a new election at term 6
2017/10/31 02:12:25 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:27 raft.go:580: INFO: 2 became candidate at term 7
2017/10/31 02:12:27 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:30 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 7
2017/10/31 02:12:29 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:32 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 7
2017/10/31 02:12:31 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:33 raft.go:749: INFO: 2 is starting a new election at term 7
2017/10/31 02:12:35 raft.go:580: INFO: 2 became candidate at term 8
2017/10/31 02:12:37 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 8
2017/10/31 02:12:39 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 8
2017/10/31 02:12:39 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:12:46 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:12:52 raft.go:749: INFO: 2 is starting a new election at term 8
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 raft.go:580: INFO: 2 became candidate at term 9
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 9
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:54 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 9
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:12:55 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:00 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:13:05 raft.go:749: INFO: 2 is starting a new election at term 9
2017/10/31 02:13:07 raft.go:580: INFO: 2 became candidate at term 10
2017/10/31 02:13:07 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 10
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:08 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 10
2017/10/31 02:13:11 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:13:15 raft.go:749: INFO: 2 is starting a new election at term 10
2017/10/31 02:13:16 raft.go:580: INFO: 2 became candidate at term 11
2017/10/31 02:13:17 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 11
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:17 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:19 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:19 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 11
2017/10/31 02:13:21 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:23 raft.go:749: INFO: 2 is starting a new election at term 11
2017/10/31 02:13:25 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:25 raft.go:580: INFO: 2 became candidate at term 12
2017/10/31 02:13:29 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:29 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 12
2017/10/31 02:13:33 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 12
2017/10/31 02:13:31 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:33 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:13:54 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:13:57 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:13:59 raft.go:749: INFO: 2 is starting a new election at term 12
2017/10/31 02:14:12 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 raft.go:580: INFO: 2 became candidate at term 13
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:13 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 13
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 13
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:14 raft.go:749: INFO: 2 is starting a new election at term 13
2017/10/31 02:14:15 raft.go:580: INFO: 2 became candidate at term 14
2017/10/31 02:14:17 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 14
2017/10/31 02:14:24 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 14
2017/10/31 02:14:26 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:14:35 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:14:43 raft.go:749: INFO: 2 is starting a new election at term 14
2017/10/31 02:14:45 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:47 raft.go:580: INFO: 2 became candidate at term 15
2017/10/31 02:14:51 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:14:52 raft.go:664: INFO: 2 received MsgVoteResp from 2 at term 15
2017/10/31 02:14:58 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:15:00 raft.go:652: INFO: 2 [logterm: 3, index: 177] sent MsgVote request to 1 at term 15
2017/10/31 02:15:02 node.go:400: WARN: A tick missed to fire. Node blocks too long!
2017/10/31 02:15:06 node.go:177: 		SENDING: MsgVote 2-->1
2017/10/31 02:15:06 node.go:554: RECEIVED: MsgVote 1-->2
2017/10/31 02:15:06 raft.go:732: INFO: 2 [term: 15] ignored a MsgVote message with lower term from 1 [term: 13]
2017/10/31 02:15:06 node.go:554: RECEIVED: MsgVoteResp 1-->2
2017/10/31 02:15:06 raft.go:664: INFO: 2 received MsgVoteResp from 1 at term 15
2017/10/31 02:15:06 raft.go:1013: INFO: 2 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
2017/10/31 02:15:06 raft.go:621: INFO: 2 became leader at term 15
2017/10/31 02:15:06 node.go:301: INFO: raft.node: 2 elected leader 2 at term 15
2017/10/31 02:15:06 node.go:177: 		SENDING: MsgApp 2-->1
2017/10/31 02:15:06 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:06 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgAppResp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2
2017/10/31 02:15:07 node.go:554: RECEIVED: MsgProp 1-->2

jzhu077 · October 31, 2017, 4:57am

I assume the predicate is balanced since I use client-side balance control. e.g. create a client for each of the dgraph instance, and use them one after another to ingest. The predicates should be balanced after that. With this setup, would it be safe to turn off the rebalancing without sacrificing the query speed?

mrjn · October 31, 2017, 5:43am

Client doesn’t guarantee balanced data. It just round robins among the servers. The predicates could still be unbalanced because some predicates tend to be much heavier than others. So, the rebalancing act by zero is quite useful.

peter · October 31, 2017, 6:33am

When the “connection unavailable” and “predicate is being moved, please retry later” messages occur, can you provide the logs for the dgraphzeros, dgraphs, and your client? Also, can you confirm that the client retries? (should be visible in the client log). You’re using a custom client right? That’s what we need to sort out this issue.

jzhu077 · October 31, 2017, 8:24pm

Agreed, I should keep the rebalancing mechanism. Alternatively, is it easy to increase the time interval between rebalancing acts? i.e just increase some time setting. Because I would like to cut down the ingestion time down as much as possible. I know that it would be much faster to use bulk loading, but I would like to use the streaming ingestion as a short-term solution before I move to bulk loading, and I can also use this as a benchmark.

update:
I assume https://github.com/dgraph-io/dgraph/blob/master/cmd/dgraphzero/tablet.go#L55 this is the only place that I need to change to increase the rebalancing interval. Please confirm

jzhu077 · October 31, 2017, 8:36pm

RIght, retry logic is missing, however, this leads to an increase in ingestion time.

mrjn · October 31, 2017, 10:31pm

That’s the right place.

Topic		Replies	Views
Dgraph zero rpc timeout when moving _predicate_ between groups Dgraph	2	567	April 17, 2018
Moving predicates - no downtime Dgraph	7	441	September 17, 2018
Predicate Rebalances (Moves) Across Servers Cause Transactions to Abort Dgraph	2	40	August 15, 2024
Predicate mutations while moving predicates between groups Dgraph mutation , status:accepted , ticket:created	9	1297	April 30, 2021
Zero auto rebalancing cause mutation rejected Users mutation	1	535	July 1, 2020

Predicate is being moved, please retry later

Related topics