uvicorn: TypeError when connection is closed in connect()

Here is a minimal example without using django:

class Application:
    def __init__(self, scope):
        self.scope = scope

    async def __call__(self, receive, send):
        if self.scope["type"] != "websocket":
            return

        while True:
            # what for the 'websocket.connect' event.
            await receive()

            # Close the connection
            await send({'type': 'websocket.close'})

To test it, you have to start it with an asgi server an open a websocket connection.

With daphne:

$ daphne asgi:Application
2019-04-13 23:49:51,867 INFO     Starting server at tcp:port=8000:interface=127.0.0.1
2019-04-13 23:49:51,867 INFO     HTTP/2 support not enabled (install the http2 and tls Twisted extras)
2019-04-13 23:49:51,867 INFO     Configuring endpoint tcp:port=8000:interface=127.0.0.1
2019-04-13 23:49:51,868 INFO     Listening on TCP address 127.0.0.1:8000
127.0.0.1:58152 - - [13/Apr/2019:23:50:00] "WSCONNECTING /" - -
127.0.0.1:58152 - - [13/Apr/2019:23:50:00] "WSREJECT /" - -
127.0.0.1:58152 - - [13/Apr/2019:23:50:00] "WSDISCONNECT /" - -
^C2019-04-13 23:50:01,841 INFO     Killed 1 pending application instances

With uvicorn and websockets:

$ uvicorn asgi:Application --ws websockets
INFO: Started server process [23052]
INFO: Waiting for application startup.
INFO: Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO: ('127.0.0.1', 58172) - "WebSocket /" 403
ERROR: Exception in ASGI application
Traceback (most recent call last):
  File "/home/ossi/src/uvicorn_test/venv/lib/python3.7/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 147, in run_asgi
    result = await asgi(self.asgi_receive, self.asgi_send)
  File "./asgi.py", line 12, in __call__
    await receive()
  File "/home/ossi/src/uvicorn_test/venv/lib/python3.7/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 227, in asgi_receive
    data = await self.recv()
  File "/home/ossi/src/uvicorn_test/venv/lib/python3.7/site-packages/websockets/protocol.py", line 419, in recv
    return_when=asyncio.FIRST_COMPLETED,
  File "/usr/lib/python3.7/asyncio/tasks.py", line 361, in wait
    fs = {ensure_future(f, loop=loop) for f in set(fs)}
  File "/usr/lib/python3.7/asyncio/tasks.py", line 361, in <setcomp>
    fs = {ensure_future(f, loop=loop) for f in set(fs)}
  File "/usr/lib/python3.7/asyncio/tasks.py", line 592, in ensure_future
    raise TypeError('An asyncio.Future, a coroutine or an awaitable is '
TypeError: An asyncio.Future, a coroutine or an awaitable is required
^CINFO: Shutting down
INFO: Waiting for application shutdown.
INFO: Finished server process [23052]

With uvicorn and wsproto:

$ uvicorn asgi:Application --ws wsproto
INFO: Started server process [23092]
INFO: Waiting for application startup.
INFO: Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO: ('127.0.0.1', 58178) - "WebSocket /" 403
ERROR: Exception in ASGI application
Traceback (most recent call last):
  File "/home/ossi/src/uvicorn_test/venv/lib/python3.7/site-packages/uvicorn/protocols/websockets/wsproto_impl.py", line 208, in run_asgi
    result = await asgi(self.receive, self.send)
  File "./asgi.py", line 15, in __call__
    await send({'type': 'websocket.close'})
  File "/home/ossi/src/uvicorn_test/venv/lib/python3.7/site-packages/uvicorn/protocols/websockets/wsproto_impl.py", line 257, in send
    output = self.conn.send(msg)
  File "/home/ossi/src/uvicorn_test/venv/lib/python3.7/site-packages/wsproto/__init__.py", line 35, in send
    data += self.handshake.send(event)
  File "/home/ossi/src/uvicorn_test/venv/lib/python3.7/site-packages/wsproto/handshake.py", line 97, in send
    "Event {} cannot be sent during the handshake".format(event)
wsproto.utilities.LocalProtocolError: Event Response(status_code=403, headers=[], http_version=b'1.1', reason=b'') cannot be sent during the handshake
^CINFO: Shutting down
INFO: Waiting for application shutdown.
INFO: Finished server process [23092]

The error seems to be, that the while True: loop does not break. But when I look into the django channels code, it seems, that django channels also does not close the loop.

The loop in django channels is here: https://github.com/django/channels/blob/03d221792e6881477911728615a6d51ec9fab73b/channels/utils.py#L45

The close message is send here: https://github.com/django/channels/blob/03d221792e6881477911728615a6d51ec9fab73b/channels/generic/websocket.py#L226

An exception, that could break the loop is raised when websocket.disconnect is handled: https://github.com/django/channels/blob/03d221792e6881477911728615a6d51ec9fab73b/channels/generic/websocket.py#L241

If anyone’s able to reduce the issue like that then I’d be very happy to dig into it.

@tomchristie ping? I have reduced the issue by enabling logging in Uvicorn’s own test suite. I also submitted pull request #704 with a sketch of a fix. Are you still keen to dig into it? 😃

My workaround is to open the connection and close it immediately.

The thing that would help most with progressing this would be to try to replicate the issue in a plain ASGI application, or in Starlette, or something more minimal than installing Channels.

If anyone’s able to reduce the issue like that then I’d be very happy to dig into it.

https://github.com/encode/uvicorn/issues/244#issuecomment-482893968

Is there any way at all I can be of any more help? I’ve helped diagnose, I’ve authored a pull request, I’ve written helpful notes on all issues I could find that seemed relevant. I’m doing my best, and I’m prepared to do better. Please direct me.

Our project experiences this stack trace >35,000 times per day. I worry that real, as-yet unknown errors are hiding among all those duplicates.

Turns out this error was being logged – and ignored – in the unit-test suite already.

I’m not 100% confident in my reading of the ASGI-to-websockets spec. The Websockets spec (as cited in the websockets codebase) suggests it’s wrong to call recv() before a successful handshake – which is why this stack trace is logged. But the ASGI spec doesn’t say anything.

For all I know, all real-world ASGI applications call recv() before the handshakes completes, whether that’s ideal or not. So my pull request [#704] makes recv() return an error message – the same one that would be returned after unexpected disconnect.