The web socket handler is stuck in an undefined state if the client did not close properly

[mykola-mokhnach]

🐞 Describe the bug

The server socket listener is forever stuck in web socket messages loop if the client does not close the socket properly

💡 To Reproduce

1. Create a new web socket handler and set the heartbeat timeout to 30 seconds
2. Connect to the created web socket with the websocat tool (brew install websockat on macOS)
3. Close the previously created websocat client by pressing Ctrl+C
4. Wait until the heartbeat timeout expires

An exception is written to the log. The web socket does never get closed and is practically stuck in messages loop.

💡 Expected behavior The server should properly close the client connection after STR and exit the messages loop

📋 Logs/tracebacks

ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-675' coro=<WebSocketWriter.ping() done, defined at /root/.local/share/virtualenvs/live-session-manager-rV8PaGpt/lib/python3.8/site-packages/aiohttp/http_websocket.py:669> exception=ConnectionResetError('Cannot write to closing transport')>
Traceback (most recent call last):
  File "/root/.local/share/virtualenvs/live-session-manager-rV8PaGpt/lib/python3.8/site-packages/aiohttp/http_websocket.py", line 673, in ping
    await self._send_frame(message, WSMsgType.PING)
  File "/root/.local/share/virtualenvs/live-session-manager-rV8PaGpt/lib/python3.8/site-packages/aiohttp/http_websocket.py", line 650, in _send_frame
    self._write(header + message)
  File "/root/.local/share/virtualenvs/live-session-manager-rV8PaGpt/lib/python3.8/site-packages/aiohttp/http_websocket.py", line 660, in _write
    raise ConnectionResetError("Cannot write to closing transport")
ConnectionResetError: Cannot write to closing transport

📋 Your version of the Python

$ python --version
3.8.6

📋 Your version of the aiohttp/yarl/multidict distributions

$ python -m pip show aiohttp
Name: aiohttp
Version: 3.7.2
Summary: Async http client/server framework (asyncio)
Home-page: https://github.com/aio-libs/aiohttp
Author: Nikolay Kim
Author-email: [email protected]
License: Apache 2
Location: /root/.local/share/virtualenvs/live-session-manager-rV8PaGpt/lib/python3.8/site-packages
Requires: chardet, attrs, async-timeout, yarl, multidict, typing-extensions
Required-by: aiohttp-swagger3

$ python -m pip show multidict
Name: multidict
Version: 5.0.2
Summary: multidict implementation
Home-page: https://github.com/aio-libs/multidict
Author: Andrew Svetlov
Author-email: [email protected]
License: Apache 2
Location: /root/.local/share/virtualenvs/live-session-manager-rV8PaGpt/lib/python3.8/site-packages
Requires: 
Required-by: yarl, aiohttp

$ python -m pip show yarl
Name: yarl
Version: 1.6.3
Summary: Yet another URL library
Home-page: https://github.com/aio-libs/yarl/
Author: Andrew Svetlov
Author-email: [email protected]
License: Apache 2
Location: /root/.local/share/virtualenvs/live-session-manager-rV8PaGpt/lib/python3.8/site-packages
Requires: idna, multidict
Required-by: aiohttp

📋 Additional context

    async def handle_establish_channel(self: T, request: web.Request) -> web.WebSocketResponse:
        ws = web.WebSocketResponse(heartbeat=heartbeat_interval_sec / 1.3)
        await ws.prepare(request)

        async for ws_message in ws:
            # the loop is stuck here
            # and never reaches the `return` statement
        return ws

[asvetlov]

Thanks for the report. I have a plan for working on it; I hope the fix will be a part of aiohttp 3.8

[mykola-mokhnach]

Thanks @asvetlov

[eino]

Hi, thanks for this awesome project. Is there perchance any update on the issue? I have met it as well randomly, where the server doesn't notice a client has disconnected (probably because of an improper disconnection), and keeps trying to send data. It's not systematic, though. I run python 3.9 and aiohttp 3.8.1

ConnectionResetError: Cannot write to closing transport
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-5179' coro=<WslinkHandler.sendWrappedMessage() done, defined at /opt/app/.venv/lib/python3.9/site-packages/wslink/backends/aiohttp/__init__.py:542> exception=ConnectionResetError('Cannot write to closing transport')>
Traceback (most recent call last):
  File (...calling code )
    await self._writer.send(data, binary=False, compress=compress)
  File "/opt/app/.venv/lib/python3.9/site-packages/aiohttp/http_websocket.py", line 690, in send
    await self._send_frame(message, WSMsgType.TEXT, compress)
  File "/opt/app/.venv/lib/python3.9/site-packages/aiohttp/http_websocket.py", line 653, in _send_frame
    self._write(header + message)

[Dreamsorcerer]

I would assume that @asvetlov hasn't had a chance to look at it yet. If anyone else wants to propose a solution, we're happy to look at a PR.

[eino]

I investigated the issue some more, and I may have found the original reason. It seems in case of WebSocketError (also any other Exception), the Websocket is closed, but iteration on it isn't stopped

This is because a msg with type ERROR is returned, https://github.com/aio-libs/aiohttp/blob/50fec957c10f1af69cbe4aac57e925b0b8da3cda/aiohttp/web_ws.py#L458-L461 but this type doesn't raise a StopAsyncIteration: https://github.com/aio-libs/aiohttp/blob/50fec957c10f1af69cbe4aac57e925b0b8da3cda/aiohttp/web_ws.py#L512-L516

Thus a client will continue waiting forever in the closed websocket iterator. And, (in our case), as it considers the socket opens, also tries to write to it (hence the "ConnectionResetError: Cannot write to closing transport" error).

As the WSMsgType.ERROR is only raised in 2 cases where the socket is closed, this msg type should cause the iteration to stop. It would be this change: https://github.com/eino/aiohttp/commit/60ce76aa6f8216aedbfe4b6e8b87a865e28f7356 I can open the PR if it looks good, what do you think?

[Dreamsorcerer]

Potentially promising. Do you think you can add a test case that reproduces the issue now?

[eino]

Actually that's not the cause of the issue. On next call, as connection is closed, receive returns WS_CLOSED_MESSAGE (line 404) thus terminate the iteration.

[anpr]

What's the current status of this? This issue is hurting us with an implementation of a websocket server.

[bdraco]

This might already be fixed in 3.9.x. Can you verify the issue still persists?

[bdraco]

This looks fixed

Reproducer on older aiohttp

from aiohttp import web


heartbeat_interval_sec = 30


async def websocket_handler(request):
    ws = web.WebSocketResponse(heartbeat=heartbeat_interval_sec / 1.3)
    await ws.prepare(request)
    print ("WebSocket connection opened")
    async for ws_message in ws:
        pass
        # the loop is stuck here
        # and never reaches the `return` statement
    print("WebSocket connection closed")
    return ws


app = web.Application()
app.add_routes(
    [
        web.get("/land/websocket_test", websocket_handler),
    ]
)

if __name__ == "__main__":
    web.run_app(app, host="0.0.0.0", port=8000)

% python3 5301.py
======== Running on http://0.0.0.0:8000 ========
(Press CTRL+C to quit)
WebSocket connection opened
WebSocket connection closed
WebSocket connection opened
WebSocket connection closed

(venv) bdraco@MacBook-Pro aiohttp % websocat ws://0.0.0.0:8000/land/websocket_test
^C
(venv) bdraco@MacBook-Pro aiohttp % websocat ws://0.0.0.0:8000/land/websocket_test
^C

[bdraco]

@mykola-mokhnach Can you still reproduce this after #7978 ?