Dgraph cluster crashes when recreating index

scroobius-pip · April 17, 2020, 8:20pm

I removed a hash index and added it back, next thing i know all my alpha pods are down:

so i delete all the alpha pods to restart them:

here’s my logs for the pods:

alpha 1

++ hostname -f
+ dgraph alpha --my=dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080 --lru_mb 1433 --zero dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 20:08:46 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 20:08:46 Integration installed: Environment
[Sentry] 2020/04/17 20:08:46 Integration installed: Modules
[Sentry] 2020/04/17 20:08:46 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 20:08:46 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 20:08:46 Integration installed: Environment
[Sentry] 2020/04/17 20:08:46 Integration installed: Modules
[Sentry] 2020/04/17 20:08:46 Integration installed: IgnoreErrors
I0417 20:08:46.955276      17 init.go:99]

Dgraph version   : v20.03.0
Dgraph SHA-256   : 07e63901be984bd20a3505a2ee5840bb8fc4f72cc7749c485f9f77db15b9b75a
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit http://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Copyright 2015-2020 Dgraph Labs, Inc.


I0417 20:08:46.956178      17 run.go:606] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000}
I0417 20:08:46.956251      17 run.go:607] x.WorkerConfig: {ExportPath:export NumPendingProposals:256 Tracing:1 MyAddr:dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080 ZeroAddr:dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080 RaftId:0 WhiteListedIPRanges:[] MaxRetries:-1 StrictMutations:false AclEnabled:false AbortOlderThan:5m0s SnapshotAfter:10000 ProposedGroupId:0 StartTime:2020-04-17 20:08:46.535453128 +0000 UTC m=+0.018060406 LudicrousMode:false}
I0417 20:08:46.956315      17 run.go:608] worker.Config: {PostingDir:p BadgerTables:mmap BadgerVlog:mmap BadgerKeyFile: WALDir:w MutationsMode:0 AuthToken: AllottedMemory:1433 HmacSecret:[] AccessJwtTtl:0s RefreshJwtTtl:0s AclRefreshInterval:0s}
I0417 20:08:46.956411      17 server_state.go:74] Setting Badger table load option: mmap
I0417 20:08:46.956422      17 server_state.go:86] Setting Badger value log load option: mmap
I0417 20:08:46.956433      17 server_state.go:131] Opening write-ahead log BadgerDB with options: {Dir:w ValueDir:w SyncWrites:false TableLoadingMode:1 ValueLogLoadingMode:2 NumVersionsToKeep:1 ReadOnly:false Truncate:true Logger:0x260a270 Compression:0 EventLogging:true InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1048576 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:true MaxCacheSize:10485760 MaxBfCacheSize:0 LoadBloomsOnOpen:true NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:10000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:1 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0417 20:08:46.981528      17 log.go:34] All 0 tables opened in 0s
I0417 20:08:46.996205      17 log.go:34] Replaying file id: 0 at offset: 0
I0417 20:08:46.999630      17 log.go:34] Replay took: 3.362015ms
I0417 20:08:46.999850      17 server_state.go:74] Setting Badger table load option: mmap
I0417 20:08:46.999861      17 server_state.go:86] Setting Badger value log load option: mmap
I0417 20:08:46.999870      17 server_state.go:154] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false TableLoadingMode:2 ValueLogLoadingMode:2 NumVersionsToKeep:2147483647 ReadOnly:false Truncate:true Logger:0x260a270 Compression:0 EventLogging:true InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:true MaxCacheSize:1073741824 MaxBfCacheSize:0 LoadBloomsOnOpen:true NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:1 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0417 20:08:47.026319      17 log.go:34] All 38 tables opened in 6ms
I0417 20:08:47.047994      17 log.go:34] Replaying file id: 0 at offset: 39031
I0417 20:08:47.048061      17 log.go:34] Replay took: 35.437µs
I0417 20:08:47.051483      17 groups.go:104] Current Raft Id: 0x1
I0417 20:08:47.052534      17 worker.go:96] Worker listening at address: [::]:7080
I0417 20:08:47.056259      17 run.go:477] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql
I0417 20:08:47.056302      17 run.go:478] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin
I0417 20:08:47.056541      17 run.go:509] gRPC server started.  Listening on port 9080
I0417 20:08:47.056626      17 run.go:510] HTTP server started.  Listening on port 8080
I0417 20:08:47.151883      17 pool.go:160] CONNECTING to dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 20:08:47.168841      17 groups.go:131] Connected to group zero. Assigned group: 0
I0417 20:08:47.168871      17 groups.go:133] Raft Id after connection to Zero: 0x1
I0417 20:08:47.168979      17 pool.go:160] CONNECTING to dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:08:47.169012      17 pool.go:160] CONNECTING to dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:08:47.169075      17 pool.go:160] CONNECTING to dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080
I0417 20:08:47.169106      17 pool.go:160] CONNECTING to dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080
I0417 20:08:47.169187      17 draft.go:175] Node ID: 0x1 with GroupID: 1
I0417 20:08:47.169253      17 node.go:145] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc02355e870 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false}
I0417 20:08:47.172112      17 node.go:314] Found hardstate: {Term:2 Vote:1 Commit:229 XXX_unrecognized:[]}
I0417 20:08:47.172209      17 node.go:323] Group 1 found 230 entries
I0417 20:08:47.172219      17 draft.go:1506] Restarting node for group: 1
I0417 20:08:47.172256      17 log.go:34] 1 became follower at term 2
I0417 20:08:47.172287      17 log.go:34] newRaft 1 [peers: [], term: 2, commit: 229, applied: 0, lastindex: 229, lastterm: 2]
I0417 20:08:47.172314      17 draft.go:136] Operation started with id: opRollup
I0417 20:08:47.172331      17 groups.go:151] Server is ready
I0417 20:08:47.172647      17 draft.go:925] Found Raft progress: 0
I0417 20:08:47.172739      17 groups.go:775] Got address of a Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 20:08:47.172887      17 groups.go:788] Starting a new membership stream receive from dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080.      
E0417 20:08:47.175134      17 groups.go:1084] Error from alpha client subscribe: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local: no such host"
W0417 20:08:47.175668      17 pool.go:254] Connection lost with dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local: no such host"
W0417 20:08:47.177142      17 pool.go:254] Connection lost with dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:08:47.178361      17 groups.go:805] Received first state update from Zero: counter:137 groups:<key:1 value:<members:<key:1 value:<id:1 group_id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" last_update:1587153919 > > members:<key:2 value:<id:2 group_id:1 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true > > members:<key:3 value:<id:3 group_id:1 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true > > tablets:<key:"description" value:<group_id:1 predicate:"description" space:1271 > > tablets:<key:"dgraph.acl.rule" value:<group_id:1 predicate:"dgraph.acl.rule" > > tablets:<key:"dgraph.graphql.schema" value:<group_id:1 predicate:"dgraph.graphql.schema" > > tablets:<key:"dgraph.group.acl" value:<group_id:1 predicate:"dgraph.group.acl" > > tablets:<key:"dgraph.password" value:<group_id:1 predicate:"dgraph.password" > 
> tablets:<key:"dgraph.rule.permission" value:<group_id:1 predicate:"dgraph.rule.permission" > > tablets:<key:"dgraph.rule.predicate" value:<group_id:1 predicate:"dgraph.rule.predicate" > > tablets:<key:"dgraph.type" value:<group_id:1 predicate:"dgraph.type" > > tablets:<key:"dgraph.user.group" value:<group_id:1 predicate:"dgraph.user.group" > > tablets:<key:"dgraph.xid" value:<group_id:1 predicate:"dgraph.xid" > > tablets:<key:"game" value:<group_id:1 predicate:"game" space:5132140 > > tablets:<key:"game.coverUrl" value:<group_id:1 predicate:"game.coverUrl" space:9948550 > > tablets:<key:"game.name" value:<group_id:1 predicate:"game.name" space:11782792 > > tablets:<key:"game.platform" value:<group_id:1 predicate:"game.platform" space:5601970 > > tablets:<key:"game.popularity" value:<group_id:1 predicate:"game.popularity" space:6002130 > > tablets:<key:"game.url" value:<group_id:1 predicate:"game.url" space:130 > > tablets:<key:"game.uuid" value:<group_id:1 predicate:"game.uuid" space:12767270 > > tablets:<key:"info" value:<group_id:1 predicate:"info" space:1669 > > tablets:<key:"name" value:<group_id:1 predicate:"name" space:90 > > tablets:<key:"negative" value:<group_id:1 predicate:"negative" > > tablets:<key:"offer" value:<group_id:1 predicate:"offer" space:76 > > tablets:<key:"offer.epochTimeCreated" value:<group_id:1 predicate:"offer.epochTimeCreated" space:151 > > tablets:<key:"offer.offerId" value:<group_id:1 predicate:"offer.offerId" space:159 > > tablets:<key:"offer.receiverGames" value:<group_id:1 predicate:"offer.receiverGames" space:64 > > tablets:<key:"offer.receiverId" value:<group_id:1 predicate:"offer.receiverId" > > tablets:<key:"offer.senderGames" value:<group_id:1 predicate:"offer.senderGames" space:62 > > tablets:<key:"offer.senderId" value:<group_id:1 predicate:"offer.senderId" > > tablets:<key:"offer.status" value:<group_id:1 predicate:"offer.status" space:157 > > tablets:<key:"platform" value:<group_id:1 predicate:"platform" space:98 > > tablets:<key:"positive" value:<group_id:1 predicate:"positive" > > tablets:<key:"tradeType" value:<group_id:1 predicate:"tradeType" space:1378 > > tablets:<key:"user" value:<group_id:1 predicate:"user" space:385 > > tablets:<key:"user.country" value:<group_id:1 predicate:"user.country" space:481 > > tablets:<key:"user.description" value:<group_id:1 predicate:"user.description" space:109 > > tablets:<key:"user.email" value:<group_id:1 predicate:"user.email" space:773 > > tablets:<key:"user.epochTimeCreated" value:<group_id:1 predicate:"user.epochTimeCreated" space:532 > > tablets:<key:"user.game" value:<group_id:1 predicate:"user.game" space:3511 > > tablets:<key:"user.gamesHas" value:<group_id:1 predicate:"user.gamesHas" > > tablets:<key:"user.gamesWant" value:<group_id:1 predicate:"user.gamesWant" > > tablets:<key:"user.isBanned" value:<group_id:1 predicate:"user.isBanned" space:87 > > tablets:<key:"user.isPro" value:<group_id:1 predicate:"user.isPro" space:84 > > tablets:<key:"user.latitude" value:<group_id:1 predicate:"user.latitude" space:382 > > tablets:<key:"user.location" value:<group_id:1 predicate:"user.location" space:447 > > tablets:<key:"user.longitude" value:<group_id:1 predicate:"user.longitude" space:383 > > tablets:<key:"user.matchNotifications" value:<group_id:1 predicate:"user.matchNotifications" space:97 > > tablets:<key:"user.noOfSuccessfulExchanges" value:<group_id:1 predicate:"user.noOfSuccessfulExchanges" space:109 > > tablets:<key:"user.participates" value:<group_id:1 predicate:"user.participates" space:428 > > tablets:<key:"user.ratingNegative" value:<group_id:1 predicate:"user.ratingNegative" space:100 > > tablets:<key:"user.ratingPositive" value:<group_id:1 predicate:"user.ratingPositive" space:100 > > tablets:<key:"user.state" value:<group_id:1 predicate:"user.state" space:487 > > tablets:<key:"user.subscriptionCancelUrl" value:<group_id:1 predicate:"user.subscriptionCancelUrl" > > tablets:<key:"user.subscriptionUpdateUrl" value:<group_id:1 predicate:"user.subscriptionUpdateUrl" > > tablets:<key:"user.userImageUrl" value:<group_id:1 predicate:"user.userImageUrl" space:912 > > tablets:<key:"user.userName" value:<group_id:1 predicate:"user.userName" space:515 > > checksum:8752590508278277041 > > zeros:<key:1 value:<id:1 addr:"dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080" leader:true > > zeros:<key:2 value:<id:2 addr:"dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080" > > zeros:<key:3 value:<id:3 addr:"dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080" > > maxLeaseId:745010 maxTxnTs:10000 maxRaftId:3 cid:"bc9b29e0-4c57-454f-a537-cfb463843a62" license:<maxNodes:18446744073709551615 expiryTs:1589734452 enabled:true >
I0417 20:08:47.195791      17 node.go:182] Setting conf state to nodes:1
I0417 20:08:47.197056      17 node.go:182] Setting conf state to nodes:1 nodes:2
I0417 20:08:47.197250      17 node.go:182] Setting conf state to nodes:1 nodes:2 nodes:3
I0417 20:08:47.255341      17 draft.go:136] Operation started with id: opIndexing
I0417 20:08:47.255749      17 draft.go:104] Operation completed with id: opRollup
I0417 20:08:47.256144      17 draft.go:104] Operation completed with id: opIndexing
I0417 20:08:47.268509      17 draft.go:136] Operation started with id: opIndexing
I0417 20:08:47.268595      17 index.go:856] Deleting index for attr user.userName and tokenizers []
I0417 20:08:47.268621      17 index.go:870] Deleting index for attr user.userName and tokenizers [hash]
I0417 20:08:47.268740      17 log.go:34] Writes flushed. Stopping compactions now...
I0417 20:08:47.273937      17 log.go:34] Got compaction priority: {level:0 score:1.74 dropPrefix:[0 0 13 117 115 101 114 46 117 115 101 114 78 97 109 101 
2 11]}
I0417 20:08:47.274396      17 log.go:34] Running for level: 0
E0417 20:08:47.289388      17 groups.go:1084] Error from alpha client subscribe: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:08:47.324469      17 log.go:34] LOG Compact 0->1, del 2 tables, add 1 tables, took 49.878808ms
I0417 20:08:47.324636      17 log.go:34] Compaction for level: 0 DONE
I0417 20:08:47.324759      17 log.go:34] DropPrefix done
I0417 20:08:47.324786      17 log.go:34] Resuming writes
I0417 20:08:47.325153      17 log.go:34] Writes flushed. Stopping compactions now...
I0417 20:08:47.364471      17 log.go:34] LOG Compact 1->1, del 1 tables, add 1 tables, took 36.907949ms
I0417 20:08:47.364529      17 log.go:34] DropPrefix done
I0417 20:08:47.364545      17 log.go:34] Resuming writes
I0417 20:08:47.364730      17 index.go:901] Rebuilding index for attr user.userName and tokenizers [hash]
I0417 20:08:47.389838      17 pool.go:160] CONNECTING to dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:08:47.413633      17 log.go:34] All 0 tables opened in 0s
2020/04/17 20:08:47 Assert failed
github.com/dgraph-io/dgraph/x.AssertTrue
        /tmp/go/src/github.com/dgraph-io/dgraph/x/error.go:94
