Testing for new vfs cache mode features

:slight_smile:

I just tested it - it doesn't show up even when the upload has finished so you would need a change modify poll or a vfs/update to get it to appear.

I think this should be fairly easy to fix though...

:blush: thank you! I work really hard on the reliability of rclone - I hate flakey tools!

1 Like

Just raising this for dialog purposes:

  • When running operations like "copy, move, sync, etc" against a mounted remove (using vfs-cache=full) the operation is much slower than running against the remote itself (which is fine in general).

  • Typically we would read through a mounted "Cache" backend to give us the future benefit of cached meta, etc. which would make local fs to local fs operations much faster (also working around the exclusive lock challenges with Cache).

Any thoughts on what might happen with VFS caching in the future to help with non-related operations? (For instance, maybe adding vfs-cache=full option to the remote config file so that any and all operations take advantage of the existing vfs cache in the future?)

# time rclone copy -v --progress --fast-list RemoteCrypt:Media/ /srv/Media/
...
real	2m5.049s

# time rclone copy -v --progress --fast-list /mnt/RemoteCrypt/Media/ /srv/Media/
...
real	20m42.357s

Is the VFS cache thread / operation safe at this point? (concurrent operations against same remote)

Tested this again this morning with the latest build. I can still repro it. Still haven't got a smaller test case, but did capture a debug log this time. I've stripped out most of the copying/encrypting/uploading from the log to make it smaller, just including the start/end of each as a reference point. I can't quite make out a clear cause from the logs... possibly something with the new directory created not being in the cached listings at the right time? https://gist.github.com/dotsam/5c78df83f496f91d1d615d4480c97605

If this isn't conclusive, let me know, and I'll keep trying for a simplified case.

Yes, that is exactly the plan.

I have a prototype vfscache backend which will wrap any backend in a VFS but still provide the backend interface for sync.

I haven't figured out how it gets configured yet, but something like you suggested above where you can put the VFS flags into the backend config.

Very useful debug log, thanks. I expect I'll be able to work it out with that.

It looks like the upload started, but then a changenotify came in an flushed the dir from the cache. Then a bit later the directory was not found...

I'm not sure why that is - I'll check the code tomorrow.

It suggests a way to replicate though by using vfs/flush on the directory that a file is being uploaded from while it is being uploaded...

What happened is this

  • file started uploading
  • directory that the file is in was cleared from the cache
  • client asks to see the file
  • rclone re-reads the directory from the server
  • the file isn't there
  • BOOM

This is easy to replicate with vfs/forget and also not too surprising. The "virtual" directory entries rclone puts in for uploading files only live in the directory cache. This is so that when you do a list the file that you are uploading appears to be stored remotely, wheras it hasn't actually arrived in the remote yet.

There are two ways of fixing this - don't flush any directory cache entries with "virtual" items in. Or keep a separate note of the virtual entries... This is related to solving the restarted uploads disappearing problem too.

I'll have a think about this - expect a new beta shortly!

1 Like

