Rclone mount and "failed to wait for in-sequence"

[Rootax]

What is the problem you are having with rclone?

Hello,

I'm using Rclone (1.51, and lastest beta at this time), under Windows 10. When I'm using rclone mount (to mount a gdrive encrypt target), I've a lot of "failed to wait for in-sequence" errors.

At first, I didn't care about them, but now I believe it's the reason why my dl speed from the mount is irregular (like fast fast fat - temporary stop/slowdown -fast fast -fast - temporary stop/slowdown, etc).

The command used right now is :
rclone.exe mount --cache-dir c:\mountcache --attr-timeout 60s -v --stats 10s --buffer-size 64M --vfs-cache-poll-interval 30s --poll-interval 60s --dir-cache-time 240s --async-read=false --vfs-read-wait 10ms --vfs-write-wait 10s --vfs-cache-mode writes --vfs-read-chunk-size 16M --vfs-read-chunk-size-limit 64M --local-no-check-updated --drive-chunk-size=256M --vfs-case-insensitive --vfs-cache-max-size 200G "gdriveencryptedownapi:seedold" G:

I tried with --async-read=true, same problem. I tried with an increased --vfs-read-wait value (up to 2s), same stuff. I tried with no buffer, smaller read chunck size, etc...

Any idea if this is normal or not ? Thx.

When the error come, it looks like that :

2020/05/04 09:02:30 DEBUG : /BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: Read: ofst=117184133, fh=0x2
2020/05/04 09:02:30 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: waiting for in-sequence read to 117184133 for 10ms
2020/05/04 09:02:30 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: aborting in-sequence read wait, off=117184133
2020/05/04 09:02:30 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: failed to wait for in-sequence read to 117184133
2020/05/04 09:02:30 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: ChunkedReader.Read at 182486661 length 1048576 chunkOffset 165713541 chunkSize 67108864
2020/05/04 09:02:30 DEBUG : /BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: >Read: n=524288
2020/05/04 09:02:30 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: ChunkedReader.Read at 183535237 length 1048576 chunkOffset 165713541 chunkSize 67108864
2020/05/04 09:02:32 DEBUG : /BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: Read: ofst=118167173, fh=0x2
2020/05/04 09:02:32 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: waiting for in-sequence read to 118167173 for 10ms
2020/05/04 09:02:32 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: aborting in-sequence read wait, off=118167173
2020/05/04 09:02:32 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: failed to wait for in-sequence read to 118167173
2020/05/04 09:02:32 DEBUG : /BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: >Read: n=524288
2020/05/04 09:02:32 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: ChunkedReader.Read at 184583813 length 1048576 chunkOffset 165713541 chunkSize 67108864
2020/05/04 09:02:37 DEBUG : /BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: Read: ofst=119166597, fh=0x2
2020/05/04 09:02:37 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: waiting for in-sequence read to 119166597 for 10ms
2020/05/04 09:02:37 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: aborting in-sequence read wait, off=119166597
2020/05/04 09:02:37 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: failed to wait for in-sequence read to 119166597
2020/05/04 09:02:37 DEBUG : /BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: >Read: n=409600
2020/05/04 09:02:37 DEBUG : BLUE GENDER/(G_P) Blue Gender 09(x264)(E578DABB).mkv: ChunkedReader.Read at 185632389 length 1048576 chunkOffset 165713541 chunkSize 67108864

[ncw (Nick Craig-Wood)]

It looks like two things are reading that stream at once. Is that the case? If so that is a case that rclone doesn't deal with well at the moment.

What is doing the reading BTW?

[Rootax]

I have this error when the windows explorer is generating thumbnail for video files, and (and it's mostly that) when the files are seeding in my torrent client. Qbittorent is reading blocs per blocs I guess, and try to access the same file at multiple "place" at the same time ?
Note that I don't write on this mount, only read. Is this a rclone problem, or a winfsp one ?

[ncw (Nick Craig-Wood)]

It is the reading at multiple places in the file at once which is the problem. Rclone has an implicit assumption that there is only one stream reading from a file at once, but rclone can't actually tell from the file system interface.

So what is happening is when the torrent reads from different places in the file then rclone will close the stream and re-open it at the new place. Since there are multiple readers from the file at once it will be doing this all the time.

You could try --vfs-cache-mode full which will download the file first. I'm in the process of finalising a major change to this mode which will mean it does partial downloads and that is probably the mode you want when I've merged it.

[Rootax]

Thx a lot for the explanation

I'll wait a new beta then. Will this include a vfs read cache, or this is not related ?

[ncw (Nick Craig-Wood)]

I won't stick this in the beta until after 1.52 is released so a couple of weeks from now.