I’ve been having trouble with new files not showing up on my google drive mount when using the cache backend in Rclone v1.40. I have dir-cache-time and cache-info-age both set to 1 week (168h).
I’m under the impression that the GD change polling should be invalidating the cache automatically… is that correct? If so, does this affect both dir-cache-time and cache-info-age? Should I be setting one or the other? The docs are rather confusing as to what the actual difference is between those options.
currently if you add a file in a new parent directory that is not known to rclone cache, it will not show up in the rclone mount.
please see this issue https://github.com/ncw/rclone/issues/2155
I’ve been following that issue as well, but in my case I’m seeing issues with the cache when adding files to existing directories that are already cached. I’ve run a test-case as follows:
I have a directory on my encrypted GD in the root called test, with an existing file named test1.txt.
After I mount the drive with rclone, I cd to test and run ls to cache the directory.
On a separate server, I copy a new file called test2.txt into the “test” directory.
I wait for the rclone mount to poll for changes, it recognizes that a new file has been added, but when I then ls in the test directory, the new file does not appear.
Here is the log from rclone:
2018/03/28 08:17:17 DEBUG : /: Lookup: name="test"
2018/03/28 08:17:17 DEBUG : /: >Lookup: node=test/, err=<nil>
2018/03/28 08:17:17 DEBUG : test/: Attr:
2018/03/28 08:17:17 DEBUG : test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2018/03/28 08:17:17 DEBUG : test/: ReadDirAll:
2018/03/28 08:17:17 DEBUG : Cache remote gd-cache:: list 'oupc4hetvha5gb7uergu2toc2g'
2018/03/28 08:17:17 DEBUG : oupc4hetvha5gb7uergu2toc2g: list: empty listing
2018/03/28 08:17:17 DEBUG : oupc4hetvha5gb7uergu2toc2g: list: read 1 from source
2018/03/28 08:17:17 DEBUG : oupc4hetvha5gb7uergu2toc2g: list: source entries: [oupc4hetvha5gb7uergu2toc2g/07j4c1j7gsptiuksfd096ne0js]
2018/03/28 08:17:17 DEBUG : oupc4hetvha5gb7uergu2toc2g: list: cached object: oupc4hetvha5gb7uergu2toc2g/07j4c1j7gsptiuksfd096ne0js
2018/03/28 08:17:17 DEBUG : oupc4hetvha5gb7uergu2toc2g: list: cached dir: 'oupc4hetvha5gb7uergu2toc2g', cache ts: 2018-03-28 08:17:17.926294745 -0700 PDT m=+10.589023451
2018/03/28 08:17:17 DEBUG : test/: >ReadDirAll: item=1, err=<nil>
2018/03/28 08:18:07 DEBUG : Cache remote gd-cache:: starting cleanup
2018/03/28 08:18:08 DEBUG : Cache remote gd-cache:: starting cleanup
2018/03/28 08:18:08 DEBUG : Google drive root 'crypt': Checking for changes on remote
2018/03/28 08:18:08 DEBUG : Google drive root 'crypt': Checking for changes on remote
2018/03/28 08:18:08 INFO : test/test2.txt: received cache expiry notification
2018/03/28 08:18:08 DEBUG : test: forgetting directory cache
2018/03/28 08:18:08 DEBUG : Cache remote gd-cache:: ignoring change notification for non cached entry oupc4hetvha5gb7uergu2toc2g/68sdr2ldjo6l6oa5e5r8094b1k
2018/03/28 08:18:08 DEBUG : Google drive root 'crypt': All changes were processed. Waiting for more.
2018/03/28 08:18:08 DEBUG : Google drive root 'crypt': All changes were processed. Waiting for more.
2018/03/28 08:18:12 DEBUG : test/: ReadDirAll:
2018/03/28 08:18:12 DEBUG : Cache remote gd-cache:: list 'oupc4hetvha5gb7uergu2toc2g'
2018/03/28 08:18:12 DEBUG : oupc4hetvha5gb7uergu2toc2g: list: warm 1 from cache for: oupc4hetvha5gb7uergu2toc2g, expiring on: 2018-04-04 08:17:17.926294745 -0700 PDT
2018/03/28 08:18:12 DEBUG : oupc4hetvha5gb7uergu2toc2g: list: cached entries: [oupc4hetvha5gb7uergu2toc2g/07j4c1j7gsptiuksfd096ne0js]
2018/03/28 08:18:12 DEBUG : test/: >ReadDirAll: item=1, err=<nil>
2018/03/28 08:19:07 DEBUG : Cache remote gd-cache:: starting cleanup
2018/03/28 08:19:08 DEBUG : Cache remote gd-cache:: starting cleanup
2018/03/28 08:19:08 DEBUG : Google drive root 'crypt': Checking for changes on remote
2018/03/28 08:19:08 DEBUG : Google drive root 'crypt': Checking for changes on remote
2018/03/28 08:19:09 DEBUG : Google drive root 'crypt': All changes were processed. Waiting for more.
2018/03/28 08:19:09 DEBUG : Google drive root 'crypt': All changes were processed. Waiting for more.
I noticed that one of the log entries says ignoring change notification for non cached entry even though the directory is cached, so perhaps there’s some confusion going on there.
I thought this was working fine in earlier betas, so I’ve been trying the same test with older versions, and I’ve narrowed it down to a change that was implemented between v1.39 beta 211 and beta 215. I’ve reverted back to beta 211 and it’s working fine, here’s the log for the same test:
This beta should fix the issue replicated here - the parent folder was not expired when an object was received as changed even though it was done in vfs.
I’m running v1.40-061-gd5b2ec32 with a crypt/cache wrapped drive remote mounted, and am still seeing issues with newly created directories not showing in the mount until I did a full expire with a HUP (didn’t try targeting the parent folder through the rc expire command, but assume that would work as well).
For a cached remote, can dir-cache-time be safely lowered, as the mount shouldn’t incur much of a penalty if it’s just hitting the bolt cache? Either way, it seems like a notification from drive should still bubble all the way up through the crypt and cache to the mount, no?
This is a read-only mount merged with a local dir with unionfs as well so I have vfs turned off, and I’m wondering if that may be related. Thoughts?
I’ve switched to debug logging now as well so I’ll have some more details if/when this happens again.
I’m doing a nightly cronjob that does a combination of rclone copy and rclone move with different exclusion lists and file age limits. I’d still prefer to keep this to control when specifically uploads happen, and to be able to keep some files local all the time. Worst-case scenario, I can have the script trigger rc cache/expire for files/directories that changed.
Nope, nothing related to files masked anywhere with a .unionfs folder.
I’ve just manually done a rclone copy of a folder that didn’t exist on the remote when I mounted it, and the next check for changes on drive didn’t seem to find anything that needed doing:
rclone[26169]: 2018/04/10 21:28:01 DEBUG : Google drive root 'Plex': Checking for changes on remote
rclone[26169]: 2018/04/10 21:28:01 DEBUG : Google drive root 'Plex': All changes were processed. Waiting for more.
rclone[26169]: 2018/04/10 21:28:02 DEBUG : Google drive root 'Plex': Checking for changes on remote
rclone[26169]: 2018/04/10 21:28:02 DEBUG : Google drive root 'Plex': All changes were processed. Waiting for more.
rclone rc vfs/forget did nothing as expected since I don’t have VFS enabled.
rclone rc cache/expire remote="existingDirectory/newDirectory" confirmed that this wasn’t in the cache:
2018/04/10 21:33:37 Failed to rc: operation "cache/expire" failed: remote control command failed: 4pd8m573jua2rm9g0iscn82tac/0cr7kkd898l3o6lnmm7lmlvvk8 doesn't exist in cache
The only thing that worked was rclone rc cache/expire remote="existingDirectory/"
My current config for reference:
[gdrive]
type = drive
client_id = REDACTED
client_secret = REDACTED
token = {"access_token":"REDACTED","token_type":"Bearer","refresh_token":"REDACTED","expiry":"2018-04-10T22:07:58.232237126-04:00"}
[gdrive-cache]
type = cache
remote = gdrive:Plex
plex_url = http://127.0.0.1:32400
plex_token = REDACTED
chunk_total_size = 50G
[gdrive-cache-crypt]
type = crypt
remote = gdrive-cache:
filename_encryption = standard
directory_name_encryption = true
password = REDACTED
password2 = REDACTED
# Used for copy/move operations
[crypt]
type = crypt
remote = gdrive:Plex
filename_encryption = standard
password = REDACTED
password2 = REDACTED
And my current mount command /usr/bin/rclone mount gdrive-cache-crypt: /data/.gdrive --read-only --allow-other --dir-cache-time=6h --cache-chunk-size=5M --cache-info-age=168h --cache-workers=8 --buffer-size 0M --attr-timeout=1s --umask 002 --rc --log-level DEBUG --gid 1001 --uid 1000 (dropped dir-cache-time to 6hrs to avoid things going going missing for a week if I didn’t notice, was 168h before)
Nope, no cache expiry notifications for a new directory. I had notifications from last night’s copy operation when files that were already on the remote were overwritten/updated, but nothing for the copy operation of this new directory and file.
The only thing I’m doing that seems slightly non-standard is having the mount read-only?