Here is a new beta with the following fixes

  • Stop virtual directory entries dropping out of the directory cache
    • a virtual directory entry is an entry rclone has made because it is uploading a file but that file hasn't actually appeared in a directory listing yet. Rclone has made these since the early days of the VFS - they aren't a new thing.
    • this should fix @dotsam 's problem
    • it also fixes the problem of disappearing directories on bucket based backends (like S3) which has been around for ages!
  • Add recovered items on cache reload to directory listings
    • this means that if you stop the mount while something is being uploaded, when you restart it the upload will restart and the file being uploaded will appear in the directory listings (it didn't before)

https://beta.rclone.org/branch/v1.52.1-145-g4d9ad98a-vfs-beta/

(Note the Windows/386 build is missing for the moment - I'm not sure anyone is on 32 bit are they?)

2 Likes

This latest beta seems to be working well for me. No issue with a file not showing in the mount while uploading anymore, no other errors. Thanks for all your work on this, Nick! Caching ain't easy!

2 Likes

What's the best way of purging the cache? vfs/forget seems to purge the directory structure but not the cache. Should I just remove the cache and metadata directories manually?

Thanks for the update. I'm getting some "context cancelled" errors in the logs after the update.

2020/06/24 02:05:39 ERROR : Media/tv/American Dad!/Season 17/American Dad! - S17E10 - Trophy Wife, Trophy Life WEBDL-1080p.mkv.partial~: Failed to copy: Post "https://www.googleapis.com/upload/drive/v3/files?alt=json&fields=id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails&supportsAllDrives=true&uploadType=resumable&upload_id=AAANsUkPHjFGZRQAu7hlpW2hRzgoEFxTNGikfRHvIxM8fwjVvfIFek6StjyGu6NS5pq613GDZk9Psouef5ST3VDRzHw": context canceled
2020/06/24 02:06:02 ERROR : Media/tv/American Dad!/Season 17/American Dad! - S17E11 - Game Night WEBDL-1080p.mkv.partial~: Failed to copy: Post "https://www.googleapis.com/upload/drive/v3/files?alt=json&fields=id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails&supportsAllDrives=true&uploadType=resumable": context canceled
2020/06/24 02:07:21 ERROR : Media/tv/The Daily Show/Season 25/The Daily Show - 2020-06-22 - June 22, 2020 WEBDL-1080p.mkv.partial~: Failed to copy: Post "https://www.googleapis.com/upload/drive/v3/files?alt=json&fields=id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails&supportsAllDrives=true&uploadType=resumable&upload_id=AAANsUlRzEH-cpPto8eGadywgb6MdiSOfr0EZlKIPEfv3pj5_jH3xFxht7EARbGocTy2AqBu9vdYgJwuzwWhEK9RQTs": context canceled
2020/06/24 02:08:24 ERROR : Media/tv/Late Night with Seth Meyers/Season 7/Late Night with Seth Meyers - 2020-06-22 - Jason Sudeikis, Mike O'Brien WEBDL-1080p.mkv.partial~: Failed to copy: Post "https://www.googleapis.com/upload/drive/v3/files?alt=json&fields=id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails&supportsAllDrives=true&uploadType=resumable&upload_id=AAANsUlMG7NGYCpDGgsAjlIupwvqBBzlGxvzuMimQss-y-J1Ezb2oycYURSK6rU42mHE9HFONXCy1jrN9_kGiz4CMC9NXcOGRg": context canceled
2020/06/24 02:09:01 ERROR : Media/tv/VICE News Tonight/Season 4/VICE News Tonight - 2020-06-22 - Monday, June 22, 2020 WEBDL-1080p.mkv.partial~: Failed to copy: Post "https://www.googleapis.com/upload/drive/v3/files?alt=json&fields=id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails&supportsAllDrives=true&uploadType=resumable&upload_id=AAANsUkV5f0X0PZT0FQsMnw-olbbfZB3QWCXRG8agBQ8qAmpgc7OMyx5_8usCE5pXzldEZYqcY4qtfT03exWONeksDA": context canceled
2020/06/24 02:10:32 ERROR : Media/tv/The Late Show with Stephen Colbert/Season 5/The Late Show with Stephen Colbert - 2020-06-22 - James Corden, Laura Benanti, Bright Eyes WEBDL-1080p.mkv.partial~: Failed to copy: Post "https://www.googleapis.com/upload/drive/v3/files?alt=json&fields=id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails&supportsAllDrives=true&uploadType=resumable&upload_id=AAANsUnnCi32xTN17lVJVSrqlp_hGz56DQyKaqmM8kpDdjjrSezzuitsrNDkSqAeXlzhZduimfoYMWr92i3JDTeMwUhKpDUoYQ": context canceled

In other news, there only appears to be one transfer going at a time now, eg:

Media/movies/xxx.mkv.partial~

Great!

Good question!

There isn't currently a way of purging the cache.

Removing the directory will work fine - it will probably even be OK if you do it while the mount is running but I don't recommend that!

Ideas - I could so one/some/all of these

  • A vfs remote control API so you could purge it like that
  • A flag to purge the cache on startup
  • An rclone command to purge the cache

Thoughts?

Those context cancelled errors are rclone deciding that it didn't need to upload that file because it got modified.

The fact that they are all .partial~ files is encouraging.

There should be only one transfer per file? Or was that not what you meant?

edit I just remembered your other topic about multiple entries - yes - this is good :slight_smile:

Whatever's easiest but I think an rc API command is probably the most versatile. Maybe something like vfs/forget but augmented to not only bust the cache structure but also remove the files.

1 Like

Those context cancelled errors are rclone deciding that it didn't need to upload that file because it got modified.

The fact that they are all .partial~ files is encouraging.

On 5 seperate mounts the "context cancelled" is only occurring on one, so I suspect it's not rclone related. The transfer is successful regardless of the error. thanks

1 Like

Earlier you suggested I switch to --vfs-cache-mode full to benefit off your new features. I'd just like to confirm that using this cache is the most efficient way to mount read-only on Windows for media into a Plex server?

It does seem a piece of each file is saved to cache but updates can be painfully slow still. Which may not be avoidable. Command used is below, perhaps some parameters need to be adjusted if anyone can chime in. Appreciated it.

Rclone mount --allow-other --user-agent=RandomAgent --timeout=1h --cache-dir="D:\rclone_cache" --dir-cache-time=168h --max-read-ahead=512k --no-checksum --read-only --vfs-cache-max-age=700h --vfs-cache-mode=full --vfs-read-chunk-size=128M --vfs-read-chunk-size-limit=off --buffer-size=128M --vfs-cache-poll-interval=5m0s --tpslimit=35 --vfs-cache-max-size 50G --poll-interval=10m --log-level=NOTICE --log-file=D:\rclone_logs\rclone.log --rc --rc-web-gui --rc-addr=localhost:27773 --rc-user=test --rc-pass=test --config="C:\Users\home\.config\rclone\rclone.conf" 720p: C:\720p

If the plex server is in the habit of reading bits of each file, then it should help, yes

I think there might be plex settings which help too, but I'm not a plex expert...

Try a smaller buffer size - say 16M I don't think it needs to be this big and it will lead to over-downloading...

--buffer-size=128M

Guys, I took some time to test and I could see a problem that I'm not sure if it is this way of cache vfs. I use the rclone assembly exclusively for reading Plex, I do not have uploading this disc and when watching some content with subtitles (external or embedded), always when I get close to the end of the movie or episode the subtitle disappears, so I need to go back some second to get it working again. At first I thought it was a plex bug, but I tested it with the old way, and everything worked.

Below is the assembly I was using and had the problem with the subtitles.

[Unit]
Description = drive
After = network-online.target

[Service]
Type = simple
User = 0
Group = 0
RestartSec = 5
ExecStart = / usr / bin / rclonebeta mount gdrive: / mnt / gdrive
--config /home/holtzflix/.config/rclone/rclone.conf
--allow-other
--allow-non-empty
--poll-interval 1m
--gid = 1000
--uid = 1000
--umask 002
--fast-list
--user-agent "6xXThq9bnCDN4NMJ"
--tpslimit 10
--dir-cache-time 2m
--vfs-cache-mode full
--vfs-cache-poll-interval 1m
--vfs-cache-max-size 30G
--vfs-cache-max-age 168h
--vfs-read-chunk-size 32M
--vfs-read-chunk-size-limit 1G
--drive-chunk-size 16M
--buffer-size 16M
--log-file /opt/cache-rclone.log
--log-level NOTICE

ExecStop = / bin / fusermount -uzq / mnt / gdrive
Restart = on-failure
TimeoutStopSec = 20s
KillMode = none
RemainAfterExit = yes

[Install]
WantedBy = multi-user.target

Before testing this version I had been using the standard cache mode, and it is like that in .config.

[cache] type = cache remote = gdrive: chunk_size = 16M info_age = 1h chunk_path = /mnt/Cache/rclone db_path = /mnt/Cache/db chunk_total_size = 30G

My question is: Is there any relationship between the beta mode and the parameters of the [cache] of the .config?

Hmm, that sounds like a difficult problem to diagnose. Are there any errors in the rclone log?

I don't see anything wrong with your setup.

Hello

I am trying to test the new vfs cache funcionality. I understand that using vfs-cache-model full should download chunks of a file and save these to disk. However, when I try to test this functionality, it appears that rclone will download the entire file at once before I can open the file.

I am on Windows 10 and I am using rclone v1.52.2-132-g61e4b4db-beta. I mount my crypt google drive with the following command:

rclone mount gdrive_enc: U: ^
--vfs-cache-mode full ^
--vfs-cache-max-age 240h ^
--vfs-cache-max-size 100G ^
--vfs-read-chunk-size 4M ^
--vfs-read-chunk-size-limit 128M ^
--cache-dir "D:\cache" ^
--buffer-size 8M ^
--allow-other  ^
--log-file D:\logs\gdrive_enc.txt ^
--log-level DEBUG

Whenever I open up a folder in the mount that contains a media file in Windows Explorer (WE), it will hang until the whole file has been downloaded. I know WE is probably trying to read media info off the file, but I would expect that would only read a few 'chunks' of the file to get this?

Also, if I open a media file with VLC, it will also hang until the entire file has been downloaded. I know this because of (1) the time it takes to open and (2) If I go into the cache folder, I can open the local media file and play it in its entirety from start to finish, with no delay.

Is this as intended and have I misunderstood how the new vfs cache should work? I was hoping that if I started watching a video file, it would only download the initial chunks to start video playback. These would be kept on disk so I could instantly rewind a few minutes without having to re-download any of the video file.

Let me know if you believe this could be an issue on my end and I will post a log file.

Thanks and keep up the great work!

You'd need to post a log file.