Yamux connection issue with go

[AgeManning]

I haven't fully tracked down the reason for this. But I'm seeing connection drops when using rust-libp2p with go-libp2p over yamux.

Specifically we hit this line: https://github.com/paritytech/yamux/blob/develop/src/connection.rs#L673

With this error:

3106e0cb/10: frame body larger than window of stream

I'll be chasing up the go-side also, just wondering if there was some extra insight on this?

[twittner]

Thank you for your report! Could you provide logs or a test case that I could use to reproduce this?

[AgeManning]

It happens intermittently in a complicated environment. We'll go digging a bit and report back with more info.

Was just fishing for potentially a known issue or something obvious that could be wrong.

[twittner]

@AgeManning, Did you manage to get some more information?

[AgeManning]

We are still looking into this. There was a recent explosion of sorts on our testnet, so have been dealing with that. I temporarily disabled yamux to solve our problems, but we will start dedicating some time to debugging the yamux issue.

Sorry for the delay, but will report back once we have more info/have found the source of the problem

[pawanjay176]

This looks like an issue with the receive_window size.
Even though the spec says to use 256 kb as the window size, go-libp2p-yamux by default has the param set to to 16mb because of performance issues
https://github.com/libp2p/go-libp2p-yamux/blob/master/transport.go#L14-L20

I might be wrong on this, but it looks to me that go-yamux doesn't adaptively adjust the receive window size for a stream based on how much data is coming in.

I was able to make rust work with go by simply by setting config.receive_window to 16 * 1024 * 1024.

[twittner]

Maybe you could provide logs on trace level which show the error you are getting? Without logs or some test case I am not sure how I could help you.

[pawanjay176]

Here are the truncated trace logs for the stream that errored.

It contains this additional debug log right before this line https://github.com/paritytech/yamux/blob/develop/src/connection.rs#L689

log::debug!("Window size: {}, credit: {}", shared.window, shared.credit);

[twittner]

Thanks. I did not see the sending initial (Header WindowUpdate 9 (len 262144) (flags 1)) line in the snippet, but from your added log I think it was granting the default credit (= 256 KiB) to the remote. Since I see no further WindowUpdates sent to the remote and if your added logs apply to connection bdd0f821 stream 9, it does indeed look as if the remote is sending 15813 bytes with a remaining window of 14074 bytes which is a protocol violation.

[pawanjay176]

I did not see the sending initial (Header WindowUpdate 9 (len 262144) (flags 1)) line in the snippet

Sorry, that line is present, got lost in misc logs!

I can chase this up with the go folks if you could help me understand the required behaviour. The spec isn't super elaborate and I'm basing this on what I understood from the code.

We should keep track of the remote's window size (which is what shared.credit represents in the rust code) and never send more bytes than the available credit. As soon as the window size becomes zero on the receiving end, receiver sends a WindowUpdate message to the sender asking it to increase its "credit".

But from the logs, it looks like go is sending more bytes than the available credit which is a protocol violation.
Is this accurate?

[twittner]

All streams start with a receive window of 256 KiB. The only way to change a receive window is via window update frames sent to the remote which inform it about how many more bytes it is allowed to sent over the stream. No endpoint must ever send more data than the sum of window updates it has received.

When opening an outbound stream one can do so either with a window update frame or a data frame. If a window update frame is used, one can immediately grant the remote a larger window, but unless one receives a window update from the remote the default setting still applies to one's own outbound data sent over this stream. When opening an outbound stream with a data frame, the default setting also applies.

If an inbound stream is opened with a data frame, its payload size must not exceed 256 KiB. If an inbound stream is opened with a window update frame, the receiver knows the size of the receive window the remote has allocated for it. Here go-yamux and this crate have implemented different behaviours I think. This crate understands the initial window update as the total receive window size whereas (I believe) go-yamux adds the window update to the implicit default of 256 KiB.

To quote the spec:

Both sides assume the initial 256KB window, but can immediately send a window update as part of the SYN/ACK indicating a larger window.

Now, "indicating a larger window" is indeed a bit open to interpretation, but given that a window update is otherwise described as "a delta update" I think the additive perspective is perhaps even more appropriate.

At the moment I do not see an easy way to upgrade from the current perspective to the additive one without breaking existing clients.

[twittner]

@pawanjay176, @AgeManning: Can this issue be closed now?

[AgeManning]

Yep, Thank you 🙏