Rclone cache uses only 1 worker

prc2k10 · March 20, 2018, 10:51am

Hi together,

i don't know if this is a bug but i have a problem with my rclone setup. I created a cache remote and use the plex integration. When i play a file i recognize that only 1 cache worker is used, but i configured 4 cache workers in my config.

Here is my rclone version:

rclone v1.40

os/arch: linux/amd64

go version: go1.10

Here is the log when i play a file:

2018-03-20T10:14:21.885Z,"media","2018/03/20 10:14:21 DEBUG : worker-0 : downloaded chunk 20971520"
2018-03-20T10:14:28.050Z,"media","2018/03/20 10:14:28 DEBUG : worker-0 : downloaded chunk 62914560"
2018-03-20T10:14:22.650Z,"media","2018/03/20 10:14:22 DEBUG : worker-0 : downloaded chunk 26214400"
2018-03-20T10:14:29.013Z,"media","2018/03/20 10:14:29 DEBUG : worker-0 : downloaded chunk 68157440"
2018-03-20T10:14:23.199Z,"media","2018/03/20 10:14:23 DEBUG : worker-0 : downloaded chunk 31457280"
2018-03-20T10:14:29.814Z,"media","2018/03/20 10:14:29 DEBUG : worker-0 : downloaded chunk 73400320"
2018-03-20T10:14:23.708Z,"media","2018/03/20 10:14:23 DEBUG : worker-0 : downloaded chunk 36700160"
2018-03-20T10:14:31.310Z,"media","2018/03/20 10:14:31 DEBUG : worker-0 : downloaded chunk 83886080"
2018-03-20T10:14:30.648Z,"media","2018/03/20 10:14:30 DEBUG : worker-0 : downloaded chunk 78643200"
2018-03-20T10:14:25.844Z,"media","2018/03/20 10:14:25 DEBUG : worker-0 : downloaded chunk 52428800"
2018-03-20T10:14:20.123Z,"media","2018/03/20 10:14:20 DEBUG : worker-0 : downloaded chunk 10485760"
2018-03-20T10:14:20.996Z,"media","2018/03/20 10:14:20 DEBUG : worker-0 : downloaded chunk 15728640"
2018-03-20T10:14:27.261Z,"media","2018/03/20 10:14:27 DEBUG : worker-0 : downloaded chunk 57671680"
2018-03-20T10:14:19.034Z,"media","2018/03/20 10:14:19 DEBUG : worker-0 : downloaded chunk 5242880"
2018-03-20T10:14:24.358Z,"media","2018/03/20 10:14:24 DEBUG : worker-0 : downloaded chunk 41943040"
2018-03-20T10:14:25.284Z,"media","2018/03/20 10:14:25 DEBUG : worker-0 : downloaded chunk 47185920"
2018-03-20T10:14:17.990Z,"media","2018/03/20 10:14:17 DEBUG : worker-0 : downloaded chunk 0"
2018-03-20T10:14:44.728Z,"media","2018/03/20 10:14:41 DEBUG : worker-0 : downloaded chunk 141557760"
2018-03-20T10:14:40.047Z,"media","2018/03/20 10:14:40 DEBUG : worker-0 : downloaded chunk 131072000"
2018-03-20T10:14:41.288Z,"media","2018/03/20 10:14:40 DEBUG : worker-0 : downloaded chunk 136314880"
2018-03-20T10:14:32.280Z,"media","2018/03/20 10:14:32 DEBUG : worker-0 : downloaded chunk 89128960"
2018-03-20T10:14:38.409Z,"media","2018/03/20 10:14:38 DEBUG : worker-0 : downloaded chunk 120586240"
2018-03-20T10:14:39.049Z,"media","2018/03/20 10:14:39 DEBUG : worker-0 : downloaded chunk 125829120"
2018-03-20T10:14:37.873Z,"media","2018/03/20 10:14:37 DEBUG : worker-0 : downloaded chunk 115343360"
2018-03-20T10:14:35.538Z,"media","2018/03/20 10:14:35 DEBUG : worker-0 : downloaded chunk 99614720"
2018-03-20T10:14:36.405Z,"media","2018/03/20 10:14:36 DEBUG : worker-0 : downloaded chunk 104857600"
2018-03-20T10:14:37.338Z,"media","2018/03/20 10:14:37 DEBUG : worker-0 : downloaded chunk 110100480"
2018-03-20T10:14:32.802Z,"media","2018/03/20 10:14:32 DEBUG : worker-0 : downloaded chunk 94371840"
2018-03-20T10:14:50.042Z,"media","2018/03/20 10:14:42 DEBUG : worker-0 : downloaded chunk 146800640"
2018-03-20T10:14:53.302Z,"media","2018/03/20 10:14:42 DEBUG : worker-0 : downloaded chunk 152043520"
2018-03-20T10:14:57.952Z,"media","2018/03/20 10:14:43 DEBUG : worker-0 : downloaded chunk 157286400"
2018-03-20T10:17:45.429Z,"media","2018/03/20 10:17:45 DEBUG : worker-0 : downloaded chunk 20971520"
2018-03-20T10:17:48.618Z,"media","2018/03/20 10:17:48 DEBUG : worker-0 : downloaded chunk 47185920"
2018-03-20T10:17:43.864Z,"media","2018/03/20 10:17:43 DEBUG : worker-0 : downloaded chunk 26214400"
2018-03-20T10:17:46.083Z,"media","2018/03/20 10:17:46 DEBUG : worker-0 : downloaded chunk 41943040"
2018-03-20T10:17:44.422Z,"media","2018/03/20 10:17:44 DEBUG : worker-0 : downloaded chunk 31457280"
2018-03-20T10:17:42.489Z,"media","2018/03/20 10:17:42 DEBUG : worker-0 : partial downloaded chunk 6.045G"
2018-03-20T10:17:44.851Z,"media","2018/03/20 10:17:44 DEBUG : worker-0 : downloaded chunk 15728640"

