search

superphy / prairiedog

next-gen pangenome graphs for predictive genomics
Other
0 stars 0 forks source link

Error when first calling rule dgraph via snakemake #134

Open kevinkle opened 5 years ago

kevinkle commented 5 years ago 
2019-08-16 15:58:20 9fb23c721f86 snakemake.logging[9] INFO 21 of 23 steps (91%) done

2019-08-16 15:58:20 9fb23c721f86 snakemake.logging[9] INFO
[Fri Aug 16 15:58:20 2019]
2019-08-16 15:58:20 9fb23c721f86 snakemake.logging[9] INFO [Fri Aug 16 15:58:20 2019]
rule done:
    input: outputs/pangenome_SRR3295967.g, outputs/pangenome_SRR2567055.g, outputs/pangenome_SRR2567158.g, outputs/pangenome_SRR3295866.g, outputs/pangenome_SRR2407715.g, outputs/pangenome_SRR2567098.g, outputs/pangenome_SRR3664657.g, outputs/pangenome_SRR3295547.g, outputs/pangenome_SRR5573048.g, outputs/pangenome_SRR2407634.g
    output: outputs/pangenome.g
    jobid: 1
2019-08-16 15:58:20 9fb23c721f86 snakemake.logging[9] INFO rule done:
    input: outputs/pangenome_SRR3295967.g, outputs/pangenome_SRR2567055.g, outputs/pangenome_SRR2567158.g, outputs/pangenome_SRR3295866.g, outputs/pangenome_SRR2407715.g, outputs/pangenome_SRR2567098.g, outputs/pangenome_SRR3664657.g, outputs/pangenome_SRR3295547.g, outputs/pangenome_SRR5573048.g, outputs/pangenome_SRR2407634.g
    output: outputs/pangenome.g
    jobid: 1

2019-08-16 15:58:20 9fb23c721f86 snakemake.logging[9] INFO
Job counts:
        count   jobs
        1       done
        1
2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[153] WARNING Job counts:
        count   jobs
        1       done
        1
Snakemake will run with samples dir samples/ and output dir outputs/
[Fri Aug 16 15:58:23 2019]
2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[9] INFO [Fri Aug 16 15:58:23 2019]
Finished job 1.
2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[9] INFO Finished job 1.
22 of 23 steps (96%) done
2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[9] INFO 22 of 23 steps (96%) done

2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[9] INFO
[Fri Aug 16 15:58:23 2019]
2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[9] INFO [Fri Aug 16 15:58:23 2019]
rule dgraph:
    input: outputs/pangenome.g, outputs/samples/kmers.rdf
    output: outputs/dgraph.done
    jobid: 0
2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[9] INFO rule dgraph:
    input: outputs/pangenome.g, outputs/samples/kmers.rdf
    output: outputs/dgraph.done
    jobid: 0

2019-08-16 15:58:23 9fb23c721f86 snakemake.logging[9] INFO
Job counts:
        count   jobs
        1       dgraph
        1
2019-08-16 15:58:25 9fb23c721f86 snakemake.logging[159] WARNING Job counts:
        count   jobs
        1       dgraph
        1
2019-08-16 15:58:25 9fb23c721f86 prairiedog[159] INFO Will setup Dgraph from folder outputs/dgraph
2019-08-16 15:58:25 9fb23c721f86 prairiedog[159] INFO Using global offset 0
I0816 15:58:25.636786     164 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.

I0816 15:58:25.637297     164 run.go:98] Setting up grpc listener at: 0.0.0.0:5080
I0816 15:58:25.637444     164 run.go:98] Setting up http listener at: 0.0.0.0:6080
badger 2019/08/16 15:58:26 INFO: All 0 tables opened in 0s
I0816 15:58:27.680103     179 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.

