Cache mount not showing files in cache-tmp-upload-path

Help and Support
1

I’m transitioning from using rclone cache to vfs. My plan is to continue using the cache mount to upload files to gdrive (I prefer doing it this way rather than via unionfs, as I’m trying to do everything in rclone) and then to use the vfs mount for media playback via plex i.e. mount both at the same time.

I’ve got 5.5TB of files queued in my cache-tmp-upload-path and I’ve just noticed that a lot of files aren’t showing in my cache mount - I’ve verified this by mounting my cache-tmp-upload-path at /mnt/disks/plex_media_uploading so I can see the decrypted files.

I’ve tried mounting just the cache to see if there’s some conflict between having the cache and a vfs mount at the same time, and the files were still missing.

Any ideas what the problem is? I’m not panicking as worst case I can create an rclone move job to move the missing encrypted files from my cache-tmp-upload-path straight to gd and hopefully at some point the cache will get back in sync.

Thanks in advance for any help

# Mount rclone cache

rclone mount --allow-other --dir-cache-time=360h --cache-chunk-path=/tmp/rclone/cache --cache-db-path=/tmp/rclone/cache --cache-chunk-size=10M --cache-total-chunk-size=8G --cache-info-age=368h --cache-db-purge --cache-workers=5 --cache-tmp-upload-path=/mnt/user/rclone_upload --cache-tmp-wait-time=60m --buffer-size 100M --umask 002 --log-level INFO --stats 1m gdrive_media: /mnt/disks/google_media &

# Mount rclone vfs mount

rclone mount --allow-other --dir-cache-time 8h --cache-dir=/tmp/rclone/vfs --vfs-cache-max-age 48h --vfs-read-chunk-size 64M --vfs-read-chunk-size-limit 512M --buffer-size 128M --syslog --umask 002 --rc --log-level INFO --stats 1m gdrive_media_vfs: /mnt/disks/plex_media &

# Mount rclone cache temp upload path

rclone mount --allow-other --dir-cache-time 5m --cache-dir=/tmp/rclone/temp --vfs-cache-max-age 1h --vfs-read-chunk-size 128M --vfs-read-chunk-size-limit 512M --buffer-size 128M --syslog --umask 002 --rc --log-level INFO --stats 1m cache_upload_temp: /mnt/disks/plex_media_uploading &
2

It might be worth trying the latest beta if you haven’t already.

There was a similar thread to this which I can’t find right now about files not being uploaded from the cache tmp file.

3

Thanks @ncw. I’m on the latest beta.

I think files are still getting uploaded (can’t tell though if it’s the old 5.5TB being uploaded or newer files). My problem is the cache mount while is supposed to show remote+local files, isn’t showing the local ones.

4

Where does the cache keep a record of what’s in the remote and what’s waiting to be transferred to provide a merged view to users? Or, does it just combine what it sees in both locations?

I’ve restarted a few times, and my cache still can’t see old files in the tmp location. Once I’ve managed to manually transfer the old files, I’ll be able to better see if it’s picking up new files.

Edit: Also, it doesn’t seem to be obeying cache-tmp-wait-time. Mine’s set at 60m, yet files I’m adding now are being transferred at the same time as they are being added to the cache. Or, are the logs showing files being added to cache-tmp-upload-path as the details in the logs aren’t encrypted?

2018/07/02 08:40:50 INFO : 
Transferred: 3.896 GBytes (8.283 MBytes/s)
Errors: 0
Checks: 0
Transferred: 3
Elapsed time: 8m1.6s
Transferring:
* ...EBDL-1080p x264 AC3 [EN+NL+FR+DE+ES].mkv: 0% /off, 6.038M/s, -
* ...Fight or Flight WEBDL-1080p x264 AAC.mkv: 0% /off, 5.856M/s, -
5

I’m having a tough time figuring out what mount/log goes with what.

Can you share your mount line along with a a snippet of a ls -alR of your cache-tmp-upload area?

You’d normally see in the log a cache expiration message and you have all 3 mounts writing to syslog so your logs are kinda overlapping. If you want to create separate files, it might be easier to track it down and just use the --log-file /home/user/somelog.log

6

I’ve ditched my multiple mount plan and gone back to using unionfs to combine remote and local files, and I’m running a manual upload job to shift the local cache files that seemed to be stuck.

7

ok, I’ve gone back to this as I really want to get this working instead of unionfs. I’ve created a new cache mount location for new files, while I manually transfer the old pending files from the old tmp directory.

