macFUSE + LoopbackFS copying files through Finder not working

[marius-enlock]

Hello,

OS: Sonoma 14.4.1

macFUSE version: 4.7.1 and 4.7.2

The issue is as follows:

I have run the example in examples/loopback/main.go
go run main.go -debug t1 t2

From the terminal cp ~/Desktop/file t1/file succeeds and works as expected

Everytime I open Finder and drag and drop files from outside the filesystem in the filesystem:

I get: The operation can’t be completed because an unexpected error occurred (error code -50).

The file gets created, but it is completely empty.

Here are the logs from the example program ran with -debug flag (test.txt - i think a couple of bytes in size; and Screenshot 2024-05-16 at 04.59.21.png - a few MB in size; are the files added using finder):
output.txt

How I encountered this issue: I was using finder on my custom filesystem, the exact same example as above results in this log message from go-fuse after which the filesystem is no longer usable (however there is no crash in my program):
Finder message:

The Finder can’t complete the operation because some data in “Screenshot 2024-04-25 at 08.33.09” can’t be read or written.
(Error code -36)

The last logs outputed by my filesystem: (i think the important part is: Failed to read from fuse conn: 5=input/output error)

Line: t=2024-05-16T08:21:23+0300 lvl=dbug msg="Lookup called" service=drive method=lookup node-id=1 name=._.metadata_never_index enc-dir-path=/Users/mfc/work/code/enlockd/playground/enc_to_mount path=/Users/mfc/work/code/enlockd/playground/test_mount
Line: 2024/05/16 08:21:23 tx 5:     OK, {tA=0s {M0100700 SZ=4096 L=1 501:20 B16*16777216 i0:5 A 1715830808.994277 M 1715830808.990933 C 1715830808.990933}}
Line: 2024/05/16 08:21:23 tx 6:     2=no such file or directory, {n0 g0 tE=0s tA=0s {M00 SZ=0 L=0 0:0 B0*0 i0:0 A 0.000000 M 0.000000 C 0.000000}}
Line: 2024/05/16 08:21:23 rx 3: OPEN n5 {O_RDONLY} 
Line: t=2024-05-16T08:21:23+0300 lvl=dbug msg="Open called" service=drive method=file-open flags=0 counter=0 node-id=5 cipher-path="/Users/mfc/work/code/enlockd/playground/enc_to_mount/Cz-IswCz0Fq0AkMD4WT2XzPvAeaM78wdAYOYmr53k9jaPT6aQGA=" meta-id="[119 19 166 170 146 216 64 50 137 101 234 163 233 62 24 242]" path=/Users/mfc/work/code/enlockd/playground/test_mount/._test.txt
Line: 2024/05/16 08:21:23 rx 7: ACCESS n1 {u=501 g=20 x} 
Line: 2024/05/16 08:21:23 tx 7:     OK
Line: 2024/05/16 08:21:23 rx 5: LOOKUP n1 ["Screenshot 2024-04-25 at 08.33.09.png"] 38b
Line: t=2024-05-16T08:21:23+0300 lvl=dbug msg="Lookup called" service=drive method=lookup node-id=1 name="Screenshot 2024-04-25 at 08.33.09.png" enc-dir-path=/Users/mfc/work/code/enlockd/playground/enc_to_mount path=/Users/mfc/work/code/enlockd/playground/test_mount
Line: 2024/05/16 08:21:23 tx 5:     OK, {n15 g0 tE=0s tA=0s {M0100700 SZ=0 L=1 501:20 B0*16777216 i0:15 A 1715836883.722600 M 1715836883.994815 C 1715836883.994815}}
Line: 2024/05/16 08:21:23 Failed to read from fuse conn: 5=input/output error
Line: 2024/05/16 08:21:23 rx 6: ACCESS n1 {u=501 g=20 x} 
Line: 2024/05/16 08:21:23 tx 6:     OK
Line: 2024/05/16 08:21:23 writer: Write/Writev failed, err: 9=bad file descriptor. opcode: ACCESS
Line: 2024/05/16 08:21:23 tx 3:     OK, {Fh 5 }
Line: 2024/05/16 08:21:23 writer: Write/Writev failed, err: 9=bad file descriptor. opcode: OPEN

I don't support XAttr, i just return syscall.ENOTSUP on all calls related to them.

Saving the files in my filesystem from applications such as Sublime text, Visual studio code, or pdf Viewer, works without issues. Also once the files are in the filesystem, I can use Finder to rename, drag them into subfolders, etc. without any problems. But pasting files with command + v fails with The operation can’t be completed because an unexpected error occurred (error code -8062). - which I can't seem to find what the error code means - and the same Failed to read from fuse conn: 5=input/output error"

[marius-enlock]

For my specific fuse filesystem, not breaking the go-fuse server loop but instead continuing on EIO, recovers and the filesystem is still usable. No hanging file, and no unmount. Just the file copy fails.

