I've been on 1.51 on Ubuntu 20 now for a number of weeks and I've not noticed the issue for me. My mergerfs mount already has "async_read=false" on the startup so not sure if that masks it or not as it would read sync to rclone I believe.
I don't use mergerfs. I read straight from rclone mounts...
Been using rclone betas and never had any async flags set. No issues
I have tested it yesterday. Get constantly-high-iowait under load.
I haven't created a debug log to check failed to wait for in-sequence read errors.
Will do this soon.
I think IOWAIT is a feature of async reading. I don't think it really means anything other than the kernel is sleeping waiting for rclone to produce the data.
The kernel asks for block x and x+1 very quickly. Rclone delivers block x then has to wait for x+1 to be downloaded before it can satisfy the demand for block x+1.
That is my theory anyway!
That would be great - thanks
@ncw do you think async reading uses more bandwidth than sync read?
I think I'm going to play with this. If it uses more bandwidth then I will disable it.
The way I see, this async reading is like the read-ahead which causes more API hits and bandwidth waste?
Think of it like an order of operations. A sync read goes in order and asks for A and waits for A to get back and goes to B.
Async it asks for A and B at the same time and they can return out of order back as you might get B before A.
Like for a database, you want to leverage async IO so it can do many reads and return what comes back when it comes back and not wait for A / B / C in order.
Good little article from Oracle that breaks it down:
https://docs.oracle.com/cd/E19253-01/816-4854/character-11/index.html
For you, I think it might be beneficial to take advantage of as you have a large number of streams going on. You see more about it now as it's become a bit more main stream in the newer Linux kernels.
Have tested --async-read=true successfully. 10min / 100MB Log no failed to wait for in-sequence read found. I see a lot of waiting for in-sequence read to 8241152 for 20ms but no fails.
My Setup has a bit changed the past weeks
Ubuntu 20.04 / Kernel 5.4.0-28 / rclone v1.51.0-360-g518d3981-beta
Will test --async-read=true from now on to give more feedback
rclone has already proved that is able to max most connections even without async reading so I don't think this makes any difference. We only need to read a file faster than it's bitrate to sustain any real world real time operation anyway.
It does looks like it's something that can cause issues if you have too many open files on the mount.
With sync read and 200 files, you'd request 200 chunks/sec. WIth async reading you'd be doing 400 chunks/sec. Is my reading right?
Assuming infinite bandwidth and unlimited API quota, that is awesome. But in real world where you are already maxing your connection I don't see how this can improve things more than cause issues not counting the bug in this thread.
Anyway I just rebooted 2 servers to reset nload stats and I'll test them with async and without async to see the impact of those settings on bandwidth usage
EDIT:
So testing with 3 servers, 2 with async and one without:
The server without async had an average bandwidth 50% lower than servers with async reads.
Servers with async reading had ridiculous peaks of bandwidth I never seen before. Like 500 Mbps for ~15 files open...each probably had less than 5 Mbps average bitrate
Servers with async reads in average had peaks 2x bigger than servers with sync reads
DO NOT USE ASYNC UNLESS YOU WANT TO READ FEW FILES FAST VS MANY FILES AT ONCE
I had to disable async as it's was clear that it was using a ridiculous amount of bandwidth. In real world bandwidht is not infinite, and the goal of a mount should be to open as much files as possible ensuring enough speeds for real-time usage.
Also I think I found a bug...my server without async still had failed to wait for in-sequence read errors in the logs...is this normal?
When did async read became default in rclone betas?
That is excellent news - thanks 
It was those failed to wait which were killing the performance, but I think they were caused by a race condition which I've fixed now.
The waiting for in-sequence reads are normal as somehow rclone gets asked for the blocks out of order.
In my tests I found that newer kernels needed the async option otherwise their max performance was much lower. Now if you are using it for streaming so not reading 100s MB/s from the mount you probaby won't notice the difference between sync and async.
I put the async mode in precisely because the sync mode gave awful performance with 5.x kernels. However it is possible that it has been fixed in later ones - I haven't tested recently!
I am using kernel 5.7rc with rclone beta (in sync mode) and can't complain about speed. Single file transfer around 500mbit/s
1 Like
Is it normal to have messages about failed to wait even with async disabled ? I'm seeing that a lot.
Truncated my logs and in less than 2 minutes there are 14 error messages like this. And I'm sure I'm using --async-read=false
I use kernel 5.6.4
Hmm, no that would seem strange as that flag should force it to use sync_read instead. At the beginning of the debug, did it show that in the options? Could be a problem with the beta maybe too if you can share the version.
I checked with the service status...
service vfs status and I can see the loaded config flags... I can't restart my mount right now.
I'm using rclone v1.51.0-360-g518d3981-beta. I did notice my bandwidth usage was higher than normal... I think that flag is broken.
I really need to know when async read became the default
In the 1.51 release:
Mount
- Enable async reads for a 20% speedup (Nick Craig-Wood)
The error messages are also present with rclone v1.51.0-264 and disabled async. I think this bug is probably present in all betas since 1.51.
What is the earliest beta that supports union remotes and eprand search? I'll rollback. The bandwidth usage right now is unsustainable. I foresee lots of complaints in peak times.
You will get those if the app reading the file is seeking about the file. They are bad if streaming but fine if seeking.
Which application are you using? Does it seek?
The applications accessing the files does allow seeking ( going back and forward ).
How do I know if those messages are because of seeking or not?
I think I tracked this to be seeking errors only... by filtering my logs with egrep 'seek|failed'
Is there a way to improve this or is just there nothing that can be done about it?
After 24 hours, my servers with async read have 101k lines with failed to wait....and without async 165k lines.
So it seems that either way you can't escape those errors, and with async I actually had less errors than without async...
If you have a workload which does seeming then you will see those messges. They aren't really errors though...
Cloud providers are really good at giving the data in a stream
0 1 2 3 4 5 6 ....
Rclone reads the data in a stream normally and most applications do normally.
However sometimes applications seek about so lets say after block 6 the app read block 100
0 1 2 3 4 5 6 ... 100
When rclone gets the request for block 100 it will wait for a short while to see if a request for block 7 is coming which would be really quick to give and if it doesn't come then it seeks (which involves breaking the connection to the cloud provider and remaking it)
One case which rclone doesn't deal well with is if two apps are streaming from the same file at once.
Each one of those "failed" messages means rclone had to stop streaming and remake the stream somewhere else. For certain kinds of workflows this is unavoidable though.
It would be interesting for me to analyse your logs just to check everything is working. Can you PM me a link to them?
My log files are really huge, like 20 GB+ but I will truncate them to a reasonable size and send to you!
One case which rclone doesn't deal well with is if two apps are streaming from the same file at once.
Can you expand on that ? I often have the same file opened multiple times in the mount. I believe lots of people do the same