search

macos-fuse-t / fuse-t

Other
889 stars 6 forks source link

Potentially opening read-only as read-write #15

Closed Jwink3101 closed 1 year ago

Jwink3101 commented 1 year ago

I will be the first to tell you that I am outside my depth here...

I was testing FUSE-T with rclone which is supposed to support it and found a bug where every time I tried to even just cat a mounted file, it would fail if the rclone mount didn't use caching. And fail no matter what for read-only.

I suspected this was a bug in rclone and created a post in their forum.

The lead developer of rclone, @ncw, suggested from the logs that FUSE-T may be incorrectly translating system calls back to rclone.

Again, I am outside my depth on pinpointing this to rclone or FUSE-T but I hope someone here could take a look, reproduce the problem, and fix it if it is on FUSE-T.

Thanks,

ncw commented 1 year ago

To add a bit more detail, user space opens a file with O_RDONLY however this arrives at rclone's fuse server with an O_RDWR flag after its been through the kernel and FUSE-T. This causes a problem for rclone as read/write files are treated very differently to read only files.

Exactly where the problem is I'm not sure, but I suspect FUSE-T since rclone works correctly with osxfuse.

Happy to help with technical stuff where I can, but I don't have a mac so we'll have to rely on @Jwink3101 to test stuff.

Jwink3101 commented 1 year ago

is it sshfs mount?

To be clear, this is not sshfs. This is using rclone's (very popular) FUSE mounting capability. This example is a toy example where I mount a local "remote" to demonstrate but I could just as easily mount S3, Dropbox, OneDrive, Google Drive, or over 40 others (plus wrapper ones around them such as encryption).

Could you add steps to reproduce?

I am happy to provide the steps.

First, just to set the stage, here,

$  system_profiler SPSoftwareDataType SPHardwareDataType
Software:

    System Software Overview:

      System Version: macOS 12.6.3 (21G419)
      Kernel Version: Darwin 21.6.0
      Boot Volume: Macintosh HD
      Boot Mode: Normal
      Computer Name: **REDACTED**
      User Name: **REDACTED**
      Secure Virtual Memory: Enabled
      System Integrity Protection: Enabled
      Time since boot: 1 day 16:22

Hardware:

    Hardware Overview:

      Model Name: MacBook Pro
      Model Identifier: MacBookPro16,1
      Processor Name: 8-Core Intel Core i9
      Processor Speed: 2.4 GHz
      Number of Processors: 1
      Total Number of Cores: 8
      L2 Cache (per Core): 256 KB
      L3 Cache: 16 MB
      Hyper-Threading Technology: Enabled
      Memory: 32 GB
      System Firmware Version: 1916.80.2.0.0 (iBridge: 20.16.3045.0.0,0)
      OS Loader Version: 540.120.3~22
      Serial Number (system): **REDACTED**
      Hardware UUID: **REDACTED**
      Provisioning UDID: **REDACTED**
      Activation Lock Status: Disabled

And

$ rclone version
rclone v1.61.1
- os/version: darwin 12.6.3 (64 bit)
- os/kernel: 21.6.0 (x86_64)
- os/type: darwin
- os/arch: amd64
- go/version: go1.19.4
- go/linking: dynamic
- go/tags: cmount

Create a test dir

$ mkdir fuse-test
$ cd fuse-test/
$ mkdir src
$ echo "test" > src/file1.txt
$ mkdir mnt

Then, as done in the forum post, I will tell rclone to mount the src as an uncached read-write. The lack of cache means that (docs):

  • Files can't be opened for both read AND write
  • Files opened for write can't be seeked
  • Existing files opened for write must have O_TRUNC set
  • Files open for read with O_TRUNC will be opened write only
  • Files open for write only will behave as if O_TRUNC was supplied
  • Open modes O_APPEND, O_TRUNC are ignored
  • If an upload fails it can't be retried

On rclone, I do this in one terminal (or GNU Screen or TMUX or tell rclone to daemonize):

$ rclone mount src/ mnt/ -vv --log-file reg_mount.log

Then in another:

$ cat mnt/file1.txt
cat: mnt/file1.txt: Input/output error

I link to the log in the forum post.

As @ncw points out in the forum, rclone gets the command to open flags=O_RDWR when cat should only read. (And this works with osxfuse properly).

This also causes a failure when you tell rclone --read-only as it doesn't support any writing.

I hope this helps. Let me know if you need more detail. Also, this is documented in that forum post with other rclone modes

macos-fuse-t commented 1 year ago