Interesting enough, is that in the go-fuse/fuse/server.go on readRequest method, handleEINTR func, just retrying the syscall.Read once in the case of an EIO succeeds and no longer breaks the loop.

On the loopback example there was never an EIO error on the fuse conn.

[hanwen]

the report is difficult to follow. Your log snippet shows a file that already exists, but you say creating (ie. copying) the file is the first operation to cause problems. Where is the log output for the failed creation?

In your log snippet, the line

Line: 2024/05/16 08:21:23 tx 5: OK, {n15 g0 tE=0s tA=0s {M0100700 SZ=0 L=1 501:20 B0*16777216 i0:15 A 1715836883.722600 M 1715836883.994815 C 1715836883.994815}}
Line: 2024/05/16 08:21:23 Failed to read from fuse conn: 5=input/output error

suggests that something in the response is wrong. The Darwin flavor of fuse.Attr has a Crtime_ field and Flags_ field that don´t make it into the debug output; perhaps that is the problem? Are you populating those fields? If so, with what data?

FUSE on OSX is generally not very reliable; I would not trust it to behave reliably after the first error happens.

[marius-enlock]

Thank you for the input!

I think there are two issues here:

The one in the title, that is reproducible with the go-fuse/examples/loopback/main.go reported in the first part of the report (with full logs attached here: https://github.com/hanwen/go-fuse/files/15329802/output.txt ).
I am still investigating to see if I can pinpoint strictly on macFUSE.

And a second issue that triggers on my custom filesystem under the same action taken in finder, that results in an EIO while reading from the macFUSE FD.

For this second part this is my Getattr - The Crtime_ and Flags_ don't get populated, I think they default to 0:

func (f *FileNode) Getattr(_ context.Context, _ fs.FileHandle, attr *fuse.AttrOut) syscall.Errno {
	logger := f.logger.New("method", "file-attr", "node-id", f.nodeID, "cipher-path", f.correspondingCiphertextPath) // log15.Logger
	if f.forgotten {
		return 0
	}

	fi := syscall.Stat_t{}
	err := syscall.Stat(f.correspondingCiphertextPath, &fi) // The underlying file saved to disk.
	if err != nil {
		logger.Error("Failed to stat cipher path", "error", err)
		return convertOsErrToSyscallErrno(err)
	}

	attr.FromStat(&fi)

	attr.Ino = f.nodeID

	attrSize := cipherFileSizeToAttributeSize(fi.Size)
	if f.fileAttrSizeWasUpdatedInMemory {
		attrSize = int64(f.attrSize)
	}

	attr.Owner = *fuse.CurrentOwner()
	attr.Blocks = uint64(fi.Blocks) // I think this might be wrong, as the disk block size is different than my logic block size.
	// Converting the blocks to the actual logic blocks doesn't seem to affect my issue. 
	attr.Blksize = FileBlockSize // This value is 16777216
	attr.Size = uint64(attrSize) 
	attr.Uid = fi.Uid
	attr.Gid = fi.Gid
	attr.Mode = (fuse.S_IFREG | 0o700)

	return 0
}

Full logs for the custom filesystem that result in EIO can be found here:
customFilesystemLogs.txt

After trying to populate Crtime_ and Flags_ with the same values as the syscall.Stat_t.Crtime/Flags, I can confirm it has no effect towards the EIO error while reading from the FD

I think both problems have to do with the ._DS_Store and ._Filename files created by Finder for every file.

[marius-enlock]

Using the following example from macFUSE https://github.com/macfuse/demo/tree/master/LoopbackFS-C/loopback

I cannot reproduce the issue encountered with the go-fuse loopback example.

[marius-enlock]

I have tested with the go-fuse memfs example, and it's the same problem when dragging and dropping files in finder (the files dont get created in the filesystem, or they get created and have 0 size, while Finder pop ups a message with an error code).

I have tested against a different FUSE library (jacobsa/fuse memfs example) and it is the exact same issue when dragging and dropping files in Finder from outside the filesystem inside filesystem. There is a Finder error code and the files have 0 bytes in size.

I suspect the issue with dragging and dropping files in Finder and macFUSE affects other library developers too

Edit: I have tested a third library and it seems it is not affected by this issue (winfps/cgofuse both memfs/passthrough examples) create the files on drag and drop, and have all the data

[hanwen]

I don´t have an OSX machine, so I can't fix any bugs by reproducing and investigating myself. I don't have appetite to comb through your entire 300kb logfile. Is there a way you can reproduce the problem to something that looks like a go-fuse unittest? If copy & paste in the finder does not work, you could try to use strace (or its equivalaent on OSX) to understand what the Finder actually does under the hood?

[marius-enlock]

Hello,

Thank you for all the input!

Thanks to osxfuse/osxfuse#1018 (comment) for pointing towards the xattr.

Implementing the interfaces for extended attributes and returning error code 0 makes Finder drag and drop work.

For my case I was returning syscall.ENOTSUP which also caused the error code while reading from the macFUSE FD.