I’m mounting a quite large directory (about ~40,000 files) in order to run a script that just renames all the files based on their st_mtime
. The backing remote (a Google Drive) is not being written/read to outside of the mount at all.
However, even with very aggressive values for both --dir-cache-time
and --cache-info-age
of over 24 hours, I’m still finding that rclone does a cold listing of the big directory (which takes over 5 minutes) every thirty or forty renames. So it’ll block a mv
for 5-150 minutes to warm up the cache, rename a couple of files in the folder for maybe 30 seconds, and then suddenly decide to invalidate the cache again, for the exact same directory it just did. This means it will likely take me days or weeks to finish renaming all the files in here.
Here’s the relevant section of the configured remotes:
[gdrive]
type = drive
client_id = ***
client_secret = ***
scope = drive
token = ***
[gdrive-cache]
type = cache
remote = gdrive:freezer/
chunk_size = 10M
workers = 10
info_age = 24h
Here’s the command I’m using to mount:
rclone mount -vvv --log-file=/home/apetresc/tmp/rclone-mount.log --dir-cache-time=240h0m gdrive-cache: freezer/
The rename script is just doing a single ls -al freezer/path/to/subdir
and then a long sequence of mv
commands within that subdir. When one of those mysterious cache misses happens, the rclone mount log looks something like this:
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball/(2015-08-14) #GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].mkv: notify: expired 'YouTube/ChannelFireball'
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball/(2016-08-27) #GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].mp4: move: file moved
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball/#GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].mp4: move: removed from cache
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball: cache: expired YouTube/ChannelFireball
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball: cache: expired YouTube
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball: cache: expired
2018/12/16 19:46:26 INFO : YouTube/ChannelFireball: move: cache expired
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball/(2016-08-27) #GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].mp4: move: added to cache
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball: cache: expired YouTube/ChannelFireball
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball: cache: expired YouTube
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball: cache: expired
2018/12/16 19:46:26 INFO : YouTube/ChannelFireball: move: cache expired
2018/12/16 19:46:26 INFO : YouTube/ChannelFireball/#GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].mp4: Moved (server side)
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball/#GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].mp4: Updating file with YouTube/ChannelFireball/(2016-08-27) #GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].mp4 0xc003c4f040
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball/: >Rename: err=<nil>
2018/12/16 19:46:26 DEBUG : YouTube/ChannelFireball/: Lookup: name="#GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].jpg"
2018/12/16 19:46:26 DEBUG : Cache remote gdrive-cache:: list 'YouTube/ChannelFireball'
2018/12/16 19:46:27 DEBUG : YouTube/ChannelFireball: list: cold listing: 2018-12-15 19:46:26.709783659 -0500 EST
2018/12/16 19:47:25 DEBUG : Cache remote gdrive-cache:: starting cleanup
2018/12/16 19:47:25 DEBUG : Google drive root 'freezer': Checking for changes on remote
2018/12/16 19:47:26 INFO : YouTube/ChannelFireball/(2015-08-14) #GPSD Quarterfinals - Ben Weitz (Jeskai) vs. Paul Rietzl (Abzan Control) [k7xGJhUOSrs].jpg: received cache expiry notification
2018/12/16 19:48:25 DEBUG : Cache remote gdrive-cache:: starting cleanup
2018/12/16 19:49:25 DEBUG : Cache remote gdrive-cache:: starting cleanup
2018/12/16 19:50:15 DEBUG : YouTube/ChannelFireball: list: read 39301 from source
2018/12/16 19:50:15 DEBUG : YouTube/ChannelFireball: list: source entries: [... 39K files omitted ...]
I really can’t figure out what I’m doing wrong here. Here’s the weirdest part; that line that says:
2018/12/16 19:46:27 DEBUG : YouTube/ChannelFireball: list: cold listing: 2018-12-15 19:46:26.709783659 -0500 EST
It’s completely bogus that there was a listing at that time, because I had definitely deleted the entire ~/.cache/rclone
directory right before starting this particular run, so there is no way that it had a cold listing from 2018-12-15. It’s like rclone just made up a listing that was almost exactly 24 hours ago to justify why it needed to re-list. And this message appears every time; five minutes later there will be another phantom cold listing that was supposedly from 2018-12-15 19:50
or somesuch. If I change --cache-info-age
, it changes the timestamps on these phantom listings so that they’re always just outside the window - even though it’s a brand new cache backend I just created.
Very much at a loss here, hoping someone can point out what I’m doing wrong. Thanks!