@ncw What I’ve noticed is that this version doesn’t seem to be obeying --cache-tmp-wait-time=90m and is transferring files immediately. This is hitting my transfer rate as I think it’s trying to upload files at the same time as they are being transferred locally to the cache mount.

rclone mount --allow-other --dir-cache-time=360h --cache-chunk-path=/tmp/rclone/cache --cache-db-path=/tmp/rclone/cache --cache-chunk-size=10M --cache-total-chunk-size=8G --cache-info-age=368h --cache-db-purge --cache-workers=5 --cache-tmp-upload-path=/mnt/user/rclone/cache --cache-tmp-wait-time=90m --buffer-size 100M --umask 002 --log-level INFO --stats 1m gdrive_media: /mnt/disks/rclone_cache

I’m running rclone v1.42-015-gb9b9bce0β

here’s a log excerpt showing transfers before the 90 mins are up - 32 at 1h21m. This is just for the cache mount. The files that are ‘transferring’ are ones I’m trying to add to the cache mount and I’m getting 1MB/s as it looks like rclone cache is uploading them in real-time, even before the 90mins is up

2018/07/03 17:59:14 INFO : 
Transferred: 22.596 GBytes (4.760 MBytes/s)
Errors: 0
Checks: 0
Transferred: 32
Elapsed time: 1h21m1.5s
Transferring:
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 67.954k/s, -
* ...randma Tourismo WEBDL-1080p h264 AAC.mkv: 0% /off, 67.672k/s, -

2018/07/03 18:00:14 INFO : 
Transferred: 22.700 GBytes (4.723 MBytes/s)
Errors: 0
Checks: 0
Transferred: 32
Elapsed time: 1h22m1.5s
Transferring:
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 1.143M/s, -
* ...randma Tourismo WEBDL-1080p h264 AAC.mkv: 0% /off, 744.257k/s, -

2018/07/03 18:01:14 INFO : 
Transferred: 22.776 GBytes (4.682 MBytes/s)
Errors: 0
Checks: 0
Transferred: 32
Elapsed time: 1h23m1.5s
Transferring:
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 1.102M/s, -
* ...randma Tourismo WEBDL-1080p h264 AAC.mkv: 0% /off, 1.544M/s, -

2018/07/03 18:02:14 INFO : 
Transferred: 23.055 GBytes (4.683 MBytes/s)
Errors: 0
Checks: 0
Transferred: 32
Elapsed time: 1h24m1.5s
Transferring:
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 3.676M/s, -
* ...randma Tourismo WEBDL-1080p h264 AAC.mkv: 0% /off, 3.258M/s, -

2018/07/03 18:02:54 INFO : 8r5frf57gimmo5kfi0bbgcvocs/tiv7964qrk1ep00nqph92qn726nhg2espi2l86gqn0bubblti09g/p4hnt5thi5hnauiq5dlq279t9o/nvfpgfc8n711os3ju5c37i3h61r3e7du65m5nnkpd8do17v8lmd91qjmd4phgfkavrcsk6rvg7mmeaiimeaik8kl5lu0jh1c7d0034ilohjv2ipva3jdrotfubq59ek7: put: uploaded in temp fs
2018/07/03 18:02:54 INFO : 8r5frf57gimmo5kfi0bbgcvocs/tiv7964qrk1ep00nqph92qn726nhg2espi2l86gqn0bubblti09g/p4hnt5thi5hnauiq5dlq279t9o/nvfpgfc8n711os3ju5c37i3h61r3e7du65m5nnkpd8do17v8lmd91qjmd4phgfkavrcsk6rvg7mmeaiimeaik8kl5lu0jh1c7d0034ilohjv2ipva3jdrotfubq59ek7: put: queued for upload
2018/07/03 18:02:54 INFO : 8r5frf57gimmo5kfi0bbgcvocs/tiv7964qrk1ep00nqph92qn726nhg2espi2l86gqn0bubblti09g/p4hnt5thi5hnauiq5dlq279t9o: put: cache expired
2018/07/03 18:03:14 INFO : 
Transferred: 23.689 GBytes (4.755 MBytes/s)
Errors: 0
Checks: 0
Transferred: 33
Elapsed time: 1h25m1.5s
Transferring:
* ...9 - Clean Sweep WEBDL-1080p h264 AAC.mkv: 0% /off, 3.334M/s, -
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 4.419M/s, -

2018/07/03 18:04:14 INFO : 
Transferred: 24.222 GBytes (4.805 MBytes/s)
Errors: 0
Checks: 0
Transferred: 33
Elapsed time: 1h26m1.5s
Transferring:
* ...9 - Clean Sweep WEBDL-1080p h264 AAC.mkv: 0% /off, 4.496M/s, -
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 4.508M/s, -

