Error in map phase of recent code

[kevinkle]

MAP 47m02s nquad_count:513.1M err_count:0.000 nquad_speed:181.8k/sec edge_count:1.283G edge_speed:454.4k/sec
MAP 47m03s nquad_count:513.3M err_count:0.000 nquad_speed:181.8k/sec edge_count:1.283G edge_speed:454.5k/sec
W0822 21:47:17.950388    5738 raft.go:707] Raft.Ready took too long to process: Timer Total: 230ms. Breakdown: [{sync 229ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
MAP 47m04s nquad_count:513.6M err_count:0.000 nquad_speed:181.8k/sec edge_count:1.284G edge_speed:454.6k/sec
MAP 47m05s nquad_count:513.9M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.285G edge_speed:454.6k/sec
W0822 21:47:20.446690    5738 raft.go:707] Raft.Ready took too long to process: Timer Total: 138ms. Breakdown: [{sync 138ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
MAP 47m06s nquad_count:514.1M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.285G edge_speed:454.7k/sec
MAP 47m07s nquad_count:514.4M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.286G edge_speed:454.8k/sec
MAP 47m08s nquad_count:514.7M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.287G edge_speed:454.9k/sec
MAP 47m09s nquad_count:514.8M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.287G edge_speed:454.8k/sec
MAP 02h26m09s nquad_count:1.382G err_count:0.000 nquad_speed:157.6k/sec edge_count:3.454G edge_speed:393.9k/sec
MAP 02h26m10s nquad_count:1.382G err_count:0.000 nquad_speed:157.6k/sec edge_count:3.455G edge_speed:393.9k/sec
90ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
MAP 47m10s nquad_count:515.0M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.287G edge_speed:454.8k/sec
MAP 47m11s nquad_count:515.2M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.288G edge_speed:454.9k/sec
E0822 21:47:26.476536    5784 xidmap.go:120] Error while getting lease: rpc error: code = DeadlineExceeded desc = context deadline exceeded
MAP 47m12s nquad_count:515.2M err_count:0.000 nquad_speed:181.9k/sec edge_count:1.288G edge_speed:454.7k/sec
W0822 21:47:26.743571    5738 raft.go:707] Raft.Ready took too long to process: Timer Total: 1.267s. Breakdown: [{sync 1.267s} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0822 21:47:27.069903    5738 raft.go:707] Raft.Ready took too long to process: Timer Total: 326ms. Breakdown: [{sync 326ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
  File "/p/prairiedog/dgraph.py", line 80, in query
  File "/opt/venv/lib/python3.7/site-packages/pydgraph/txn.py", line 82, in query
  File "/opt/venv/lib/python3.7/site-packages/pydgraph/txn.py", line 73, in query
  File "/opt/venv/lib/python3.7/site-packages/pydgraph/client_stub.py", line 51, in query
  File "/opt/venv/lib/python3.7/site-packages/grpc/_channel.py", line 565, in __call__
  File "/opt/venv/lib/python3.7/site-packages/grpc/_channel.py", line 467, in _end_unary_response_blocking
  File "/.pyenv/versions/3.7.0/lib/python3.7/concurrent/futures/thread.py", line 57, in run
2019-08-23 04:10:31 6ff79a72ebdf snakemake.logging[5711] 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":"@1566533431.607265184","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3818,"referenced_errors":[{"created":"@1566533431.606239979","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":395,"grpc_status":14}]}"
>
  File "/p/Snakefile", line 152, in __rule_dgraph
  File "/p/prairiedog/dgraph_bundled_helper.py", line 38, in load
  File "/p/prairiedog/dgraph_bundled.py", line 204, in __init__
  File "/p/prairiedog/dgraph_bundled.py", line 233, in __init__
  File "/p/prairiedog/errors.py", line 21, in __init__
  File "/p/prairiedog/dgraph.py", line 210, in nodes
  File "/p/prairiedog/dgraph.py", line 80, in query
  File "/opt/venv/lib/python3.7/site-packages/pydgraph/txn.py", line 82, in query
  File "/opt/venv/lib/python3.7/site-packages/pydgraph/txn.py", line 73, in query
  File "/opt/venv/lib/python3.7/site-packages/pydgraph/client_stub.py", line 51, in query
  File "/opt/venv/lib/python3.7/site-packages/grpc/_channel.py", line 565, in __call__
  File "/opt/venv/lib/python3.7/site-packages/grpc/_channel.py", line 467, in _end_unary_response_blocking
  File "/.pyenv/versions/3.7.0/lib/python3.7/concurrent/futures/thread.py", line 57, in run
Exiting because a job execution failed. Look above for error message
2019-08-23 04:10:31 6ff79a72ebdf snakemake.logging[5711] ERROR Exiting because a job execution failed. Look above for error message
Snakemake will run with samples dir samples/ and output dir outputs/
I0823 04:10:33.691289    8116 node.go:88] 35 tables out of 1017 opened in 15.236s
I0823 04:10:35.722148    8096 run.go:257] --- Received terminated signal
I0823 04:10:35.722448    8096 run.go:269] Shutting down...
E0823 04:10:35.722539    8096 http.go:236] Stopped taking more http(s) requests. Err: accept tcp [::]:6081: use of closed network connection
I0823 04:10:35.722571    8096 http.go:240] All http(s) requests finished.
I0823 04:10:35.722616    8096 raft.go:611] Zero Node.Run finished.
I0823 04:10:35.722653    8096 run.go:153] gRPC server stopped : accept tcp [::]:5081: use of closed network connection
I0823 04:10:35.722703    8096 run.go:284] All done.
badger 2019/08/23 04:10:35 DEBUG: Storing value log head: {Fid:0 Len:42 Offset:686}
badger 2019/08/23 04:10:36 INFO: Got compaction priority: {level:0 score:1.73 dropPrefix:[]}
badger 2019/08/23 04:10:36 INFO: Running for level: 0
badger 2019/08/23 04:10:36 DEBUG: LOG Compact. Added 7 keys. Skipped 2 keys. Iteration took: 516.134µs
badger 2019/08/23 04:10:36 DEBUG: Discard stats: map[]
badger 2019/08/23 04:10:36 INFO: LOG Compact 0->1, del 1 tables, add 1 tables, took 700.129989ms
badger 2019/08/23 04:10:36 INFO: Compaction for level: 0 DONE
badger 2019/08/23 04:10:36 INFO: Force compaction on level 0 done
Shutting down, this might take some time.
2019-08-23 04:10:37 6ff79a72ebdf snakemake.logging[9] WARNING Shutting down, this might take some time.
Exiting because a job execution failed. Look above for error message
2019-08-23 04:10:37 6ff79a72ebdf snakemake.logging[9] ERROR Exiting because a job execution failed. Look above for error message
Complete log: /p/.snakemake/log/2019-08-22T203107.070600.snakemake.log
2019-08-23 04:10:37 6ff79a72ebdf snakemake.logging[9] WARNING Complete log: /p/.snakemake/log/2019-08-22T203107.070600.snakemake.log
Snakemake will run with samples dir samples/ and output dir outputs/
kevin@panther /m/1/pdg-test>

[kevinkle]

Looks like some error occurred in DgraphBundled and the query part is part of our custom error trying to dump the existing nodes.

[kevinkle]

Went through fine so far

[kevinkle]

Not sure what happened, but has been working fine now