Writes failing to gdrive mount on OSX, potentially extended attributes problem

What is the problem you are having with rclone?

I've been using rclone for a long time on a linux host, and am now for the first time setting up on Mac OS X 13.3.1. I've tried with both Fuse-T and Macfuse, and am currently using Macfuse.

I've created a mount for a team drive successfully, and reads are fine. Writes, however, report that they fail.

Writes work fine with a direct "rclone copy" command. They do not, however, using applications - sonarr, radarr, finder, even the cp command in the terminal. Super weirdly, when testing with the cp command, I can see the entire file successfully copied into the VFS cache, and rclone then uploads it. The cp command however errors with
"could not copy extended attributes to : Operation not permitted" and reports it has failed.

When I look at trace-level logs for the other applications, it suggests that the problem is the same - they copy, then get an error (not specified in their logs), then clean up after themselves. Rclone logs show that rclone notices the file in the VFS, and schedules an upload, and cancels that upload after the file is deleted (at the point that Radarr thinks it has failed, and cleans up after itself, I think).

Things I've tried:

  • Macfuse and Fuse-T (problem remains),
  • disabling the vfs,
  • deleting the vfs meta and starting it afresh,
  • switching to umask 000,
  • both with and without "--noapplexattr" in the mount command

Run the command 'rclone version' and share the full output of the command.

rclone v1.62.2
- os/version: darwin 13.3.1 (64 bit)
- os/kernel: 22.4.0 (arm64)
- os/type: darwin
- os/arch: arm64 (ARMv8 compatible)
- go/version: go1.20.2
- go/linking: dynamic
- go/tags: cmount

Which cloud storage system are you using? (eg Google Drive)

Google drive, specifically via a team shared drive.

The command you were trying to run (eg rclone copy /tmp remote:tmp)

/usr/local/bin/rclone mount Movies: /Users/<me>/rclone/Movies \
--daemon \
--allow-other \
--dir-cache-time 9999h \
--log-file /Users/<me>/rclone/Logs/rclone-movies.log \
--log-level INFO \
--umask 000 \
--cache-dir=/Volumes/Server/Rclone-cache \
--vfs-cache-mode writes \
--vfs-cache-max-size 100G \
--vfs-fast-fingerprint \
--vfs-cache-max-age 9999h \
--tpslimit 12 \
--tpslimit-burst 0

The rclone config contents with secrets removed.

[MountName]
type = drive
client_id = <myid>
client_secret = <mysecret>
scope = drive
chunk_size = 128Mi
server_side_across_configs = true
token = {"access_token":<mytoken>}
team_drive = <myteamdrive>
root_folder_id =

A log from the command with the -vv flag

N/A

This is rclone saying it doesn't support extended attributes I think. Though the rclone methods all return ENOSYS which should be "Function not implemented" or something like that, not EPERM.

What kind of file are you copying? Does it have extended attributes?

File is an MKV downloaded by sabnzbd. I’ve got no real Mac experience, so I’m unsure how to check for extended attributes sorry.

This is the log from sonar:

2023-05-15 04:01:52.1|Warn|ImportApprovedEpisodes|Couldn't import episode /Volumes/Server/Sabnzbd/Complete/file.mkv

