Plex slow to start playing uncached file; lots of "list: cached object"

I know there have been several topics about this same issue, but none of them seem to offer anything conclusive (unless I missed something). The issue is slow start times using the cache; once it plays, it runs fine. And this doesn’t happen all of the time.

My mount:

rclone mount --config /home/peter/.config/rclone/rclone.conf --allow-other --allow-non-empty gdrive-cached: /mnt/media

Things I’ve checked:

  • Network activity: once I click “play” in Plex, it can take up to 30 seconds to see any network activity
  • Plex integration: I see Rclone in my list of authorized devices in Plex, which make me assume this isn’t the problem

When playing a file, in cases where the start is really slow, there seem to be a lot of consecutive lines like this one in the debug log while network activity is still 0:

DEBUG : 66a689i3h71h00ae4g4npospb4/i7cflgb42au1uuai6iqi86pai4: list: cached object: 66a689i3h71h00ae4g4npospb4/i7cflgb42au1uuai6iqi86pai4/upr6ciu3p5vabnlibsursegke1vsafhsk5bb3jtd40rs8m61g20g

This is for files which aren’t in the cache yet. It’s as Rclone goes through the cache to look for it (and since I have a 250GB cache size, it takes a while), and only starts downloading if it can’t find it. But, this doesn’t happen with all uncached files; some do play after a few seconds.

Any thoughts from someone in the know on a) what those gazillion “list: cached object” lines mean, and b) why it goes through all of them before playing?

If that’s all you are running, the directory cache defaults are only 5 minutes for the dir-cache

The cache-info-age default is 6 hours so it’ll refresh every 6 hours as well.

I think the messages you are seeing are normal based on your settings.

So are there settings to enhance this? It seems like Rclone won’t start downloading until this is done, which takes a while. You’d think it wouldn’t need more than a second to figure out if a file is cached or not.

The very first time you run, there is no cache database so it has to create/store all the information and get listings. You have the dir-cache time very low at 5 minutes by default so it expires rather quickly.

To start playing something, you mentioned you have the plex integration going on as well so that limits the workers down as well making things a bit slower. Once plex figures out something is playing, it ups the workers for playback, but that has a lag to it as well.

This is a good spot to get an idea of values and what you can use:

https://rclone.org/cache/#known-issues

You are right that this is it, because a new play within five minutes is fast. I’m wondering if there’s an optimisation that could be made, for instance by Rclone first streaming the file (after checking just this one for existence) before refreshing everything.

Since I’m running Plex not on the same machine the content originates from, I can’t set --dir-cache-time to something really high because then no new content would show up.

They aren’t related to things showing up.

If new things are added to the mount, that is handled by:

 --poll-interval duration             Time to wait between polling for changes. Must be smaller than dir-cache-time. Only on supported remotes. Set to 0 to disable. (default 1m0s)

So the normal lag for something is 1 minute to show up.

Got it. Wondering why the default is only 5 minutes then. Wouldn’t it make more sense to have a higher default if new stuff shows up anyway? What’s the downside if I change it to 24 hours (and set --cache-info-age to something higher)?

I don’t think there is much of an issue that I can see.

Default values are dependent on the use case so I’m not sure there is a perfect value for that.

For what you want, I’d increase them.

According to the docs, they are very much related to things showing up:

Using the --dir-cache-time flag, you can set how long a directory should be considered up to date and not refreshed from the backend. Changes made locally in the mount may appear immediately or invalidate the cache. However, changes done on the remote will only be picked up once the cache expires.

Meaning this won’t work for me, because I make updates outside of the local mount.

See this:

Give it a try and see if it works for you.

I will, thanks. Seems like the documentation is off then.

Tried it: looks like the documentation is correct and @ncw was wrong (or I didn’t understand what he was saying): with a high --dir-cache-time and the default poll interval of 1m, no changes (made on the remote from another machine) are displayed in the mounted cache.

Can you please share a log of what’s not working and what your specific config is?

Saying it’s not working or something is wrong without any information doesn’t help solve or remedy the issue.

I’m not saying anything is wrong: I’m saying Rclone works exactly according to what the documentation states, which unless I misunderstood you is different from what you (or @ncw) said.

So here is the data to show how it works.

I copy a file outside of my mount using an rclone copy and it shows up in the 1 minute polling interval.

felix@gemini:/gmedia$ rclone copy /etc/hosts gcrypt:
felix@gemini:/gmedia$ ls
mounted  Movies  Radarr_Movies  torrents  TV  TV_Ended
felix@gemini:/gmedia$ date
Fri Oct 26 09:36:44 EDT 2018
felix@gemini:/gmedia$ ls
mounted  Movies  Radarr_Movies  torrents  TV  TV_Ended
felix@gemini:/gmedia$ ls
hosts  mounted  Movies  Radarr_Movies  torrents  TV  TV_Ended
felix@gemini:/gmedia$ date
Fri Oct 26 09:37:13 EDT 2018

My dir-cache-time is 72 hours.

felix@gemini:/gmedia$ ps -ef | grep rclone
felix      578     1  0 Oct15 ?        01:53:39 /usr/bin/rclone mount gcrypt: /GD --allow-other --bind 192.168.1.30 --buffer-size 1G --dir-cache-time 72h --drive-chunk-size 32M --fast-list --log-level INFO --log-file /home/felix/logs/rclone.log --umask 002 --vfs-read-chunk-size 128M --vfs-read-chunk-size-limit off

If the polling detects a change, it will invalidate the cache as show above as a minute went by and not 72 hours.

If you have something that is working different, please share the commands/logs.

felix@gemini:/gmedia$ ps -ef | grep rclone
felix      578     1  0 Oct15 ?        01:53:39 /usr/bin/rclone mount gcrypt: /GD --allow-other --bind 192.168.1.30 --buffer-size 1G --dir-cache-time 72h --drive-chunk-size 32M --fast-list --log-level INFO --log-file /home/felix/logs/rclone.log --umask 002 --vfs-read-chunk-size 128M --vfs-read-chunk-size-limit off