By default fuse-t opens a file with maximum available permissions. This is because of NFSv4 nature which opens a single file exactly once even when there are multiple clients requesting that file. Since with fuse we don't expect to have multiple clients I'll try to revise the logic and don't upgrade open permissions. This would require some testing to see if nothing else is going to be broken. In any case I'll add an option to fuse to force permissions either way. I'll update this ticker later.

Jwink3101 commented 1 year ago

Since with fuse we don't expect to have multiple clients I'll try to revise the logic and don't upgrade open permissions

Again, @ncw could comment better but it is also not an uncommon use case for users to create an rclone FUSE mount on which many other users read. However, the permissions should be the same I would think and I don't know how it handles concurrent users on the same file with different modes.

macos-fuse-t commented 1 year ago

Please try this pre-release. https://github.com/macos-fuse-t/fuse-t/releases/download/1.0.12a/fuse-t-macos-installer-1.0.12a.pkg

If it's working with rclone and all tests are passed I will publish it.

Jwink3101 commented 1 year ago

The good news is that it works for reading from non-cached remotes and with rclone --read-only.

However, writing to files without cache is not working now. At least not compared to how it work on my Linux machine I can compare against. It is letting rclone now open files in a disallowed way and then not sending the changes back.

For example, on Linux:

$ echo "hi">> mnt/file1.txt
-bash: echo: write error: Illegal seek

while on mac with FUSE-T, the same command throws no error but also doesn't append to the file. I would expect an error (rather than silently failing) but it failing is the expected outcome. I don't know if this is rclone or FUSE-T

Here is the rclone log for @ncw:

2023/01/26 15:41:23 DEBUG : /: Statfs:
2023/01/26 15:41:23 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:23 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:23 DEBUG : /: >Getattr: errc=0
2023/01/26 15:41:23 DEBUG : /: Statfs:
2023/01/26 15:41:23 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:23 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:23 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:23 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:23 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:23 DEBUG : /file1.txt: OpenEx: flags=0x2
2023/01/26 15:41:23 DEBUG : /file1.txt: OpenFile: flags=O_RDWR, perm=-rwxrwxrwx
2023/01/26 15:41:23 DEBUG : file1.txt: Open: flags=O_RDWR
2023/01/26 15:41:23 DEBUG : file1.txt: >Open: fd=file1.txt (w), err=<nil>
2023/01/26 15:41:23 DEBUG : /file1.txt: >OpenFile: fd=file1.txt (w), err=<nil>
2023/01/26 15:41:23 DEBUG : /file1.txt: >OpenEx: errc=0, fh=0x0
2023/01/26 15:41:23 DEBUG : /: Statfs:
2023/01/26 15:41:23 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:23 DEBUG : /file1.txt: Read: ofst=0, fh=0x0
2023/01/26 15:41:23 ERROR : file1.txt: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal
2023/01/26 15:41:23 DEBUG : /file1.txt: >Read: n=-1
2023/01/26 15:41:23 DEBUG : /file1.txt: Write: ofst=5, fh=0x0
2023/01/26 15:41:23 DEBUG : file1.txt: waiting for in-sequence write to 5 for 1s
2023/01/26 15:41:23 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:23 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:23 DEBUG : /: Statfs:
2023/01/26 15:41:23 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:24 DEBUG : file1.txt: aborting in-sequence write wait, off=5
2023/01/26 15:41:24 DEBUG : file1.txt: failed to wait for in-sequence write to 5
2023/01/26 15:41:24 ERROR : file1.txt: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes
2023/01/26 15:41:24 DEBUG : /file1.txt: >Write: n=-29
2023/01/26 15:41:24 DEBUG : /file1.txt: Flush: fh=0x0
2023/01/26 15:41:24 DEBUG : file1.txt: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
2023/01/26 15:41:24 ERROR : file1.txt: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes
2023/01/26 15:41:24 DEBUG : /file1.txt: >Flush: errc=-1
2023/01/26 15:41:24 DEBUG : /file1.txt: Release: fh=0x0
2023/01/26 15:41:24 DEBUG : file1.txt: WriteFileHandle.Release closing
2023/01/26 15:41:24 DEBUG : /file1.txt: >Release: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:24 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:24 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:24 DEBUG : /: Statfs:
2023/01/26 15:41:24 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:24 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: OpenEx: flags=0x0
2023/01/26 15:41:24 DEBUG : /file1.txt: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2023/01/26 15:41:24 DEBUG : file1.txt: Open: flags=O_RDONLY
2023/01/26 15:41:24 DEBUG : file1.txt: >Open: fd=file1.txt (r), err=<nil>
2023/01/26 15:41:24 DEBUG : /file1.txt: >OpenFile: fd=file1.txt (r), err=<nil>
2023/01/26 15:41:24 DEBUG : /file1.txt: >OpenEx: errc=0, fh=0x0
2023/01/26 15:41:24 DEBUG : /: Statfs:
2023/01/26 15:41:24 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Read: ofst=0, fh=0x0
2023/01/26 15:41:24 DEBUG : file1.txt: ChunkedReader.openRange at 0 length 134217728
2023/01/26 15:41:24 DEBUG : file1.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2023/01/26 15:41:24 DEBUG : /file1.txt: >Read: n=5
2023/01/26 15:41:24 DEBUG : /file1.txt: Flush: fh=0x0
2023/01/26 15:41:24 DEBUG : /file1.txt: >Flush: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Release: fh=0x0
2023/01/26 15:41:24 DEBUG : file1.txt: ReadFileHandle.Release closing
2023/01/26 15:41:24 DEBUG : /file1.txt: >Release: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:24 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:24 DEBUG : /: Statfs:
2023/01/26 15:41:24 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:24 DEBUG : /: Statfs:
2023/01/26 15:41:24 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:24 DEBUG : /file1.txt: >Getattr: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: OpenEx: flags=0x0
2023/01/26 15:41:24 DEBUG : /file1.txt: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2023/01/26 15:41:24 DEBUG : file1.txt: Open: flags=O_RDONLY
2023/01/26 15:41:24 DEBUG : file1.txt: >Open: fd=file1.txt (r), err=<nil>
2023/01/26 15:41:24 DEBUG : /file1.txt: >OpenFile: fd=file1.txt (r), err=<nil>
2023/01/26 15:41:24 DEBUG : /file1.txt: >OpenEx: errc=0, fh=0x0
2023/01/26 15:41:24 DEBUG : /: Statfs:
2023/01/26 15:41:24 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:244199454 Bfree:65992272 Bavail:65992272 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Flush: fh=0x0
2023/01/26 15:41:24 DEBUG : /file1.txt: >Flush: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Release: fh=0x0
2023/01/26 15:41:24 DEBUG : /file1.txt: >Release: errc=0
2023/01/26 15:41:24 DEBUG : /file1.txt: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/01/26 15:41:24 DEBUG : /file1.txt: >Getattr: errc=0

