Mount cache coherency with remote (out of sync with remote)

What is the problem you are having with rclone?

I've got a crypt remote on gdrive mounted across multiple clients (2 different windows machines with identical configs), using the same OAuth ID, and I've noticed that sometimes I'll get into a situation where a client can get out of sync with the underlying remote, and I can't get it back into sync.

This leads to some bad situations, for instance, files aren't reflected where they are in the remote (using an rclone ls or lsd), and are showing in the original locations still, having been moved on a different machine mounting the space (i.e. sonarr is moving a file, and the clients aren't seeing this has happened). Worse still, the client seeing the old location, and deleting it, will delete the file in the new location, I assume because the underlying identifier is what gets removed and gdrive removes it, regardless of where it is.

Just killing and re-starting the rclone mount doesn't seem to force a cache refresh, I'm going to start using "--rc", and see if I can force the sync up from that, but I've started wondering if I shouldn't be sharing an oauth ID across clients? I've just now created a new OauthID to use for the client having coherncy problems with the remote. It's strange to me that the changes aren't being picked up, and I wondered if maybe the change is tracked by ID, maybe GDrive isn't reporting a chance because it thinks another client using that ID has already acknowledged it?

What is your rclone version (output from rclone version)

rclone v1.53.1

  • os/arch: windows/amd64
  • go version: go1.15

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Windows 10 x64 1909, build 18363.1016

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

Gdrive

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

rclone mount secV:/ V: --fuse-flag --VolumePrefix=\server\GDriveSecV --dir-cache-time=1000h --poll-interval 15s --cache-dir="c:\rclone.cache" --vfs-cache-mode full --vfs-cache-max-size 50G --vfs-cache-max-age 12h --bwlimit 20M –v

The rclone config contents with secrets removed.


[secV]
type = crypt
remote = gdroot:/secV
filename_encryption = standard
directory_name_encryption = true
password = 


[gdroot]
type = drive
client_id = xxx.apps.googleusercontent.com
client_secret = xxx
scope = drive
token = {"access_token":"xxx","token_type":"Bearer","refresh_token":"1//xxx","expiry":"2020-11-08T12:05:00.8780766-05:00"}


A log from the command with the -vv flag

Posting some of the current running log, it just looks like this, it's what I have, but it's after I re-created the gdroot remote with a new oauth ID for just this client computer. Which coincidentally or not seemed to get the mount back into sync with the underlying storage for now.