Here is my rclone config:

[xxx-cache]
type = cache
remote = xxx:
plex_url = http://x.x.x.x:32400
plex_username = xxx
plex_password = xxx
chunk_size = 5M
info_age = 24h
chunk_total_size = 40G
plex_token = xxx

Here is my local mount rclone config

[xxx-crypt]
type = crypt
remote = xxx-cache:xxx
filename_encryption = standard
password = xxx
password2 = xxx

And here is my rclone mount:

rclone mount --config=/config/rclone.conf --buffer-size 256M --checkers 8 --cache-writes --allow-non-empty --allow-other --uid 1500 --gid 2500 --vfs-cache-mode off --vfs-cache-max-age 1h0m0s --log-level DEBUG --cache-chunk-size 5M --cache-total-chunk-size 40G --cache-info-age 24h --cache-workers 4 --cache-chunk-path /chunks --cache-db-path /chunks/db --cache-db-purge xxx-crypt: /cloud-decrypt

I hope someone can help me.

Thanks
cheers

prc2k10

ncw · March 20, 2018, 11:06am

This was discussed here Speed disparity between mount and copy

I think it is to do with the plex integration.

prc2k10 · March 20, 2018, 11:14am

okay i downgraded plex to the latest public version:

2018-03-20T11:12:39.977Z,"media","2018/03/20 11:12:08 DEBUG : worker-0 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 15728640"
2018-03-20T11:13:11.032Z,"media","2018/03/20 11:12:38 DEBUG : worker-2 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 68157440"
2018-03-20T11:13:11.049Z,"media","2018/03/20 11:12:38 DEBUG : worker-3 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 62914560"
2018-03-20T11:12:10.295Z,"media","2018/03/20 11:11:36 DEBUG : worker-0 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 5242880"
2018-03-20T11:12:39.976Z,"media","2018/03/20 11:12:08 DEBUG : worker-2 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 20971520"
2018-03-20T11:13:39.708Z,"media","2018/03/20 11:13:08 DEBUG : worker-1 : downloaded chunk 10485760"
2018-03-20T11:13:39.713Z,"media","2018/03/20 11:13:09 DEBUG : worker-3 : downloaded chunk 20971520"
2018-03-20T11:12:55.580Z,"media","2018/03/20 11:12:23 DEBUG : worker-1 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 47185920"
2018-03-20T11:12:55.581Z,"media","2018/03/20 11:12:23 DEBUG : worker-2 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 36700160"
2018-03-20T11:12:24.768Z,"media","2018/03/20 11:11:52 DEBUG : worker-0 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 10485760"
2018-03-20T11:12:39.977Z,"media","2018/03/20 11:12:08 DEBUG : worker-3 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 26214400"
2018-03-20T11:12:39.978Z,"media","2018/03/20 11:12:08 DEBUG : worker-1 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 31457280"
2018-03-20T11:12:55.582Z,"media","2018/03/20 11:12:23 DEBUG : worker-3 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 52428800"
2018-03-20T11:13:25.215Z,"media","2018/03/20 11:12:53 DEBUG : worker-0 : downloaded chunk 0"
2018-03-20T11:11:54.585Z,"media","2018/03/20 11:11:21 DEBUG : worker-0 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 0"
2018-03-20T11:13:11.031Z,"media","2018/03/20 11:12:37 DEBUG : worker-0 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 57671680"
2018-03-20T11:13:11.034Z,"media","2018/03/20 11:12:38 DEBUG : worker-1 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 73400320"
2018-03-20T11:12:55.577Z,"media","2018/03/20 11:12:23 DEBUG : worker-0 <9hgof4r9u88chnh7qa6i0lg1e90t9k9bm49qo7ldijoj7j75va90>: downloaded chunk 41943040"
2018-03-20T11:13:39.709Z,"media","2018/03/20 11:13:09 DEBUG : worker-0 : downloaded chunk 5242880"
2018-03-20T11:13:39.710Z,"media","2018/03/20 11:13:09 DEBUG : worker-2 : downloaded chunk 15728640"

looks better now.

spicypixel · March 20, 2018, 12:30pm

Yeah remusb is working on using websockets to get playback information, should then work with plexpass and such going forth assuming no major breaks in how plex presents the information.

remus.bunduc · March 20, 2018, 4:04pm

This is the issue for this: https://github.com/ncw/rclone/issues/2102 (although the original issue was fixed)

remus.bunduc · March 22, 2018, 9:20pm

so this made it in the latest beta: https://beta.rclone.org/v1.40-012-g0ed0d9a7/ (it will be a few mins more to populate the others)

It’s using @daniel-loader 's suggestion with websockets and I managed to update to the troubled version to confirm it works with it too.