github.com/dgraph-io/dgraph/posting.(*Txn).addIndexMutations
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:94
github.com/dgraph-io/dgraph/posting.rebuildTokIndex.func1.1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:921
github.com/dgraph-io/dgraph/posting.(*List).iterate
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/list.go:677
github.com/dgraph-io/dgraph/posting.(*List).Iterate
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/list.go:556
github.com/dgraph-io/dgraph/posting.rebuildTokIndex.func1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:912
github.com/dgraph-io/dgraph/posting.(*rebuilder).Run.func1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:604
github.com/dgraph-io/badger/v2.(*Stream).produceKVs.func1
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:191
github.com/dgraph-io/badger/v2.(*Stream).produceKVs
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:234
github.com/dgraph-io/badger/v2.(*Stream).Orchestrate.func1
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:337
runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1373

scroobius-pip · April 17, 2020, 8:22pm

alpha 2

++ hostname -f
+ dgraph alpha --my=dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080 --lru_mb 1433 --zero dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 20:14:30 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 20:14:30 Integration installed: Environment
[Sentry] 2020/04/17 20:14:30 Integration installed: Modules
[Sentry] 2020/04/17 20:14:30 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 20:14:31 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 20:14:31 Integration installed: Environment
[Sentry] 2020/04/17 20:14:31 Integration installed: Modules
[Sentry] 2020/04/17 20:14:31 Integration installed: IgnoreErrors
I0417 20:14:31.365735      16 init.go:99]

Dgraph version   : v20.03.0
Dgraph SHA-256   : 07e63901be984bd20a3505a2ee5840bb8fc4f72cc7749c485f9f77db15b9b75a
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit http://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Copyright 2015-2020 Dgraph Labs, Inc.


