Code 1006 during web socket termination on Google Chrome when outgoing data is queued during the `close()`

[jonathanslenders]

Only in Chrome, not in Firefox nor Safari, we get an 1006 status code in the browser in the WebSocket.onerror callback.

The error happens if outgoing data is queued at the point that we call await websocket.close() in the FastAPI application. Placing a short sleep in front of the close() call resolves the issue.

The error only happens when using http/2. Not when using http/1.1.

Using Chrome's built-in chrome://net-export, we can see the following difference between a successful teardown and a failure:

When we have a success (1000 code in Chrome), with a sleep before the close() call, we see the following at the end of the logs:

t=16596 [st=10599]  HTTP2_STREAM_UPDATE_RECV_WINDOW
                    --> delta = -4
                    --> stream_id = 39
                    --> window_size = 6291452
t=16596 [st=10599]  HTTP2_STREAM_UPDATE_RECV_WINDOW
                    --> delta = 4
                    --> stream_id = 39
                    --> window_size = 6291456
t=16596 [st=10599]  WEBSOCKET_RECV_FRAME_HEADER
                    --> final = true
                    --> masked = false
                    --> opcode = 8
                    --> payload_length = 2
                    --> reserved1 = false
                    --> reserved2 = false
                    --> reserved3 = false
t=16596 [st=10599]  WEBSOCKET_SENT_FRAME_HEADER
                    --> final = true
                    --> masked = true
                    --> opcode = 8
                    --> payload_length = 2
                    --> reserved1 = false
                    --> reserved2 = false
                    --> reserved3 = false
t=16596 [st=10599]  HTTP2_STREAM_UPDATE_SEND_WINDOW
                    --> delta = -8
                    --> stream_id = 39
                    --> window_size = 65351
t=16596 [st=10599]  WEBSOCKET_READ_BUFFER_SIZE_CHANGED
                    --> read_buffer_size_in_bytes = 1000
t=16596 [st=10599]  HTTP2_STREAM_UPDATE_SEND_WINDOW
                    --> delta = 8
                    --> stream_id = 39
                    --> window_size = 65359

However, without the sleep, we see the following at the end of the logs:

t=9382 [st=1040]  HTTP2_STREAM_UPDATE_RECV_WINDOW
                  --> delta = 232
                  --> stream_id = 19
                  --> window_size = 5983778
t=9382 [st=1040]  HTTP2_STREAM_UPDATE_RECV_WINDOW
                  --> delta = -4
                  --> stream_id = 19
                  --> window_size = 5983774
t=9392 [st=1050]  WEBSOCKET_READ_BUFFER_SIZE_CHANGED
                  --> read_buffer_size_in_bytes = 131000
t=9408 [st=1066]  WEBSOCKET_RECV_FRAME_HEADER
                  --> final = true
                  --> masked = false
                  --> opcode = 8
                  --> payload_length = 2
                  --> reserved1 = false
                  --> reserved2 = false
                  --> reserved3 = false
t=9416 [st=1074]  WEBSOCKET_SENT_FRAME_HEADER
                  --> final = true
                  --> masked = true
                  --> opcode = 8
                  --> payload_length = 2
                  --> reserved1 = false
                  --> reserved2 = false
                  --> reserved3 = false

This is mostly identical, except some h2 flow control that's missing at the end.

I also notice that Chrome reports a successful 1000 code after we apply the following (obviously incorrect) patch to Hypercorn:

--- a/src/hypercorn/protocol/ws_stream.py
+++ b/src/hypercorn/protocol/ws_stream.py
@@ -300,7 +300,7 @@ class WSStream:
                         reason=message.get("reason"),
                     )
                 )
-                await self.send(EndData(stream_id=self.stream_id))
+                # await self.send(EndData(stream_id=self.stream_id))
             else:
                 raise UnexpectedMessageError(self.state, message["type"])

So, the web browser tries to send a close message after we sent our close message as a result of our ASGI app producing a "websocket.close" message. But somehow it's not able to deliver this close response. I can't tell if the h2 channel is closed at this point or if there is no flow control quota. I would assume that the h2 EndData message only does a half-close, meaning we still have the receive window open for the browser to send its "close" message.

The FastAPI websocket endpoint looks something like this:

@router.websocket("/ws")
async def websocket_endpoint(websocket: WebSocket) -> None:
    await websocket.accept()
    ... = await websocket.receive_json()

    await websocket.send_text(<lots of data>)

    await websocket.close()

Unfortunately, I don't have a precise reproduction script, but already wanted to share the findings so far in the hope that maybe it does ring a bell.

[apawlucz-cisco]

I have a repro app.

main_hypercorn.py
index.html

For testing use Chrome. As only Chrome reports error 1006.
I think this is is due to the fact that after sending the close frame from the server rapidly after sending the data, there is no time to exchange WINDOW_UPDATE flow control events, and Chrome reporting this fact as abnormal closure.

Before running the app - make sure both lines in the main_hypercorn.py are UNCOMMENTED:

await websocket.send_bytes(data)
await websocket.close()

Worth mentioning the above mentioned issue only happens if:

1. There is a permanent Websocket connection created (app button "Connect to /permanent").
2. The 1. connection is created using HTTP2 (sometimes it's neccessary to use hard reload on the app and try several times so the connection is established using HTTP2).

3. While the permanent connection is established - then try to create another websocket connection (button "Connect to /ws"). Now it should produce 1006 websocket code in the browser.

For the issue to disappear - adding a sleep before sending the close is enough:

await websocket.send_bytes(data)
await asyncio.sleep(1)
await websocket.close()

Though I feel this is rather workaround, not a fix.