Bug #18888
Updated by Peter Amstutz about 2 years ago
<pre>
$ arvados-cwl-runner --debug download_def.cwl --scripts scripts/
INFO /home/peter/work/scripts/venv3/bin/arvados-cwl-runner 2.4.0.dev20220310214858, arvados-python-client 2.4.0.dev20220310214858, cwltool 3.1.20220224085855
INFO Resolved 'download_def.cwl' to 'file:///home/peter/work/3rdparty/alphafold/download_def.cwl'
DEBUG Parsed job order from command line: {
"id": "download_def.cwl",
"scripts": {
"class": "Directory",
"location": "file:///home/peter/work/3rdparty/alphafold/scripts/"
}
}
INFO Using cluster x1fnz (https://172.17.0.2:3001/)
INFO Upload local files: "scripts"
DEBUG {'x1fnz-bi6l4-114285986efd63e1': OrderedDict([('href', '/keep_services/x1fnz-bi6l4-114285986efd63e1'), ('kind', 'arvados#keepService'), ('etag', '64emidmw6rnehr2dczxs92c8'), ('uuid', 'x1fnz-bi6l4-114285986efd63e1'), ('owner_uuid', 'x1fnz-tpzed-000000000000000'), ('created_at', '2022-03-17T18:49:24.847116000Z'), ('modified_by_client_uuid', None), ('modified_by_user_uuid', 'x1fnz-tpzed-000000000000000'), ('modified_at', '2022-03-17T18:49:24.847116000Z'), ('service_host', '172.17.0.2'), ('service_port', 25101), ('service_ssl_flag', True), ('service_type', 'proxy'), ('read_only', False), ('_service_root', 'https://172.17.0.2:25101/')])}
DEBUG 1f64d06922dd7a09473fe800c510dee8+1354: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/1f64d06922dd7a09473fe800c510dee8
INFO PUT 200: 1354 bytes in 12.429237365722656 msec (0.104 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-1, started daemon 140342110295808)> succeeded 1f64d06922dd7a09473fe800c510dee8+1354 https://172.17.0.2:25101/
DEBUG db9e62b653f5ea04309d2167f70bb43d+1394: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/db9e62b653f5ea04309d2167f70bb43d
INFO PUT 200: 1394 bytes in 1.5549659729003906 msec (0.855 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-2, started daemon 140342110295808)> succeeded db9e62b653f5ea04309d2167f70bb43d+1394 https://172.17.0.2:25101/
DEBUG 1026ba07c5dd7fe2272d2f7c58ce59a9+1249: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/1026ba07c5dd7fe2272d2f7c58ce59a9
INFO PUT 200: 1249 bytes in 1.514434814453125 msec (0.787 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-3, started daemon 140342110295808)> succeeded 1026ba07c5dd7fe2272d2f7c58ce59a9+1249 https://172.17.0.2:25101/
DEBUG 50819448fbb1fcc38f12da9f02df12d2+2343: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/50819448fbb1fcc38f12da9f02df12d2
INFO PUT 200: 2343 bytes in 1.6179084777832031 msec (1.381 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-4, started daemon 140342110295808)> succeeded 50819448fbb1fcc38f12da9f02df12d2+2343 https://172.17.0.2:25101/
DEBUG 5cd5abaaf2cbb1ca4337ea61ab789294+1323: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/5cd5abaaf2cbb1ca4337ea61ab789294
INFO PUT 200: 1323 bytes in 1.4336109161376953 msec (0.880 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-5, started daemon 140342110295808)> succeeded 5cd5abaaf2cbb1ca4337ea61ab789294+1323 https://172.17.0.2:25101/
DEBUG a07e65b628577c9af53d64023c2381c0+1509: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/a07e65b628577c9af53d64023c2381c0
INFO PUT 200: 1509 bytes in 1.8351078033447266 msec (0.784 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-6, started daemon 140342110295808)> succeeded a07e65b628577c9af53d64023c2381c0+1509 https://172.17.0.2:25101/
DEBUG 3eaf2718afff27f2dc312166c744c9a0+1439: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/3eaf2718afff27f2dc312166c744c9a0
INFO PUT 200: 1439 bytes in 1.3494491577148438 msec (1.017 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-7, started daemon 140342110295808)> succeeded 3eaf2718afff27f2dc312166c744c9a0+1439 https://172.17.0.2:25101/
DEBUG ecd63ff2d692cbafd4e8e0a811c6f911+1406: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/ecd63ff2d692cbafd4e8e0a811c6f911
INFO PUT 200: 1406 bytes in 1.2781620025634766 msec (1.049 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-8, started daemon 140342110295808)> succeeded ecd63ff2d692cbafd4e8e0a811c6f911+1406 https://172.17.0.2:25101/
DEBUG 22d655f2575b9ad58e46f559603696b6+1522: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/22d655f2575b9ad58e46f559603696b6
INFO PUT 200: 1522 bytes in 1.1749267578125 msec (1.235 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-9, started daemon 140342110295808)> succeeded 22d655f2575b9ad58e46f559603696b6+1522 https://172.17.0.2:25101/
DEBUG aeb3ed2dfc69c0b72b636ff386d407ea+2298: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/aeb3ed2dfc69c0b72b636ff386d407ea
INFO PUT 200: 2298 bytes in 1.2860298156738281 msec (1.704 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-10, started daemon 140342110295808)> succeeded aeb3ed2dfc69c0b72b636ff386d407ea+2298 https://172.17.0.2:25101/
DEBUG 1081aba37ccf5eb1295336d8a3ba5879+2051: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/1081aba37ccf5eb1295336d8a3ba5879
INFO PUT 200: 2051 bytes in 2.0923614501953125 msec (0.935 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-11, started daemon 140342110295808)> succeeded 1081aba37ccf5eb1295336d8a3ba5879+2051 https://172.17.0.2:25101/
INFO Using collection d106612c9d08c8e26e40f9909b613198+774 (x1fnz-4zz18-5uxdy2vt9ruf0ro)
INFO Upload local files: "scripts"
DEBUG 1f64d06922dd7a09473fe800c510dee8+1354: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/1f64d06922dd7a09473fe800c510dee8
INFO PUT 200: 1354 bytes in 1.7938613891601562 msec (0.720 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-12, started daemon 140342110295808)> succeeded 1f64d06922dd7a09473fe800c510dee8+1354 https://172.17.0.2:25101/
DEBUG db9e62b653f5ea04309d2167f70bb43d+1394: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/db9e62b653f5ea04309d2167f70bb43d
INFO PUT 200: 1394 bytes in 1.1601448059082031 msec (1.146 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-13, started daemon 140342110295808)> succeeded db9e62b653f5ea04309d2167f70bb43d+1394 https://172.17.0.2:25101/
DEBUG 1026ba07c5dd7fe2272d2f7c58ce59a9+1249: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/1026ba07c5dd7fe2272d2f7c58ce59a9
INFO PUT 200: 1249 bytes in 1.2826919555664062 msec (0.929 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-14, started daemon 140342110295808)> succeeded 1026ba07c5dd7fe2272d2f7c58ce59a9+1249 https://172.17.0.2:25101/
DEBUG 50819448fbb1fcc38f12da9f02df12d2+2343: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/50819448fbb1fcc38f12da9f02df12d2
INFO PUT 200: 2343 bytes in 1.2192726135253906 msec (1.833 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-15, started daemon 140342110295808)> succeeded 50819448fbb1fcc38f12da9f02df12d2+2343 https://172.17.0.2:25101/
DEBUG 5cd5abaaf2cbb1ca4337ea61ab789294+1323: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/5cd5abaaf2cbb1ca4337ea61ab789294
INFO PUT 200: 1323 bytes in 1.186370849609375 msec (1.064 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-16, started daemon 140342110295808)> succeeded 5cd5abaaf2cbb1ca4337ea61ab789294+1323 https://172.17.0.2:25101/
DEBUG a07e65b628577c9af53d64023c2381c0+1509: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/a07e65b628577c9af53d64023c2381c0
INFO PUT 200: 1509 bytes in 1.4586448669433594 msec (0.987 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-17, started daemon 140342110295808)> succeeded a07e65b628577c9af53d64023c2381c0+1509 https://172.17.0.2:25101/
DEBUG 3eaf2718afff27f2dc312166c744c9a0+1439: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/3eaf2718afff27f2dc312166c744c9a0
INFO PUT 200: 1439 bytes in 1.3539791107177734 msec (1.014 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-18, started daemon 140342110295808)> succeeded 3eaf2718afff27f2dc312166c744c9a0+1439 https://172.17.0.2:25101/
DEBUG ecd63ff2d692cbafd4e8e0a811c6f911+1406: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/ecd63ff2d692cbafd4e8e0a811c6f911
INFO PUT 200: 1406 bytes in 1.5573501586914062 msec (0.861 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-19, started daemon 140342110295808)> succeeded ecd63ff2d692cbafd4e8e0a811c6f911+1406 https://172.17.0.2:25101/
DEBUG 22d655f2575b9ad58e46f559603696b6+1522: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/22d655f2575b9ad58e46f559603696b6
INFO PUT 200: 1522 bytes in 1.7366409301757812 msec (0.836 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-20, started daemon 140342110295808)> succeeded 22d655f2575b9ad58e46f559603696b6+1522 https://172.17.0.2:25101/
DEBUG aeb3ed2dfc69c0b72b636ff386d407ea+2298: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/aeb3ed2dfc69c0b72b636ff386d407ea
INFO PUT 200: 2298 bytes in 1.3263225555419922 msec (1.652 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-21, started daemon 140342110295808)> succeeded aeb3ed2dfc69c0b72b636ff386d407ea+2298 https://172.17.0.2:25101/
DEBUG 1081aba37ccf5eb1295336d8a3ba5879+2051: ['https://172.17.0.2:25101/']
DEBUG Pool max threads is 1
DEBUG Request: PUT https://172.17.0.2:25101/1081aba37ccf5eb1295336d8a3ba5879
INFO PUT 200: 2051 bytes in 1.2395381927490234 msec (1.578 MiB/sec)
DEBUG KeepWriterThread <KeepWriterThread(Thread-22, started daemon 140342110295808)> succeeded 1081aba37ccf5eb1295336d8a3ba5879+2051 https://172.17.0.2:25101/
INFO Using collection d106612c9d08c8e26e40f9909b613198+774 (x1fnz-4zz18-gqx42dl08u9l3c3)
ERROR Unhandled error:
'file:///home/peter/work/3rdparty/alphafold/scripts/'
Traceback (most recent call last):
File "/home/peter/work/scripts/venv3/lib/python3.9/site-packages/cwltool/main.py", line 1343, in main
(out, status) = real_executor(
File "/home/peter/work/arvados/sdk/cwl/arvados_cwl/executor.py", line 592, in arv_executor
merged_map = upload_workflow_deps(self, tool)
File "/home/peter/work/arvados/sdk/cwl/arvados_cwl/runner.py", line 606, in upload_workflow_deps
tool.visit(upload_tool_deps)
File "/home/peter/work/scripts/venv3/lib/python3.9/site-packages/cwltool/process.py", line 1087, in visit
op(self.tool)
File "/home/peter/work/arvados/sdk/cwl/arvados_cwl/runner.py", line 592, in upload_tool_deps
pm = upload_dependencies(arvrunner,
File "/home/peter/work/arvados/sdk/cwl/arvados_cwl/runner.py", line 435, in upload_dependencies
visit_class(workflowobj, ("File", "Directory"), setloc)
File "/home/peter/work/scripts/venv3/lib/python3.9/site-packages/cwltool/utils.py", line 216, in visit_class
visit_class(rec[d], cls, op)
File "/home/peter/work/scripts/venv3/lib/python3.9/site-packages/cwltool/utils.py", line 219, in visit_class
visit_class(d, cls, op)
File "/home/peter/work/scripts/venv3/lib/python3.9/site-packages/cwltool/utils.py", line 216, in visit_class
visit_class(rec[d], cls, op)
File "/home/peter/work/scripts/venv3/lib/python3.9/site-packages/cwltool/utils.py", line 214, in visit_class
op(rec)
File "/home/peter/work/arvados/sdk/cwl/arvados_cwl/runner.py", line 405, in setloc
p["location"] = mapper.mapper(p["location"]).resolved
File "/home/peter/work/scripts/venv3/lib/python3.9/site-packages/cwltool/pathmapper.py", line 186, in mapper
return self._pathmap[src]
KeyError: 'file:///home/peter/work/3rdparty/alphafold/scripts/'
</pre>
I also had this happen using a Directory default value, but now I can't reproduce it.