Project

General

Profile

Bug #16367 » arvados.log

Michael Crusoe, 04/24/2020 04:47 PM

 
1
$ arvados-cwl-runner msa.cwl msa_arv.yaml
2
INFO /home/michael/src/2020-covid-19-bh/env3.7/bin/arvados-cwl-runner 2.1.0.dev20200407192516, arvados-python-client 2.0.1, cwltool 3.0.20200324120055
3
INFO Resolved 'msa.cwl' to 'file:///home/michael/src/2020-covid-19-bh/msa/msa.cwl'
4
INFO Using empty collection d41d8cd98f00b204e9800998ecf8427e+0
5
INFO Using empty collection d41d8cd98f00b204e9800998ecf8427e+0
6
INFO Using empty collection d41d8cd98f00b204e9800998ecf8427e+0
7
INFO Using empty collection d41d8cd98f00b204e9800998ecf8427e+0
8
INFO Using collection cache size 256 MiB
9
INFO ['docker', 'pull', 'arvados/jobs:2.1.0.dev20200407192516']
10
2.1.0.dev20200407192516: Pulling from arvados/jobs
11
fc7181108d40: Pull complete 
12
e5c973b5b8ee: Pull complete 
13
82f5b8b26077: Pull complete 
14
5d73d76a59bb: Pull complete 
15
72db1e144257: Pull complete 
16
b995ebdb747b: Pull complete 
17
fa3c0ba3b337: Pull complete 
18
7dcb6e3b462b: Pull complete 
19
618929f6c3c2: Pull complete 
20
613110052abc: Pull complete 
21
0ea5bf6bcbfb: Pull complete 
22
Digest: sha256:f2c1bb4d16402e7e7dbd922ee69d485dd63dcb5e308fbf8b22ee20d053416363
23
Status: Downloaded newer image for arvados/jobs:2.1.0.dev20200407192516
24
docker.io/arvados/jobs:2.1.0.dev20200407192516
25
INFO Uploading Docker image arvados/jobs:2.1.0.dev20200407192516
26
2020-04-24 18:42:14 arvados.arv_put[37450] INFO: Creating new cache file at /home/michael/.cache/arvados/arv-put/bd0e10119db97007dbc105c8dcc5aeea
27
0M / 261M 0.0% 2020-04-24 18:43:01 arvados.arv_put[37450] WARNING: Abnormal termination:
28
Traceback (most recent call last):
29
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 712, in commit_bufferblock
30
    block.set_state(_BufferBlock.PENDING)
31
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
32
    return orig_func(self, *args, **kwargs)
33
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 360, in set_state
34
    raise StateChangeError("Invalid state change from %s to %s" % (self._state, nextstate), self._state, nextstate)
35
arvados.arvfile.StateChangeError: Invalid state change from 1 to 1
36

    
37
During handling of the above exception, another exception occurred:
38

    
39
Traceback (most recent call last):
40
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/commands/put.py", line 606, in start
41
    self._upload_files()
42
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/commands/put.py", line 835, in _upload_files
43
    output.close(flush=False)
44
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 1360, in close
45
    self.arvadosfile.remove_writer(self, flush)
46
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
47
    return orig_func(self, *args, **kwargs)
48
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 1038, in remove_writer
49
    self.flush()
50
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
51
    return orig_func(self, *args, **kwargs)
52
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 1192, in flush
53
    self.parent._my_block_manager().commit_bufferblock(bb, sync=True)
54
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 722, in commit_bufferblock
55
    raise block.error
56
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 560, in _commit_bufferblock_worker
57
    loc = self._keep.put(bufferblock.buffer_view[0:bufferblock.write_pointer].tobytes(), num_retries=self.num_retries, copies=self.copies)
58
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/retry.py", line 177, in num_retries_setter
59
    return orig_func(self, *args, **kwargs)
60
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/keep.py", line 1200, in put
61
    data_hash, loop.attempts_str(), copies, writer_pool.done()), service_errors, label="service")
62
arvados.errors.KeepWriteError: failed to write 42ccf9c5663306c85f9bf29c879a35d9 after 2 attempts (wanted 2 copies but wrote 0): service https://keep.lugli.arvadosapi.com:443/ responded with 413 HTTP/2 413 
63

    
64

    
65
261M / 261M 100.0% 2020-04-24 18:43:01 cwltool[37450] ERROR: Workflow execution failed (X-Request-Id: req-dmhpayon8ql30aj22jrk)
66
Traceback (most recent call last):
67
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 712, in commit_bufferblock
68
    block.set_state(_BufferBlock.PENDING)