I0417 20:14:31.368334      16 run.go:606] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000}
I0417 20:14:31.368424      16 run.go:607] x.WorkerConfig: {ExportPath:export NumPendingProposals:256 Tracing:1 MyAddr:dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080 ZeroAddr:dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080 RaftId:0 WhiteListedIPRanges:[] MaxRetries:-1 StrictMutations:false AclEnabled:false AbortOlderThan:5m0s SnapshotAfter:10000 ProposedGroupId:0 StartTime:2020-04-17 20:14:30.831445813 +0000 UTC m=+0.020350982 LudicrousMode:false}
I0417 20:14:31.368483      16 run.go:608] worker.Config: {PostingDir:p BadgerTables:mmap BadgerVlog:mmap BadgerKeyFile: WALDir:w MutationsMode:0 AuthToken: AllottedMemory:1433 HmacSecret:[] AccessJwtTtl:0s RefreshJwtTtl:0s AclRefreshInterval:0s}
I0417 20:14:31.368608      16 server_state.go:74] Setting Badger table load option: mmap
I0417 20:14:31.368625      16 server_state.go:86] Setting Badger value log load option: mmap
I0417 20:14:31.368635      16 server_state.go:131] Opening write-ahead log BadgerDB with options: {Dir:w ValueDir:w SyncWrites:false TableLoadingMode:1 ValueLogLoadingMode:2 NumVersionsToKeep:1 ReadOnly:false Truncate:true Logger:0x260a270 Compression:0 EventLogging:true InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1048576 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:true MaxCacheSize:10485760 MaxBfCacheSize:0 LoadBloomsOnOpen:true NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:10000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:1 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0417 20:14:31.377958      16 log.go:34] All 0 tables opened in 0s
I0417 20:14:31.389530      16 log.go:34] Replaying file id: 0 at offset: 0
I0417 20:14:31.391869      16 log.go:34] Replay took: 2.306171ms
I0417 20:14:31.392179      16 server_state.go:74] Setting Badger table load option: mmap
I0417 20:14:31.392195      16 server_state.go:86] Setting Badger value log load option: mmap
I0417 20:14:31.392346      16 server_state.go:154] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false TableLoadingMode:2 ValueLogLoadingMode:2 NumVersionsToKeep:2147483647 ReadOnly:false Truncate:true Logger:0x260a270 Compression:0 EventLogging:true InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:true MaxCacheSize:1073741824 MaxBfCacheSize:0 LoadBloomsOnOpen:true NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:1 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0417 20:14:31.442473      16 log.go:34] All 38 tables opened in 25ms
I0417 20:14:31.455443      16 log.go:34] Replaying file id: 0 at offset: 39347
I0417 20:14:31.455599      16 log.go:34] Replay took: 6.722µs
I0417 20:14:31.460646      16 groups.go:104] Current Raft Id: 0x2
I0417 20:14:31.461096      16 worker.go:96] Worker listening at address: [::]:7080
I0417 20:14:31.462867      16 run.go:477] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql
I0417 20:14:31.462923      16 run.go:478] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin
I0417 20:14:31.462988      16 run.go:509] gRPC server started.  Listening on port 9080
I0417 20:14:31.463011      16 run.go:510] HTTP server started.  Listening on port 8080
I0417 20:14:31.560990      16 pool.go:160] CONNECTING to dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:31.585730      16 groups.go:131] Connected to group zero. Assigned group: 0
I0417 20:14:31.585770      16 groups.go:133] Raft Id after connection to Zero: 0x2
I0417 20:14:31.586520      16 pool.go:160] CONNECTING to dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:14:31.588204      16 pool.go:160] CONNECTING to dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:14:31.589310      16 pool.go:160] CONNECTING to dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:31.591702      16 pool.go:160] CONNECTING to dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:31.592524      16 draft.go:175] Node ID: 0x2 with GroupID: 1
I0417 20:14:31.593449      16 node.go:145] Setting raft.Config to: &{ID:2 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc023590e70 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false}
I0417 20:14:31.600398      16 node.go:314] Found hardstate: {Term:2 Vote:0 Commit:229 XXX_unrecognized:[]}
I0417 20:14:31.600860      16 node.go:323] Group 1 found 230 entries
I0417 20:14:31.601027      16 draft.go:1506] Restarting node for group: 1
I0417 20:14:31.601796      16 log.go:34] 2 became follower at term 2
I0417 20:14:31.602026      16 log.go:34] newRaft 2 [peers: [], term: 2, commit: 229, applied: 0, lastindex: 229, lastterm: 2]
I0417 20:14:31.602258      16 draft.go:136] Operation started with id: opRollup
I0417 20:14:31.602421      16 groups.go:151] Server is ready
I0417 20:14:31.602933      16 draft.go:925] Found Raft progress: 0
I0417 20:14:31.603238      16 groups.go:775] Got address of a Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:31.607767      16 groups.go:788] Starting a new membership stream receive from dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080.      
W0417 20:14:31.614465      16 pool.go:254] Connection lost with dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local: no such host"
E0417 20:14:31.615115      16 groups.go:1084] Error from alpha client subscribe: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:14:31.617946      16 groups.go:805] Received first state update from Zero: counter:137 groups:<key:1 value:<members:<key:1 value:<id:1 group_id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" last_update:1587153919 > > members:<key:2 value:<id:2 group_id:1 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true > > members:<key:3 value:<id:3 group_id:1 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true > > tablets:<key:"description" value:<group_id:1 predicate:"description" space:1271 > > tablets:<key:"dgraph.acl.rule" value:<group_id:1 predicate:"dgraph.acl.rule" > > tablets:<key:"dgraph.graphql.schema" value:<group_id:1 predicate:"dgraph.graphql.schema" > > tablets:<key:"dgraph.group.acl" value:<group_id:1 predicate:"dgraph.group.acl" > > tablets:<key:"dgraph.password" value:<group_id:1 predicate:"dgraph.password" > 
> tablets:<key:"dgraph.rule.permission" value:<group_id:1 predicate:"dgraph.rule.permission" > > tablets:<key:"dgraph.rule.predicate" value:<group_id:1 predicate:"dgraph.rule.predicate" > > tablets:<key:"dgraph.type" value:<group_id:1 predicate:"dgraph.type" > > tablets:<key:"dgraph.user.group" value:<group_id:1 predicate:"dgraph.user.group" > > tablets:<key:"dgraph.xid" value:<group_id:1 predicate:"dgraph.xid" > > tablets:<key:"game" value:<group_id:1 predicate:"game" space:5132140 > > tablets:<key:"game.coverUrl" value:<group_id:1 predicate:"game.coverUrl" space:9948550 > > tablets:<key:"game.name" value:<group_id:1 predicate:"game.name" space:11782792 > > tablets:<key:"game.platform" value:<group_id:1 predicate:"game.platform" space:5601970 > > tablets:<key:"game.popularity" value:<group_id:1 predicate:"game.popularity" space:6002130 > > tablets:<key:"game.url" value:<group_id:1 predicate:"game.url" space:130 > > tablets:<key:"game.uuid" value:<group_id:1 predicate:"game.uuid" space:12767270 > > tablets:<key:"info" value:<group_id:1 predicate:"info" space:1669 > > tablets:<key:"name" value:<group_id:1 predicate:"name" space:90 > > tablets:<key:"negative" value:<group_id:1 predicate:"negative" > > tablets:<key:"offer" value:<group_id:1 predicate:"offer" space:76 > > tablets:<key:"offer.epochTimeCreated" value:<group_id:1 predicate:"offer.epochTimeCreated" space:151 > > tablets:<key:"offer.offerId" value:<group_id:1 predicate:"offer.offerId" space:159 > > tablets:<key:"offer.receiverGames" value:<group_id:1 predicate:"offer.receiverGames" space:64 > > tablets:<key:"offer.receiverId" value:<group_id:1 predicate:"offer.receiverId" > > tablets:<key:"offer.senderGames" value:<group_id:1 predicate:"offer.senderGames" space:62 > > tablets:<key:"offer.senderId" value:<group_id:1 predicate:"offer.senderId" > > tablets:<key:"offer.status" value:<group_id:1 predicate:"offer.status" space:157 > > tablets:<key:"platform" value:<group_id:1 predicate:"platform" space:98 > > tablets:<key:"positive" value:<group_id:1 predicate:"positive" > > tablets:<key:"tradeType" value:<group_id:1 predicate:"tradeType" space:1378 > > tablets:<key:"user" value:<group_id:1 predicate:"user" space:385 > > tablets:<key:"user.country" value:<group_id:1 predicate:"user.country" space:481 > > tablets:<key:"user.description" value:<group_id:1 predicate:"user.description" space:109 > > tablets:<key:"user.email" value:<group_id:1 predicate:"user.email" space:773 > > tablets:<key:"user.epochTimeCreated" value:<group_id:1 predicate:"user.epochTimeCreated" space:532 > > tablets:<key:"user.game" value:<group_id:1 predicate:"user.game" space:3511 > > tablets:<key:"user.gamesHas" value:<group_id:1 predicate:"user.gamesHas" > > tablets:<key:"user.gamesWant" value:<group_id:1 predicate:"user.gamesWant" > > tablets:<key:"user.isBanned" value:<group_id:1 predicate:"user.isBanned" space:87 > > tablets:<key:"user.isPro" value:<group_id:1 predicate:"user.isPro" space:84 > > tablets:<key:"user.latitude" value:<group_id:1 predicate:"user.latitude" space:382 > > tablets:<key:"user.location" value:<group_id:1 predicate:"user.location" space:447 > > tablets:<key:"user.longitude" value:<group_id:1 predicate:"user.longitude" space:383 > > tablets:<key:"user.matchNotifications" value:<group_id:1 predicate:"user.matchNotifications" space:97 > > tablets:<key:"user.noOfSuccessfulExchanges" value:<group_id:1 predicate:"user.noOfSuccessfulExchanges" space:109 > > tablets:<key:"user.participates" value:<group_id:1 predicate:"user.participates" space:428 > > tablets:<key:"user.ratingNegative" value:<group_id:1 predicate:"user.ratingNegative" space:100 > > tablets:<key:"user.ratingPositive" value:<group_id:1 predicate:"user.ratingPositive" space:100 > > tablets:<key:"user.state" value:<group_id:1 predicate:"user.state" space:487 > > tablets:<key:"user.subscriptionCancelUrl" value:<group_id:1 predicate:"user.subscriptionCancelUrl" > > tablets:<key:"user.subscriptionUpdateUrl" value:<group_id:1 predicate:"user.subscriptionUpdateUrl" > > tablets:<key:"user.userImageUrl" value:<group_id:1 predicate:"user.userImageUrl" space:912 > > tablets:<key:"user.userName" value:<group_id:1 predicate:"user.userName" space:515 > > checksum:8752590508278277041 > > zeros:<key:1 value:<id:1 addr:"dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080" leader:true > > zeros:<key:2 value:<id:2 addr:"dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080" > > zeros:<key:3 value:<id:3 addr:"dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080" > > maxLeaseId:745010 maxTxnTs:10000 maxRaftId:3 cid:"bc9b29e0-4c57-454f-a537-cfb463843a62" license:<maxNodes:18446744073709551615 expiryTs:1589734452 enabled:true >
I0417 20:14:31.631931      16 node.go:182] Setting conf state to nodes:1
I0417 20:14:31.641852      16 node.go:182] Setting conf state to nodes:1 nodes:2
W0417 20:14:31.634676      16 pool.go:254] Connection lost with dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:14:31.642546      16 node.go:182] Setting conf state to nodes:1 nodes:2 nodes:3
I0417 20:14:31.727650      16 draft.go:136] Operation started with id: opIndexing
I0417 20:14:31.727982      16 draft.go:104] Operation completed with id: opIndexing
I0417 20:14:31.728019      16 draft.go:104] Operation completed with id: opRollup
E0417 20:14:31.739977      16 groups.go:1084] Error from alpha client subscribe: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:14:31.750290      16 draft.go:136] Operation started with id: opIndexing
I0417 20:14:31.750412      16 index.go:856] Deleting index for attr user.userName and tokenizers []
I0417 20:14:31.750423      16 index.go:870] Deleting index for attr user.userName and tokenizers [hash]
I0417 20:14:31.750453      16 log.go:34] Writes flushed. Stopping compactions now...
I0417 20:14:31.787704      16 log.go:34] Got compaction priority: {level:0 score:1.74 dropPrefix:[0 0 13 117 115 101 114 46 117 115 101 114 78 97 109 101 
2 11]}
I0417 20:14:31.795773      16 log.go:34] Running for level: 0
E0417 20:14:31.840363      16 groups.go:1084] Error from alpha client subscribe: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:14:31.870336      16 log.go:34] LOG Compact 0->1, del 2 tables, add 1 tables, took 74.474159ms
I0417 20:14:31.870530      16 log.go:34] Compaction for level: 0 DONE
I0417 20:14:31.870640      16 log.go:34] DropPrefix done
I0417 20:14:31.870656      16 log.go:34] Resuming writes
I0417 20:14:31.870822      16 log.go:34] Writes flushed. Stopping compactions now...
E0417 20:14:31.941788      16 groups.go:1084] Error from alpha client subscribe: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:14:31.988960      16 log.go:34] LOG Compact 1->1, del 1 tables, add 1 tables, took 108.506946ms
I0417 20:14:31.989022      16 log.go:34] DropPrefix done
I0417 20:14:31.989033      16 log.go:34] Resuming writes
I0417 20:14:31.989417      16 index.go:901] Rebuilding index for attr user.userName and tokenizers [hash]
I0417 20:14:32.042706      16 pool.go:160] CONNECTING to dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:14:32.131112      16 log.go:34] All 0 tables opened in 0s
2020/04/17 20:14:32 Assert failed
github.com/dgraph-io/dgraph/x.AssertTrue
        /tmp/go/src/github.com/dgraph-io/dgraph/x/error.go:94
