Fixing client throwing `no close frame received or sent` error

[desmondcorreia]

Hello All,

I recently came across this library and I am using it to put together a proof of concept for tooling. I am only implementing the client side as the server is an embedded industrial product (It's closed source I have no access to it).

The server sends out unsolicited events over the websocket. I have written a client to observe these events and then respond. The same websocket that handles the receive is used for sending. (I.e. a new one is not opened)

I get error 1 when calling send. However if I call await asyncio.sleep(0) to force a yield to the background thread then error 1 stop happening. Code Snippet 2 although works adds latency to system. I need to respond with very low latency. So I believe this yield is adding too much time to the code. Although unconfirmed since I can't profile the code without it.

Is there anyway to fix Error 1 without using the yield in Code Snippet 2

Error 1

asyncio.exceptions.IncompleteReadError: 0 bytes read on a total of 2 expected bytes

Code Snippet 1

This throws error 1

await self.ws.send(json.dumps(payload))
print("Send done")

Code Snippet 2

This does not throws error 1.

await asyncio.sleep(0) #Yeild to the background thread
await self.ws.send(json.dumps(payload))
print("Send done")

Sequence of Operations

• Websocket client connects. Wired ethernet.
• Websocket await unsolicited event from the server.
• Websocket client sends respond payload

[aaugustin]

Does https://websockets.readthedocs.io/en/stable/howto/faq.html#what-does-connectionclosederror-no-close-frame-received-or-sent-mean help? You didn't provide the full stack track but I suspect that's what you're hitting.

If you understand why the server closes the connection, then you can avoid it. Try enabling debug logs: https://websockets.readthedocs.io/en/stable/howto/cheatsheet.html#debugging and see what changes between the two scenarios?

I would challenge that await asyncio.sleep(0) adds significant latency. It takes 14µs on my machine:

>>> import asyncio
>>> import timeit
>>> async def test():
...     for _ in range(100_000):
...         await asyncio.sleep(0)
...
>>> def run_test():
...     loop = asyncio.new_event_loop()
...     loop.run_until_complete(test())
...     loop.close()
... 
>>> timeit.timeit(run_test_2, number=1)
1.3974632090000227

Yes, it has a cost, but perhaps not as high as you would expect.

[desmondcorreia]

I did enable debug logs but I do not have the trace. I will grab a new one later and send it to you. However if my memory serves me well the client sent 1000 which is normal close sequence. But this should not have occurred and it doesn't occur when using Code Snippet 2 above.

The method you use to profile yield depends on the work the background thread has to do. But I do suspect the time is somewhat trivial although I would like to confirm it.

Regardless yielding seems like an odd way to fix this. Do you have any insight into why this is the case? As well as anything I can try?

[aaugustin]

Yes, it's very odd that adding await asyncio.sleep(0) changes the behavior.

I would like to understand why that is. Specifically, I would like to understand if the problem is on the client and the server side. Embedded industrial products don't always have the most compliant implementations...

This is why I would like to see exactly what websockets sends before the connection is closed. I suspect the server gets something they don't like and shuts down the connection brutally. Now, if the thing it dislikes is clearly legit, that's a bug in the server and you're going to keep the workaround...

[aaugustin]

If I had to make a wild guess, based on typical bugs found in such industrial products, I would bet that the server depends on how the stream is fragmented in TCP packets, when it shouldn't. (WebSocket is a TLV-protocol for that reason.)

Here's what could happen:

1. You are sending two messages in a single TCP packet. "You" might include websockets automatically answering a ping with a pong — that's why I asked for debug logs, where we could see that.
2. The server reads everything available on the TCP connection and attempts to parse it as a WebSocket message. (Implementation error here.) Since there are two WebSocket messages concatenated, this fails and the server closes brutally the connection, hence the error you're seeing.
3. By yielding to the event loop before sending the second message, you let asyncio send the first message in a TCP packet, then the second message is sent in a separate TCP packet. This avoids triggering the bug.

To be really sure about what you're sending to the server and what it dislikes, you'd have to pull Wireshark — pretty typical for debugging such black boxes....

Given the lack of updates in about 6 months and insufficient information to debug, I'm going to close this.