No leader at term 3; dropping index reading msg

tlmichael · December 14, 2018, 2:55pm

Ahh, after changing server to alpha then, when running it it first loads all the data:

Attaching to xxxxxxx_zero_1, zero_1 | I1214 14:52:14.524222 zero_1 |
zero_1 | Dgraph version zero_1 | Commit SHA-1 zero_1 | Commit timestamp zero_1 | Branch : HEAD
zero_1 |
zero_1 | For Dgraph official zero_1 | For discussions about Dgraph zero_1 | To say hi to the community zero_1 |
zero_1 | Licensed under zero_1 |
zero_1 |
zero_1 | I1214 14:52:14.524964 zero_1 | I1214 14:52:14.525044 zero_1 | badger2018/12/14 zero_1 | badger2018/12/14 zero_1 | I1214 14:52:14.541635 server_1 | I1214 14:52:15.508225 server_1 |
server_1 | Dgraph version server_1 | Commit SHA-1 server_1 | Commit timestamp server_1 | Branch : HEAD
server_1 |
server_1 | For Dgraph official server_1 | For discussions about Dgraph server_1 | To say hi to the community server_1 |
server_1 | Licensed under server_1 |
server_1 |
zero_1 | I1214 14:52:14.542135 server_1 | I1214 14:52:15.508472 server_1 | I1214 14:52:15.508481 ratel_1 | 2018/12/14 14:52:16 zero_1 | I1214 14:52:14.542212 server_1 | I1214 14:52:15.508485 server_1 | badger2018/12/14 server_1 | badger2018/12/14 server_1 | I1214 14:52:15.517213 server_1 | I1214 14:52:15.517246 server_1 | I1214 14:52:15.517259 zero_1 | I1214 14:52:14.543501 zero_1 | I1214 14:52:14.543521 server_1 | badger2018/12/14 server_1 | badger2018/12/14 server_1 | I1214 14:52:15.567809 server_1 | I1214 14:52:15.567829 server_1 | I1214 14:52:15.567805 server_1 | I1214 14:52:15.567811 zero_1 | I1214 14:52:14.543548 server_1 | I1214 14:52:15.569387 zero_1 | E1214 14:52:15.557917 zero_1 | I1214 14:52:15.558361 server_1 | I1214 14:52:15.569895 zero_1 | I1214 14:52:15.558860 server_1 | I1214 14:52:15.575788 server_1 | I1214 14:52:15.575848 server_1 | I1214 14:52:15.594979 server_1 | I1214 14:52:15.595004 server_1 | I1214 14:52:15.596512 server_1 | I1214 14:52:15.596519 server_1 | I1214 14:52:15.596531 zero_1 | I1214 14:52:15.558939 server_1 | I1214 14:52:15.597566 server_1 | I1214 14:52:15.597649 zero_1 | I1214 14:52:15.559037 server_1 | I1214 14:52:15.767871 zero_1 | I1214 14:52:15.569493 server_1 | E1214 14:52:15.767994 xxxxxxx_server_1, xxxxxxx_ratel_1
1 init.go:80]
: v1.0.10
: 8b801bd7
: 2018-11-05 17:52:33 -0800
documentation, visit https://docs.dgraph.io.
, visit http://discuss.hypermode.com.
, visit https://dgraph.slack.com.
Apache 2.0. Copyright 2015-2018 Dgraph Labs, Inc.
1 run.go:90] Setting up grpc listener at: 0.0.0.0:5080
1 run.go:90] Setting up http listener at: 0.0.0.0:6080
14:52:14 INFO: Replaying file id: 0 at offset: 1019703
14:52:14 INFO: Replay took: 11.761µs
1 node.go:152] Setting raft.Config to: &{ID:1 peers: ElectionTick:100 HeartbeatTick:1 Storage:0xc0000aaa90 Applied:4131 MaxSizePerMsg:1048576 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x1d112c0}
1 init.go:80]
: v1.0.10
: 8b801bd7
: 2018-11-05 17:52:33 -0800
documentation, visit https://docs.dgraph.io.
, visit http://discuss.hypermode.com.
, visit https://dgraph.slack.com.
Apache 2.0. Copyright 2015-2018 Dgraph Labs, Inc.
1 node.go:271] Found Snapshot.Metadata: {ConfState:{Nodes: XXX_unrecognized:} Index:4131 Term:3 XXX_unrecognized:}
1 server.go:115] Setting Badger table load option: mmap
1 server.go:127] Setting Badger value log load option: mmap
Listening on port 8000…
1 node.go:282] Found hardstate: {Term:3 Vote:1 Commit:4396 XXX_unrecognized:}
1 server.go:155] Opening write-ahead log BadgerDB with options: {Dir:w ValueDir:w SyncWrites:true TableLoadingMode:1 ValueLogLoadingMode:2 NumVersionsToKeep:1 MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:65500 NumMemtables:5 NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:10000 NumCompactors:3 managedTxns:false DoNotCompact:false maxBatchCount:0 maxBatchSize:0 ReadOnly:false Truncate:true}
14:52:15 INFO: Replaying file id: 3 at offset: 1504
14:52:15 INFO: Replay took: 26.334µs
1 server.go:115] Setting Badger table load option: mmap
1 server.go:127] Setting Badger value log load option: mmap
1 server.go:169] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:true TableLoadingMode:2 ValueLogLoadingMode:2 NumVersionsToKeep:2147483647 MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:3 managedTxns:false DoNotCompact:false maxBatchCount:0 maxBatchSize:0 ReadOnly:false Truncate:true}
1 node.go:291] Group 0 found 266 entries
1 raft.go:371] Restarting node for dgraphzero
14:52:15 INFO: Replaying file id: 1 at offset: 98425724
14:52:15 INFO: Replay took: 9.699µs
1 run.go:338] gRPC server started. Listening on port 9080
1 run.go:339] HTTP server started. Listening on port 8080
1 groups.go:92] Current Raft Id: 1
1 worker.go:80] Worker listening at address: [::]:7080
1 node.go:174] Setting conf state to
1 pool.go:118] CONNECTED to zero:5080
1 pool.go:178] Echo error from server:7080. Err: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = “transport: Error while dialing dial tcp 172.20.0.3:7080: connect: connection refused”
1 pool.go:118] CONNECTED to server:7080
1 groups.go:119] Connected to group zero. Assigned group: 0
1 node.go:84] 1 became follower at term 3
1 draft.go:74] Node ID: 1 with GroupID: 1
1 node.go:152] Setting raft.Config to: &{ID:1 peers: ElectionTick:100 HeartbeatTick:1 Storage:0xc000249110 Applied:36857 MaxSizePerMsg:1048576 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x1d112c0}
1 node.go:271] Found Snapshot.Metadata: {ConfState:{Nodes: XXX_unrecognized:} Index:36857 Term:3 XXX_unrecognized:}
1 node.go:282] Found hardstate: {Term:3 Vote:1 Commit:37748 XXX_unrecognized:}
1 node.go:291] Group 1 found 892 entries
1 draft.go:1047] Restarting node for group: 1
1 node.go:174] Setting conf state to
1 node.go:84] newRaft 1 [peers: , term: 3, commit: 4396, applied: 4131, lastindex: 4396, lastterm: 3]
1 node.go:84] 1 became follower at term 3
1 node.go:84] newRaft 1 [peers: , term: 3, commit: 37748, applied: 36857, lastindex: 37748, lastterm: 3]
1 run.go:229] Running Dgraph Zero…
1 draft.go:313] Skipping snapshot at 36857, because found one at 36857
1 zero.go:375] Got connection request: id:1 addr:“server:7080”
1 draft.go:407] Applying proposal. Error: proto: wrong wireType = 1 for field BlockSize. Proposal: "mutations:<group_id:1 start_ts:42500 edges:<entity:728 attr:\

