Hello, sorry, my bad.
Just to summarize what I'm doing in my test procedure for both copy/sync (works fine) and mount CtrlC-Ctrp-P (works terribly slow).
For simplification one big test file ~4.5GB test.mp4 is downloaded in both use cases.
Downloaded with below "rclone copy" gets there in less than 4minutes and 20MB/s transfer, all nice here, blazing fast:
rclone -P --transfers 20 --disable-http2 --multi-thread-streams=20 --multi-thread-cutoff=200M copy "koofr:Pub/test.mp4" Downloads/
But when I'm doing this big test file transfer via the mount operation + Nautilus File Explorer (exactly as specified in my initial post, with same flags as for 'rclone copy') transfer is slashed to ~1MB (It's currently ongoing with ETA of 1h more...
).
Remark 1: for a moment I've changed vfs-cache-mode from 'writes' to 'full' but no difference in download speed via Nautilus File Explorer, still ~1MB/s...
Remark 2: It's funny, but upload speeds seem to be much nicer and it gets to 8-10MB/s similar to upload with copy/sync. I'm checking the logs to see when file actually uploaded as Nautilus reports completion of upload very quickly due to vfs-cache, all as expected)
Logs of download via mount with "-vv" option are probably just endless stream of following similar lines :
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=446824448
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=446955520
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=447086592
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=447217664
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=447348736
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=447479808
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:29 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=447610880
2023/06/14 18:46:31 DEBUG : Pub/test.mp4: ChunkedReader.Read at 448786432 length 1048576 chunkOffset 402653184 chunkSize 536870912
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=447741952
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=447873024
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448004096
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448135168
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448266240
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448397312
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448528384
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:31 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448659456
2023/06/14 18:46:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2023/06/14 18:46:32 DEBUG : Pub/test.mp4: ChunkedReader.Read at 449835008 length 1048576 chunkOffset 402653184 chunkSize 536870912
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448790528
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=448921600
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=449052672
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=449183744
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=449314816
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=449445888
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=449576960
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:32 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=449708032
2023/06/14 18:46:33 DEBUG : Pub/test.mp4: ChunkedReader.Read at 450883584 length 1048576 chunkOffset 402653184 chunkSize 536870912
2023/06/14 18:46:33 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
2023/06/14 18:46:33 DEBUG : &{Pub/test.mp4 (r)}: Read: len=131072, offset=449839104
2023/06/14 18:46:33 DEBUG : &{Pub/test.mp4 (r)}: >Read: read=131072, err=<nil>
Every 10 seconds also occurs (as expected for "writes" vfs-cache-mode with 10s polling) below line:
2023/06/14 18:46:21 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)