Bug #17983
Updated by Ward Vandewege over 2 years ago
<pre>
ward@shell:~$ arv-mount --debug --foreground --read-write --collection pirca-4zz18-nsaus8rzkfeh69m keep/
2021-08-06 14:54:54 arvados.arv-mount[1224] DEBUG: arv-mount debugging enabled
2021-08-06 14:54:54 arvados.arv-mount[1224] INFO: /usr/bin/arv-mount 2.2.1 started
2021-08-06 14:54:54 arvados.arv-mount[1224] INFO: enable write is True
2021-08-06 14:54:54 arvados.arvados_fuse[1224] DEBUG: InodeCache touched inode 1 (size 0) (uuid pirca-4zz18-nsaus8rzkfeh69m) total now 0 (1 entries)
FUSE library version: 2.9.9
unique: 1, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0
INIT: 7.27
flags=0x003ffffb
max_readahead=0x00020000
INIT: 7.19
flags=0x00000021
max_readahead=0x00020000
max_write=0x00020000
max_background=0
congestion_threshold=0
unique: 1, success, outsize: 40
unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 1299
unique: 2, success, outsize: 120
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 1299
unique: 3, success, outsize: 96
unique: 4, opcode: OPENDIR (27), nodeid: 1, insize: 48, pid: 1311
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: arv-mount opendir: inode 1
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: InodeCache touched inode 1 (size 0) (uuid pirca-4zz18-nsaus8rzkfeh69m) total now 0 (1 entries)
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: Updating collection pirca-4zz18-nsaus8rzkfeh69m inode 1 to record version None
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: <arvados_fuse.fusedir.CollectionDirectory object at 0x7fb99c7c2558> manifest_size 116
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: InodeCache touched inode 1 (size 14848) (uuid pirca-4zz18-nsaus8rzkfeh69m) total now 14848 (1 entries)
unique: 4, success, outsize: 32
unique: 5, opcode: READDIR (28), nodeid: 1, insize: 80, pid: 1311
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: arv-mount readdir: fh 0 off 0
unique: 5, success, outsize: 120
unique: 6, opcode: LOOKUP (1), nodeid: 1, insize: 55, pid: 1311
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: InodeCache touched inode 1 (size 14848) (uuid pirca-4zz18-nsaus8rzkfeh69m) total now 14848 (1 entries)
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: arv-mount lookup: parent_inode 1 name 'stderr (1).txt' inode 2
unique: 6, success, outsize: 144
unique: 7, opcode: READDIR (28), nodeid: 1, insize: 80, pid: 1311
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: arv-mount readdir: fh 0 off 3
unique: 7, success, outsize: 16
unique: 8, opcode: RELEASEDIR (29), nodeid: 1, insize: 64, pid: 0
2021-08-06 14:56:08 arvados.arvados_fuse[1224] DEBUG: arv-mount release fh 0
unique: 8, success, outsize: 16
unique: 9, opcode: LOOKUP (1), nodeid: 1, insize: 49, pid: 1313
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: InodeCache touched inode 1 (size 14848) (uuid pirca-4zz18-nsaus8rzkfeh69m) total now 14848 (1 entries)
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: arv-mount lookup: parent_inode 1 name 'testfile' not found
unique: 9, error: -2 (No such file or directory), outsize: 16
unique: 10, opcode: CREATE (35), nodeid: 1, insize: 65, pid: 1313
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: arv-mount create: parent_inode 1 'testfile' 100644
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: collection notify add <arvados.collection.Collection object at 0x7fb99c6a4b70> testfile <arvados.arvfile.ArvadosFile object at 0x7fb99c82b048>
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: collection notify mod <arvados.collection.Collection object at 0x7fb99c6a4b70> testfile (<arvados.arvfile.ArvadosFile object at 0x7fb99c82b048>, <arvados.arvfile.ArvadosFile object at 0x7fb99c82b048>)
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: InodeCache touched inode 1 (size 14848) (uuid pirca-4zz18-nsaus8rzkfeh69m) total now 14848 (1 entries)
unique: 10, success, outsize: 160
unique: 11, opcode: FLUSH (25), nodeid: 3, insize: 64, pid: 1313
unique: 11, success, outsize: 16
unique: 12, opcode: GETXATTR (22), nodeid: 3, insize: 68, pid: 1313
unique: 12, error: -38 (Function not implemented), outsize: 16
unique: 13, opcode: WRITE (16), nodeid: 3, insize: 112, pid: 1313
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: arv-mount write 1 0 32
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: collection notify write <arvados.collection.Collection object at 0x7fb99c6a4b70> testfile (<arvados.arvfile.ArvadosFile object at 0x7fb99c82b048>, <arvados.arvfile.ArvadosFile object at 0x7fb99c82b048>)
unique: 13, success, outsize: 24
unique: 14, opcode: FLUSH (25), nodeid: 3, insize: 64, pid: 1313
2021-08-06 14:56:21 arvados.arvados_fuse[1224] DEBUG: collection notify mod <arvados.collection.Collection object at 0x7fb99c6a4b70> testfile (<arvados.arvfile.ArvadosFile object at 0x7fb99c82b048>, <arvados.arvfile.ArvadosFile object at 0x7fb99c82b048>)
2021-08-06 14:56:21 arvados.keep[1224] DEBUG: {'pirca-bi6l4-1cd520a55b71d5a7': {'href': '/keep_services/pirca-bi6l4-1cd520a55b71d5a7', 'kind': 'arvados#keepService', 'etag': '2k0rcryua3dxrzkrar3m1pvyc', 'uuid': 'pirca-bi6l4-1cd520a55b71d5a7', 'owner_uuid': 'pirca-tpzed-000000000000000', 'created_at': '2021-08-02T14:54:54.574032000Z', 'modified_by_client_uuid': None, 'modified_by_user_uuid': 'pirca-tpzed-000000000000000', 'modified_at': '2021-08-02T14:54:54.574032000Z', 'service_host': 'keep0.pirca.arvadosapi.com', 'service_port': 25107, 'service_ssl_flag': False, 'service_type': 'disk', 'read_only': False, '_service_root': 'http://keep0.pirca.arvadosapi.com:25107/'}, 'pirca-bi6l4-629198f41fae2d7c': {'href': '/keep_services/pirca-bi6l4-629198f41fae2d7c', 'kind': 'arvados#keepService', 'etag': '97c5ja2or0op55az5cx3dxaui', 'uuid': 'pirca-bi6l4-629198f41fae2d7c', 'owner_uuid': 'pirca-tpzed-000000000000000', 'created_at': '2021-08-02T14:54:54.574032000Z', 'modified_by_client_uuid': None, 'modified_by_user_uuid': 'pirca-tpzed-000000000000000', 'modified_at': '2021-08-02T14:54:54.574032000Z', 'service_host': 'keep1.pirca.arvadosapi.com', 'service_port': 25107, 'service_ssl_flag': False, 'service_type': 'disk', 'read_only': False, '_service_root': 'http://keep1.pirca.arvadosapi.com:25107/'}}
2021-08-06 14:56:21 arvados.keep[1224] DEBUG: 0837c95a7eebd0844371cda55d082228+32: ['http://keep1.pirca.arvadosapi.com:25107/', 'http://keep0.pirca.arvadosapi.com:25107/']
2021-08-06 14:56:21 arvados.keep[1224] DEBUG: Pool max threads is 2
2021-08-06 14:56:21 arvados.keep[1224] DEBUG: Request: PUT http://keep1.pirca.arvadosapi.com:25107/0837c95a7eebd0844371cda55d082228
2021-08-06 14:56:21 arvados.keep[1224] DEBUG: Request: PUT http://keep0.pirca.arvadosapi.com:25107/0837c95a7eebd0844371cda55d082228
2021-08-06 14:56:21 arvados.keep[1224] INFO: PUT 200: 32 bytes in 147.55630493164062 msec (0.000 MiB/sec)
2021-08-06 14:56:21 arvados.keep[1224] DEBUG: KeepWriterThread <KeepWriterThread(Thread-37, started daemon 140433837463296)> succeeded 0837c95a7eebd0844371cda55d082228+32 http://keep0.pirca.arvadosapi.com:25107/
2021-08-06 14:56:21 arvados.keep[1224] INFO: PUT 200: 32 bytes in 170.5644130706787 msec (0.000 MiB/sec)
2021-08-06 14:56:21 arvados.keep[1224] DEBUG: KeepWriterThread <KeepWriterThread(Thread-36, started daemon 140433845856000)> succeeded 0837c95a7eebd0844371cda55d082228+32 http://keep1.pirca.arvadosapi.com:25107/
</pre>
The above backtrace was caused by (in a separate shell):
<pre>
ward@shell:~$ date > keep/testfile
</pre>
which just hangs.
On latest main with collection versioning disabled, the problem is identical (tested on tordo).
When the `--disable-event-listening` flag is added to `arv-mount`, the deadlock does not happen.
On latest main with collection collction versioning enabled, the behavior is better (no hang) but still suboptimal, but that's because of another bug (see https://dev.arvados.org/issues/17983#note-5):
<pre>
ward@shell:~$ arv-mount --foreground --debug --read-write --collection ce8i5-4zz18-k74yj38bjtguqg4 keep
2021-08-06 15:19:53 arvados.arv-mount[1884] DEBUG: arv-mount debugging enabled (e.g. ce8i5),
2021-08-06 15:19:53 arvados.arv-mount[1884] INFO: /usr/bin/arv-mount 2.3.0.dev20210726143205 started
2021-08-06 15:19:53 arvados.arv-mount[1884] INFO: enable write is True
2021-08-06 15:19:53 arvados.arvados_fuse[1884] DEBUG: InodeCache touched inode 1 (size 0) (uuid ce8i5-4zz18-k74yj38bjtguqg4) total now 0 (1 entries)
FUSE library version: 2.9.7
unique: 2, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0
INIT: 7.31
flags=0x03fffffb
max_readahead=0x00020000
INIT: 7.19
flags=0x00000021
max_readahead=0x00020000
max_write=0x00020000
max_background=0
congestion_threshold=0
unique: 2, success, outsize: 40
unique: 4, opcode: LOOKUP (1), nodeid: 1, insize: 43, pid: 1925
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: InodeCache touched inode 1 (size 0) (uuid ce8i5-4zz18-k74yj38bjtguqg4) total now 0 (1 entries)
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: Updating collection ce8i5-4zz18-k74yj38bjtguqg4 inode 1 to record version None
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: <arvados_fuse.fusedir.CollectionDirectory object at 0x7f9df1d97b88> manifest_size 102
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: InodeCache touched inode 1 (size 13056) (uuid ce8i5-4zz18-k74yj38bjtguqg4) total now 13056 (1 entries)
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: arv-mount lookup: parent_inode 1 name 'xy' not found
unique: 4, error: -2 (No such file or directory), outsize: 16
unique: 6, opcode: CREATE (35), nodeid: 1, insize: 59, pid: 1925
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: arv-mount create: parent_inode 1 'xy' 100664
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: collection notify add <arvados.collection.Collection object at 0x7f9df1e44588> xy <arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: collection notify mod <arvados.collection.Collection object at 0x7f9df1e44588> xy (<arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>, <arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>)
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: InodeCache touched inode 1 (size 13056) (uuid ce8i5-4zz18-k74yj38bjtguqg4) total now 13056 (1 entries)
unique: 6, success, outsize: 160
unique: 8, opcode: FLUSH (25), nodeid: 3, insize: 64, pid: 1925
2021-08-06 15:19:59 arvados.arvados_fuse[1884] ERROR: Unhandled exception during FUSE operation
Traceback (most recent call last):
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 327, in catch_exceptions_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 835, in flush
self._filehandles[fh].flush()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 126, in flush
return self.obj.flush()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/fusefile.py", line 80, in flush
self.arvfile.parent.root_collection().save()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/arvfile.py", line 469, in must_be_writable_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/retry.py", line 177, in num_retries_setter
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/collection.py", line 1621, in save
).execute(num_retries=num_retries))
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
return wrapped(*args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/googleapiclient/http.py", line 840, in execute
raise HttpError(resp, content, uri=self.uri)
arvados.errors.ApiError: <HttpError 422 when requesting https://ce8i5.arvadosapi.com/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4?alt=json returned "//railsapi.internal/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4: 422 Unprocessable Entity: #<NoMethodError: undefined method `each_line' for nil:NilClass> (req-puytdn1bmo02euf8fjwm)">
unique: 8, error: -5 (Input/output error), outsize: 16
unique: 10, opcode: GETXATTR (22), nodeid: 3, insize: 68, pid: 1925
unique: 10, error: -38 (Function not implemented), outsize: 16
unique: 12, opcode: WRITE (16), nodeid: 3, insize: 109, pid: 1925
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: arv-mount write 0 0 29
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: collection notify write <arvados.collection.Collection object at 0x7f9df1e44588> xy (<arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>, <arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>)
unique: 12, success, outsize: 24
unique: 14, opcode: FLUSH (25), nodeid: 3, insize: 64, pid: 1925
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: collection notify mod <arvados.collection.Collection object at 0x7f9df1e44588> xy (<arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>, <arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>)
NOTIFY: code=2 length=40
2021-08-06 15:19:59 arvados.keep[1884] DEBUG: {'ce8i5-bi6l4-e590e84c83da7331': {'href': '/keep_services/ce8i5-bi6l4-e590e84c83da7331', 'kind': 'arvados#keepService', 'etag': '4v201wqdbg3e2tkfepptokiqs', 'uuid': 'ce8i5-bi6l4-e590e84c83da7331', 'owner_uuid': 'ce8i5-tpzed-000000000000000', 'created_at': '2021-08-04T16:51:32.445461000Z', 'modified_by_client_uuid': None, 'modified_by_user_uuid': 'ce8i5-tpzed-000000000000000', 'modified_at': '2021-08-04T16:51:32.445461000Z', 'service_host': 'keep0.ce8i5.arvadosapi.com', 'service_port': 25107, 'service_ssl_flag': False, 'service_type': 'disk', 'read_only': False, '_service_root': 'http://keep0.ce8i5.arvadosapi.com:25107/'}}
2021-08-06 15:19:59 arvados.keep[1884] DEBUG: 6553036b26773f12f96a68142e010f6a+29: ['http://keep0.ce8i5.arvadosapi.com:25107/']
2021-08-06 15:19:59 arvados.keep[1884] DEBUG: Pool max threads is 2
2021-08-06 15:19:59 arvados.keep[1884] DEBUG: Request: PUT http://keep0.ce8i5.arvadosapi.com:25107/6553036b26773f12f96a68142e010f6a
2021-08-06 15:19:59 arvados.keep[1884] INFO: PUT 200: 29 bytes in 619.6091175079346 msec (0.000 MiB/sec)
2021-08-06 15:19:59 arvados.keep[1884] DEBUG: KeepWriterThread <KeepWriterThread(Thread-36, started daemon 140315499423488)> succeeded 6553036b26773f12f96a68142e010f6a+29 http://keep0.ce8i5.arvadosapi.com:25107/
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: collection notify mod <arvados.collection.Collection object at 0x7f9df1e44588> xy (<arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>, <arvados.arvfile.ArvadosFile object at 0x7f9df1d684c0>)
NOTIFY: code=2 length=40
2021-08-06 15:19:59 arvados.arvados_fuse[1884] ERROR: Unhandled exception during FUSE operation
Traceback (most recent call last):
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 327, in catch_exceptions_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 835, in flush
self._filehandles[fh].flush()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 126, in flush
return self.obj.flush()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/fusefile.py", line 80, in flush
self.arvfile.parent.root_collection().save()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/arvfile.py", line 469, in must_be_writable_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/retry.py", line 177, in num_retries_setter
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/collection.py", line 1621, in save
).execute(num_retries=num_retries))
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
return wrapped(*args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/googleapiclient/http.py", line 840, in execute
raise HttpError(resp, content, uri=self.uri)
arvados.errors.ApiError: <HttpError 422 when requesting https://ce8i5.arvadosapi.com/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4?alt=json returned "//railsapi.internal/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4: 422 Unprocessable Entity: #<NoMethodError: undefined method `each_line' for nil:NilClass> (req-9r96avrlw2t948a6f7zq)">
unique: 14, error: -5 (Input/output error), outsize: 16
unique: 16, opcode: RELEASE (18), nodeid: 3, insize: 64, pid: 0
2021-08-06 15:19:59 arvados.arvados_fuse[1884] DEBUG: arv-mount release fh 0
2021-08-06 15:20:00 arvados.arvados_fuse[1884] ERROR: Unhandled exception during FUSE operation
Traceback (most recent call last):
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 327, in catch_exceptions_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 687, in release
self._filehandles[fh].flush()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/__init__.py", line 126, in flush
return self.obj.flush()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados_fuse/fusefile.py", line 80, in flush
self.arvfile.parent.root_collection().save()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/arvfile.py", line 469, in must_be_writable_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/arvfile.py", line 270, in synchronized_wrapper
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/retry.py", line 177, in num_retries_setter
return orig_func(self, *args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/arvados/collection.py", line 1621, in save
).execute(num_retries=num_retries))
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
return wrapped(*args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.6/site-packages/googleapiclient/http.py", line 840, in execute
raise HttpError(resp, content, uri=self.uri)
arvados.errors.ApiError: <HttpError 422 when requesting https://ce8i5.arvadosapi.com/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4?alt=json returned "//railsapi.internal/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4: 422 Unprocessable Entity: #<NoMethodError: undefined method `each_line' for nil:NilClass> (req-055kh17g0sm2d067zexx)">
unique: 16, error: -5 (Input/output error), outsize: 16
</pre>
The process that tries to write fails instead of hanging, which is better:
<pre>
ward@shell:~$ date > keep/xy
date: write error: Input/output error
</pre>
Since the deadlock keep mount didn't hang, you can now proceed:
<pre>
ward@shell:~$ cat keep/
file1.txt xy
ward@shell:~$ cat keep/xy
Fri Aug 6 15:19:59 UTC 2021
cat: keep/xy: Input/output error
</pre>
But we're in a bad state; the keep mount has cached the addition of the 'xy' file with the content as the output of the date command, which is partially masked due to bug https://dev.arvados.org/issues/18005. expected, but when verifying the contents of the collection on workbench, that file is not present.