I0816 15:58:27.698064     179 run.go:461] x.Config: {DebugMode:false PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000}
I0816 15:58:27.698099     179 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}
I0816 15:58:27.698144     179 run.go:463] edgraph.Config: {PostingDir:outputs/dgraph/p BadgerTables:mmap BadgerVlog:mmap WALDir:outputs/dgraph/alpha/w MutationsMode:0 AuthToken: AllottedMemory:2048}
I0816 15:58:27.698418     179 server.go:115] Setting Badger table load option: mmap
I0816 15:58:27.698430     179 server.go:127] Setting Badger value log load option: mmap
I0816 15:58:27.698440     179 server.go:155] Opening write-ahead log BadgerDB with options: {Dir:outputs/dgraph/alpha/w ValueDir:outputs/dgraph/alpha/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}
I0816 15:58:28.046453     164 node.go:157] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:100 HeartbeatTick:1 Storage:0xc00049de60 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x1f86470 DisableProposalForwarding:false}
I0816 15:58:28.047458     164 node.go:326] Group 0 found 1 entries
I0816 15:58:28.047647     164 node.go:88] 1 became follower at term 0
I0816 15:58:28.048188     164 node.go:88] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0816 15:58:28.048239     164 node.go:88] 1 became follower at term 1
I0816 15:58:28.048490     164 run.go:282] Running Dgraph Zero...
E0816 15:58:28.049585     164 raft.go:499] While proposing CID: Not Zero leader. Aborting proposal: cid:"c9b85649-9376-49dc-a750-f41766cd16f6" . Retrying...
I0816 15:58:28.946156     164 node.go:193] Setting conf state to nodes:1
I0816 15:58:28.946278     164 raft.go:676] Done applying conf change at 0x1
W0816 15:58:28.946350     164 raft.go:707] Raft.Ready took too long to process: Timer Total: 898ms. Breakdown: [{sync 896ms} {disk 1ms} {proposals 1ms} {advance 0s}]. Num entries: 1. MustSync: true
I0816 15:58:29.049034     164 node.go:88] 1 no leader at term 1; dropping index reading msg
I0816 15:58:29.302983     179 node.go:88] All 0 tables opened in 0s
I0816 15:58:30.364379     179 server.go:115] Setting Badger table load option: mmap
I0816 15:58:30.364411     179 server.go:127] Setting Badger value log load option: mmap
I0816 15:58:30.364425     179 server.go:169] Opening postings BadgerDB with options: {Dir:outputs/dgraph/p ValueDir:outputs/dgraph/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}
W0816 15:58:31.049092     164 node.go:668] [0x1] Read index context timed out
I0816 15:58:31.049153     164 node.go:88] 1 no leader at term 1; dropping index reading msg
E0816 15:58:31.052288     164 raft.go:499] While proposing CID: Not Zero leader. Aborting proposal: cid:"3b28522b-2c6e-4332-a7ad-3f5675095eed" . Retrying...
I0816 15:58:31.108713     164 node.go:88] 1 is starting a new election at term 1
I0816 15:58:31.108748     164 node.go:88] 1 became pre-candidate at term 1
I0816 15:58:31.108760     164 node.go:88] 1 received MsgPreVoteResp from 1 at term 1
I0816 15:58:31.108787     164 node.go:88] 1 became candidate at term 2
I0816 15:58:31.108797     164 node.go:88] 1 received MsgVoteResp from 1 at term 2
I0816 15:58:31.108817     164 node.go:88] 1 became leader at term 2
I0816 15:58:31.108830     164 node.go:88] raft.node: 1 elected leader 1 at term 2
I0816 15:58:31.108891     164 raft.go:642] I've become the leader, updating leases.
I0816 15:58:31.108907     164 assign.go:42] Updated Lease id: 1. Txn Ts: 1
I0816 15:58:31.620742     179 node.go:88] All 0 tables opened in 0s
2019-08-16 15:58:31 9fb23c721f86 prairiedog[159] INFO Will connect to Dgraph instance at localhost:9080
2019-08-16 15:58:31 9fb23c721f86 prairiedog[159] DEBUG Done initializing Dgraph client
2019-08-16 15:58:31 9fb23c721f86 prairiedog[159] INFO Set global offset to 1
[Fri Aug 16 15:58:31 2019]
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[159] INFO [Fri Aug 16 15:58:31 2019]
Error in rule dgraph:
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[159] ERROR Error in rule dgraph:
    jobid: 0
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[159] ERROR     jobid: 0
    output: outputs/dgraph.done
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[159] ERROR     output: outputs/dgraph.done

2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[159] ERROR
RuleException:
_Rendezvous in line 152 of /p/Snakefile:
<_Rendezvous of RPC that terminated with:
        status = StatusCode.UNAVAILABLE
        details = "failed to connect to all addresses"
        debug_error_string = "{"created":"@1565971111.770094132","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1565971111.770083379","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"
