++ hostname -f
+ dgraph alpha --my=dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080 --lru_mb 1340 --zero dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
[Decoder]: Using assembly version of decoder
I1126 12:51:52.913429       1 init.go:98] 

Dgraph version   : v1.1.0
Dgraph SHA-256   : 7d4294a80f74692695467e2cf17f74648c18087ed7057d798f40e1d3a31d2095
Commit SHA-1     : ef7cdb28
Commit timestamp : 2019-09-04 00:12:51 -0700
Branch           : HEAD
Go version       : go1.12.7

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit https://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-2018 Dgraph Labs, Inc.


I1126 12:51:52.915360       1 run.go:500] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000}
I1126 12:51:52.915581       1 run.go:501] 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}
I1126 12:51:52.915804       1 run.go:502] edgraph.Config: {PostingDir:p BadgerTables:mmap BadgerVlog:mmap WALDir:w MutationsMode:0 AuthToken: AllottedMemory:1340.0MB AccessJwtTtl:0s RefreshJwtTtl:0s AclRefreshInterval:0s}
I1126 12:51:52.916081       1 server.go:133] Setting Badger table load option: mmap
I1126 12:51:52.916248       1 server.go:145] Setting Badger value log load option: mmap
I1126 12:51:52.916411       1 server.go:173] Opening write-ahead log BadgerDB with options: {Dir:w ValueDir:w SyncWrites:false TableLoadingMode:1 ValueLogLoadingMode:2 NumVersionsToKeep:1 ReadOnly:false Truncate:true Logger:0x22d6ac8 MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1048576 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:10000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I1126 12:51:53.106690       1 log.go:34] All 2 tables opened in 177ms
I1126 12:51:53.113310       1 log.go:34] Replaying file id: 1 at offset: 11780479
I1126 12:51:53.114926       1 log.go:34] Replay took: 1.106631ms
I1126 12:51:53.115231       1 log.go:34] Replaying file id: 2 at offset: 0
I1126 12:51:53.193572       1 log.go:34] Replay took: 78.177963ms
I1126 12:51:53.194339       1 server.go:133] Setting Badger table load option: mmap
I1126 12:51:53.194636       1 server.go:145] Setting Badger value log load option: mmap
I1126 12:51:53.194802       1 server.go:186] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false TableLoadingMode:2 ValueLogLoadingMode:2 NumVersionsToKeep:2147483647 ReadOnly:false Truncate:true Logger:0x22d6ac8 MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ChecksumVerificationMode:0 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I1126 12:51:53.210264       1 log.go:34] All 1 tables opened in 2ms
I1126 12:51:53.216029       1 log.go:34] Replaying file id: 0 at offset: 3223
I1126 12:51:55.313654       1 log.go:34] Replay took: 2.097014366s
I1126 12:51:55.315027       1 groups.go:98] Current Raft Id: 0x1
I1126 12:51:55.315688       1 run.go:417] gRPC server started.  Listening on port 9080
I1126 12:51:55.316415       1 run.go:418] HTTP server started.  Listening on port 8080
I1126 12:51:55.316018       1 worker.go:81] Worker listening at address: [::]:7080
I1126 12:51:55.415740       1 pool.go:148] CONNECTED to dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I1126 12:51:55.424824       1 groups.go:121] Connected to group zero. Assigned group: 0
I1126 12:51:55.425028       1 groups.go:123] Raft Id after connection to Zero: 0x1
I1126 12:51:55.425342       1 draft.go:76] Node ID: 0x1 with GroupID: 1
I1126 12:51:55.425618       1 node.go:143] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc011807980 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x22d6ac8 DisableProposalForwarding:false}
I1126 12:51:55.426466       1 node.go:312] Found hardstate: {Term:5 Vote:1 Commit:9129 XXX_unrecognized:[]}
I1126 12:51:55.440891       1 node.go:321] Group 1 found 9130 entries
I1126 12:51:55.441669       1 draft.go:1369] Restarting node for group: 1
I1126 12:51:55.442486       1 log.go:34] 1 became follower at term 5
I1126 12:51:55.443329       1 log.go:34] newRaft 1 [peers: [], term: 5, commit: 9129, applied: 0, lastindex: 9129, lastterm: 5]
I1126 12:51:55.443718       1 groups.go:141] Server is ready
I1126 12:51:55.444245       1 draft.go:749] Found Raft progress: 8760
I1126 12:51:55.449280       1 groups.go:727] Got address of a Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I1126 12:51:55.449698       1 groups.go:740] Starting a new membership stream receive from dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080.
I1126 12:51:55.452522       1 groups.go:757] Received first state update from Zero: counter:2749 groups:<key:1 value:<members:<key:1 value:<id:1 group_id:1 addr:"dgraph-alpha-0.dgraph-alpha.default.svc.cluster.local:7080" leader:true last_update:1573889930 > > tablets:<key:"description" value:<group_id:1 predicate:"description" > > 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.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" > > tablets:<key:"game.coverUrl" value:<group_id:1 predicate:"game.coverUrl" > > tablets:<key:"game.name" value:<group_id:1 predicate:"game.name" > > tablets:<key:"game.platform" value:<group_id:1 predicate:"game.platform" > > tablets:<key:"game.popularity" value:<group_id:1 predicate:"game.popularity" > > tablets:<key:"game.url" value:<group_id:1 predicate:"game.url" > > tablets:<key:"game.uuid" value:<group_id:1 predicate:"game.uuid" > > tablets:<key:"info" value:<group_id:1 predicate:"info" > > tablets:<key:"name" value:<group_id:1 predicate:"name" > > tablets:<key:"negative" value:<group_id:1 predicate:"negative" > > tablets:<key:"offer" value:<group_id:1 predicate:"offer" > > tablets:<key:"offer.epochTimeCreated" value:<group_id:1 predicate:"offer.epochTimeCreated" > > tablets:<key:"offer.offerId" value:<group_id:1 predicate:"offer.offerId" > > tablets:<key:"offer.receiverGames" value:<group_id:1 predicate:"offer.receiverGames" > > tablets:<key:"offer.receiverId" value:<group_id:1 predicate:"offer.receiverId" > > tablets:<key:"offer.senderGames" value:<group_id:1 predicate:"offer.senderGames" > > tablets:<key:"offer.senderId" value:<group_id:1 predicate:"offer.senderId" > > tablets:<key:"offer.status" value:<group_id:1 predicate:"offer.status" > > tablets:<key:"platform" value:<group_id:1 predicate:"platform" > > tablets:<key:"positive" value:<group_id:1 predicate:"positive" > > tablets:<key:"tradeType" value:<group_id:1 predicate:"tradeType" > > tablets:<key:"user" value:<group_id:1 predicate:"user" > > tablets:<key:"user.country" value:<group_id:1 predicate:"user.country" > > tablets:<key:"user.description" value:<group_id:1 predicate:"user.description" > > tablets:<key:"user.email" value:<group_id:1 predicate:"user.email" > > tablets:<key:"user.epochTimeCreated" value:<group_id:1 predicate:"user.epochTimeCreated" > > tablets:<key:"user.game" value:<group_id:1 predicate:"user.game" > > 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.isPro" value:<group_id:1 predicate:"user.isPro" > > tablets:<key:"user.latitude" value:<group_id:1 predicate:"user.latitude" > > tablets:<key:"user.location" value:<group_id:1 predicate:"user.location" > > tablets:<key:"user.longitude" value:<group_id:1 predicate:"user.longitude" > > tablets:<key:"user.matchNotifications" value:<group_id:1 predicate:"user.matchNotifications" > > tablets:<key:"user.noOfSuccessfulExchanges" value:<group_id:1 predicate:"user.noOfSuccessfulExchanges" > > tablets:<key:"user.participates" value:<group_id:1 predicate:"user.participates" > > tablets:<key:"user.ratingNegative" value:<group_id:1 predicate:"user.ratingNegative" > > tablets:<key:"user.ratingPositive" value:<group_id:1 predicate:"user.ratingPositive" > > tablets:<key:"user.state" value:<group_id:1 predicate:"user.state" > > tablets:<key:"user.userImageUrl" value:<group_id:1 predicate:"user.userImageUrl" > > tablets:<key:"user.userName" value:<group_id:1 predicate:"user.userName" > > checksum:8312327540618214961 > > zeros:<key:1 value:<id:1 addr:"dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080" leader:true > > maxLeaseId:120000 maxTxnTs:20000 maxRaftId:1 cid:"f2695ad9-6621-484e-a460-153517dea620" license:<maxNodes:18446744073709551615 expiryTs:1576448981 enabled:true > 
I1126 12:51:55.628001       1 node.go:180] Setting conf state to nodes:1 
I1126 12:51:59.244391       1 log.go:34] 1 is starting a new election at term 5
I1126 12:51:59.244784       1 log.go:34] 1 became pre-candidate at term 5
I1126 12:51:59.244946       1 log.go:34] 1 received MsgPreVoteResp from 1 at term 5
I1126 12:51:59.245170       1 log.go:34] 1 became candidate at term 6
I1126 12:51:59.245382       1 log.go:34] 1 received MsgVoteResp from 1 at term 6
I1126 12:51:59.245651       1 log.go:34] 1 became leader at term 6
I1126 12:51:59.245882       1 log.go:34] raft.node: 1 elected leader 1 at term 6
I1126 12:51:59.449000       1 groups.go:808] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I1126 12:51:59.449512       1 groups.go:817] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
W1126 12:52:20.840627       1 draft.go:958] Raft.Ready took too long to process: Timer Total: 262ms. Breakdown: [{sync 260ms} {disk 1ms} {proposals 1ms} {advance 0s}] Num entries: 1. MustSync: true
W1126 12:52:54.776348       1 draft.go:958] Raft.Ready took too long to process: Timer Total: 260ms. Breakdown: [{sync 258ms} {proposals 1ms} {disk 0s} {advance 0s}] Num entries: 1. MustSync: true
W1126 12:53:12.540103       1 draft.go:958] Raft.Ready took too long to process: Timer Total: 224ms. Breakdown: [{sync 223ms} {disk 0s} {proposals 0s} {advance 0s}] Num entries: 1. MustSync: true
I1126 12:53:17.841257       1 admin_backup.go:129] Created backup request: read_ts:18689 unix_ts:"20191126.125317.149" destination:"s3://s3.us-east-2.amazonaws.com/dgraph-backup-dgraph" . Groups=[1]
I1126 12:53:17.841430       1 backup_ee.go:33] Backup request: group 1 at 18689
I1126 12:53:18.918875       1 log.go:34] Dgraph.Backup Time elapsed: 01s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:53:20.097113       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 563.508568ms.
I1126 12:53:20.098417       1 log.go:34] Dgraph.Backup Time elapsed: 02s, bytes sent: 4.3 MB, speed: 2.2 MB/sec
I1126 12:53:20.918904       1 log.go:34] Dgraph.Backup Time elapsed: 03s, bytes sent: 4.3 MB, speed: 1.4 MB/sec
I1126 12:53:21.549265       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 517.778025ms.
I1126 12:53:21.918921       1 log.go:34] Dgraph.Backup Time elapsed: 04s, bytes sent: 8.6 MB, speed: 2.2 MB/sec
I1126 12:53:24.234601       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 1.45471572s.
I1126 12:53:24.237018       1 log.go:34] Dgraph.Backup Time elapsed: 06s, bytes sent: 13 MB, speed: 2.2 MB/sec
I1126 12:53:25.156020       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 715.02704ms.
I1126 12:53:25.159172       1 log.go:34] Dgraph.Backup Time elapsed: 07s, bytes sent: 17 MB, speed: 2.5 MB/sec
I1126 12:53:25.918957       1 log.go:34] Dgraph.Backup Time elapsed: 08s, bytes sent: 17 MB, speed: 2.2 MB/sec
I1126 12:53:27.616581       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 1.29693704s.
I1126 12:53:27.616954       1 log.go:34] Dgraph.Backup Time elapsed: 09s, bytes sent: 22 MB, speed: 2.4 MB/sec
I1126 12:53:28.015359       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 389.756546ms.
I1126 12:53:28.022226       1 log.go:34] Dgraph.Backup Time elapsed: 10s, bytes sent: 26 MB, speed: 2.6 MB/sec
I1126 12:53:28.877579       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 392.390302ms.
I1126 12:53:28.918952       1 log.go:34] Dgraph.Backup Time elapsed: 11s, bytes sent: 30 MB, speed: 2.7 MB/sec
I1126 12:53:29.918934       1 log.go:34] Dgraph.Backup Time elapsed: 12s, bytes sent: 30 MB, speed: 2.5 MB/sec
I1126 12:53:30.445929       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 484.364405ms.
I1126 12:53:30.943432       1 log.go:34] Dgraph.Backup Created batch of size: 2.9 MB in 127.950017ms.
I1126 12:53:30.943852       1 log.go:34] Dgraph.Backup Time elapsed: 13s, bytes sent: 37 MB, speed: 2.9 MB/sec
I1126 12:53:30.944047       1 log.go:34] Dgraph.Backup Sent 441748 keys
I1126 12:53:32.215001       1 backup.go:157] Backup complete: group 1 at 18689
I1126 12:53:35.179030       1 groups.go:872] Zero leadership changed. Renewing oracle delta stream.
E1126 12:53:35.181652       1 groups.go:848] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
I1126 12:53:35.449104       1 groups.go:808] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I1126 12:53:35.449452       1 groups.go:817] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I1126 12:53:35.480991       1 backup.go:188] Backup completed OK.
W1126 12:54:01.244165       1 draft.go:958] Raft.Ready took too long to process: Timer Total: 267ms. Breakdown: [{sync 262ms} {proposals 1ms} {disk 0s} {advance 0s}] Num entries: 1. MustSync: true
I1126 12:54:56.545744       1 draft.go:374] Creating snapshot at index: 10255. ReadTs: 19269.
W1126 12:54:56.915974       1 draft.go:958] Raft.Ready took too long to process: Timer Total: 281ms. Breakdown: [{sync 256ms} {disk 22ms} {proposals 0s} {advance 0s}] Num entries: 1. MustSync: true
W1126 12:55:08.278642       1 draft.go:958] Raft.Ready took too long to process: Timer Total: 227ms. Breakdown: [{sync 226ms} {disk 0s} {proposals 0s} {advance 0s}] Num entries: 1. MustSync: true
I1126 12:56:59.077157       1 log.go:34] Rolling up Created batch of size: 4.3 MB in 3.052018594s.
I1126 12:56:59.083469       1 log.go:34] Rolling up Time elapsed: 03s, bytes sent: 4.3 MB, speed: 1.4 MB/sec
I1126 12:57:01.403072       1 log.go:34] Rolling up Created batch of size: 4.3 MB in 2.310656181s.
I1126 12:57:01.403487       1 log.go:34] Rolling up Time elapsed: 05s, bytes sent: 8.6 MB, speed: 1.7 MB/sec
I1126 12:57:03.927136       1 log.go:34] Rolling up Created batch of size: 4.3 MB in 2.48776673s.
I1126 12:57:04.761630       1 admin_backup.go:129] Created backup request: read_ts:19567 since_ts:18689 unix_ts:"20191126.125704.207" destination:"s3://s3.us-east-2.amazonaws.com/dgraph-backup-dgraph" . Groups=[1]
I1126 12:57:04.767194       1 backup_ee.go:33] Backup request: group 1 at 19567
I1126 12:57:05.868912       1 log.go:34] Dgraph.Backup Time elapsed: 01s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:57:06.844002       1 log.go:34] Dgraph.Backup Time elapsed: 02s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:57:07.843977       1 log.go:34] Dgraph.Backup Time elapsed: 03s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:57:08.531541       1 log.go:34] Rolling up Created batch of size: 4.3 MB in 4.582188021s.
I1126 12:57:08.548313       1 log.go:34] Rolling up Time elapsed: 13s, bytes sent: 17 MB, speed: 1.3 MB/sec
I1126 12:57:08.843966       1 log.go:34] Dgraph.Backup Time elapsed: 04s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:57:09.844035       1 log.go:34] Dgraph.Backup Time elapsed: 05s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:57:10.844033       1 log.go:34] Dgraph.Backup Time elapsed: 06s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:57:11.843932       1 log.go:34] Dgraph.Backup Time elapsed: 07s, bytes sent: 0 B, speed: 0 B/sec
I1126 12:57:13.962901       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 1.712652968s.
I1126 12:57:13.969307       1 log.go:34] Dgraph.Backup Time elapsed: 09s, bytes sent: 4.3 MB, speed: 478 kB/sec
I1126 12:57:14.843954       1 log.go:34] Dgraph.Backup Time elapsed: 10s, bytes sent: 4.3 MB, speed: 430 kB/sec
I1126 12:57:15.129096       1 log.go:34] Rolling up Created batch of size: 8.5 MB in 6.54451807s.
I1126 12:57:15.843956       1 log.go:34] Dgraph.Backup Time elapsed: 11s, bytes sent: 4.3 MB, speed: 391 kB/sec
I1126 12:57:16.845654       1 log.go:34] Dgraph.Backup Time elapsed: 12s, bytes sent: 4.3 MB, speed: 358 kB/sec
I1126 12:57:17.844075       1 log.go:34] Dgraph.Backup Time elapsed: 13s, bytes sent: 4.3 MB, speed: 331 kB/sec
I1126 12:57:19.758010       1 log.go:34] Dgraph.Backup Created batch of size: 4.3 MB in 1.61545702s.
I1126 12:57:19.776079       1 log.go:34] Dgraph.Backup Time elapsed: 14s, bytes sent: 8.6 MB, speed: 614 kB/sec
I1126 12:57:20.273598       1 log.go:34] Dgraph.Backup Created batch of size: 1.2 MB in 448.782976ms.
I1126 12:57:20.277262       1 log.go:34] Dgraph.Backup Time elapsed: 15s, bytes sent: 9.7 MB, speed: 650 kB/sec
I1126 12:57:20.277637       1 log.go:34] Dgraph.Backup Sent 114758 keys
I1126 12:57:21.751731       1 backup.go:157] Backup complete: group 1 at 19567
I1126 12:57:26.882460       1 groups.go:872] Zero leadership changed. Renewing oracle delta stream.
E1126 12:57:27.025858       1 groups.go:848] Error in oracle delta stream. Error: rpc error: code = Canceled desc = context canceled
I1126 12:57:27.480879       1 groups.go:808] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I1126 12:57:27.558164       1 groups.go:817] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I1126 12:57:27.874885       1 backup.go:188] Backup completed OK.
I1126 12:57:31.564926       1 log.go:34] Rolling up Created batch of size: 17 MB in 16.349314471s.
I1126 12:57:31.565310       1 log.go:34] Rolling up Time elapsed: 36s, bytes sent: 43 MB, speed: 1.2 MB/sec
I1126 12:57:36.586440       1 log.go:34] Rolling up Created batch of size: 9.8 MB in 4.998847917s.
I1126 12:57:36.591231       1 log.go:34] Rolling up Sent 515242 keys
I1126 12:57:36.670238       1 draft.go:1040] Rolled up 515242 keys. Done
I1126 12:57:36.671011       1 draft.go:415] List rollup at Ts 19269: OK.