[v4.0.0.495] System.UnauthorizedAccessException: Access to the path is denied.
---> System.IO.IOException: Operation not permitted
--- End of inner exception stack trace ---
at Interop.ThrowExceptionForIoErrno(ErrorInfo errorInfo, String path, Boolean isDirectory, Func2 errorRewriter) at System.IO.FileSystem.CopyFile(String sourceFullPath, String destFullPath, Boolean overwrite) at System.IO.FileSystem.LinkOrCopyFile(String sourceFullPath, String destFullPath) at System.IO.FileSystem.MoveFile(String sourceFullPath, String destFullPath, Boolean overwrite) at System.IO.File.Move(String sourceFileName, String destFileName, Boolean overwrite) at NzbDrone.Mono.Disk.DiskProvider.TransferFilePatched(String source, String destination, Boolean overwrite, Boolean move) in C:\BuildAgent\work\13f3e374fa512e16\src\NzbDrone.Mono\Disk\DiskProvider.cs:line 342 at NzbDrone.Common.Disk.DiskProviderBase.MoveFile(String source, String destination, Boolean overwrite) in C:\BuildAgent\work\13f3e374fa512e16\src\NzbDrone.Common\Disk\DiskProviderBase.cs:line 245 at NzbDrone.Common.Disk.DiskTransferService.TryMoveFileVerified(String sourcePath, String targetPath, Int64 originalSize) in C:\BuildAgent\work\13f3e374fa512e16\src\NzbDrone.Common\Disk\DiskTransferService.cs:line 506 at NzbDrone.Common.Disk.DiskTransferService.TransferFile(String sourcePath, String targetPath, TransferMode mode, Boolean overwrite) in C:\BuildAgent\work\13f3e374fa512e16\src\NzbDrone.Common\Disk\DiskTransferService.cs:line 296 at NzbDrone.Core.MediaFiles.EpisodeFileMovingService.TransferFile(EpisodeFile episodeFile, Series series, List1 episodes, String destinationFilePath, TransferMode mode) in C:\BuildAgent\work\13f3e374fa512e16\src\NzbDrone.Core\MediaFiles\EpisodeFileMovingService.cs:line 140
at NzbDrone.Core.MediaFiles.UpgradeMediaFileService.UpgradeEpisodeFile(EpisodeFile episodeFile, LocalEpisode localEpisode, Boolean copyOnly) in C:\BuildAgent\work\13f3e374fa512e16\src\NzbDrone.Core\MediaFiles\UpgradeMediaFileService.cs:line 77
at NzbDrone.Core.MediaFiles.EpisodeImport.ImportApprovedEpisodes.Import(List`1 decisions, Boolean newDownload, DownloadClientItem downloadClientItem, ImportMode importMode) in C:\BuildAgent\work\13f3e374fa512e16\src\NzbDrone.Core\MediaFiles\EpisodeImport\ImportApprovedEpisodes.cs:line 113

Sonarr is, however, writing successfully (albeit momentarily), and is able to create folders fine. And I’ve tried everything I can around permissions adjustment (hence a 000 umask atm)

I don't have a mac so it will be guesswork from me too!

What I would do on linux is strace (I think dtruss on OSX) sonar to find out exactly which system calls sonar is calling. That will tell us why it is getting Operation not permitted.

Once thing that might be worth trying is switching to --vfs-cache-mode full - that might help.

I’ve tried now with full vfs cache and get the same error.

I’ve never tried dtruss but a quick google suggests it’s not really a thing on macs any more? No idea of the reality of that…

Is there any chance that a full uninstall and re-setup of Rclone might change anything?

The error looks to be permission?

You'd want to share a rclone debug log at the same time you generate the error.

It's stupid I got so caught up in other things i never thought to change the rclone logs to Debug...

Before trying to generate the error, straight away my rclone log after mounting gets spammed with the below:

023/05/16 07:15:58 DEBUG : rclone: Version "v1.62.2" finishing with parameters ["/usr/local/bin/rclone" "mount" "TV:" "/Users/<me>/rclone/TV" "--daemon" "--allow-other" "--dir-cache-time" "9999h" "--log-file" "/Users/<me>/rclone/Logs/rclone-tv.log" "--log-level" "DEBUG" "--cache-dir=/Volumes/Server/Rclone-cache" "--vfs-cache-mode" "writes" "--vfs-cache-max-size" "100G" "--vfs-fast-fingerprint" "--vfs-cache-max-age" "9999h" "--tpslimit" "5" "--tpslimit-burst" "0" "--daemon-timeout" "30m"]
2023/05/16 07:16:12 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:16:12 DEBUG : /: >Getattr: errc=0
2023/05/16 07:16:12 DEBUG : /: Access: mask=00
2023/05/16 07:16:12 DEBUG : /: >Access: errc=0
2023/05/16 07:16:12 DEBUG : /: Access: mask=00
2023/05/16 07:16:12 DEBUG : /: >Access: errc=0
2023/05/16 07:16:12 DEBUG : /: Access: mask=00
2023/05/16 07:16:12 DEBUG : /: >Access: errc=0
2023/05/16 07:16:12 DEBUG : /: Access: mask=00
2023/05/16 07:16:12 DEBUG : /: >Access: errc=0
2023/05/16 07:16:12 DEBUG : /: Access: mask=00

(deleted this section as I've put a larger log snippet in the next reply)

As a nerdy sidneote - thanks both of you for all the work you put into this, and particularly Animosity - the resources you put online were how I got started with all of this years ago...

The full log is massive, but from first to last mention of a failed file, uninterrupted except to censor filename and path:

2023/05/16 07:23:30 DEBUG : /<folder>: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>: >Getattr: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /: Statfs: 
2023/05/16 07:23:30 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/05/16 07:23:30 DEBUG : /: Access: mask=00
2023/05/16 07:23:30 DEBUG : /: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /: Statfs: 
2023/05/16 07:23:30 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/05/16 07:23:30 DEBUG : /: Statfs: 
2023/05/16 07:23:30 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/05/16 07:23:30 DEBUG : /: Statfs: 
2023/05/16 07:23:30 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/05/16 07:23:30 DEBUG : /: Statfs: 
2023/05/16 07:23:30 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:4294967295 Bfree:4294967295 Bavail:4294967295 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: Access: mask=02
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: CreateEx: flags=0xA02, mode=0100644
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv: Open: flags=O_RDWR|O_CREATE|O_EXCL
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv: newRWFileHandle: 
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv(0x14000863240): openPending: 
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv: vfs cache: truncate to size=0 (not needed as size correct)
2023/05/16 07:23:30 DEBUG : <folder>/Season 13: Added virtual directory entry vAddFile: "file.mkv"
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv(0x14000863240): >openPending: err=<nil>
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv: >newRWFileHandle: err=<nil>
2023/05/16 07:23:30 DEBUG : <folder>/Season 13: Added virtual directory entry vAddFile: "file.mkv"
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv: >Open: fd=<folder>/Season 13/file.mkv (rw), err=<nil>
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >CreateEx: errc=0, fh=0x1
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0x1
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getxattr: name="com.apple.provenance"
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getxattr: errc=-78, value=""
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getxattr: name="com.apple.provenance"
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getxattr: errc=-78, value=""
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Chmod: mode=0100644
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Chmod: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0x1
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getxattr: name="com.apple.provenance"
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getxattr: errc=-78, value=""
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=04
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Listxattr: fill=0x1021c9c60
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Listxattr: errc=-78
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=02
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Flush: fh=0x1
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv(0x14000863240): RWFileHandle.Flush
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Flush: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Release: fh=0x1
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv(0x14000863240): RWFileHandle.Release
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv(0x14000863240): close: 
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv: vfs cache: setting modification time to 2023-05-16 07:23:30.382416 +1200 NZST m=+456.653406960
2023/05/16 07:23:30 INFO  : <folder>/Season 13/file.mkv: vfs cache: queuing for upload in 5s
2023/05/16 07:23:30 DEBUG : <folder>/Season 13/file.mkv(0x14000863240): >close: err=<nil>
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Release: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /: Access: mask=01
2023/05/16 07:23:30 DEBUG : /: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>: Access: mask=01
2023/05/16 07:23:30 DEBUG : /<folder>: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: >Getattr: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: Access: mask=01
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=00
2023/05/16 07:23:30 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /: Access: mask=01
2023/05/16 07:23:33 DEBUG : /: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>: Access: mask=01
2023/05/16 07:23:33 DEBUG : /<folder>: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: Access: mask=01
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=00
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=00
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: Access: mask=00
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: Unlink: 
2023/05/16 07:23:33 DEBUG : <folder>/Season 13/file.mkv: Remove: 
2023/05/16 07:23:33 DEBUG : <folder>/Season 13/file.mkv: vfs cache: cancelling writeback (uploading false) 0x14000296540 item 9
2023/05/16 07:23:33 INFO  : <folder>/Season 13/file.mkv: vfs cache: removed cache file as file deleted
2023/05/16 07:23:33 DEBUG : <folder>/Season 13/file.mkv: vfs cache: removed metadata from cache as file deleted
2023/05/16 07:23:33 DEBUG : <folder>/Season 13: Added virtual directory entry vDel: "file.mkv"
2023/05/16 07:23:33 DEBUG : <folder>/Season 13/file.mkv: >Remove: err=<nil>
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: >Unlink: errc=0
2023/05/16 07:23:33 DEBUG : /: Access: mask=01
2023/05/16 07:23:33 DEBUG : /: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>: Access: mask=01
2023/05/16 07:23:33 DEBUG : /<folder>: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: Access: mask=00
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: >Getattr: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: Access: mask=01
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13/file.mkv: >Getattr: errc=-2
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: Access: mask=04
2023/05/16 07:23:33 DEBUG : /<folder>/Season 13: >Access: errc=0
2023/05/16 07:23:43 DEBUG : /: Access: mask=00
2023/05/16 07:23:43 DEBUG : /: >Access: errc=0

Of particular interest seems to be the specific xattr which is failing, com.apple.provenance, which from a quick google appears to be a new xattr which has caused issues with other software, eg: macos - What is the `com.apple.provenance` xattr (extended attribute) and how can I delete it? - Ask Different

Can you try with a small test file?

Just pick one of these:

https://www.larmoire.info/jellyfish/

Copy it locally to where your NZB source is.
Copy it to the mount directly without Sonarr.

Grab the full debug log for that as nothing will be private at that point.

Error 78 is ENOSYS which is rclone telling the OS that it doesn't support xattr.

There aren't any other unexpected errors in the log. For some reason the application stops writing the file, closes it and deletes it. This cancels the upload.

Rclone never returns any permissions errors.

So I think this is due to the application not liking something, but exactly what isn't clear from the log.

Deleted posts because I thought I’d solved a thing, but hadn’t actually - the mount wasn’t mounted and I’d been copying to the local drive by accident

OK, so I’m 100% now that the com.Apple.provenance extended attribute is triggering something that prevents a Mac from moving or copying a file successfully to a volume that doesn’t preserve that extended attribute.

When I tested with the sample files Animosity linked to, there was no error. I also confirmed that file after downloading did not have the com.apple.provenance xattr. It did, however, have a range of other xattr, which did not prevent the copy from working.

I confirmed all the sabnzbd files did have the com.apple.provenance attribute.

I ran xattr -d com.apple.provenance to remove that xattr, then ran the import again using Sonarr. It worked perfectly.

I’ve tried putting a post processing script into sab to do this, but haven’t gotten it working yet…

No idea if rclone could or should work around this, but it’s definitely that specific xattr causing the problem.

Good testing - well done.

On careful reading of the xattr man pages I think the problem might be that FUSE is passing the ENOSYS to the OS directly which is confusing the application. FUSE on linux takes ENOSYS as a signal that the call isn't implemented and never calls it again, whereas we can see the OS continually calls Getxattr on macOS.

You can check this for me by running

xattr /path/to/a/file/on/the/rclone/mount.txt
echo $?

If that returns ENOSYS (78) rather than ENOTSUP then this may help

v1.63.0-beta.7046.065e63960.fix-mount-osx-xattr on branch fix-mount-osx-xattr (uploaded in 15-30 mins)

This returns ENOTSUP from the xattr calls instead of ENOSYS. This probably needs gating for macOS only if it works.

Hmm. That just returned “0” when I tried it.

Hmm! Have a go with the beta anyway and see if that helps!

I've now tested that beta branch, and it appears to solve the problem.

I will say - it wasn't a perfect like-for-like test as I had to use the amd64 build rather than the arm64 build, as I couldn't figure out how to sign the arm64 build! But assuming that doesn't impact things, then yes, it seems that's solved the problem.

Good

Can you test the unmodified amd64 rclone and see if it has the same problem?

I don't normally sign the arm64 build - I don't really understand mac signatures, alas!

Yeah, I also don't understand them - but installing via brew takes care of doing it, so I just let it happen! Will test when I'm back at the mac tomorrow.

1 Like