OS X .Trashes items do not see Remove when emptying trash

[ryanstout]

Ok, so feel free to say this it outside of the scope of bazil/fuse, but I've got my file system working and I added -o local,... to mount_darwin.go to run the file system locally. On osx when I drag a file to the trash, it goes to a .Trashes folder on the file system. (I can even restore fine) The weird thing though is that when I empty the trash, I don't get any Remove or Rename's. Any idea what OSX does when you clear the trash on a local file system? The files just stay there and the trash bin shows full. I'm just wondering if anyone has any ideas on this? Thanks!

[tv42]

I have not dealt with how Finder deletes files yet. If you run with debug (set fuse.Debug to a function like https://github.com/bazillion/fuse/blob/2664175cb4560cb9d273a22ffb620cb7beeb702c/fs/fstestutil/debug.go#L41-43 ), you should see all incoming requests, even if you don't have a handler for them.

With that, when you empty a trash bin that has items in it, If nothing shows up, then the problem is in osxfuse. If something shows up, copy-paste the relevant log here and I'll help you figure out how to handle it.

[ryanstout]

Thanks, didn't think of the debug thing. Here's what I get. Looks like maybe its related to xattr's. As far as I can tell my xattr implementation is working, but maybe it isn't.

2014/09/09 16:32:06 FUSE: <- Access [ID=0x8 Node=0x1 Uid=0 Gid=0 Pid=36599] mask=0x1
2014/09/09 16:32:06 FUSE: -> ID=0x8
2014/09/09 16:32:06 FUSE: <- Statfs [ID=0x9 Node=0x1 Uid=501 Gid=20 Pid=268]

2014/09/09 16:32:06 FUSE: -> ID=0x9 Statfs {Blocks:34359738368 Bfree:17179869184 Bavail:17179869184 Files:536870912 Ffree:268435456 Bsize:4194304 Namelen:2048 Frsize:0}
2014/09/09 16:32:06 FUSE: <- Access [ID=0xa Node=0x1 Uid=501 Gid=20 Pid=268] mask=0x1
2014/09/09 16:32:06 FUSE: -> ID=0xa
2014/09/09 16:32:06 FUSE: <- Access [ID=0xb Node=0x2 Uid=501 Gid=20 Pid=268] mask=0x1
2014/09/09 16:32:06 FUSE: -> ID=0xb
2014/09/09 16:32:06 FUSE: <- Access [ID=0xc Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0xc
2014/09/09 16:32:06 FUSE: <- Access [ID=0xd Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0xd
2014/09/09 16:32:06 FUSE: <- Access [ID=0xe Node=0x2 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0xe
2014/09/09 16:32:06 FUSE: <- Access [ID=0xf Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0xf
2014/09/09 16:32:06 FUSE: <- Access [ID=0x10 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0x10
2014/09/09 16:32:06 FUSE: <- Access [ID=0x11 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x2
2014/09/09 16:32:06 FUSE: -> ID=0x11
2014/09/09 16:32:06 FUSE: <- Access [ID=0x12 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x4
2014/09/09 16:32:06 FUSE: -> ID=0x12
2014/09/09 16:32:06 FUSE: <- Access [ID=0x13 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x1
2014/09/09 16:32:06 FUSE: -> ID=0x13
2014/09/09 16:32:06 FUSE: <- Getxattr [ID=0x15 Node=0x3 Uid=501 Gid=20 Pid=268] "com.apple.FinderInfo" 32 @0
2014/09/09 16:32:06 FUSE: -> ID=0x15 error=operation not supported
2014/09/09 16:32:06 FUSE: <- Lookup [ID=0x16 Node=0x2 Uid=501 Gid=20 Pid=268] "._501"
2014/09/09 16:32:06 FUSE: -> ID=0x16 error=ENOENT
2014/09/09 16:32:06 FUSE: <- Access [ID=0x14 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0x14
2014/09/09 16:32:06 FUSE: <- Access [ID=0x19 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x4
2014/09/09 16:32:06 FUSE: -> ID=0x19
2014/09/09 16:32:06 FUSE: <- Getxattr [ID=0x18 Node=0x3 Uid=501 Gid=20 Pid=268] "com.apple.metadata:_kMDItemUserTags" 0 @0
2014/09/09 16:32:06 FUSE: -> ID=0x18 error=operation not supported
2014/09/09 16:32:06 FUSE: <- Lookup [ID=0x17 Node=0x2 Uid=501 Gid=20 Pid=268] "._501"
2014/09/09 16:32:06 FUSE: -> ID=0x17 error=ENOENT
2014/09/09 16:32:06 FUSE: <- Access [ID=0x0 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0x0
2014/09/09 16:32:06 FUSE: <- Access [ID=0x1a Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0x1a
2014/09/09 16:32:06 FUSE: <- Access [ID=0x2 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x2
2014/09/09 16:32:06 FUSE: -> ID=0x2
2014/09/09 16:32:06 FUSE: <- Access [ID=0x1b Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x4
2014/09/09 16:32:06 FUSE: -> ID=0x1b
2014/09/09 16:32:06 FUSE: <- Access [ID=0x3 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x1
2014/09/09 16:32:06 FUSE: -> ID=0x3
2014/09/09 16:32:06 FUSE: <- Getxattr [ID=0x1 Node=0x3 Uid=501 Gid=20 Pid=268] "com.apple.FinderInfo" 32 @0
2014/09/09 16:32:06 FUSE: -> ID=0x1 error=operation not supported
2014/09/09 16:32:06 FUSE: <- Lookup [ID=0x5 Node=0x2 Uid=501 Gid=20 Pid=268] "._501"
2014/09/09 16:32:06 FUSE: -> ID=0x5 error=ENOENT
2014/09/09 16:32:06 FUSE: <- Access [ID=0x4 Node=0x3 Uid=501 Gid=20 Pid=268] mask=0x4
2014/09/09 16:32:06 FUSE: -> ID=0x4
2014/09/09 16:32:06 FUSE: <- Open [ID=0x6 Node=0x3 Uid=501 Gid=20 Pid=268] dir=true fl=OpenReadOnly
2014/09/09 16:32:06 FUSE: -> ID=0x6 Open {Handle:1 Flags:0}
2014/09/09 16:32:06 FUSE: <- Statfs [ID=0x7 Node=0x1 Uid=501 Gid=20 Pid=268]

2014/09/09 16:32:06 FUSE: -> ID=0x7 Statfs {Blocks:34359738368 Bfree:17179869184 Bavail:17179869184 Files:536870912 Ffree:268435456 Bsize:4194304 Namelen:2048 Frsize:0}
2014/09/09 16:32:06 FUSE: <- Read [ID=0x8 Node=0x3 Uid=501 Gid=20 Pid=268] 0x1 1536 @0x0 dir=true
2014/09/09 16:32:06 FUSE: -> ID=0x8 Read 40
2014/09/09 16:32:06 FUSE: <- Access [ID=0x9 Node=0x5 Uid=501 Gid=20 Pid=268] mask=0x0
2014/09/09 16:32:06 FUSE: -> ID=0x9
2014/09/09 16:32:06 FUSE: <- Access [ID=0xa Node=0x5 Uid=501 Gid=20 Pid=268] mask=0x2
2014/09/09 16:32:06 FUSE: -> ID=0xa
2014/09/09 16:32:06 FUSE: <- Access [ID=0xb Node=0x5 Uid=501 Gid=20 Pid=268] mask=0x4
2014/09/09 16:32:06 FUSE: -> ID=0xb
2014/09/09 16:32:06 FUSE: <- Access [ID=0xc Node=0x5 Uid=501 Gid=20 Pid=268] mask=0x1
2014/09/09 16:32:06 FUSE: -> ID=0xc
2014/09/09 16:32:06 FUSE: <- Getxattr [ID=0xd Node=0x5 Uid=501 Gid=20 Pid=268] "com.apple.FinderInfo" 32 @0
2014/09/09 16:32:06 FUSE: -> ID=0xd error=attribute not found
2014/09/09 16:32:06 FUSE: <- Getxattr [ID=0xe Node=0x5 Uid=501 Gid=20 Pid=268] "com.apple.ResourceFork" 0 @0
2014/09/09 16:32:06 FUSE: -> ID=0xe error=attribute not found
2014/09/09 16:32:06 FUSE: <- Read [ID=0xf Node=0x3 Uid=501 Gid=20 Pid=268] 0x1 1536 @0x28 dir=true
2014/09/09 16:32:06 FUSE: -> ID=0xf Read 0
2014/09/09 16:32:06 FUSE: <- Release [ID=0x10 Node=0x3 Uid=501 Gid=20 Pid=268] 0x1 fl=OpenReadOnly rfl=0 owner=0x0
2014/09/09 16:32:06 FUSE: -> ID=0x10
2014/09/09 16:32:06 FUSE: <- Access [ID=0x11 Node=0x5 Uid=501 Gid=20 Pid=268] mask=0x4
2014/09/09 16:32:06 FUSE: -> ID=0x11
2014/09/09 16:32:06 FUSE: <- Getxattr [ID=0x12 Node=0x5 Uid=501 Gid=20 Pid=268] "com.apple.metadata:_kMDItemUserTags" 0 @0
2014/09/09 16:32:06 FUSE: -> ID=0x12 error=attribute not found
2014/09/09 16:32:06 FUSE: <- Statfs [ID=0x13 Node=0x1 Uid=501 Gid=20 Pid=268]

2014/09/09 16:32:06 FUSE: -> ID=0x13 Statfs {Blocks:34359738368 Bfree:17179869184 Bavail:17179869184 Files:536870912 Ffree:268435456 Bsize:4194304 Namelen:2048 Frsize:0}

[tv42]

Well your fs is definitely claiming ENOTSUP "operation not supported" on a Getxattr there a couple of times, for node ids 0x3 and 0x5. If you read earlier in the log, you'll see what Lookup, Mkdir, Create etc call gave the kernel those node ids.

My guess is that you implemented xattrs for some of your nodes, but not all of them. For example, on files but not on directories.

It also seems pretty intent on looking up a file called ._501, and the dot-underscore was one of those OS X oddities having to do with extended attributes.

[ryanstout]

@tv42 Thanks, I think that gives me something to go on. ._501 is what the file got renamed to when it was moved to the trash. I'll see if I can track it down.

[tv42]

My understanding is this: on "multi-user" volumes (not $HOME), OS X puts Finder trash into .Trashes/$UID/*. Your uid, based on the debug log, is 501.

When the file system does not support xattrs, Finder puts xattr data for file foo/bar into foo/._bar.
https://apple.stackexchange.com/questions/14980/why-are-dot-underscore-files-created-and-how-can-i-avoid-them

So, in this case, your fs does not support xattrs (on the right nodes?), so Finder tries to store the xattr data for .Trashes/501 as .Trashes/._501. I guess the lookup failures for ._501 are pretty much the semantic equivalent of doing an lsattr or getattr and getting no xattrs back as a result; Finder does that lookup just to see if there are fake-xattrs.

It is opening your node 0x3 as a directory and listing its contents. If 0x3 was the lookup result for e.g. .Trashes/501, then it would be iterating those results.. and is is getting one 40-byte chunk of direntries listed. Quick skimming of the code says that oughta be one direntry with a 16-byte filename.

[tv42]

Flagging as low priority as this really needs manual QA with a test filesystem that does not currently exist.

[tv42]

Perhaps osascript can help in automating that; it'll still need to run in a desktop session.

http://hints.macworld.com/article.php?story=20091003083125659

[ztalbot2000]

I have replicated this issue exactly. There are two errors. The last is because when the mount failed, the mount point was trying to be moved to .Trash, but root does not have a .Trash directory. The .Trash directory is created when you log in via the main login screen. Something never done by root.
The first error was the mount failure. If you use dd to image Raspbian to an SD card and then try to mount it right away the mount fails because the filesystem is not ext2/3/4 but squashfs. Hence trying to put the mount point in the .Trash.
This explains every aspect and if the problem is still open, it should be closed.

[tv42]

@ztalbot2000 I'm sorry I didn't understand what you're trying to say. How is FUSE relevant to RPi SD cards? It also doesn't seem to relate to Ryan's problem much. For example, you're talking about a mount point being moved to .Trash, Ryan was talking about files inside his FUSE filesystem being moved to .Trashes.

[ztalbot2000]

Here is my log. Look familiar?

udo /Volumes/crosstoolBase/brew/bin/fuse-ext2 -v /dev/disk3s2 ./linux -o debug
Password:
Mounting /dev/disk3s2 Read-Only.
Use 'force' or 'rw+' options to enable Read-Write mode
FUSE library version: 2.9.7
nullpath_ok: 0
nopath: 0
utime_omit_ok: 0
unique: 2, opcode: INIT (26), nodeid: 0, insize: 56, pid: 24022
INIT: 7.19
flags=0xf8000008
max_readahead=0x00100000
INIT: 7.19
flags=0x00000010
max_readahead=0x00100000
max_write=0x02000000
max_background=0
congestion_threshold=0
unique: 2, success, outsize: 40
unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 123
getattr /
unique: 2, success, outsize: 136
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 0
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 123
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 123
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 123
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: LOOKUP (1), nodeid: 1, insize: 51, pid: 60
LOOKUP /.fseventsd
getattr /.fseventsd
unique: 3, error: -2 (No such file or directory), outsize: 16
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 197
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 325
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 733
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 732
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 875
getattr /
unique: 2, success, outsize: 136
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 875
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 197
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 325
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 732
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 733
statfs /
unique: 3, success, outsize: 96
unique: 3, opcode: GETXATTR (22), nodeid: 1, insize: 77, pid: 876
getxattr / com.apple.FinderInfo 32 0
unique: 3, success, outsize: 48
unique: 2, opcode: GETXATTR (22), nodeid: 1, insize: 77, pid: 876
getxattr / com.apple.FinderInfo 32 0
unique: 2, success, outsize: 48
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 876
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: GETXATTR (22), nodeid: 1, insize: 77, pid: 876
getxattr / com.apple.FinderInfo 32 0
unique: 3, success, outsize: 48
unique: 2, opcode: LOOKUP (1), nodeid: 1, insize: 51, pid: 876
LOOKUP /.localized
getattr /.localized
unique: 2, error: -2 (No such file or directory), outsize: 16
unique: 3, opcode: LOOKUP (1), nodeid: 1, insize: 51, pid: 876
LOOKUP /.localized
getattr /.localized
unique: 3, error: -2 (No such file or directory), outsize: 16
unique: 2, opcode: GETXATTR (22), nodeid: 1, insize: 92, pid: 876
getxattr / com.apple.metadata:_kMDItemUserTags 0 0
unique: 2, error: -45 (Operation not supported), outsize: 16
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 197
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 325
statfs /
unique: 2, success, outsize: 96
unique: 3, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 876
getattr /
unique: 3, success, outsize: 136
unique: 2, opcode: GETXATTR (22), nodeid: 1, insize: 77, pid: 876
getxattr / com.apple.FinderInfo 32 0
unique: 2, success, outsize: 48
unique: 3, opcode: GETXATTR (22), nodeid: 1, insize: 92, pid: 876
getxattr / com.apple.metadata:_kMDItemUserTags 0 0
unique: 3, error: -45 (Operation not supported), outsize: 16
unique: 2, opcode: GETXATTR (22), nodeid: 1, insize: 92, pid: 876
getxattr / com.apple.metadata:_kMDItemUserTags 0 0
unique: 2, error: -45 (Operation not supported), outsize: 16
unique: 3, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 732
statfs /
unique: 3, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 733
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: GETXATTR (22), nodeid: 1, insize: 77, pid: 876
getxattr / com.apple.FinderInfo 32 0
unique: 2, success, outsize: 48
unique: 3, opcode: GETXATTR (22), nodeid: 1, insize: 92, pid: 876
getxattr / com.apple.metadata:_kMDItemUserTags 0 0
unique: 3, error: -45 (Operation not supported), outsize: 16
unique: 2, opcode: GETXATTR (22), nodeid: 1, insize: 92, pid: 876
getxattr / com.apple.metadata:_kMDItemUserTags 0 0
unique: 2, error: -45 (Operation not supported), outsize: 16
unique: 3, opcode: GETXATTR (22), nodeid: 1, insize: 77, pid: 876
getxattr / com.apple.FinderInfo 32 0
unique: 3, success, outsize: 48
unique: 2, opcode: GETXATTR (22), nodeid: 1, insize: 92, pid: 876
getxattr / com.apple.metadata:_kMDItemUserTags 0 0
unique: 2, error: -45 (Operation not supported), outsize: 16
unique: 3, opcode: GETXATTR (22), nodeid: 1, insize: 92, pid: 876
getxattr / com.apple.metadata:_kMDItemUserTags 0 0
unique: 3, error: -45 (Operation not supported), outsize: 16
^Cunique: 2, opcode: DESTROY (38), nodeid: 1, insize: 40, pid: 24054
unique: 2, success, outsize: 16

Based on what I was doing it puts my previous explanation into context.
Mounting a squashfs with fuse will reproduce the first mount error and the subsequent error of trying to put the failed mount point into the .Trash, which root does not have.

[tv42]

The original problem was that the reporter claimed to not see any FUSE activity when he emptied the trash. (Still waiting for details.) I don't see how you talking about .Trash not existing has anything to do with that.

[tv42]

Heads up: the future of macOS support is in danger. If you care about FUSE on macOS, please encourage talented developers to pick up maintenance of the open source project. See #224

[tv42]

Can't do anything here.

Tagged as doc because of the braindump of macOS trash behavior in #40 (comment) -- it'd be nice of some macOS people wrote up all the oddities of Finder etc, and .Trash and the xattr kludge would be part of that.