Project

General

Profile

Bug #18888

Updated by Peter Amstutz over 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. 

Back