2020/11/08 11:19:47 DEBUG : rclone: Version "v1.53.1" starting with parameters ["rclone" "mount" "secV:/" "V:" "--fuse-flag" "--VolumePrefix=\\server\\GDriveSecV" "--dir-cache-time=1000h" "--poll-interval" "15s" "--cache-dir=c:\\rclone.cache" "--vfs-cache-mode" "full" "--vfs-cache-max-size" "50G" "--vfs-cache-max-age" "12h" "--bwlimit" "20M" "-vv" "--rc"]
2020/11/08 11:19:47 NOTICE: Serving remote control on http://127.0.0.1:5572/
2020/11/08 11:19:47 DEBUG : Creating backend with remote "secV:/"
2020/11/08 11:19:47 DEBUG : Using config file from "C:\\Users\\jason\\.config\\rclone\\rclone.conf"
2020/11/08 11:19:47 INFO  : Starting bandwidth limiter at 20MBytes/s
2020/11/08 11:19:47 DEBUG : Creating backend with remote "gdroot:/secV"
2020/11/08 11:19:48 DEBUG : Google drive root 'secV': root_folder_id = "0AEd1gOojXazyUk9PVA" - save this in the config to speed up startup
2020/11/08 11:19:48 DEBUG : fs cache: renaming cache item "gdroot:/secV" to be canonical "gdroot:secV"
2020/11/08 11:19:48 DEBUG : fs cache: switching user supplied name "gdroot:/secV" for canonical name "gdroot:secV"
2020/11/08 11:19:48 DEBUG : vfs cache: root is "\\\\?\\c:\\rclone.cache\\vfs\\secV"
2020/11/08 11:19:48 DEBUG : vfs cache: metadata root is "\\\\?\\c:\\rclone.cache\\vfs\\secV"
2020/11/08 11:19:48 DEBUG : Creating backend with remote "\\\\?\\c:\\rclone.cache\\vfs\\secV"
2020/11/08 11:19:48 DEBUG : fs cache: renaming cache item "\\\\?\\c:\\rclone.cache\\vfs\\secV" to be canonical "//?/c:/rclone.cache/vfs/secV"
2020/11/08 11:19:48 DEBUG : fs cache: switching user supplied name "\\\\?\\c:\\rclone.cache\\vfs\\secV" for canonical name "//?/c:/rclone.cache/vfs/secV"
2020/11/08 11:19:48 DEBUG : Encrypted drive 'secV:/': Mounting on "V:"
2020/11/08 11:19:48 DEBUG : vfs cache RemoveNotInUse (maxAge=43200000000000, emptyOnly=false): item TV/American Gods/Season 2/American Gods - S02E02 - The Beguiling Man Bluray-1080p.mkv not removed, freed 0 bytes
2020/11/08 11:19:48 DEBUG : vfs cache RemoveNotInUse (maxAge=43200000000000, emptyOnly=false): item TV/Letterkenny/Season 1/Letterkenny.S01E04.Wing.Man.Wayne.mkv not removed, freed 0 bytes
2020/11/08 11:19:48 DEBUG : Encrypted drive 'secV:/': Mounting with options: ["-o" "fsname=secV:/" "-o" "subtype=rclone" "-o" "max_readahead=131072" "-o" "attr_timeout=1" "-o" "atomic_o_trunc" "-o" "uid=-1" "-o" "gid=-1" "--FileSystemName=rclone" "-o" "volname=secV" "--VolumePrefix=\\server\\GDriveSecV"]
2020/11/08 11:19:48 INFO  : vfs cache: cleaned: objects 2 (was 2) in use 0, to upload 0, uploading 0, total size 361.477M (was 0)
2020/11/08 11:19:48 DEBUG : Encrypted drive 'secV:/': Init:
2020/11/08 11:19:48 DEBUG : Encrypted drive 'secV:/': >Init:
2020/11/08 11:19:48 DEBUG : /: Statfs:
2020/11/08 11:19:48 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:279222827915 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2020/11/08 11:19:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:48 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:48 DEBUG : /: Readlink:
2020/11/08 11:19:48 DEBUG : /: >Readlink: linkPath="", errc=-40
The service rclone has been started.
2020/11/08 11:19:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:48 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:48 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:48 DEBUG : /: Opendir:
2020/11/08 11:19:48 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:48 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:48 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:48 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:48 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:48 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:48 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:48 DEBUG : /: Opendir:
2020/11/08 11:19:48 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:48 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:48 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:48 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:48 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:48 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:48 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:48 DEBUG : /: Opendir:
2020/11/08 11:19:48 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:48 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:48 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:48 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:48 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:48 DEBUG : /Desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /Desktop.ini: >Getattr: errc=-2
2020/11/08 11:19:49 DEBUG : /Desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /Desktop.ini: >Getattr: errc=-2
2020/11/08 11:19:49 DEBUG : /AutoRun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /AutoRun.inf: >Getattr: errc=-2
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x1
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/11/08 11:19:49 DEBUG : /: >Getattr: errc=0
2020/11/08 11:19:49 DEBUG : /: Opendir:
2020/11/08 11:19:49 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/11/08 11:19:49 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/11/08 11:19:49 DEBUG : /: >Opendir: errc=0, fh=0x0
2020/11/08 11:19:49 DEBUG : /: Releasedir: fh=0x0
2020/11/08 11:19:49 DEBUG : /: >Releasedir: errc=0
2020/11/08 11:20:03 DEBUG : Google drive root 'secV': Checking for changes on remote
2020/11/08 11:20:18 DEBUG : Google drive root 'secV': Checking for changes on remote
2020/11/08 11:20:33 DEBUG : Google drive root 'secV': Checking for changes on remote
2020/11/08 11:20:48 DEBUG : Google drive root 'secV': Checking for changes on remote
2020/11/08 11:20:48 DEBUG : vfs cache RemoveNotInUse (maxAge=43200000000000, emptyOnly=false): item TV/American Gods/Season 2/American Gods - S02E02 - The Beguiling Man Bluray-1080p.mkv not removed, freed 0 bytes
2020/11/08 11:20:48 DEBUG : vfs cache RemoveNotInUse (maxAge=43200000000000, emptyOnly=false): item TV/Letterkenny/Season 1/Letterkenny.S01E04.Wing.Man.Wayne.mkv not removed, freed 0 bytes
2020/11/08 11:20:48 INFO  : vfs cache: cleaned: objects 2 (was 2) in use 0, to upload 0, uploading 0, total size 361.477M (was 361.477M)
2020/11/08 11:21:03 DEBUG : Google drive root 'secV': Checking for changes on remote
2020/11/08 11:21:18 DEBUG : Google drive root 'secV': Checking for changes on remote
2020/11/08 11:21:33 DEBUG : Google drive root 'secV': Checking for changes on remote
2020/11/08 11:21:48 DEBUG : Google drive root 'secV': Checking for changes on remote

I would have thought that would work.

That should work.

I don't think it will matter.

Note that there is an current bug related to this: https://github.com/rclone/rclone/issues/4446 which might be relevant.

Thanks for that. It does seem possible I'm running into that at least some of the time. I also found the cache not flushing and updating after the restart particularly odd, which is why I posted about it. I won't worry about it much though, as long as I can get it to flush with the rc commands.

Maybe sideways related, maybe not, sonarr has an option to use hardlinks instead of copies, and I wasn't sure if hardlinks were usable with the mount. The scenarios presented I don't think are a big issue for me right now, but the setting was initially enabled on my setup, and I had wondered if that was contributing to the issue I was seeing. I've since disabled though, and moved to copy/move only.

Thanks!

Can you try the latest beta? I just put a fix in for that bug...

No they aren't unfortunately.

I've updated to the latest beta. It will be difficult to tell if it's fixed or not, as I can't reproduce the problem at will, so hopefully it just doesn't occur any more.

Thanks!

1 Like

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.