69
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
70
    return orig_func(self, *args, **kwargs)
71
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 360, in set_state
72
    raise StateChangeError("Invalid state change from %s to %s" % (self._state, nextstate), self._state, nextstate)
73
arvados.arvfile.StateChangeError: Invalid state change from 1 to 1
74

    
75
During handling of the above exception, another exception occurred:
76

    
77
Traceback (most recent call last):
78
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/arvdocker.py", line 64, in arv_docker_get_image
79
    arvados.commands.keepdocker.main(args, stdout=sys.stderr, install_sig_handlers=False, api=api_client)
80
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/commands/keepdocker.py", line 506, in main
81
    install_sig_handlers=install_sig_handlers).strip()
82
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/commands/put.py", line 1304, in main
83
    writer.start(save_collection=not(args.stream or args.raw))
84
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/commands/put.py", line 606, in start
85
    self._upload_files()
86
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/commands/put.py", line 835, in _upload_files
87
    output.close(flush=False)
88
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 1360, in close
89
    self.arvadosfile.remove_writer(self, flush)
90
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
91
    return orig_func(self, *args, **kwargs)
92
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 1038, in remove_writer
93
    self.flush()
94
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
95
    return orig_func(self, *args, **kwargs)
96
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 1192, in flush
97
    self.parent._my_block_manager().commit_bufferblock(bb, sync=True)
98
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 722, in commit_bufferblock
99
    raise block.error
100
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/arvfile.py", line 560, in _commit_bufferblock_worker
101
    loc = self._keep.put(bufferblock.buffer_view[0:bufferblock.write_pointer].tobytes(), num_retries=self.num_retries, copies=self.copies)
102
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/retry.py", line 177, in num_retries_setter
103
    return orig_func(self, *args, **kwargs)
104
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/arvados/keep.py", line 1200, in put
105
    data_hash, loop.attempts_str(), copies, writer_pool.done()), service_errors, label="service")
106
arvados.errors.KeepWriteError: failed to write 42ccf9c5663306c85f9bf29c879a35d9 after 2 attempts (wanted 2 copies but wrote 0): service https://keep.lugli.arvadosapi.com:443/ responded with 413 HTTP/2 413 
107

    
108

    
109
The above exception was the direct cause of the following exception:
110

    
111
Traceback (most recent call last):
112
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/runner.py", line 548, in arvados_jobs_image
113
    return arvados_cwl.arvdocker.arv_docker_get_image(arvrunner.api, {"dockerPull": img}, True, arvrunner.project_uuid)
114
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/arvdocker.py", line 80, in arv_docker_get_image
115
    cached_lookups[dockerRequirement["dockerImageId"]] = pdh
116
  File "/home/michael/src/2020-covid-19-bh/env3.7/lib/python3.7/site-packages/schema_salad/sourceline.py", line 305, in __exit__
117
    raise self.makeError(str(exc_value)) from exc_value
118
cwltool.errors.WorkflowException: failed to write 42ccf9c5663306c85f9bf29c879a35d9 after 2 attempts (wanted 2 copies but wrote 0): service https://keep.lugli.arvadosapi.com:443/ responded with 413 HTTP/2 413 
119

    
120

    
121
During handling of the above exception, another exception occurred:
122

    
123
Traceback (most recent call last):
124
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/executor.py", line 703, in arv_executor
125
    self.start_run(runnable, runtimeContext)
126
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/executor.py", line 232, in start_run
127
    self.workflow_eval_lock, self.stop_polling)
128
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/task_queue.py", line 49, in add
129
    task()
130
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/arvcontainer.py", line 508, in run
131
    job_spec = self.arvados_job_spec(runtimeContext)
132
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/arvcontainer.py", line 408, in arvados_job_spec
133
    "container_image": arvados_jobs_image(self.arvrunner, self.jobs_image),
134
  File "/home/michael/src/arvados/sdk/cwl/arvados_cwl/runner.py", line 550, in arvados_jobs_image
135
    raise Exception("Docker image %s is not available\n%s" % (img, e) )
136
Exception: Docker image arvados/jobs:2.1.0.dev20200407192516 is not available
137
failed to write 42ccf9c5663306c85f9bf29c879a35d9 after 2 attempts (wanted 2 copies but wrote 0): service https://keep.lugli.arvadosapi.com:443/ responded with 413 HTTP/2 413 
138

    
139
2020-04-24 18:43:01 cwltool[37450] ERROR: Workflow error, try again with --debug for more information:
140
Workflow did not return a result.
(1-1/9)