github.com/dgraph-io/dgraph/posting.(*Txn).addIndexMutations
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:94
github.com/dgraph-io/dgraph/posting.rebuildTokIndex.func1.1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:921
github.com/dgraph-io/dgraph/posting.(*List).iterate
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/list.go:677
github.com/dgraph-io/dgraph/posting.(*List).Iterate
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/list.go:556
github.com/dgraph-io/dgraph/posting.rebuildTokIndex.func1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:912
github.com/dgraph-io/dgraph/posting.(*rebuilder).Run.func1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:604
github.com/dgraph-io/badger/v2.(*Stream).produceKVs.func1
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:191
github.com/dgraph-io/badger/v2.(*Stream).produceKVs
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:234
github.com/dgraph-io/badger/v2.(*Stream).Orchestrate.func1
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:337
runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1373

scroobius-pip · April 17, 2020, 8:22pm

alpha 3

++ hostname -f
+ dgraph alpha --my=dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080 --lru_mb 1433 --zero dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 20:14:32 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 20:14:32 Integration installed: Environment
[Sentry] 2020/04/17 20:14:32 Integration installed: Modules
[Sentry] 2020/04/17 20:14:32 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 20:14:32 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 20:14:32 Integration installed: Environment
[Sentry] 2020/04/17 20:14:32 Integration installed: Modules
[Sentry] 2020/04/17 20:14:32 Integration installed: IgnoreErrors
I0417 20:14:32.422545      18 init.go:99]

Dgraph version   : v20.03.0
Dgraph SHA-256   : 07e63901be984bd20a3505a2ee5840bb8fc4f72cc7749c485f9f77db15b9b75a
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit http://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Copyright 2015-2020 Dgraph Labs, Inc.


