Project

General

Profile

Actions

Bug #18316

closed

arv-mount tries to save collection on file close even in read-only mode

Added by Peter Amstutz about 3 years ago. Updated about 3 years ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Category:
FUSE
Target version:
Story points:
-
Release relationship:
Auto

Description

De-identified customer backtrace:

2021-11-01 15:22:50 arvados.arvados_fuse127303 ERROR: Error during finalize of inode 13
Traceback (most recent call last):
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.8/site-packages/arvados_fuse/__init__.py", line 314, in clear
v.finalize()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.8/site-packages/arvados_fuse/fusedir.py", line 581, in finalize
self.collection.save()
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.8/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.8/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.8/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.8/site-packages/arvados/collection.py", line 1626, in save
self._remember_api_response(self._my_api().collections().update(
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.8/site-packages/googleapiclient/_helpers.py", line 134, in positional_wrapper
return wrapped(*args, **kwargs)
File "/usr/share/python3/dist/python3-arvados-fuse/lib/python3.8/site-packages/googleapiclient/http.py", line 915, in execute
raise HttpError(resp, content, uri=self.uri)
arvados.errors.ApiError: <HttpError 403 when requesting https://.....com/arvados/v1/collections/....-4zz18-.........?alt=json returned "request failed: http://localhost:8000/arvados/v1/collections/....-4zz18-...........: 403 Forbidden: Uuid ....-4zz18-.......... is not writable by ....-tpzed-......... (req-ixqstv61tuf3vnx21lwf)">

The token doesn't have write access, but it is trying to save the collection anyway. It shouldn't be trying to save the collection when it closes the file.

There seem to be 2 main bugs here:

  • Not tracking change operations, tries to saves the collection record on close every time even though nothing changed, which is unnecessary and incorrect
  • Arv-mount was started in read-only mode but flush() still tries to save the collection.

Subtasks 1 (0 open1 closed)

Task #18358: Review 18316-fuse-read-onlyResolvedPeter Amstutz11/12/2021Actions
Actions #1

Updated by Peter Amstutz about 3 years ago

  • Description updated (diff)
Actions #2

Updated by Peter Amstutz about 3 years ago

  • Assigned To set to Peter Amstutz
Actions #3

Updated by Peter Amstutz about 3 years ago

18316-fuse-read-only @ d3ffe252f9d7cbbad9a7bf61ccf5d26129720f43

developer-run-tests: #2795

This propagates the enable_write flag to the FUSE directory/file python objects to ensure that when in read-only mode, it won't try to save the collection.

Does not fix the related bug that in read-write mode, it still doesn't track if the user has write permission on a collection or not, or if you tried to change the collection or not. So you'll still get error-on-close if you access a file in a collection that was loaded by uuid (via MagicDirectory or ProjectDirectory). This requires a bit more thought on how best to implement properly.

Actions #4

Updated by Peter Amstutz about 3 years ago

  • Status changed from New to In Progress
Actions #5

Updated by Lucas Di Pentima about 3 years ago

Although the updates and test look good, I'm wondering why the original report said that this didn't happen on versions previous to 2.3.0

I've tried to do a manual test against a local arvbox instance, and I'm getting I/O Errors when doing a simple cat <file>. Am I doing something wrong here?

(venv-arvados) lucas@buster:~$ arv-mount --version
/home/lucas/venv-arvados/bin/arv-mount 2.4.0.dev20211112222152
(venv-arvados) lucas@buster:~$ arv-mount ./tmp
(venv-arvados) lucas@buster:~$ cd ./tmp/by_id/x240b-4zz18-e1s0llgw4y50icd
(venv-arvados) lucas@buster:~/tmp/by_id/x240b-4zz18-e1s0llgw4y50icd$ cat test.js
cat: test.js: Input/output error
Actions #6

Updated by Lucas Di Pentima about 3 years ago

Same thing with --debug:

(venv-arvados) lucas@buster:~$ arv-mount --debug ./tmp
2021-11-15 13:27:53 arvados.arv-mount[24252] DEBUG: arv-mount debugging enabled
2021-11-15 13:27:53 arvados.arv-mount[24252] INFO: /home/lucas/venv-arvados/bin/arv-mount 2.4.0.dev20211112222152 started
2021-11-15 13:27:53 arvados.arv-mount[24252] INFO: enable write is False
2021-11-15 13:27:54 arvados.arvados_fuse[24252] DEBUG: InodeCache touched inode 5 (size 0) (uuid x240b-tpzed-k11iuqilds4s827) total now 0 (1 entries)
FUSE library version: 2.9.9
(venv-arvados) lucas@buster:~$ cd ./tmp/by_id/x240b-4zz18-e1s0llgw4y50icd
(venv-arvados) lucas@buster:~/tmp/by_id/x240b-4zz18-e1s0llgw4y50icd$ cat test.js
cat: test.js: Input/output error
Actions #7

Updated by Lucas Di Pentima about 3 years ago

Let me re-do my manual test with arvbox in dev mode instead of publicdev because part of the log says:

2021-11-15 13:40:10 arvados.keep[14412] DEBUG: Request fail: GET http://localhost:25107/136b64e537cfd8920f03646ab852fb61+46+A1975c2037e57581f288f8820b26e005b86e5ac92@61a5022b => <class 'arvados.errors.HttpError'>: (0, "(7, 'Failed to connect to localhost port 25107: Connection refused')")
2021-11-15 13:40:10 arvados.arvados_fuse[14412] ERROR: Unhandled exception during FUSE operation
Traceback (most recent call last):
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados_fuse-2.4.0.dev20211112222152-py3.7.egg/arvados_fuse/__init__.py", line 327, in catch_exceptions_wrapper
    return orig_func(self, *args, **kwargs)
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados_fuse-2.4.0.dev20211112222152-py3.7.egg/arvados_fuse/__init__.py", line 655, in read
    r = handle.obj.readfrom(off, size, self.num_retries)
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados_fuse-2.4.0.dev20211112222152-py3.7.egg/arvados_fuse/fusefile.py", line 66, in readfrom
    return self.arvfile.readfrom(off, size, num_retries, exact=True)
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados/arvfile.py", line 1106, in readfrom
    block = self.parent._my_block_manager().get_block_contents(lr.locator, num_retries=num_retries, cache_only=(bool(data) and not exact))
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados/arvfile.py", line 784, in get_block_contents
    return self._keep.get(locator, num_retries=num_retries)
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados/retry.py", line 177, in num_retries_setter
    return orig_func(self, *args, **kwargs)
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados/keep.py", line 1056, in get
    return self._get_or_head(loc_s, method="GET", **kwargs)
  File "/home/lucas/venv-arvados/lib/python3.7/site-packages/arvados/keep.py", line 1182, in _get_or_head
    "[{}] failed to read {} after {}".format(request_id, loc_s, loop.attempts_str()), service_errors, label="service")
arvados.errors.KeepReadError: [req-qgowoe2t8nm779xdla27] failed to read 136b64e537cfd8920f03646ab852fb61+46+A1975c2037e57581f288f8820b26e005b86e5ac92@61a5022b after 5 attempts: service http://localhost:25108/ responded with 0 (7, 'Failed
to connect to localhost port 25108: Connection refused'); service http://localhost:25107/ responded with 0 (7, 'Failed to connect to localhost port 25107: Connection refused')

Maybe I'm having a keepproxy issue.

Actions #8

Updated by Lucas Di Pentima about 3 years ago

It worked on dev mode, LGTM.

Actions #9

Updated by Peter Amstutz about 3 years ago

  • Status changed from In Progress to Resolved
Actions #10

Updated by Peter Amstutz about 3 years ago

  • Release set to 45
Actions

Also available in: Atom PDF