Project

General

Profile

Actions
Copy link

Bug #18888

closed

Error uploading Directory provided on the command line

Added by Peter Amstutz 11 months ago. Updated 9 months ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Peter Amstutz
Category:
CWL
Target version:
2022-04-27 Sprint
Start date:
04/19/2022
Due date:
% Done:

100%

Estimated time:
(Total: 0.00 h)
Story points:
-
Release:
Arvados 2.4.1
Release relationship:
Auto

Description

$ 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/'

I also had this happen using a Directory default value, but now I can't reproduce it.

Subtasks 1 (0 open — 1 closed)

Task #18953: Review 18888-cwl-dir-argResolvedPeter Amstutz04/19/2022

Actions

Related issues

Related to Arvados Epics - Story #17848: CWL runner improvementsIn Progress07/01/202106/30/2023

Actions
Actions
Copy link
 #1

Updated by Peter Amstutz 11 months ago

  • Description updated (diff)
Actions
Copy link
 #2

Updated by Peter Amstutz 11 months ago

  • Description updated (diff)
  • Subject changed from Error uploading Directory specified as "default" or provided on the command line to Error uploading Directory provided on the command line
Actions
Copy link
 #3

Updated by Peter Amstutz 11 months ago

Actions
Copy link
 #4

Updated by Peter Amstutz 10 months ago

  • Target version changed from 2022-03-30 Sprint to 2022-04-13 Sprint
Actions
Copy link
 #5

Updated by Peter Amstutz 10 months ago

  • Target version changed from 2022-04-13 Sprint to 2022-04-27 Sprint
Actions
Copy link
 #6

Updated by Peter Amstutz 10 months ago

The bug was actually not handling the command line, it was due to the "default" value of the Directory using "scripts/" (trailing slash) instead of "script".

File paths are normalized, but the normalization was being skipped for file objects in "default" for some reason.

18888-cwl-dir-arg @ 16628b89b26d26182f66a01a22e91af9307a3e57

developer-run-tests: #3068

Actions
Copy link
 #7

Updated by Peter Amstutz 10 months ago

  • Status changed from New to In Progress
Actions
Copy link
 #9

Updated by Peter Amstutz 10 months ago

Duh, I changed the status messages but didn't update the tests, of course tests are failing. Sorry.

I was thinking of a different branch, but obviously this one needs to have tests fixed too.

Actions
Copy link
 #11

Updated by Lucas Di Pentima 10 months ago

This LGTM, thanks!

Actions
Copy link
 #12

Updated by Peter Amstutz 10 months ago

  • Status changed from In Progress to Resolved
Actions
Copy link
 #13

Updated by Peter Amstutz 9 months ago

  • Release set to 51
Actions
Copy link

Also available in: Atom PDF