Warning: This standalone version is meant for quickstart purposes only. It is NOT RECOMMENDED for production environments. 2020/08/11 10:47:47 Listening on :8000... [Decoder]: Using assembly version of decoder [Decoder]: Using assembly version of decoder [Sentry] 2020/08/11 10:47:47 Integration installed: ContextifyFrames [Sentry] 2020/08/11 10:47:47 Integration installed: Environment [Sentry] 2020/08/11 10:47:47 Integration installed: Modules [Sentry] 2020/08/11 10:47:47 Integration installed: IgnoreErrors [Sentry] 2020/08/11 10:47:47 Integration installed: ContextifyFrames [Sentry] 2020/08/11 10:47:47 Integration installed: Environment [Sentry] 2020/08/11 10:47:47 Integration installed: Modules [Sentry] 2020/08/11 10:47:47 Integration installed: IgnoreErrors [Decoder]: Using assembly version of decoder [Decoder]: Using assembly version of decoder [Sentry] 2020/08/11 10:47:47 Integration installed: ContextifyFrames [Sentry] 2020/08/11 10:47:47 Integration installed: Environment [Sentry] 2020/08/11 10:47:47 Integration installed: Modules [Sentry] 2020/08/11 10:47:47 Integration installed: IgnoreErrors [Sentry] 2020/08/11 10:47:47 Integration installed: ContextifyFrames [Sentry] 2020/08/11 10:47:47 Integration installed: Environment [Sentry] 2020/08/11 10:47:47 Integration installed: Modules [Sentry] 2020/08/11 10:47:47 Integration installed: IgnoreErrors I0811 10:47:47.709034 36 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 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-2020 Dgraph Labs, Inc. I0811 10:47:47.709543 35 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 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-2020 Dgraph Labs, Inc. I0811 10:47:47.710224 35 run.go:606] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000} I0811 10:47:47.710364 36 run.go:105] Setting up grpc listener at: 0.0.0.0:5080 I0811 10:47:47.710259 35 run.go:607] x.WorkerConfig: {ExportPath:export NumPendingProposals:256 Tracing:1 MyAddr: ZeroAddr:localhost:5080 RaftId:0 WhiteListedIPRanges:[{Lower:0.0.0.0 Upper:255.255.255.255}] MaxRetries:-1 StrictMutations:false AclEnabled:false AbortOlderThan:5m0s SnapshotAfter:10000 ProposedGroupId:0 StartTime:2020-08-11 10:47:47.39723754 +0000 UTC m=+0.009760679 LudicrousMode:false} I0811 10:47:47.710597 35 run.go:608] worker.Config: {PostingDir:p BadgerTables:mmap BadgerVlog:mmap BadgerKeyFile: WALDir:w MutationsMode:0 AuthToken: AllottedMemory:2658 HmacSecret:[] AccessJwtTtl:0s RefreshJwtTtl:0s AclRefreshInterval:0s} I0811 10:47:47.710764 35 server_state.go:74] Setting Badger table load option: mmap I0811 10:47:47.710779 35 server_state.go:86] Setting Badger value log load option: mmap I0811 10:47:47.710890 36 run.go:105] Setting up http listener at: 0.0.0.0:6080 I0811 10:47:47.710786 35 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} badger 2020/08/11 10:47:47 INFO: All 1 tables opened in 24ms badger 2020/08/11 10:47:47 INFO: Replaying file id: 5 at offset: 20990663 I0811 10:47:47.847404 35 log.go:34] All 3 tables opened in 130ms I0811 10:47:47.915036 35 log.go:34] Replaying file id: 2485 at offset: 1437634 I0811 10:47:47.915297 35 log.go:34] Replay took: 44.325µs I0811 10:47:47.915336 35 log.go:34] Replaying file id: 2486 at offset: 0 I0811 10:47:47.932359 35 log.go:34] Replay took: 16.830077ms I0811 10:47:47.932612 35 log.go:34] Replaying file id: 2487 at offset: 0 I0811 10:47:47.962800 35 log.go:34] Replay took: 30.165948ms I0811 10:47:47.962866 35 log.go:34] Replaying file id: 2488 at offset: 0 I0811 10:47:47.963069 35 log.go:34] Replay took: 5.151µs I0811 10:47:47.963393 35 server_state.go:74] Setting Badger table load option: mmap I0811 10:47:47.963408 35 server_state.go:86] Setting Badger value log load option: mmap I0811 10:47:47.963416 35 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} I0811 10:47:48.131407 35 log.go:34] All 16 tables opened in 144ms I0811 10:47:48.135658 35 log.go:34] Replaying file id: 87 at offset: 16018524 badger 2020/08/11 10:47:48 INFO: Replay took: 1.097499048s badger 2020/08/11 10:47:48 INFO: Replaying file id: 6 at offset: 0 badger 2020/08/11 10:47:49 DEBUG: Storing value log head: {Fid:0 Len:0 Offset:0} badger 2020/08/11 10:47:49 DEBUG: Flushing memtable, mt.size=67108943 size of flushChan: 0 I0811 10:47:50.284960 35 log.go:34] Replay took: 2.149098924s I0811 10:47:50.285381 35 log.go:34] Replaying file id: 88 at offset: 0 badger 2020/08/11 10:47:51 INFO: Replay took: 2.320616696s badger 2020/08/11 10:47:51 INFO: Replaying file id: 7 at offset: 0 badger 2020/08/11 10:47:52 DEBUG: Flushing memtable, mt.size=67108887 size of flushChan: 0 badger 2020/08/11 10:47:52 DEBUG: Storing value log head: {Fid:0 Len:0 Offset:0} I0811 10:47:53.091506 35 log.go:34] Replay took: 2.80592498s I0811 10:47:53.095637 35 log.go:34] Replaying file id: 89 at offset: 0 badger 2020/08/11 10:47:53 INFO: Replay took: 2.506823934s badger 2020/08/11 10:47:53 INFO: Replaying file id: 8 at offset: 0 I0811 10:47:54.137316 35 log.go:34] Replay took: 1.041306745s I0811 10:47:54.169768 35 groups.go:104] Current Raft Id: 0x1 I0811 10:47:54.170099 35 worker.go:96] Worker listening at address: [::]:7080 I0811 10:47:54.170960 35 run.go:477] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql I0811 10:47:54.170976 35 run.go:478] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin I0811 10:47:54.170998 35 run.go:509] gRPC server started. Listening on port 9080 I0811 10:47:54.171008 35 run.go:510] HTTP server started. Listening on port 8080 I0811 10:47:54.270884 35 pool.go:160] CONNECTING to localhost:5080 badger 2020/08/11 10:47:55 DEBUG: Flushing memtable, mt.size=67108925 size of flushChan: 0 badger 2020/08/11 10:47:55 DEBUG: Storing value log head: {Fid:0 Len:0 Offset:0} badger 2020/08/11 10:47:56 INFO: Replay took: 2.964744593s badger 2020/08/11 10:47:56 INFO: Replaying file id: 9 at offset: 0 badger 2020/08/11 10:47:58 DEBUG: Flushing memtable, mt.size=67108866 size of flushChan: 0 badger 2020/08/11 10:47:58 DEBUG: Storing value log head: {Fid:0 Len:0 Offset:0} badger 2020/08/11 10:47:58 INFO: Replay took: 2.070347492s badger 2020/08/11 10:47:58 INFO: Replaying file id: 10 at offset: 0 badger 2020/08/11 10:47:58 INFO: Replay took: 92.233311ms badger 2020/08/11 10:47:58 DEBUG: Value log discard stats empty I0811 10:47:58.922237 36 node.go:145] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc001ecaf90 Applied:2719197 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false} I0811 10:47:58.922776 36 node.go:303] Found Snapshot.Metadata: {ConfState:{Nodes:[1] Learners:[] XXX_unrecognized:[]} Index:2719197 Term:9 XXX_unrecognized:[]} I0811 10:47:58.923014 36 node.go:314] Found hardstate: {Term:9 Vote:1 Commit:2719199 XXX_unrecognized:[]} I0811 10:47:58.924466 36 zero.go:417] Got connection request: cluster_info_only:true I0811 10:47:59.171783 35 query.go:123] Dgraph query execution failed : Dgraph query failed because Please retry again, server is not ready to accept requests I0811 10:47:59.171819 35 admin.go:510] Error reading GraphQL schema: Dgraph query failed because Dgraph query failed because Please retry again, server is not ready to accept requests. I0811 10:48:00.464698 36 node.go:323] Group 0 found 3 entries I0811 10:48:00.464729 36 raft.go:447] Restarting node for dgraphzero I0811 10:48:00.464758 36 node.go:182] Setting conf state to nodes:1 I0811 10:48:00.464947 36 pool.go:160] CONNECTING to localhost:7080 W0811 10:48:00.466196 36 pool.go:254] Connection lost with localhost:7080. Error: rpc error: code = Unknown desc = No node has been set up yet I0811 10:48:01.588289 36 log.go:34] 1 became follower at term 9 I0811 10:48:01.588479 36 log.go:34] newRaft 1 [peers: [1], term: 9, commit: 2719199, applied: 2719197, lastindex: 2719199, lastterm: 9] I0811 10:48:01.596523 36 run.go:296] Running Dgraph Zero... I0811 10:48:01.868337 36 log.go:34] 1 no leader at term 9; dropping index reading msg I0811 10:48:01.870140 36 oracle.go:107] Purged below ts:8340254, len(o.commits):0, len(o.rowCommit):0 W0811 10:48:03.590329 36 node.go:671] [0x1] Read index context timed out I0811 10:48:03.590373 36 log.go:34] 1 no leader at term 9; dropping index reading msg I0811 10:48:04.172030 35 query.go:123] Dgraph query execution failed : Dgraph query failed because Please retry again, server is not ready to accept requests I0811 10:48:04.172062 35 admin.go:510] Error reading GraphQL schema: Dgraph query failed because Dgraph query failed because Please retry again, server is not ready to accept requests. I0811 10:48:04.271725 36 zero.go:426] Connected: cluster_info_only:true I0811 10:48:04.472862 36 zero.go:417] Got connection request: cluster_info_only:true I0811 10:48:05.190418 36 log.go:34] 1 is starting a new election at term 9 I0811 10:48:05.190459 36 log.go:34] 1 became pre-candidate at term 9 I0811 10:48:05.190466 36 log.go:34] 1 received MsgPreVoteResp from 1 at term 9 I0811 10:48:05.190533 36 log.go:34] 1 became candidate at term 10 I0811 10:48:05.190539 36 log.go:34] 1 received MsgVoteResp from 1 at term 10 I0811 10:48:05.190635 36 log.go:34] 1 became leader at term 10 I0811 10:48:05.190644 36 log.go:34] raft.node: 1 elected leader 1 at term 10 I0811 10:48:05.190679 36 raft.go:667] I've become the leader, updating leases. I0811 10:48:05.190686 36 assign.go:42] Updated Lease id: 1040262. Txn Ts: 8350001 W0811 10:48:05.590428 36 node.go:671] [0x1] Read index context timed out I0811 10:48:05.591093 36 zero.go:435] Connected: cluster_info_only:true I0811 10:48:05.592372 36 zero.go:417] Got connection request: id:1 addr:"localhost:7080" I0811 10:48:05.592653 36 zero.go:544] Connected: id:1 addr:"localhost:7080" I0811 10:48:05.593418 35 groups.go:131] Connected to group zero. Assigned group: 0 I0811 10:48:05.593433 35 groups.go:133] Raft Id after connection to Zero: 0x1 I0811 10:48:05.593504 35 draft.go:175] Node ID: 0x1 with GroupID: 1 I0811 10:48:05.593588 35 node.go:145] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc05aa374d0 Applied:7584570 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x260a270 DisableProposalForwarding:false} I0811 10:48:05.593660 35 pool.go:160] CONNECTING to localhost:7080 W0811 10:48:05.594888 35 pool.go:254] Connection lost with localhost:7080. Error: rpc error: code = Unknown desc = No node has been set up yet I0811 10:48:05.615819 35 node.go:303] Found Snapshot.Metadata: {ConfState:{Nodes:[1] Learners:[] XXX_unrecognized:[]} Index:7584570 Term:9 XXX_unrecognized:[]} I0811 10:48:05.616277 35 node.go:314] Found hardstate: {Term:9 Vote:1 Commit:7584571 XXX_unrecognized:[]} I0811 10:48:07.507449 35 node.go:323] Group 1 found 2 entries I0811 10:48:07.507491 35 draft.go:1506] Restarting node for group: 1 I0811 10:48:07.507509 35 node.go:182] Setting conf state to nodes:1 I0811 10:48:09.172259 35 query.go:123] Dgraph query execution failed : Dgraph query failed because Please retry again, server is not ready to accept requests I0811 10:48:09.172297 35 admin.go:510] Error reading GraphQL schema: Dgraph query failed because Dgraph query failed because Please retry again, server is not ready to accept requests. I0811 10:48:09.288827 35 log.go:34] 1 became follower at term 9 I0811 10:48:09.289279 35 log.go:34] newRaft 1 [peers: [1], term: 9, commit: 7584571, applied: 7584570, lastindex: 7584571, lastterm: 9] I0811 10:48:09.289441 35 draft.go:136] Operation started with id: opRollup I0811 10:48:09.289670 35 groups.go:151] Server is ready I0811 10:48:09.289938 35 draft.go:925] Found Raft progress: 7584570 I0811 10:48:09.290028 35 groups.go:775] Got address of a Zero leader: localhost:5080 I0811 10:48:09.290450 35 groups.go:788] Starting a new membership stream receive from localhost:5080. I0811 10:48:09.291950 35 draft.go:519] Skipping snapshot at 7584570, because found one at 7584570 I0811 10:48:09.291922 35 groups.go:805] Received first state update from Zero: counter:2719199 groups: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > snapshot_ts:8340254 checksum:6111909556707352185 > > zeros: > maxLeaseId:1040261 maxTxnTs:8350000 maxRaftId:1 cid:"06c047fa-53e4-41dc-bc23-1ee70050d34b" license: I0811 10:48:12.190140 35 log.go:34] 1 is starting a new election at term 9 I0811 10:48:12.190449 35 log.go:34] 1 became pre-candidate at term 9 I0811 10:48:12.190462 35 log.go:34] 1 received MsgPreVoteResp from 1 at term 9 I0811 10:48:12.190792 35 log.go:34] 1 became candidate at term 10 I0811 10:48:12.190808 35 log.go:34] 1 received MsgVoteResp from 1 at term 10 I0811 10:48:12.191045 35 log.go:34] 1 became leader at term 10 I0811 10:48:12.191059 35 log.go:34] raft.node: 1 elected leader 1 at term 10 I0811 10:48:12.289942 35 groups.go:856] Leader idx=0x1 of group=1 is connecting to Zero for txn updates I0811 10:48:12.289976 35 groups.go:865] Got Zero leader: localhost:5080 I0811 10:48:14.204845 35 admin.go:513] No GraphQL schema in Dgraph; serving empty GraphQL API I0811 11:01:09.604453 35 draft.go:523] Creating snapshot at index: 7598601. ReadTs: 8364902. I0811 11:01:12.304508 36 oracle.go:107] Purged below ts:8364902, len(o.commits):61, len(o.rowCommit):1304 I0811 11:01:22.971005 36 raft.go:616] Writing snapshot at index: 2724140, applied mark: 2725262 I0811 11:02:09.640435 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 11:02:09.640494 35 log.go:34] Running for level: 0 I0811 11:02:09.747437 35 draft.go:523] Creating snapshot at index: 7615574. ReadTs: 8382246. I0811 11:02:11.485397 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 1.844875989s I0811 11:02:11.485636 35 log.go:34] Compaction for level: 0 DONE I0811 11:02:18.307627 36 oracle.go:107] Purged below ts:8382246, len(o.commits):587, len(o.rowCommit):12481 I0811 11:02:23.138332 36 raft.go:616] Writing snapshot at index: 2729913, applied mark: 2730854 I0811 12:01:09.468226 35 draft.go:523] Creating snapshot at index: 7631448. ReadTs: 8399248. I0811 12:01:18.314430 36 oracle.go:107] Purged below ts:8399248, len(o.commits):679, len(o.rowCommit):14601 I0811 12:01:23.014684 36 raft.go:616] Writing snapshot at index: 2735412, applied mark: 2736552 I0811 12:01:57.640725 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 12:01:57.640764 35 log.go:34] Running for level: 0 I0811 12:01:59.545566 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 1.904773902s I0811 12:01:59.545759 35 log.go:34] Compaction for level: 0 DONE I0811 12:02:09.572222 35 draft.go:523] Creating snapshot at index: 7648356. ReadTs: 8416521. I0811 12:02:13.308149 36 oracle.go:107] Purged below ts:8416521, len(o.commits):216, len(o.rowCommit):4561 I0811 12:02:23.211662 36 raft.go:616] Writing snapshot at index: 2741162, applied mark: 2742383 I0811 12:16:09.389496 35 draft.go:523] Creating snapshot at index: 7659877. ReadTs: 8430178. I0811 12:16:20.299923 36 oracle.go:107] Purged below ts:8430178, len(o.commits):742, len(o.rowCommit):14049 I0811 12:16:23.258182 36 raft.go:616] Writing snapshot at index: 2745587, applied mark: 2746704 I0811 12:17:09.483388 35 draft.go:523] Creating snapshot at index: 7671591. ReadTs: 8445048. I0811 12:17:12.640241 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 12:17:12.640284 35 log.go:34] Running for level: 0 I0811 12:17:14.513677 36 oracle.go:107] Purged below ts:8445048, len(o.commits):164, len(o.rowCommit):5136 I0811 12:17:14.803972 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.163658262s I0811 12:17:14.804314 35 log.go:34] Compaction for level: 0 DONE I0811 12:17:22.979005 36 raft.go:616] Writing snapshot at index: 2750530, applied mark: 2751445 I0811 12:35:09.362173 35 draft.go:523] Creating snapshot at index: 7682568. ReadTs: 8458831. I0811 12:35:12.294977 36 oracle.go:107] Purged below ts:8458831, len(o.commits):0, len(o.rowCommit):1 I0811 12:35:22.633301 36 raft.go:616] Writing snapshot at index: 2755177, applied mark: 2755179 I0811 12:39:09.363056 35 draft.go:523] Creating snapshot at index: 7693140. ReadTs: 8472137. I0811 12:39:12.294476 36 oracle.go:107] Purged below ts:8472137, len(o.commits):0, len(o.rowCommit):1 I0811 12:39:22.625424 36 raft.go:616] Writing snapshot at index: 2759633, applied mark: 2759635 I0811 12:41:21.640284 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 12:41:21.640333 35 log.go:34] Running for level: 0 I0811 12:41:23.265038 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 1.624676816s I0811 12:41:23.265089 35 log.go:34] Compaction for level: 0 DONE I0811 13:01:09.533853 35 draft.go:523] Creating snapshot at index: 7714251. ReadTs: 8495930. I0811 13:01:12.306316 36 oracle.go:107] Purged below ts:8495930, len(o.commits):51, len(o.rowCommit):1084 I0811 13:01:23.031825 36 raft.go:616] Writing snapshot at index: 2767548, applied mark: 2768646 I0811 13:02:09.539061 35 draft.go:523] Creating snapshot at index: 7731135. ReadTs: 8513213. I0811 13:02:09.640292 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 13:02:09.640351 35 log.go:34] Running for level: 0 I0811 13:02:11.351188 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 1.710800367s I0811 13:02:11.351345 35 log.go:34] Compaction for level: 0 DONE I0811 13:02:18.311537 36 oracle.go:107] Purged below ts:8513213, len(o.commits):568, len(o.rowCommit):12107 I0811 13:02:23.136352 36 raft.go:616] Writing snapshot at index: 2773301, applied mark: 2774259 I0811 13:03:53.917142 35 export.go:643] Got readonly ts from Zero: 8516504 I0811 13:03:53.917159 35 export.go:647] Requesting export for groups: [1] I0811 13:03:53.917181 35 export.go:389] Export requested at 8516504. I0811 13:03:53.918452 35 export.go:395] Running export for group 1 at timestamp 8516504. I0811 13:03:53.919726 35 export.go:416] Exporting data for group: 1 at /dgraph/export/dgraph.r8516504.u0811.1303/g01.rdf.gz I0811 13:03:53.920048 35 export.go:427] Exporting schema for group: 1 at /dgraph/export/dgraph.r8516504.u0811.1303/g01.schema.gz I0811 13:03:54.920736 35 log.go:34] Export Time elapsed: 01s, bytes sent: 0 B, speed: 0 B/sec I0811 13:03:55.126414 35 log.go:34] Export Created batch of size: 157 kB in 56.008656ms. I0811 13:03:55.931437 35 log.go:34] Export Time elapsed: 02s, bytes sent: 157 kB, speed: 78 kB/sec I0811 13:03:56.920833 35 log.go:34] Export Time elapsed: 03s, bytes sent: 157 kB, speed: 52 kB/sec I0811 13:03:57.936727 35 log.go:34] Export Time elapsed: 04s, bytes sent: 157 kB, speed: 39 kB/sec I0811 13:03:58.923612 35 log.go:34] Export Time elapsed: 05s, bytes sent: 157 kB, speed: 31 kB/sec I0811 13:03:59.920700 35 log.go:34] Export Time elapsed: 06s, bytes sent: 157 kB, speed: 26 kB/sec I0811 13:04:00.920664 35 log.go:34] Export Time elapsed: 07s, bytes sent: 157 kB, speed: 22 kB/sec I0811 13:04:01.929868 35 log.go:34] Export Time elapsed: 08s, bytes sent: 157 kB, speed: 20 kB/sec I0811 13:04:02.922128 35 log.go:34] Export Time elapsed: 09s, bytes sent: 157 kB, speed: 17 kB/sec I0811 13:04:03.933367 35 log.go:34] Export Time elapsed: 10s, bytes sent: 157 kB, speed: 16 kB/sec I0811 13:04:05.154432 35 log.go:34] Export Created batch of size: 665 kB in 466.829983ms. I0811 13:04:05.154467 35 log.go:34] Export Time elapsed: 11s, bytes sent: 822 kB, speed: 75 kB/sec I0811 13:04:05.989543 35 log.go:34] Export Time elapsed: 12s, bytes sent: 822 kB, speed: 68 kB/sec I0811 13:04:08.547967 35 log.go:34] Export Created batch of size: 2.1 MB in 2.247027773s. I0811 13:04:12.322909 35 log.go:34] Export Created batch of size: 3.6 MB in 3.737839892s. I0811 13:04:14.872234 35 log.go:34] Export Created batch of size: 5.2 MB in 2.526436843s. I0811 13:04:16.128405 35 log.go:34] Export Created batch of size: 9.0 MB in 1.215816821s. I0811 13:04:16.128442 35 log.go:34] Export Time elapsed: 22s, bytes sent: 21 MB, speed: 940 kB/sec I0811 13:04:16.639241 35 log.go:34] Export Created batch of size: 3.3 MB in 325.81764ms. I0811 13:04:17.345153 35 log.go:34] Export Created batch of size: 2.3 MB in 692.135857ms. I0811 13:04:17.345194 35 log.go:34] Export Time elapsed: 23s, bytes sent: 26 MB, speed: 1.1 MB/sec I0811 13:04:17.345201 35 log.go:34] Export Sent 421569 keys I0811 13:04:17.354640 35 export.go:587] Export DONE for group 1 at timestamp 8516504. I0811 13:04:17.354703 35 export.go:670] Export at readTs 8516504 DONE I0811 14:01:09.549030 35 draft.go:523] Creating snapshot at index: 7752281. ReadTs: 8536881. I0811 14:01:18.317654 36 oracle.go:107] Purged below ts:8536881, len(o.commits):650, len(o.rowCommit):13933 I0811 14:01:23.026288 36 raft.go:616] Writing snapshot at index: 2781031, applied mark: 2782132 I0811 14:01:35.640301 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 14:01:35.641001 35 log.go:34] Running for level: 0 I0811 14:01:37.723091 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.081929581s I0811 14:01:37.723127 35 log.go:34] Compaction for level: 0 DONE I0811 14:02:09.589056 35 draft.go:523] Creating snapshot at index: 7769052. ReadTs: 8554022. I0811 14:02:12.308918 36 oracle.go:107] Purged below ts:8554022, len(o.commits):51, len(o.rowCommit):1100 I0811 14:02:23.440534 36 raft.go:616] Writing snapshot at index: 2786737, applied mark: 2787932 I0811 14:02:24.801277 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 14:02:24.801315 35 log.go:34] Running for level: 0 I0811 14:02:44.285355 35 log.go:34] LOG Compact 0->1, del 17 tables, add 12 tables, took 19.48196147s I0811 14:02:44.286807 35 log.go:34] Compaction for level: 0 DONE I0811 14:55:09.485532 35 draft.go:523] Creating snapshot at index: 7782179. ReadTs: 8569757. I0811 14:55:18.301587 36 oracle.go:107] Purged below ts:8569757, len(o.commits):0, len(o.rowCommit):1 I0811 14:55:22.679179 36 raft.go:616] Writing snapshot at index: 2791854, applied mark: 2791856 I0811 15:00:54.640327 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 15:00:54.640372 35 log.go:34] Running for level: 0 I0811 15:00:57.208213 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.567814199s I0811 15:00:57.208253 35 log.go:34] Compaction for level: 0 DONE I0811 15:01:09.535714 35 draft.go:523] Creating snapshot at index: 7796263. ReadTs: 8584693. I0811 15:01:20.305654 36 oracle.go:107] Purged below ts:8584693, len(o.commits):932, len(o.rowCommit):20050 I0811 15:01:23.093492 36 raft.go:616] Writing snapshot at index: 2796804, applied mark: 2797998 I0811 15:02:09.561751 35 draft.go:523] Creating snapshot at index: 7813669. ReadTs: 8602520. I0811 15:02:14.310808 36 oracle.go:107] Purged below ts:8602520, len(o.commits):220, len(o.rowCommit):4689 I0811 15:02:22.689695 36 raft.go:616] Writing snapshot at index: 2802722, applied mark: 2803593 I0811 15:02:44.640398 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 15:02:44.640486 35 log.go:34] Running for level: 0 I0811 15:02:47.010042 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.369530215s I0811 15:02:47.010495 35 log.go:34] Compaction for level: 0 DONE I0811 15:03:09.598410 35 draft.go:523] Creating snapshot at index: 7825260. ReadTs: 8616835. I0811 15:03:18.298318 36 oracle.go:107] Purged below ts:8616835, len(o.commits):582, len(o.rowCommit):12468 I0811 15:03:22.679157 36 raft.go:616] Writing snapshot at index: 2807359, applied mark: 2807942 I0811 16:01:09.748600 35 draft.go:523] Creating snapshot at index: 7843451. ReadTs: 8637050. I0811 16:01:14.303837 36 oracle.go:107] Purged below ts:8637050, len(o.commits):210, len(o.rowCommit):4517 I0811 16:01:23.175568 36 raft.go:616] Writing snapshot at index: 2814106, applied mark: 2815229 I0811 16:01:35.640347 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 16:01:35.640583 35 log.go:34] Running for level: 0 I0811 16:01:38.022632 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.381974469s I0811 16:01:38.023023 35 log.go:34] Compaction for level: 0 DONE I0811 16:02:09.563618 35 draft.go:523] Creating snapshot at index: 7860352. ReadTs: 8654314. I0811 16:02:20.308435 36 oracle.go:107] Purged below ts:8654314, len(o.commits):902, len(o.rowCommit):19213 I0811 16:02:23.174103 36 raft.go:616] Writing snapshot at index: 2819853, applied mark: 2821037 I0811 16:20:09.474587 35 draft.go:523] Creating snapshot at index: 7870618. ReadTs: 8666665. I0811 16:20:17.300708 36 oracle.go:107] Purged below ts:8666665, len(o.commits):237, len(o.rowCommit):6640 I0811 16:20:22.634542 36 raft.go:616] Writing snapshot at index: 2823812, applied mark: 2824050 I0811 16:29:39.640327 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 16:29:39.640461 35 log.go:34] Running for level: 0 I0811 16:29:41.668997 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.02844596s I0811 16:29:41.669126 35 log.go:34] Compaction for level: 0 DONE I0811 16:31:09.364536 35 draft.go:523] Creating snapshot at index: 7881689. ReadTs: 8680501. I0811 16:31:17.294687 36 oracle.go:107] Purged below ts:8680501, len(o.commits):0, len(o.rowCommit):1 I0811 16:31:22.611339 36 raft.go:616] Writing snapshot at index: 2828475, applied mark: 2828477 I0811 16:36:09.384578 35 draft.go:523] Creating snapshot at index: 7891994. ReadTs: 8693446. I0811 16:36:14.294431 36 oracle.go:107] Purged below ts:8693446, len(o.commits):0, len(o.rowCommit):1 I0811 16:36:22.651157 36 raft.go:616] Writing snapshot at index: 2832806, applied mark: 2832808 I0811 17:01:08.640481 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 17:01:08.640528 35 log.go:34] Running for level: 0 I0811 17:01:09.788010 35 draft.go:523] Creating snapshot at index: 7905709. ReadTs: 8708031. I0811 17:01:10.750859 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.110300939s I0811 17:01:10.751349 35 log.go:34] Compaction for level: 0 DONE I0811 17:01:20.305933 36 oracle.go:107] Purged below ts:8708031, len(o.commits):775, len(o.rowCommit):16732 I0811 17:01:23.133149 36 raft.go:616] Writing snapshot at index: 2837640, applied mark: 2838687 I0811 17:02:09.673658 35 draft.go:523] Creating snapshot at index: 7922560. ReadTs: 8725282. I0811 17:02:13.307956 36 oracle.go:107] Purged below ts:8725282, len(o.commits):100, len(o.rowCommit):2177 I0811 17:02:23.175458 36 raft.go:616] Writing snapshot at index: 2843382, applied mark: 2844465 I0811 17:57:09.617438 35 draft.go:523] Creating snapshot at index: 7932803. ReadTs: 8737650. I0811 17:57:09.640368 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 17:57:09.640416 35 log.go:34] Running for level: 0 I0811 17:57:11.467001 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 1.826554008s I0811 17:57:11.467288 35 log.go:34] Compaction for level: 0 DONE I0811 17:57:12.302565 36 oracle.go:107] Purged below ts:8737650, len(o.commits):0, len(o.rowCommit):1 I0811 17:57:22.812980 36 raft.go:616] Writing snapshot at index: 2847380, applied mark: 2848193 I0811 18:01:09.553259 35 draft.go:523] Creating snapshot at index: 7954565. ReadTs: 8763016. I0811 18:01:14.302481 36 oracle.go:107] Purged below ts:8763016, len(o.commits):223, len(o.rowCommit):4765 I0811 18:01:23.168197 36 raft.go:616] Writing snapshot at index: 2855823, applied mark: 2857002 I0811 18:01:33.800683 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 18:01:33.801084 35 log.go:34] Running for level: 0 I0811 18:01:35.976285 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.174918981s I0811 18:01:35.976821 35 log.go:34] Compaction for level: 0 DONE I0811 18:02:09.588288 35 draft.go:523] Creating snapshot at index: 7972228. ReadTs: 8781072. I0811 18:02:18.307814 36 oracle.go:107] Purged below ts:8781072, len(o.commits):712, len(o.rowCommit):15181 I0811 18:02:23.363771 36 raft.go:616] Writing snapshot at index: 2861834, applied mark: 2863061 I0811 19:01:04.640247 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 19:01:04.640290 35 log.go:34] Running for level: 0 I0811 19:01:06.787696 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.147378924s I0811 19:01:06.788081 35 log.go:34] Compaction for level: 0 DONE I0811 19:01:09.611338 35 draft.go:523] Creating snapshot at index: 7993871. ReadTs: 8804429. I0811 19:01:20.315549 36 oracle.go:107] Purged below ts:8804429, len(o.commits):992, len(o.rowCommit):21262 I0811 19:01:23.187039 36 raft.go:616] Writing snapshot at index: 2869459, applied mark: 2870737 I0811 19:02:09.582584 35 draft.go:523] Creating snapshot at index: 8012288. ReadTs: 8823440. I0811 19:02:15.309378 36 oracle.go:107] Purged below ts:8823440, len(o.commits):164, len(o.rowCommit):38389 I0811 19:02:22.661212 36 raft.go:616] Writing snapshot at index: 2875648, applied mark: 2875813 I0811 20:00:58.641234 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 20:00:58.641602 35 log.go:34] Running for level: 0 I0811 20:01:00.925262 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.283460013s I0811 20:01:00.925303 35 log.go:34] Compaction for level: 0 DONE I0811 20:01:09.531831 35 draft.go:523] Creating snapshot at index: 8025660. ReadTs: 8837717. I0811 20:01:16.309331 36 oracle.go:107] Purged below ts:8837717, len(o.commits):561, len(o.rowCommit):12016 I0811 20:01:23.455563 36 raft.go:616] Writing snapshot at index: 2880383, applied mark: 2881662 I0811 20:02:09.548870 35 draft.go:523] Creating snapshot at index: 8043604. ReadTs: 8856063. I0811 20:02:10.311432 36 oracle.go:107] Purged below ts:8856063, len(o.commits):12, len(o.rowCommit):286 I0811 20:02:13.048084 36 raft.go:616] Writing snapshot at index: 2886490, applied mark: 2886527 I0811 21:00:44.640202 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 21:00:44.640500 35 log.go:34] Running for level: 0 I0811 21:00:46.900719 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.26018842s I0811 21:00:46.901542 35 log.go:34] Compaction for level: 0 DONE I0811 21:01:09.576409 35 draft.go:523] Creating snapshot at index: 8061223. ReadTs: 8874853. I0811 21:01:11.315367 36 oracle.go:107] Purged below ts:8874853, len(o.commits):11, len(o.rowCommit):271 I0811 21:01:13.049584 36 raft.go:616] Writing snapshot at index: 2892588, applied mark: 2892675 I0811 21:02:09.568310 35 draft.go:523] Creating snapshot at index: 8078788. ReadTs: 8892876. I0811 21:02:17.317384 36 oracle.go:107] Purged below ts:8892876, len(o.commits):512, len(o.rowCommit):10795 I0811 21:02:22.635354 36 raft.go:616] Writing snapshot at index: 2898536, applied mark: 2899147 I0811 21:23:42.640505 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 21:23:42.640549 35 log.go:34] Running for level: 0 I0811 21:23:44.264744 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 1.62415681s I0811 21:23:44.264800 35 log.go:34] Compaction for level: 0 DONE I0811 22:01:09.522789 35 draft.go:523] Creating snapshot at index: 8097035. ReadTs: 8912642. I0811 22:01:18.310011 36 oracle.go:107] Purged below ts:8912642, len(o.commits):718, len(o.rowCommit):15556 I0811 22:01:23.109129 36 raft.go:616] Writing snapshot at index: 2905009, applied mark: 2906193 I0811 22:02:06.798871 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 22:02:06.798917 35 log.go:34] Running for level: 0 I0811 22:02:09.244259 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.445315319s I0811 22:02:09.244296 35 log.go:34] Compaction for level: 0 DONE I0811 22:02:09.616858 35 draft.go:523] Creating snapshot at index: 8114519. ReadTs: 8930595. I0811 22:02:13.309391 36 oracle.go:107] Purged below ts:8930595, len(o.commits):195, len(o.rowCommit):4163 I0811 22:02:22.667000 36 raft.go:616] Writing snapshot at index: 2910934, applied mark: 2911540 I0811 23:01:09.477354 35 draft.go:523] Creating snapshot at index: 8130449. ReadTs: 8947602. I0811 23:01:15.310246 36 oracle.go:107] Purged below ts:8947602, len(o.commits):387, len(o.rowCommit):8409 I0811 23:01:23.291375 36 raft.go:616] Writing snapshot at index: 2916492, applied mark: 2917711 I0811 23:01:24.012639 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 23:01:24.012683 35 log.go:34] Running for level: 0 I0811 23:01:47.708487 35 log.go:34] LOG Compact 0->1, del 17 tables, add 12 tables, took 23.695774269s I0811 23:01:47.708530 35 log.go:34] Compaction for level: 0 DONE I0811 23:01:47.711127 35 log.go:34] Got compaction priority: {level:1 score:1.047909937798977 dropPrefix:[]} I0811 23:01:47.711190 35 log.go:34] Running for level: 1 I0811 23:01:49.787908 35 log.go:34] LOG Compact 1->2, del 2 tables, add 2 tables, took 2.076607965s I0811 23:01:49.788042 35 log.go:34] Compaction for level: 1 DONE I0811 23:02:02.798668 35 log.go:34] Got compaction priority: {level:0 score:1 dropPrefix:[]} I0811 23:02:02.798709 35 log.go:34] Running for level: 0 I0811 23:02:05.588477 35 log.go:34] LOG Compact 0->1, del 6 tables, add 1 tables, took 2.78973941s I0811 23:02:05.588813 35 log.go:34] Compaction for level: 0 DONE I0811 23:02:09.694392 35 draft.go:523] Creating snapshot at index: 8145811. ReadTs: 8963338. I0811 23:02:10.417434 36 oracle.go:107] Purged below ts:8963338, len(o.commits):6, len(o.rowCommit):154 runtime/cgo: pthread_create failed: Resource temporarily unavailable W0811 23:04:05.176556 35 groups.go:835] No membership update for 10s. Closing connection to Zero. E0811 23:04:06.804167 35 groups.go:796] Unable to sync memberships. Error: rpc error: code = Canceled desc = context canceled. State: E0811 23:04:06.869526 35 groups.go:744] While sending membership update: rpc error: code = Unavailable desc = transport is closing E0811 23:04:06.869825 35 groups.go:896] Error in oracle delta stream. Error: rpc error: code = Unavailable desc = transport is closing W0811 23:04:06.870025 35 pool.go:254] Connection lost with localhost:5080. Error: rpc error: code = Unavailable desc = transport is closing W0811 23:04:06.870105 35 draft.go:1211] While sending membership to Zero. Error: rpc error: code = Unavailable desc = transport is closing E0811 23:04:06.889557 35 groups.go:744] While sending membership update: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:5080: connect: connection refused" E0811 23:04:07.290211 35 groups.go:744] While sending membership update: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:5080: connect: connection refused" I0811 23:04:08.057900 35 groups.go:856] Leader idx=0x1 of group=1 is connecting to Zero for txn updates I0811 23:04:08.057926 35 groups.go:865] Got Zero leader: localhost:5080 E0811 23:04:08.058262 35 groups.go:877] Error while calling Oracle rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:5080: connect: connection refused" E0811 23:04:08.290335 35 groups.go:744] While sending membership update: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:5080: connect: connection refused" I0811 23:04:09.058456 35 groups.go:856] Leader idx=0x1 of group=1 is connecting to Zero for txn updates I0811 23:09:09.290847 35 draft.go:1269] Found 1 old transactions. Acting to abort them. I0811 23:09:09.290872 35 draft.go:1272] Done abortOldTransactions for 1 txns. Error: No connection exists github.com/dgraph-io/dgraph/worker.init /tmp/go/src/github.com/dgraph-io/dgraph/worker/draft.go:1218 runtime.doInit /usr/local/go/src/runtime/proc.go:5414 runtime.doInit /usr/local/go/src/runtime/proc.go:5409 runtime.doInit /usr/local/go/src/runtime/proc.go:5409 runtime.doInit /usr/local/go/src/runtime/proc.go:5409 runtime.main /usr/local/go/src/runtime/proc.go:190 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1373 I0811 23:10:09.290683 35 draft.go:1269] Found 1 old transactions. Acting to abort them. I0811 23:10:09.290980 35 draft.go:1272] Done abortOldTransactions for 1 txns. Error: No connection exists github.com/dgraph-io/dgraph/worker.init /tmp/go/src/github.com/dgraph-io/dgraph/worker/draft.go:1218 runtime.doInit /usr/local/go/src/runtime/proc.go:5414 runtime.doInit /usr/local/go/src/runtime/proc.go:5409 runtime.doInit /usr/local/go/src/runtime/proc.go:5409 runtime.doInit /usr/local/go/src/runtime/proc.go:5409 runtime.main /usr/local/go/src/runtime/proc.go:190 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1373