I0417 20:14:32.423564      18 run.go:606] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000}
I0417 20:14:32.423625      18 run.go:607] x.WorkerConfig: {ExportPath:export NumPendingProposals:256 Tracing:1 MyAddr:dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080 ZeroAddr:dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080 RaftId:0 WhiteListedIPRanges:[] MaxRetries:-1 StrictMutations:false AclEnabled:false AbortOlderThan:5m0s SnapshotAfter:10000 ProposedGroupId:0 StartTime:2020-04-17 20:14:32.052549031 +0000 UTC m=+0.036628997 LudicrousMode:false}
I0417 20:14:32.423684      18 run.go:608] worker.Config: {PostingDir:p BadgerTables:mmap BadgerVlog:mmap BadgerKeyFile: WALDir:w MutationsMode:0 AuthToken: AllottedMemory:1433 HmacSecret:[] AccessJwtTtl:0s RefreshJwtTtl:0s AclRefreshInterval:0s}
I0417 20:14:32.423771      18 server_state.go:74] Setting Badger table load option: mmap
I0417 20:14:32.423779      18 server_state.go:86] Setting Badger value log load option: mmap
I0417 20:14:32.423786      18 server_state.go:131] Opening write-ahead log BadgerDB with options: {Dir:w ValueDir:w SyncWrites:false TableLoadingMode:1 ValueLogLoadingMode:2 NumVersionsToKeep:1 ReadOnly:false Truncate:true Logger:0x260a270 Compression:0 EventLogging:true InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1048576 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:true MaxCacheSize:10485760 MaxBfCacheSize:0 LoadBloomsOnOpen:true NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:10000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:1 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0417 20:14:32.431986      18 log.go:34] All 0 tables opened in 0s
I0417 20:14:32.442706      18 log.go:34] Replaying file id: 0 at offset: 0
I0417 20:14:32.445439      18 log.go:34] Replay took: 2.691058ms
I0417 20:14:32.445778      18 server_state.go:74] Setting Badger table load option: mmap
I0417 20:14:32.445856      18 server_state.go:86] Setting Badger value log load option: mmap
I0417 20:14:32.445876      18 server_state.go:154] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false TableLoadingMode:2 ValueLogLoadingMode:2 NumVersionsToKeep:2147483647 ReadOnly:false Truncate:true Logger:0x260a270 Compression:0 EventLogging:true InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:true MaxCacheSize:1073741824 MaxBfCacheSize:0 LoadBloomsOnOpen:true NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:1 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0417 20:14:32.481750      18 log.go:34] All 38 tables opened in 9ms
I0417 20:14:32.492686      18 log.go:34] Replaying file id: 0 at offset: 39347
I0417 20:14:32.492713      18 log.go:34] Replay took: 4.959µs
I0417 20:14:32.496441      18 groups.go:104] Current Raft Id: 0x3
I0417 20:14:32.496526      18 worker.go:96] Worker listening at address: [::]:7080
I0417 20:14:32.497894      18 run.go:477] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql
I0417 20:14:32.497919      18 run.go:478] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin
I0417 20:14:32.497960      18 run.go:509] gRPC server started.  Listening on port 9080
I0417 20:14:32.497973      18 run.go:510] HTTP server started.  Listening on port 8080
I0417 20:14:32.597331      18 pool.go:160] CONNECTING to dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:32.634895      18 groups.go:131] Connected to group zero. Assigned group: 0
I0417 20:14:32.634931      18 groups.go:133] Raft Id after connection to Zero: 0x3
I0417 20:14:32.635012      18 pool.go:160] CONNECTING to dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:14:32.635051      18 pool.go:160] CONNECTING to dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:14:32.635098      18 pool.go:160] CONNECTING to dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:32.635131      18 pool.go:160] CONNECTING to dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:32.635235      18 draft.go:175] Node ID: 0x3 with GroupID: 1
I0417 20:14:32.635409      18 node.go:145] Setting raft.Config to: &{ID:3 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc0000f58f0 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false}
I0417 20:14:32.640287      18 node.go:314] Found hardstate: {Term:2 Vote:0 Commit:229 XXX_unrecognized:[]}
I0417 20:14:32.640576      18 node.go:323] Group 1 found 230 entries
I0417 20:14:32.640595      18 draft.go:1506] Restarting node for group: 1
I0417 20:14:32.640654      18 log.go:34] 3 became follower at term 2
I0417 20:14:32.640695      18 log.go:34] newRaft 3 [peers: [], term: 2, commit: 229, applied: 0, lastindex: 229, lastterm: 2]
I0417 20:14:32.640766      18 draft.go:136] Operation started with id: opRollup
I0417 20:14:32.640789      18 groups.go:151] Server is ready
I0417 20:14:32.641500      18 draft.go:925] Found Raft progress: 0
I0417 20:14:32.649016      18 groups.go:775] Got address of a Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 20:14:32.653202      18 groups.go:788] Starting a new membership stream receive from dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080.      
I0417 20:14:32.657349      18 node.go:182] Setting conf state to nodes:1
I0417 20:14:32.657556      18 node.go:182] Setting conf state to nodes:1 nodes:2
I0417 20:14:32.657692      18 node.go:182] Setting conf state to nodes:1 nodes:2 nodes:3
E0417 20:14:32.660514      18 groups.go:1084] Error from alpha client subscribe: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local: no such host"
W0417 20:14:32.660595      18 pool.go:254] Connection lost with dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local: no such host"
I0417 20:14:32.664232      18 groups.go:805] Received first state update from Zero: counter:137 groups:<key:1 value:<members:<key:1 value:<id:1 group_id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" last_update:1587153919 > > members:<key:2 value:<id:2 group_id:1 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true > > members:<key:3 value:<id:3 group_id:1 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true > > tablets:<key:"description" value:<group_id:1 predicate:"description" space:1271 > > tablets:<key:"dgraph.acl.rule" value:<group_id:1 predicate:"dgraph.acl.rule" > > tablets:<key:"dgraph.graphql.schema" value:<group_id:1 predicate:"dgraph.graphql.schema" > > tablets:<key:"dgraph.group.acl" value:<group_id:1 predicate:"dgraph.group.acl" > > tablets:<key:"dgraph.password" value:<group_id:1 predicate:"dgraph.password" > 
> tablets:<key:"dgraph.rule.permission" value:<group_id:1 predicate:"dgraph.rule.permission" > > tablets:<key:"dgraph.rule.predicate" value:<group_id:1 predicate:"dgraph.rule.predicate" > > tablets:<key:"dgraph.type" value:<group_id:1 predicate:"dgraph.type" > > tablets:<key:"dgraph.user.group" value:<group_id:1 predicate:"dgraph.user.group" > > tablets:<key:"dgraph.xid" value:<group_id:1 predicate:"dgraph.xid" > > tablets:<key:"game" value:<group_id:1 predicate:"game" space:5132140 > > tablets:<key:"game.coverUrl" value:<group_id:1 predicate:"game.coverUrl" space:9948550 > > tablets:<key:"game.name" value:<group_id:1 predicate:"game.name" space:11782792 > > tablets:<key:"game.platform" value:<group_id:1 predicate:"game.platform" space:5601970 > > tablets:<key:"game.popularity" value:<group_id:1 predicate:"game.popularity" space:6002130 > > tablets:<key:"game.url" value:<group_id:1 predicate:"game.url" space:130 > > tablets:<key:"game.uuid" value:<group_id:1 predicate:"game.uuid" space:12767270 > > tablets:<key:"info" value:<group_id:1 predicate:"info" space:1669 > > tablets:<key:"name" value:<group_id:1 predicate:"name" space:90 > > tablets:<key:"negative" value:<group_id:1 predicate:"negative" > > tablets:<key:"offer" value:<group_id:1 predicate:"offer" space:76 > > tablets:<key:"offer.epochTimeCreated" value:<group_id:1 predicate:"offer.epochTimeCreated" space:151 > > tablets:<key:"offer.offerId" value:<group_id:1 predicate:"offer.offerId" space:159 > > tablets:<key:"offer.receiverGames" value:<group_id:1 predicate:"offer.receiverGames" space:64 > > tablets:<key:"offer.receiverId" value:<group_id:1 predicate:"offer.receiverId" > > tablets:<key:"offer.senderGames" value:<group_id:1 predicate:"offer.senderGames" space:62 > > tablets:<key:"offer.senderId" value:<group_id:1 predicate:"offer.senderId" > > tablets:<key:"offer.status" value:<group_id:1 predicate:"offer.status" space:157 > > tablets:<key:"platform" value:<group_id:1 predicate:"platform" space:98 > > tablets:<key:"positive" value:<group_id:1 predicate:"positive" > > tablets:<key:"tradeType" value:<group_id:1 predicate:"tradeType" space:1378 > > tablets:<key:"user" value:<group_id:1 predicate:"user" space:385 > > tablets:<key:"user.country" value:<group_id:1 predicate:"user.country" space:481 > > tablets:<key:"user.description" value:<group_id:1 predicate:"user.description" space:109 > > tablets:<key:"user.email" value:<group_id:1 predicate:"user.email" space:773 > > tablets:<key:"user.epochTimeCreated" value:<group_id:1 predicate:"user.epochTimeCreated" space:532 > > tablets:<key:"user.game" value:<group_id:1 predicate:"user.game" space:3511 > > tablets:<key:"user.gamesHas" value:<group_id:1 predicate:"user.gamesHas" > > tablets:<key:"user.gamesWant" value:<group_id:1 predicate:"user.gamesWant" > > tablets:<key:"user.isBanned" value:<group_id:1 predicate:"user.isBanned" space:87 > > tablets:<key:"user.isPro" value:<group_id:1 predicate:"user.isPro" space:84 > > tablets:<key:"user.latitude" value:<group_id:1 predicate:"user.latitude" space:382 > > tablets:<key:"user.location" value:<group_id:1 predicate:"user.location" space:447 > > tablets:<key:"user.longitude" value:<group_id:1 predicate:"user.longitude" space:383 > > tablets:<key:"user.matchNotifications" value:<group_id:1 predicate:"user.matchNotifications" space:97 > > tablets:<key:"user.noOfSuccessfulExchanges" value:<group_id:1 predicate:"user.noOfSuccessfulExchanges" space:109 > > tablets:<key:"user.participates" value:<group_id:1 predicate:"user.participates" space:428 > > tablets:<key:"user.ratingNegative" value:<group_id:1 predicate:"user.ratingNegative" space:100 > > tablets:<key:"user.ratingPositive" value:<group_id:1 predicate:"user.ratingPositive" space:100 > > tablets:<key:"user.state" value:<group_id:1 predicate:"user.state" space:487 > > tablets:<key:"user.subscriptionCancelUrl" value:<group_id:1 predicate:"user.subscriptionCancelUrl" > > tablets:<key:"user.subscriptionUpdateUrl" value:<group_id:1 predicate:"user.subscriptionUpdateUrl" > > tablets:<key:"user.userImageUrl" value:<group_id:1 predicate:"user.userImageUrl" space:912 > > tablets:<key:"user.userName" value:<group_id:1 predicate:"user.userName" space:515 > > checksum:8752590508278277041 > > zeros:<key:1 value:<id:1 addr:"dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080" leader:true > > zeros:<key:2 value:<id:2 addr:"dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080" > > zeros:<key:3 value:<id:3 addr:"dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080" > > maxLeaseId:745010 maxTxnTs:10000 maxRaftId:3 cid:"bc9b29e0-4c57-454f-a537-cfb463843a62" license:<maxNodes:18446744073709551615 expiryTs:1589734452 enabled:true >
I0417 20:14:32.721897      18 draft.go:136] Operation started with id: opIndexing
I0417 20:14:32.722088      18 draft.go:104] Operation completed with id: opRollup
I0417 20:14:32.724643      18 draft.go:104] Operation completed with id: opIndexing
I0417 20:14:32.743401      18 draft.go:136] Operation started with id: opIndexing
I0417 20:14:32.743656      18 index.go:856] Deleting index for attr user.userName and tokenizers []
I0417 20:14:32.744274      18 index.go:870] Deleting index for attr user.userName and tokenizers [hash]
I0417 20:14:32.744398      18 log.go:34] Writes flushed. Stopping compactions now...
I0417 20:14:32.755639      18 log.go:34] Got compaction priority: {level:0 score:1.74 dropPrefix:[0 0 13 117 115 101 114 46 117 115 101 114 78 97 109 101 
2 11]}
I0417 20:14:32.755725      18 log.go:34] Running for level: 0
I0417 20:14:32.798180      18 log.go:34] LOG Compact 0->1, del 2 tables, add 1 tables, took 42.399119ms
I0417 20:14:32.798256      18 log.go:34] Compaction for level: 0 DONE
I0417 20:14:32.798410      18 log.go:34] DropPrefix done
I0417 20:14:32.798438      18 log.go:34] Resuming writes
I0417 20:14:32.799079      18 log.go:34] Writes flushed. Stopping compactions now...
I0417 20:14:32.844970      18 log.go:34] LOG Compact 1->1, del 1 tables, add 1 tables, took 40.275375ms
I0417 20:14:32.845248      18 log.go:34] DropPrefix done
I0417 20:14:32.846136      18 log.go:34] Resuming writes
I0417 20:14:32.846379      18 index.go:901] Rebuilding index for attr user.userName and tokenizers [hash]
W0417 20:14:32.911236      18 pool.go:254] Connection lost with dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = transport is closing
E0417 20:14:32.911416      18 groups.go:1093] Error from worker subscribe stream: rpc error: code = Unavailable desc = transport is closing
I0417 20:14:32.911575      18 pool.go:160] CONNECTING to dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080
I0417 20:14:32.932885      18 log.go:34] All 0 tables opened in 0s
2020/04/17 20:14:32 Assert failed
github.com/dgraph-io/dgraph/x.AssertTrue
        /tmp/go/src/github.com/dgraph-io/dgraph/x/error.go:94