2018/07/03 18:05:14 INFO : 
Transferred: 24.696 GBytes (4.843 MBytes/s)
Errors: 0
Checks: 0
Transferred: 33
Elapsed time: 1h27m1.5s
Transferring:
* ...9 - Clean Sweep WEBDL-1080p h264 AAC.mkv: 0% /off, 4.196M/s, -
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 4.106M/s, -

2018/07/03 18:06:14 INFO : 
Transferred: 25.156 GBytes (4.877 MBytes/s)
Errors: 0
Checks: 0
Transferred: 33
Elapsed time: 1h28m1.5s
Transferring:
* ...9 - Clean Sweep WEBDL-1080p h264 AAC.mkv: 0% /off, 3.769M/s, -
* ...et WEBDL-1080p Proper h264 EAC3 [EN].mkv: 0% /off, 3.561M/s, -

2018/07/03 18:06:16 INFO : 8r5frf57gimmo5kfi0bbgcvocs/tiv7964qrk1ep00nqph92qn726nhg2espi2l86gqn0bubblti09g/p4hnt5thi5hnauiq5dlq279t9o/2rcs128gr8uf71o65p8814n0uc6eo7i5ibevvil8vn7rgmgfjv4l6fcke9600qfn8ukgk6uej3ubvotai8b69mrvb1ic0gp8q98eje1umgj878lc5hgh94oqcqf65vdn: put: uploaded in temp fs
2018/07/03 18:06:16 INFO : 8r5frf57gimmo5kfi0bbgcvocs/tiv7964qrk1ep00nqph92qn726nhg2espi2l86gqn0bubblti09g/p4hnt5thi5hnauiq5dlq279t9o/2rcs128gr8uf71o65p8814n0uc6eo7i5ibevvil8vn7rgmgfjv4l6fcke9600qfn8ukgk6uej3ubvotai8b69mrvb1ic0gp8q98eje1umgj878lc5hgh94oqcqf65vdn: put: queued for upload
2018/07/03 18:06:16 INFO : 8r5frf57gimmo5kfi0bbgcvocs/tiv7964qrk1ep00nqph92qn726nhg2espi2l86gqn0bubblti09g/p4hnt5thi5hnauiq5dlq279t9o: put: cache expired
8

Ok. I did a bit of testing and the stats kind of confuses the messaging in there as I’d probably remove that line.

You should see a start upload message in the logs.

Here is an example of your version with a 3 minute rest time:

2018/07/03 13:51:32 INFO  : gcachetest: File Age: 368h0m0s
2018/07/03 13:51:32 INFO  : gcachetest: Upload Temp Rest Time: 3m0s
2018/07/03 13:51:32 INFO  : gcachetest: Upload Temp FS: /data/test
2018/07/03 13:51:38 INFO  : rs88l6p51j4kp0g9if3j294ts0: put: uploaded in temp fs
2018/07/03 13:51:38 INFO  : rs88l6p51j4kp0g9if3j294ts0: put: queued for upload
2018/07/03 13:51:38 INFO  : : put: cache expired
2018/07/03 13:51:38 INFO  : hosts: Copied (new)
2018/07/03 13:52:33 INFO  :
Transferred:    868 Bytes (14 Bytes/s)
Errors:                 0
Checks:                 0
Transferred:            1
Elapsed time:      1m1.3s

2018/07/03 13:53:33 INFO  :
Transferred:    868 Bytes (7 Bytes/s)
Errors:                 0
Checks:                 0
Transferred:            1
Elapsed time:      2m1.3s

2018/07/03 13:54:33 INFO  :
Transferred:    868 Bytes (4 Bytes/s)
Errors:                 0
Checks:                 0
Transferred:            1
Elapsed time:      3m1.3s

2018/07/03 13:54:38 INFO  : rs88l6p51j4kp0g9if3j294ts0: background upload: started upload
2018/07/03 13:54:39 INFO  : rs88l6p51j4kp0g9if3j294ts0: Copied (new)
2018/07/03 13:54:39 INFO  : rs88l6p51j4kp0g9if3j294ts0: Deleted
2018/07/03 13:54:39 INFO  : rs88l6p51j4kp0g9if3j294ts0: background upload: uploaded entry
2018/07/03 13:54:39 INFO  : rs88l6p51j4kp0g9if3j294ts0: finished background upload

It waited 3 minutes properly.