Closed kevinkle closed 4 years ago
tests/test_dgraph.py::test_dgraph_install PASSED
tests/test_dgraph.py::test_dgraph_conftest 2019-07-16 20:28:27 fbf9036d11f2 prairiedog[1332] INFO Will setup Dgraph from folder /tmp/tmp3z2xcutg
I0716 20:28:27.487702 1385 init.go:88]
Dgraph version : v1.0.16
Commit SHA-1 : 0590ee95
Commit timestamp : 2019-07-11 11:52:54 -0700
Branch : HEAD
Go version : go1.12.5
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.
I0716 20:28:27.487967 1385 run.go:98] Setting up grpc listener at: 0.0.0.0:5080
I0716 20:28:27.488180 1385 run.go:98] Setting up http listener at: 0.0.0.0:6080
badger 2019/07/16 20:28:27 INFO: All 0 tables opened in 0s
I0716 20:28:27.493949 1385 node.go:157] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:100 HeartbeatTick:1 Storage:0xc000302060 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x1f86470 DisableProposalForwarding:false}
I0716 20:28:27.494862 1385 node.go:326] Group 0 found 1 entries
I0716 20:28:27.495413 1385 node.go:88] 1 became follower at term 0
I0716 20:28:27.495447 1385 node.go:88] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0716 20:28:27.495458 1385 node.go:88] 1 became follower at term 1
I0716 20:28:27.495532 1385 run.go:282] Running Dgraph Zero...
E0716 20:28:27.496594 1385 raft.go:499] While proposing CID: Not Zero leader. Aborting proposal: cid:"1bbb1073-e0ae-4070-b685-09ec548c2133" . Retrying...
I0716 20:28:27.496149 1385 node.go:193] Setting conf state to nodes:1
I0716 20:28:27.496875 1385 raft.go:676] Done applying conf change at 0x1
I0716 20:28:28.495974 1385 node.go:88] 1 no leader at term 1; dropping index reading msg
I0716 20:28:29.493763 1405 init.go:88]
Dgraph version : v1.0.16
Commit SHA-1 : 0590ee95
Commit timestamp : 2019-07-11 11:52:54 -0700
Branch : HEAD
Go version : go1.12.5
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.
I0716 20:28:29.494058 1405 run.go:461] x.Config: {DebugMode:false PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000}
I0716 20:28:29.494073 1405 run.go:462] worker.Config: {ExportPath:export NumPendingProposals:256 Tracing:1 MyAddr: ZeroAddr:localhost:5080 RaftId:0 ExpandEdge:true WhiteListedIPRanges:[] MaxRetries:-1 StrictMutations:false SnapshotAfter:10000 AbortOlderThan:5m0s}
I0716 20:28:29.494088 1405 run.go:463] edgraph.Config: {PostingDir:p BadgerTables:mmap BadgerVlog:mmap WALDir:w MutationsMode:0 AuthToken: AllottedMemory:2048}
I0716 20:28:29.494142 1405 server.go:115] Setting Badger table load option: mmap
I0716 20:28:29.494147 1405 server.go:127] Setting Badger value log load option: mmap
I0716 20:28:29.494152 1405 server.go:155] Opening write-ahead log BadgerDB with options: {Dir:w ValueDir:w SyncWrites:false TableLoadingMode:1 ValueLogLoadingMode:2 NumVersionsToKeep:1 ReadOnly:false Truncate:true Logger:0x1f86470 MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:65500 NumMemtables:5 NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:10000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0716 20:28:29.517401 1405 node.go:88] All 0 tables opened in 0s
I0716 20:28:29.522445 1405 server.go:115] Setting Badger table load option: mmap
I0716 20:28:29.522455 1405 server.go:127] Setting Badger value log load option: mmap
I0716 20:28:29.522462 1405 server.go:169] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false TableLoadingMode:2 ValueLogLoadingMode:2 NumVersionsToKeep:2147483647 ReadOnly:false Truncate:true Logger:0x1f86470 MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0716 20:28:29.550897 1405 node.go:88] All 0 tables opened in 0s
I0716 20:28:29.569878 1405 groups.go:96] Current Raft Id: 0x0
I0716 20:28:29.569885 1405 run.go:392] gRPC server started. Listening on port 9080
I0716 20:28:29.569901 1405 run.go:393] HTTP server started. Listening on port 8080
I0716 20:28:29.569989 1405 worker.go:81] Worker listening at address: [::]:7080
I0716 20:28:29.670123 1405 pool.go:138] CONNECTED to localhost:5080
I0716 20:28:29.684260 1385 zero.go:396] Got connection request: cluster_info_only:true
I0716 20:28:30.415788 1385 node.go:88] 1 is starting a new election at term 1
I0716 20:28:30.415813 1385 node.go:88] 1 became pre-candidate at term 1
I0716 20:28:30.415823 1385 node.go:88] 1 received MsgPreVoteResp from 1 at term 1
I0716 20:28:30.415842 1385 node.go:88] 1 became candidate at term 2
I0716 20:28:30.415848 1385 node.go:88] 1 received MsgVoteResp from 1 at term 2
I0716 20:28:30.415858 1385 node.go:88] 1 became leader at term 2
I0716 20:28:30.415865 1385 node.go:88] raft.node: 1 elected leader 1 at term 2
I0716 20:28:30.415893 1385 raft.go:642] I've become the leader, updating leases.
I0716 20:28:30.415902 1385 assign.go:42] Updated Lease id: 1. Txn Ts: 1
W0716 20:28:30.496033 1385 node.go:668] [0x1] Read index context timed out
I0716 20:28:30.496135 1385 zero.go:414] Connected: cluster_info_only:true
I0716 20:28:30.497600 1385 zero.go:396] Got connection request: addr:"localhost:7080"
I0716 20:28:30.503693 1385 raft.go:493] CID set for cluster: 0be7dfb2-5328-45c0-ad52-212c362784c4
I0716 20:28:30.503763 1385 pool.go:138] CONNECTED to localhost:7080
I0716 20:28:30.514112 1385 zero.go:523] Connected: id:1 group_id:1 addr:"localhost:7080"
I0716 20:28:30.514351 1405 groups.go:119] Connected to group zero. Assigned group: 1
I0716 20:28:30.514365 1405 groups.go:121] Raft Id after connection to Zero: 0x1
I0716 20:28:30.514533 1405 draft.go:74] Node ID: 0x1 with GroupID: 1
I0716 20:28:30.514577 1405 node.go:157] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:100 HeartbeatTick:1 Storage:0xc00939a7b0 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x1f86470 DisableProposalForwarding:false}
I0716 20:28:30.514630 1405 node.go:326] Group 1 found 1 entries
I0716 20:28:30.514637 1405 draft.go:1340] New Node for group: 1
I0716 20:28:30.514672 1405 node.go:88] 1 became follower at term 0
I0716 20:28:30.514702 1405 node.go:88] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0716 20:28:30.514709 1405 node.go:88] 1 became follower at term 1
I0716 20:28:30.514746 1405 groups.go:139] Server is ready
I0716 20:28:30.514786 1405 groups.go:650] Got address of a Zero leader: localhost:5080
I0716 20:28:30.514855 1405 draft.go:716] Found Raft progress: 0
I0716 20:28:30.514898 1405 groups.go:663] Starting a new membership stream receive from localhost:5080.
I0716 20:28:30.527358 1405 node.go:193] Setting conf state to nodes:1
I0716 20:28:30.527496 1405 node.go:88] 1 is starting a new election at term 1
I0716 20:28:30.527511 1405 node.go:88] 1 became pre-candidate at term 1
I0716 20:28:30.527516 1405 node.go:88] 1 received MsgPreVoteResp from 1 at term 1
I0716 20:28:30.527527 1405 node.go:88] 1 became candidate at term 2
I0716 20:28:30.527531 1405 node.go:88] 1 received MsgVoteResp from 1 at term 2
I0716 20:28:30.527539 1405 node.go:88] 1 became leader at term 2
I0716 20:28:30.527545 1405 node.go:88] raft.node: 1 elected leader 1 at term 2
I0716 20:28:30.527589 1405 groups.go:372] Serving tablet for: _predicate_
I0716 20:28:30.527584 1405 groups.go:680] Received first state update from Zero: counter:5 groups:<key:1 value:<members:<key:1 value:<id:1 group_id:1 addr:"localhost:7080" > > tablets:<key:"_predicate_" value:<group_id:1 predicate:"_predicate_" > > checksum:3910901543130921129 > > zeros:<key:1 value:<id:1 addr:"localhost:5080" leader:true > > maxRaftId:1 cid:"0be7dfb2-5328-45c0-ad52-212c362784c4"
I0716 20:28:30.542108 1405 mutation.go:145] Done schema update predicate:"_predicate_" value_type:STRING list:true
PASSEDI0716 20:28:31.489120 1405 server.go:273] Received ALTER op: drop_all:true
I0716 20:28:31.489135 1405 server.go:600] Got Alter request from "127.0.0.1:36830"
I0716 20:28:31.490140 1405 server.go:301] ALTER op: drop_all:true done
I0716 20:28:31.490471 1405 run.go:512] Caught Ctrl-C. Terminating now (this may take a few seconds)...
I0716 20:28:31.490460 1385 run.go:257] --- Received terminated signal
E0716 20:28:31.490497 1405 run.go:298] GRPC listener canceled: accept tcp [::]:9080: use of closed network connection
I0716 20:28:31.490527 1385 run.go:269] Shutting down...
E0716 20:28:31.490553 1385 http.go:236] Stopped taking more http(s) requests. Err: accept tcp [::]:6080: use of closed network connection
I0716 20:28:31.490569 1385 http.go:240] All http(s) requests finished.
I0716 20:28:31.490589 1385 raft.go:611] Zero Node.Run finished.
I0716 20:28:31.490604 1385 run.go:153] gRPC server stopped : accept tcp [::]:5080: use of closed network connection
E0716 20:28:31.490564 1405 run.go:317] Stopped taking more http(s) requests. Err: accept tcp [::]:8080: use of closed network connection
E0716 20:28:31.490719 1405 groups.go:671] Unable to sync memberships. Error: rpc error: code = Unknown desc = Server is being shut down. State: <nil>
I0716 20:28:31.490790 1405 run.go:525] GRPC and HTTP stopped.
I0716 20:28:31.490798 1405 worker.go:95] Stopping group...
I0716 20:28:31.490801 1405 groups.go:650] Got address of a Zero leader: localhost:5080
E0716 20:28:31.491018 1405 groups.go:656] Error while calling 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"
I0716 20:28:32.491185 1405 worker.go:98] Stopping node...
I0716 20:28:32.491223 1405 draft.go:687] Stopping node.Run
I0716 20:28:32.491254 1405 draft.go:727] Raft node done.
I0716 20:28:32.491264 1405 worker.go:101] Stopping worker server...
I0716 20:28:32.491329 1405 run.go:527] Server shutdown. Bye!
W0716 20:28:32.491427 1385 pool.go:226] Connection lost with localhost:7080. Error: rpc error: code = Unavailable desc = transport is closing
I0716 20:28:32.492735 1405 node.go:88] Got compaction priority: {level:0 score:1.73 dropPrefix:[]}
I0716 20:28:32.493284 1405 node.go:88] Running for level: 0
I0716 20:28:32.493847 1405 node.go:88] LOG Compact 0->1, del 1 tables, add 1 tables, took 535.935µs
I0716 20:28:32.493874 1405 node.go:88] Compaction for level: 0 DONE
I0716 20:28:32.493900 1405 node.go:88] Force compaction on level 0 done
I0716 20:28:32.494378 1405 node.go:88] Got compaction priority: {level:0 score:1.73 dropPrefix:[]}
I0716 20:28:32.494395 1405 node.go:88] Running for level: 0
I0716 20:28:32.494837 1405 node.go:88] LOG Compact 0->1, del 1 tables, add 1 tables, took 428.664µs
I0716 20:28:32.494856 1405 node.go:88] Compaction for level: 0 DONE
I0716 20:28:32.494864 1405 node.go:88] Force compaction on level 0 done
I0716 20:28:32.494963 1405 run.go:468] Finished disposing server state.
I0716 20:28:32.497167 1385 run.go:284] All done.
badger 2019/07/16 20:28:32 DEBUG: Storing value log head: {Fid:0 Len:42 Offset:1471}
badger 2019/07/16 20:28:32 INFO: Got compaction priority: {level:0 score:1.73 dropPrefix:[]}
badger 2019/07/16 20:28:32 INFO: Running for level: 0
badger 2019/07/16 20:28:32 DEBUG: LOG Compact. Added 11 keys. Skipped 6 keys. Iteration took: 87.349µs
badger 2019/07/16 20:28:32 DEBUG: Discard stats: map[]
badger 2019/07/16 20:28:32 INFO: LOG Compact 0->1, del 1 tables, add 1 tables, took 463.558µs
badger 2019/07/16 20:28:32 INFO: Compaction for level: 0 DONE
badger 2019/07/16 20:28:32 INFO: Force compaction on level 0 done
Process-based Dgraph setup looks ok so far as of https://github.com/superphy/prairiedog/commit/413b43169b3853a71c8464ac8545784e8db5e561 . Will need to integrate actual queries/graphing tests
Tests running, closing. Will create new issues as needed.
Looks like it'll be problematic to test against the Docker composition while in circleci (https://circleci.com/docs/2.0/building-docker-images/#accessing-services).
Can try using binaries for dgraph itself