github.com/dgraph-io/dgraph/posting.(*Txn).addIndexMutations
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:94
github.com/dgraph-io/dgraph/posting.rebuildTokIndex.func1.1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:921
github.com/dgraph-io/dgraph/posting.(*List).iterate
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/list.go:677
github.com/dgraph-io/dgraph/posting.(*List).Iterate
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/list.go:556
github.com/dgraph-io/dgraph/posting.rebuildTokIndex.func1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:912
github.com/dgraph-io/dgraph/posting.(*rebuilder).Run.func1
        /tmp/go/src/github.com/dgraph-io/dgraph/posting/index.go:604
github.com/dgraph-io/badger/v2.(*Stream).produceKVs.func1
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:191
github.com/dgraph-io/badger/v2.(*Stream).produceKVs
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:234
github.com/dgraph-io/badger/v2.(*Stream).Orchestrate.func1
        /tmp/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200316175624-91c31ebe8c22/stream.go:337
runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1373

scroobius-pip · April 17, 2020, 8:23pm

zero 1:

++ hostname
+ [[ dgraph-zero-0 =~ -([0-9]+)$ ]]
+ ordinal=0
+ idx=1
+ [[ 0 -eq 0 ]]
++ hostname -f
+ exec dgraph zero --my=dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080 --idx 1 --replicas 3
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 16:54:06 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 16:54:06 Integration installed: Environment
[Sentry] 2020/04/17 16:54:06 Integration installed: Modules
[Sentry] 2020/04/17 16:54:06 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 16:54:06 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 16:54:06 Integration installed: Environment
[Sentry] 2020/04/17 16:54:06 Integration installed: Modules
[Sentry] 2020/04/17 16:54:06 Integration installed: IgnoreErrors
I0417 16:54:06.664134      19 init.go:99]

Dgraph version   : v20.03.0
Dgraph SHA-256   : 07e63901be984bd20a3505a2ee5840bb8fc4f72cc7749c485f9f77db15b9b75a
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit http://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Copyright 2015-2020 Dgraph Labs, Inc.