>
  File "/p/Snakefile", line 152, in __rule_dgraph
  File "/p/prairiedog/dgraph_bundled.py", line 123, in __init__
  File "/p/prairiedog/dgraph_bundled.py", line 83, in set_schema
  File "/opt/venv/site-packages/pydgraph/client.py", line 87, in alter
  File "/opt/venv/site-packages/pydgraph/client.py", line 78, in alter
  File "/opt/venv/site-packages/pydgraph/client_stub.py", line 46, in alter
  File "/opt/venv/site-packages/grpc/_channel.py", line 565, in __call__
  File "/opt/venv/site-packages/grpc/_channel.py", line 467, in _end_unary_response_blocking
  File "/.pyenv/versions/pypy3.6-7.1.1/lib-python/3/concurrent/futures/thread.py", line 55, in run
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[159] ERROR RuleException:
_Rendezvous in line 152 of /p/Snakefile:
<_Rendezvous of RPC that terminated with:
        status = StatusCode.UNAVAILABLE
        details = "failed to connect to all addresses"
        debug_error_string = "{"created":"@1565971111.770094132","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1565971111.770083379","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"
>
  File "/p/Snakefile", line 152, in __rule_dgraph
  File "/p/prairiedog/dgraph_bundled.py", line 123, in __init__
  File "/p/prairiedog/dgraph_bundled.py", line 83, in set_schema
  File "/opt/venv/site-packages/pydgraph/client.py", line 87, in alter
  File "/opt/venv/site-packages/pydgraph/client.py", line 78, in alter
  File "/opt/venv/site-packages/pydgraph/client_stub.py", line 46, in alter
  File "/opt/venv/site-packages/grpc/_channel.py", line 565, in __call__
  File "/opt/venv/site-packages/grpc/_channel.py", line 467, in _end_unary_response_blocking
  File "/.pyenv/versions/pypy3.6-7.1.1/lib-python/3/concurrent/futures/thread.py", line 55, in run
Exiting because a job execution failed. Look above for error message
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[159] ERROR Exiting because a job execution failed. Look above for error message
Snakemake will run with samples dir samples/ and output dir outputs/
Initializing built-in dgraph instance...
Shutting down, this might take some time.
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[9] WARNING Shutting down, this might take some time.
Exiting because a job execution failed. Look above for error message
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[9] ERROR Exiting because a job execution failed. Look above for error message
Complete log: /p/.snakemake/log/2019-08-16T155553.037218.snakemake.log
2019-08-16 15:58:31 9fb23c721f86 snakemake.logging[9] WARNING Complete log: /p/.snakemake/log/2019-08-16T155553.037218.snakemake.log
Snakemake will run with samples dir samples/ and output dir outputs/

this doesnt happen on second invocation

kevinkle commented 5 years ago

Looks like its something to do with our folder setup code, the empty /p and /w /alpha gets added after second call

├── dgraph
│   ├── alpha
│   │   └── w
│   ├── outputs
│   │   └── dgraph
│   │       ├── alpha
│   │       │   └── w
│   │       │       ├── 000000.vlog
│   │       │       ├── LOCK
│   │       │       └── MANIFEST
│   │       ├── p
│   │       │   ├── 000000.vlog
│   │       │   ├── LOCK
│   │       │   └── MANIFEST
│   │       └── w
│   │           ├── 000000.vlog
│   │           ├── LOCK
│   │           └── MANIFEST
│   ├── p
│   └── w
kevinkle commented 5 years ago

After calling ratel, after graphing

.
├── dgraph
│   ├── alpha
│   │   └── w
│   ├── outputs
│   │   └── dgraph
│   │       ├── alpha
│   │       │   └── w
│   │       │       ├── 000000.vlog
│   │       │       ├── LOCK
│   │       │       └── MANIFEST
│   │       ├── outputs
│   │       │   └── dgraph
│   │       │       ├── alpha
│   │       │       │   └── w
│   │       │       │       ├── 000000.vlog
│   │       │       │       ├── LOCK
│   │       │       │       └── MANIFEST
│   │       │       ├── p
│   │       │       │   ├── 000000.vlog
│   │       │       │   ├── LOCK
│   │       │       │   └── MANIFEST
│   │       │       └── w
│   │       │           ├── 000000.vlog
│   │       │           ├── LOCK
│   │       │           └── MANIFEST
│   │       ├── p
│   │       │   ├── 000000.vlog
│   │       │   ├── LOCK
│   │       │   └── MANIFEST
│   │       └── w
│   │           ├── 000000.vlog
│   │           ├── LOCK
│   │           └── MANIFEST
│   ├── p
│   └── w