Intermittent protocol failure and malformed payload

[Maldris]

I'm willing to bet this is an oversight on my part, but here goes.

I wrote a light weight websocket connection between two servers for work, with both client and server utilising gobwas/ws.

Intermittently (and much more frequently on windows) I will get a read error "frames from client to server must be masked" on the server, and terminate the connection. However, all writes from my client code use wsutil.WriteClientMessage, so all messages should be masked (assuming my understanding of the library is correct). I note that this, and some other protocol errors happened early on when I was accidentally reading from the connection in two goroutines simultaneously, though I believe this has been resolved.

I also see the occasional issue where a message payload contains additional bytes (usually ~4) on the front that look like part of the websocket frame data (payload is always JSON in current usages).

I suspect I've overlooked something in one of the systems designs, but at this point I've run out of ideas as to the cause, so I'm appealing for assistance.

Summary:

• Server intermittently (and more frequently on windows) produces read error "frames from client to server must be masked"
• client intermittently has additional bytes prefixed to payload, preventing message parsing

the client library I wrote can be seen here: https://github.com/Maldris/evtWebsocketClient and a gist of the server connection/communication logic can be seen here: https://gist.github.com/Maldris/4f62a8b7456fd82c3de6551ef4d8d99c

[gobwas]

Hi @Maldris! At this weekend Im planning to work on this. Thank you!

[Maldris]

Thanks for the assistance. I feel like I've been beating my head against a brick wall trying to figure it out at this point. But I still feel like I've missed something bleedingly obvious and made a stupid mistake somewhere.

[gobwas]

Hi @Maldris! Sorry for the delay. After digging into your code I eventually find this:

• Looks like here is a typo (does not make sense for solving the problem) – it is possible to send text message inside pinger goroutine;
• Here you use wsutil.ReadData(rw io.ReadWriter) function, which can produce writes to the given rw (in your case it is net.Conn) out of synchronization logic. That is, ReadData or ReadClientData will write responses at the control messages read by the rw.Read() by calling directly the rw.Write() (in your case net.Conn.Write()) method, without calling your write() which is synchronized. So Im solving this by giving some buffer as io.Writer part of argument to the wsutil.ReadData():

var buf bytes.Buffer
msg, err := wsutil.ReadClientData(struct { 
    io.Reader
    io.Writer
}{conn, &buf})
if err != nil {
    // handle error
}
if buf.Len() > 0 {
    // write or enqueue to be written buf.Bytes()
}
// process msg.

We can think about a special notice in comment to the ReadData* functions, to prevent misunderstanding on what they do and why there is an io.ReadWriter and not just io.Reader. Also there is a variant to simply remove them? :)

[gobwas]

@Maldris 🏓

[Maldris]

Hi @gobwas, Sorry for the delay, I got crazy busy as we got some purchase inquiries in another part of the business that we weren't expecting interest in, then I got rather ill, and simply forgot to respond here.

• The sending of text messages inside the ping routine was largely there so I could use it for debugging, as the wsutil package doesn't return the contents of ping frames (I understand why, but I needed to test some things with it, so I implemented that), it will likely be removed later.
• I'm annoyed at myself for not realising that, I do recall when I first implemented it noting that it took a ReadWriter and thinking that was odd, this explains everything, and explains the symptoms I was experiencing.

After implementing the suggested solution with a buffer (and a direct write method rather than the existing wrapped one) I haven't noticed the errors occurring again. So it does appear that it was simultaneous writes to the connection from different goroutines.

I may not have time before new years but Ill fork the project and try make some candidates for updated comments on those functions soon, investment has just dumped a lot of additional work in my lap.

[gobwas]

Nice to hear it @Maldris! Have a nice holidays and see you in 2018 🎆

[Maldris]

I wanted to run the general format of the comments past you as there are limited warnings in the documentation, and wanted to check some formatting options to match the existing documentation style.

The following examples will be as though for the method ReadClientData (for convenience of discussion)

the closest equivalent style to other notes:

// ReadClientData reads next data message from rw, considering that caller
// represents server side. It is a shortcut for ReadData(rw, ws.StateServerSide).
//
// Note this may handle and write control frames to the io.ReadWriter representing
// the connection.

the closest to things like the warning on DebugDialer:

// ReadClientData reads next data message from rw, considering that caller
// represents server side. It is a shortcut for ReadData(rw, ws.StateServerSide).
//
// Note that the connection should not be written to while this function is being
// executed as doing so risks corruption to message frames.

a much more verbose option that explains the consequences/requirements (seems vastly overkill)

// ReadClientData reads next data message from rw, considering that caller
// represents server side. It is a shortcut for ReadData(rw, ws.StateServerSide).
//
// Note this accepts a io.ReadWriter, and will internally handle
// control frames, writing to the connection, ensure that no writes occur to
// the connection while ReadClientData is executing, or frames with overlap
// and become corrupt.

[gobwas]

Hi @Maldris! Thanks for such deep thoughts on giving a warning. Will be this (the first option with little changes) ok?

// ReadClientData reads next data message from rw, considering that caller
// represents server side. It is a shortcut for ReadData(rw, ws.StateServerSide).
//
// Note this may handle and write control frames into the writer part of a given io.ReadWriter.