I0417 16:54:06.665674      19 run.go:105] Setting up grpc listener at: 0.0.0.0:5080
I0417 16:54:06.667721      19 run.go:105] Setting up http listener at: 0.0.0.0:6080
badger 2020/04/17 16:54:06 INFO: All 0 tables opened in 1ms
I0417 16:54:06.796767      19 node.go:145] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc000114c30 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false}
I0417 16:54:06.797618      19 node.go:323] Group 0 found 1 entries
I0417 16:54:06.797784      19 log.go:34] 1 became follower at term 0
I0417 16:54:06.797826      19 log.go:34] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0417 16:54:06.797843      19 log.go:34] 1 became follower at term 1
I0417 16:54:06.798146      19 run.go:296] Running Dgraph Zero...
E0417 16:54:06.798564      19 raft.go:516] While proposing CID: Not Zero leader. Aborting proposal: cid:"3ebd4e89-f493-4832-afe4-3730e819e0d9" . Retrying...
I0417 16:54:06.832711      19 node.go:182] Setting conf state to nodes:1
I0417 16:54:06.832963      19 raft.go:702] Done applying conf change at 0x1
I0417 16:54:07.801784      19 log.go:34] 1 no leader at term 1; dropping index reading msg
E0417 16:54:09.800379      19 raft.go:516] While proposing CID: Not Zero leader. Aborting proposal: cid:"e5dc0379-1e9e-4b1d-93d3-becc266c8628" . Retrying...
W0417 16:54:09.801791      19 node.go:671] [0x1] Read index context timed out
I0417 16:54:09.801887      19 log.go:34] 1 no leader at term 1; dropping index reading msg
I0417 16:54:10.698429      19 log.go:34] 1 is starting a new election at term 1
I0417 16:54:10.698506      19 log.go:34] 1 became pre-candidate at term 1
I0417 16:54:10.698671      19 log.go:34] 1 received MsgPreVoteResp from 1 at term 1
I0417 16:54:10.698758      19 log.go:34] 1 became candidate at term 2
I0417 16:54:10.698765      19 log.go:34] 1 received MsgVoteResp from 1 at term 2
I0417 16:54:10.698784      19 log.go:34] 1 became leader at term 2
I0417 16:54:10.698849      19 log.go:34] raft.node: 1 elected leader 1 at term 2
I0417 16:54:10.699035      19 raft.go:667] I've become the leader, updating leases.
I0417 16:54:10.699053      19 assign.go:42] Updated Lease id: 1. Txn Ts: 1
W0417 16:54:11.801935      19 node.go:671] [0x1] Read index context timed out
I0417 16:54:12.908321      19 raft.go:509] CID set for cluster: bc9b29e0-4c57-454f-a537-cfb463843a62
I0417 16:54:12.916795      19 license_ee.go:45] Enterprise state proposed to the cluster: key:"z1-9154516789730504541" license:<maxNodes:18446744073709551615 expiryTs:1589734452 >
I0417 16:54:17.828181      19 pool.go:160] CONNECTING to dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080
I0417 16:54:17.828228      19 node.go:583] Trying to add 0x2 to cluster. Addr: dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080
I0417 16:54:17.828239      19 node.go:584] Current confstate at 0x1: nodes:1
I0417 16:54:17.900273      19 node.go:182] Setting conf state to nodes:1 nodes:2
I0417 16:54:17.900344      19 raft.go:702] Done applying conf change at 0x1
I0417 16:54:17.900716      19 node.go:746] [0x2] Done joining cluster with err: <nil>
I0417 16:54:26.896882      19 pool.go:160] CONNECTING to dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080
I0417 16:54:26.896912      19 node.go:583] Trying to add 0x3 to cluster. Addr: dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080
I0417 16:54:26.896921      19 node.go:584] Current confstate at 0x1: nodes:1 nodes:2 
I0417 16:54:26.975140      19 node.go:182] Setting conf state to nodes:1 nodes:2 nodes:3
I0417 16:54:26.975195      19 raft.go:702] Done applying conf change at 0x1
I0417 16:54:26.975225      19 node.go:746] [0x3] Done joining cluster with err: <nil>
I0417 18:22:20.976742      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 18:22:20.982186      19 zero.go:435] Connected: cluster_info_only:true
I0417 18:22:20.985710      19 zero.go:417] Got connection request: group_id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true
I0417 18:22:20.988208      19 pool.go:160] CONNECTING to dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080
W0417 18:22:20.993597      19 pool.go:254] Connection lost with dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unknown desc = No node has been set up yet
I0417 18:22:21.012319      19 zero.go:562] Connected: id:1 group_id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true
I0417 18:22:26.599738      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 18:22:26.607155      19 zero.go:435] Connected: cluster_info_only:true
I0417 18:22:26.611874      19 zero.go:417] Got connection request: group_id:1 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true
I0417 18:22:26.617991      19 pool.go:160] CONNECTING to dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080
I0417 18:22:26.632023      19 zero.go:562] Connected: id:2 group_id:1 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true
W0417 18:22:26.636593      19 pool.go:254] Connection lost with dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unknown desc = No node has been set up yet
I0417 18:22:28.159208      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 18:22:28.163017      19 zero.go:435] Connected: cluster_info_only:true
I0417 18:22:28.168893      19 zero.go:417] Got connection request: group_id:1 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true
I0417 18:22:28.173532      19 pool.go:160] CONNECTING to dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080
W0417 18:22:28.183618      19 pool.go:254] Connection lost with dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unknown desc = No node has been set up yet
I0417 18:22:28.194310      19 zero.go:562] Connected: id:3 group_id:1 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080" force_group_id:true
I0417 20:05:19.452582      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:05:19.456416      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:05:19.464231      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:19.468110      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:19.904191      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:05:19.906270      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:05:19.908015      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:19.911043      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:20.355160      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:05:20.361501      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:05:20.369397      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:20.374075      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:34.314550      19 zero.go:417] Got connection request: cluster_info_only:true 
I0417 20:05:34.317389      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:05:34.326882      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:34.332643      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:35.160419      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:05:35.169022      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:05:35.172164      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:35.176017      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:35.792553      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:05:35.801662      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:05:35.809040      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:05:35.811792      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:00.875267      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:06:00.879319      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:06:00.887080      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:00.891179      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:01.209452      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:06:01.217376      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:06:01.220422      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:01.224765      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:06.231738      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:06:06.234827      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:06:06.245413      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:06.249074      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:44.034369      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:06:44.042316      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:06:44.045294      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:44.048471      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:56.855563      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:06:56.859760      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:06:56.870962      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:56.881382      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:57.184925      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:06:57.188680      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:06:57.192339      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:06:57.195641      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:28.294886      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:28.297890      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:28.304865      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" 
I0417 20:08:28.309661      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:30.157139      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:30.160852      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:30.163180      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:30.166834      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:31.590491      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:31.594420      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:31.598254      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:31.601605      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:34.470353      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:34.474197      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:34.478991      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:34.483821      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:41.412749      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:41.415147      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:41.419607      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:41.422684      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:43.548390      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:43.554709      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:43.558225      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:43.560902      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:47.157885      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:47.161755      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:47.165253      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:47.167926      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:50.897666      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:50.901687      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:50.906169      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:50.910342      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:57.224803      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:08:57.228917      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:08:57.234678      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:08:57.239589      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:09:16.068620      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:09:16.075384      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:09:16.082961      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:09:16.086098      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" 
I0417 20:09:19.789432      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:09:19.795032      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:09:19.801727      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:09:19.811128      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:09:27.255948      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:09:27.261468      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:09:27.265177      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:09:27.269935      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:10:07.151786      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:10:07.155226      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:10:07.158942      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:10:07.161924      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:10:11.207726      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:10:11.210363      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:10:11.213342      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:10:11.216651      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:10:19.405715      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:10:19.408697      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:10:19.413668      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:10:19.416693      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:11:35.141890      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:11:35.144398      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:11:35.147084      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:11:35.150418      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:11:38.890214      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:11:38.893632      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:11:38.898598      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:11:38.902923      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:11:44.244789      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:11:44.247789      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:11:44.251616      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:11:44.256023      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:14:18.098497      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:14:18.101232      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:14:18.104379      19 zero.go:417] Got connection request: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:14:18.108779      19 zero.go:544] Connected: id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:14:30.934830      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:14:30.937216      19 zero.go:435] Connected: cluster_info_only:true 
I0417 20:14:30.943642      19 zero.go:417] Got connection request: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:14:30.947062      19 zero.go:544] Connected: id:2 addr:"dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:14:31.265315      19 zero.go:417] Got connection request: cluster_info_only:true
I0417 20:14:31.268884      19 zero.go:435] Connected: cluster_info_only:true
I0417 20:14:31.274923      19 zero.go:417] Got connection request: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"
I0417 20:14:31.283578      19 zero.go:544] Connected: id:3 addr:"dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080"

zero 2:

++ hostname
+ [[ dgraph-zero-1 =~ -([0-9]+)$ ]]
+ ordinal=1
+ idx=2
+ [[ 1 -eq 0 ]]
++ hostname -f
+ exec dgraph zero --my=dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080 --peer dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080 --idx 2 --replicas 3
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 16:54:17 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 16:54:17 Integration installed: Environment
[Sentry] 2020/04/17 16:54:17 Integration installed: Modules
[Sentry] 2020/04/17 16:54:17 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 16:54:17 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 16:54:17 Integration installed: Environment
[Sentry] 2020/04/17 16:54:17 Integration installed: Modules
[Sentry] 2020/04/17 16:54:17 Integration installed: IgnoreErrors
I0417 16:54:18.156200      19 init.go:99]

Dgraph version   : v20.03.0
Dgraph SHA-256   : 07e63901be984bd20a3505a2ee5840bb8fc4f72cc7749c485f9f77db15b9b75a
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit http://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Copyright 2015-2020 Dgraph Labs, Inc.


I0417 16:54:18.157694      19 run.go:105] Setting up grpc listener at: 0.0.0.0:5080
I0417 16:54:18.159648      19 run.go:105] Setting up http listener at: 0.0.0.0:6080
badger 2020/04/17 16:54:18 INFO: All 0 tables opened in 0s
I0417 16:54:18.331674      19 node.go:145] Setting raft.Config to: &{ID:2 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc00010c030 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false}
I0417 16:54:18.331984      19 node.go:323] Group 0 found 1 entries
I0417 16:54:18.332049      19 pool.go:160] CONNECTING to dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 16:54:18.420494      19 raft.go:494] [0x2] Starting node
I0417 16:54:18.420598      19 log.go:34] 2 became follower at term 0
I0417 16:54:18.420665      19 log.go:34] newRaft 2 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0417 16:54:18.420726      19 log.go:34] 2 became follower at term 1
I0417 16:54:18.420873      19 run.go:296] Running Dgraph Zero...
I0417 16:54:19.421488      19 log.go:34] 2 [term: 1] received a MsgHeartbeat message with higher term from 1 [term: 2]
I0417 16:54:19.421542      19 log.go:34] 2 became follower at term 2

zero 3:

