Rclone mount cache not offloading

What is the problem you are having with rclone?

Hi all,

I have rclone mounted with the flags shown below. I have set the cache size to 100G and would like it to clear after 4h however much of the content cached isn't cleared until I unmount and remount the drive. Does anyone know why? Thanks in advance.

What is your rclone version (output from rclone version)

rclone v1.53.3

  • os/arch: linux/amd64
  • go version: go1.15.5

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

Ubuntu Server 18.04

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

Google Drive

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

rclone mount drive: /home/mount --allow-other --dir-cache-time=4h --log-level INFO --log-file /root/rclone.log --poll-interval=15s --umask 002 --user-agent project --cache-dir=/root/drive-cache --vfs-cache-mode full --vfs-cache-max-size=100G --vfs-cache-max-age=4h

The rclone config contents with secrets removed.

[drive]
type = drive
client_id = REMOVED
client_secret = REMOVED
scope = drive
token = {"REMOVED"}
team_drive = REMOVED
root_folder_id =

A log from the command with the -vv flag

N/A

The cache doesn't clear if files are in use. You'd see that in the log file if it was provided.

Most files aren't in use after 4h.
(more context):
I have a webserver which uses the rclone mount to playback video, and in the backend, all playback links die after 4h so I'm not sure why the file isn't removed from the cache as it's not accessed after that period of time.

Without a debug log file and some details, there is not much more to add.

Hi,

I've uploaded the logs to Github however the forums don't allow me to add links nor upload the file directly so -
raw . githubusercontent . com/Fyse/spamaaa/main/rclone.log

Please let me know what kind of details you'd like..
Thanks very much for the help!

That is unfortunate as we had issues with spam/links/etc. You can post links now as I fixed that.

That's only an INFO log as we normally want -vv so it's a debug log.

You can see the line though:

2021/01/10 00:42:12 INFO  : vfs cache: cleaned: objects 75 (was 75) in use 75, to upload 0, uploading 0, total size 105.173G (was 105.173G)

Meaning, there are 75 files in use and that are not going to be cleaned. The debug log gives more details.

Hi,

After one day of usage I now have a 700mb log file. I've gone through it and it's pretty much a whole lot of file reads, however after a while the files are not read anymore but still don't offload..
Log file: https://drive.google.com/file/d/1IuGCt9NF_W710OPLksdFSJgK6D2YFJiS/view?usp=sharing

That log seems a bit tough as it looks like 2 rclone processes are writing to it.

This guy seems normal and this should write a 'clean' message every 1 minute based on the default cleaning interval of one minute.

2021/01/10 13:49:41 DEBUG : rclone: Version "v1.53.3" starting with parameters ["rclone" "mount" "fyse:fyse" "/home/fyse" "--allow-other" "--dir-cache-time=4h" "--log-file" "/root/rclone.log" "--poll-interval=15s" "--umask" "002" "--user-agent" "fyse" "--cache-dir=/root/drive-cache" "--vfs-cache-mode" "full" "--vfs-cache-max-size=100G" "--vfs-cache-max-age=4h" "-vv"]

This would be the flag to change that one minute and I don't see it set:

--vfs-cache-poll-interval duration   Interval to poll the cache for stale objects. (default 1m0s)

You have one process writing at 42 seconds and one process writing at 14 seconds every minute:

2021/01/11 21:09:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.026G (was 104.026G)
2021/01/11 21:10:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:10:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.052G (was 104.052G)
2021/01/11 21:11:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:11:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.061G (was 104.061G)
2021/01/11 21:12:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:12:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.070G (was 104.070G)
2021/01/11 21:13:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:13:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.131G (was 104.131G)
2021/01/11 21:14:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:14:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.157G (was 104.157G)
2021/01/11 21:15:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:15:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.183G (was 104.183G)
2021/01/11 21:16:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:16:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.218G (was 104.218G)
2021/01/11 21:17:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2021/01/11 21:17:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.227G (was 104.227G)
2021/01/11 21:18:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)

If you see "RemoveNotInUse" in the debug log, that means the file was removed from cache because it's not being used.

There are a lot of those:

grep "RemoveNotInUse" rclone.log  |wc -l
71319

So that 71k times a file was removed from the cache.

Your last couple lines look very normal as well as you can see things removing and you still have a lot of files in use in the cache.

2021/01/11 21:17:42 DEBUG : vfs cache RemoveNotInUse (maxAge=14400000000000, emptyOnly=false): item Star Wars Episode 3 - Revenge of the Sith (2005).mp4 not removed, freed 0 bytes
2021/01/11 21:17:42 DEBUG : vfs cache RemoveNotInUse (maxAge=14400000000000, emptyOnly=false): item Inside Out (2015).mp4 not removed, freed 0 bytes
2021/01/11 21:17:42 DEBUG : vfs cache RemoveNotInUse (maxAge=14400000000000, emptyOnly=false): item Underwater (2020).mp4 not removed, freed 0 bytes
2021/01/11 21:17:42 DEBUG : vfs cache RemoveNotInUse (maxAge=14400000000000, emptyOnly=false): item Ready or Not (2019).mp4 not removed, freed 0 bytes
2021/01/11 21:17:42 DEBUG : vfs cache RemoveNotInUse (maxAge=14400000000000, emptyOnly=false): item We're the Millers (2013).mp4 not removed, freed 0 bytes
2021/01/11 21:17:42 DEBUG : vfs cache RemoveNotInUse (maxAge=14400000000000, emptyOnly=false): item Star Wars: The Clone Wars (2008).mp4 not removed, freed 0 bytes
2021/01/11 21:17:42 INFO  : vfs cache: cleaned: objects 60 (was 60) in use 60, to upload 0, uploading 0, total size 104.227G (was 104.227G)

What do you think should be happening that isn't?

Hi,

I think my webserver is holding up the files for some reason and the cache isn't disposing of them. I've decided ti just try and clear the entire cache every 12h. Is there any command/rc endpoint I can use to manually delete the cache?

What problem are you trying to solve with that?

If the files are in use and you clear it, it would just grab them all again on the next pass since they are in use.

For the new mode, I'm not aware of any rc or other command to clear out the cache while it's running.