Using rclone's full cache mode does seem to be working

macos-fuse-t commented 1 year ago

According to the logs the append ">>" command opens the file as read and write instead of write only on Linux. This could be due to implementation differences between the shell code on macos and Linux. According to the previous post O_RDWR mode should not succeed and that's the case according to the logs: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2023/01/26 15:41:23 DEBUG : /file1.txt: >Read: n=-1 Perhaps you don't see the logs on the console due to buffering, because there are error logs in the log file? Anyone else wants to comment on this?

ncw commented 1 year ago

while on mac with FUSE-T, the same command throws no error but also doesn't append to the file. I would expect an error (rather than silently failing) but it failing is the expected outcome. I don't know if this is rclone or FUSE-T

From the log

2023/01/26 15:41:24 ERROR : file1.txt: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2023/01/26 15:41:24 DEBUG : /file1.txt: >Write: n=-29

Rclone returns the error code back to userspace as the result of the Write Call. I assume error 29 is ESPIPE (invalid seek).

If that didn't get reported to the user then it either got lost in fuse-t or the kernel or the shell didn't report it to you.

I suggest you use /bin/echo (or wherever it is on macOS!) rather than the shell builtin then you can dtruss it.

2023/01/26 15:41:23 DEBUG : /file1.txt: OpenFile: flags=O_RDWR, perm=-rwxrwxrwx

When I try this experiment on Linux I see the flags O_WRONLY|O_APPEND|O_CREATE and when I repeat the experiment when there is an existing file I see the flags O_WRONLY|O_APPEND in rclone.

I suspect @Jwink3101 was trying this on an existing file, as if I try it on Linux I get

$ echo hello >> /mnt/tmp/hello9.txt ; echo $?
0
$ echo hello >> /mnt/tmp/hello9.txt ; echo $?
bash: echo: write error: Illegal seek
1

And the underlying rclone error is

2023/01/27 12:01:09 ERROR : hello9.txt: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes

So I think that is expected, except for the O_WRONLY getting transformed into O_RDWR. As it happens this doesn't matter in rclone provided the user doesn't actually read from the file handle.

macos-fuse-t commented 1 year ago

It seems that RDWR flags come from the client side, so I'm closing this as done