++ hostname
+ [[ dgraph-zero-2 =~ -([0-9]+)$ ]]
+ ordinal=2
+ idx=3
+ [[ 2 -eq 0 ]]
++ hostname -f
+ exec dgraph zero --my=dgraph-zero-2.dgraph-zero.default.svc.cluster.local:5080 --peer dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080 --idx 3 --replicas 3
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 16:54:27 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 16:54:27 Integration installed: Environment
[Sentry] 2020/04/17 16:54:27 Integration installed: Modules
[Sentry] 2020/04/17 16:54:27 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
[Sentry] 2020/04/17 16:54:27 Integration installed: ContextifyFrames
[Sentry] 2020/04/17 16:54:27 Integration installed: Environment
[Sentry] 2020/04/17 16:54:27 Integration installed: Modules
[Sentry] 2020/04/17 16:54:27 Integration installed: IgnoreErrors
I0417 16:54:28.117171      17 init.go:99]

Dgraph version   : v20.03.0
Dgraph SHA-256   : 07e63901be984bd20a3505a2ee5840bb8fc4f72cc7749c485f9f77db15b9b75a
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit http://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Copyright 2015-2020 Dgraph Labs, Inc.


I0417 16:54:28.118734      17 run.go:105] Setting up grpc listener at: 0.0.0.0:5080
I0417 16:54:28.120048      17 run.go:105] Setting up http listener at: 0.0.0.0:6080
badger 2020/04/17 16:54:28 INFO: All 0 tables opened in 4ms
I0417 16:54:28.236633      17 node.go:145] Setting raft.Config to: &{ID:3 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc0003977a0 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false}
I0417 16:54:28.237110      17 node.go:323] Group 0 found 1 entries
I0417 16:54:28.237234      17 pool.go:160] CONNECTING to dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0417 16:54:28.324719      17 raft.go:494] [0x3] Starting node
I0417 16:54:28.324826      17 log.go:34] 3 became follower at term 0
I0417 16:54:28.324870      17 log.go:34] newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0417 16:54:28.324879      17 log.go:34] 3 became follower at term 1
I0417 16:54:28.325319      17 run.go:296] Running Dgraph Zero...
I0417 16:54:29.325719      17 log.go:34] 3 no leader at term 1; dropping index reading msg
I0417 16:54:29.348044      17 log.go:34] 3 [term: 1] received a MsgHeartbeat message with higher term from 1 [term: 2]
I0417 16:54:29.348086      17 log.go:34] 3 became follower at term 2
I0417 16:54:29.348097      17 log.go:34] raft.node: 3 elected leader 1 at term 2
I0417 16:54:30.469092      17 node.go:182] Setting conf state to nodes:1
I0417 16:54:30.469271      17 raft.go:702] Done applying conf change at 0x3
I0417 16:54:30.469806      17 node.go:182] Setting conf state to nodes:1 nodes:2
I0417 16:54:30.469876      17 raft.go:702] Done applying conf change at 0x3
I0417 16:54:30.470132      17 node.go:182] Setting conf state to nodes:1 nodes:2 nodes:3
I0417 16:54:30.470177      17 raft.go:702] Done applying conf change at 0x3
I0417 16:54:30.470550      17 pool.go:160] CONNECTING to dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080
W0417 16:54:31.325746      17 node.go:671] [0x3] Read index context timed out
I0417 18:22:22.364992      17 pool.go:160] CONNECTING to dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080
I0417 18:22:27.984063      17 pool.go:160] CONNECTING to dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080
I0417 18:22:29.542400      17 pool.go:160] CONNECTING to dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080
W0417 18:22:29.548688      17 pool.go:254] Connection lost with dgraph-alpha-2.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unknown desc = No node has been set up yet
W0417 20:05:19.182448      17 pool.go:254] Connection lost with dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = transport is closing
W0417 20:05:19.671772      17 pool.go:254] Connection lost with dgraph-alpha-1.dgraph-alpha.default.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = transport is closing

scroobius-pip · April 17, 2020, 8:27pm

I’ve been trying to come up with something production ready for product launch, it’s really frustrating. Boy i can’t wait for a managed service.

dmai · April 17, 2020, 8:36pm

This assertion failure shouldn’t happen. Are the Alphas up again after restarting?

Are the disks OK and have sufficient space? Looks like there was an issue with the indexing and possibly the write-ahead log if this is being replayed.

scroobius-pip · April 17, 2020, 8:41pm

I’ve been trying it’s currently on the 7th restart. It’s still not up.
Update:

currently on the 19th restart

scroobius-pip · April 17, 2020, 8:42pm

Disk space ? I believe I’ve got enough space

scroobius-pip · April 17, 2020, 9:24pm

I’m not sure if this is related but i had issues querying with the “eq” function on a hash indexed predicate, some results weren’t showing. And before this issue i had recently restored the database from an export.

dmai · April 17, 2020, 10:04pm

Thanks for the additional details. Could you share some examples of the queries you’re seeing unexpected results with? If you can reproduce this issue from a fresh database, that would help us drill down to what’s causing this assertion failure you’re seeing.

To get yourself up and running again you can start with a fresh cluster and load your data from the export.

scroobius-pip · April 17, 2020, 10:06pm

Okay will do that and get back to you

scroobius-pip · April 17, 2020, 11:02pm

Here’s the query i’m having issues with:

{
        user(func: eq(user.userName, "sim04ful")){
        uid
        }
}

it returns the following result:

{
  "data": {
    "user": []
  },
  "extensions": {
    "server_latency": {
      "parsing_ns": 130445,
      "processing_ns": 492484,
      "encoding_ns": 10139,
      "total_ns": 925676
    },
    "txn": {
      "start_ts": 9
    },
    "metrics": {
      "num_uids": {
        "uid": 0,
        "user.userName": 0
      }
    }
  }
}

but when i run the following query to list all users:

{
  users(func: has(<user>)) {
          uid
	user.userName
  }
}

i get this result:

{
  "data": {
    "users": [
      {
        "uid": "0x186a2"
      },
      {
        "uid": "0x19899"
      },
      {
        "uid": "0x6ca51",
        "user.userName": "sim04ful"
      },
      {
        "uid": "0x6ca6d",
        "user.userName": "sim04fulqam"
      },
      {
        "uid": "0x6ca7a",
        "user.userName": "olsn."
      }
    ]
  },
  "extensions": {
    "server_latency": {
      "parsing_ns": 518433,
      "processing_ns": 3838681,
      "encoding_ns": 69170,
      "total_ns": 4651215
    },
    "txn": {
      "start_ts": 11
    },
    "metrics": {
      "num_uids": {
        "uid": 5,
        "user": 0,
        "user.userName": 5
      }
    }
  }
}

here’s the index settings im using:

scroobius-pip · April 17, 2020, 11:06pm

I then remove the index like this:

and recreate it:

the “updating” button seems to be stuck,

And there we go:

scroobius-pip · April 17, 2020, 11:07pm

g01.rdf.gz (3.3 MB) g01.schema.gz (553 Bytes)

Here are my export files that i loaded into the cluster.

dmai · April 17, 2020, 11:18pm

Thanks for sharing the exported dataset.

I see <0x0> UIDs in your data set. This isn’t a valid UID. If you change these to a valid UID (or a blank node so the UID is assigned automatically when you mutate), then your issue should be resolved.

If you’re using live loader or bulk loader to load the data, you can use the --new_uids=true flag to create new UIDs.

scroobius-pip · April 17, 2020, 11:21pm

well i followed the tutorial on exporting the database, and i didn’t edit the files. Isn’t the invalid uid from a fault in dgraph’s export functionality ?

scroobius-pip · April 17, 2020, 11:23pm

using the --new_uids=true flag is perfectly acceptable but that seems to be ignoring the underlying problem which is that the export function generated an invalid file.

dmai · April 17, 2020, 11:26pm

Export should definitely not be writing out wrong UIDs, and especially not invalid UIDs like <0x0>. We’ll look into it. Can you share a copy of the p directory from an Alpha where the export came from? That would help.

scroobius-pip · April 17, 2020, 11:30pm

dmai · April 17, 2020, 11:48pm

Thanks. Do you have a p directory from before a bulk load of an export?

Topic		Replies	Views
Alpha node restart failed Dgraph dgraph	12	1551	February 15, 2024
Unexpected fault address error on one of the pods Issues kind:question	2	1582	April 13, 2021
Dgraph Zero crashes with Fatal error along with infinite loop in Alpha Dgraph	5	721	April 22, 2021
Deleted node appears after alpha restart Dgraph kind:bug	0	524	November 21, 2021
Advice on handling corrupt alpha pod Dgraph kind:question , dgraph	1	732	January 5, 2023

Dgraph cluster crashes when recreating index

Related topics