[…a lot of data loaded here, seems my entire database…]

e_type:STRING > edges:<entity:1310 attr:"predicate" value:"nodeType" value_type:STRING > edges:<entity:1310 attr:"date" value:"2018-12-07T19:45:00Z" value_type:STRING > edges:<entity:1310 attr:"predicate" value:"date" value_type:STRING > > key:"01-12437238023092424395" ".
server_1 | I1214 14:44:25.124114 1 mutation.go:181] Done schema update predicate:“nodeType” value_type:STRING directive:INDEX tokenizer:“exact”
zero_1 | W1214 14:44:25.215747 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:44:25.215807 1 node.go:84] 1 no leader at term 3; dropping index reading msg
server_1 | I1214 14:44:26.220543 1 mutation.go:181] Done schema update predicate:“date” value_type:DATETIME directive:INDEX tokenizer:“day”

then update all the schema before getting the dropping index error:

server_1 | I1214 14:49:40.007281 1 mutation.go:181] Done schema update predicate:“date” value_type:DATETIME directive:INDEX tokenizer:“day”
zero_1 | W1214 14:49:42.852696 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:49:42.852757 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | W1214 14:49:45.852843 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:49:45.852871 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | I1214 14:49:48.420797 1 oracle.go:100] Purged below ts:43083, len(o.commits):0, len(o.rowCommit):0
zero_1 | W1214 14:49:48.853019 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:49:48.853059 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | W1214 14:49:51.853114 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:49:51.853148 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | W1214 14:49:54.853290 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:49:54.853340 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | W1214 14:49:57.853691 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:49:57.853787 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | W1214 14:50:00.854039 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:50:00.854141 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | W1214 14:50:03.854430 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:50:03.854535 1 node.go:84] 1 no leader at term 3; dropping index reading msg
zero_1 | W1214 14:50:06.854679 1 node.go:551] [1] Read index context timed out
zero_1 | I1214 14:50:06.854765 1 node.go:84] 1 no leader at term 3; dropping index reading msg

Topic		Replies	Views
Help needed: dgraph keeps crashing under load - what s going on? Dgraph	4	1843	April 13, 2020
Dgraph runs into a error loop and freezes the host Users	20	2223	February 21, 2018
Unable to reach leader in group 1 - dir structures help Dgraph	38	1870	April 11, 2023
Export fails with dgraph:v20.07.0 Dgraph area:import-export	8	1420	August 15, 2020
Errors running dgraph/dgraph:master with Docker Compose Dgraph graphql , kind:question	13	1001	December 23, 2020

No leader at term 3; dropping index reading msg

Related topics