Uvicorn: TypeError when connection is closed in connect()

Created on 14 Nov 2018  路  18Comments  路  Source: encode/uvicorn

I have the same problem then #185 but I think, I can reproduce it.

When you close a connection in the connect() method of a WebsocketConsumer, it works fine with daphne but uvicorn raises a TypeError 

Traceback (most recent call last):
  File "/home/ossi/src/channels-examples/.venv/lib/python3.7/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
    result = await asgi(self.asgi_receive, self.asgi_send)
  File "/home/ossi/src/channels-examples/.venv/lib/python3.7/site-packages/channels/sessions.py", line 179, in __call__
    return await self.inner(receive, self.send)
  File "/home/ossi/src/channels-examples/.venv/lib/python3.7/site-packages/channels/middleware.py", line 41, in coroutine_call
    await inner_instance(receive, send)
  File "/home/ossi/src/channels-examples/.venv/lib/python3.7/site-packages/channels/consumer.py", line 59, in __call__
    [receive, self.channel_receive], self.dispatch
  File "/home/ossi/src/channels-examples/.venv/lib/python3.7/site-packages/channels/utils.py", line 59, in await_many_dispatch
    await task
  File "/home/ossi/src/channels-examples/.venv/lib/python3.7/site-packages/channels/utils.py", line 51, in await_many_dispatch
    result = task.result()
  File "/home/ossi/src/channels-examples/.venv/lib/python3.7/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 222, in asgi_receive
    data = await self.recv()
  File "/home/ossi/src/channels-examples/.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

I created this branch on the django-channels-example repository: https://github.com/ostcar/channels-examples/tree/uvicorn-test

All I changed was, that the websocket connection is always closed: https://github.com/andrewgodwin/channels-examples/compare/master...ostcar:uvicorn-test

I think the problem is, that you call websockets.WebSocketServerProtocol.recv() before the websocket connection is open so websockets.WebSocketServerProtocol.connection_open() was not called. In this case the attribute transfer_data_task is still None. So when websockets.WebSocketServerProtocol.recv() calls 

yield from asyncio.wait(
                    [pop_message_waiter, self.transfer_data_task],
                    loop=self.loop,
                    return_when=asyncio.FIRST_COMPLETED,
                )

it tries to await None what causes the exception.

I don't know, if this is a but in the websockets package or if you should check self.closed before calling self.recv()

bug websockets
Source
picture ostcar
👍7

Most helpful comment

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? :)

picture adamhooper on 8 Sep 2020
👍5

All 18 comments

I'm also facing this issue - when connections are closed, several errors pop up. Doesn't affect operation, but quite concerning nonetheless.

Full stack trace (may be mixed with other errs...):

[2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 674, in transfer_data
Jan 07 11:56:32 makerlog gunicorn[19800]:     message = yield from self.read_message()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 742, in read_message
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_data_frame(max_size=self.max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 815, in read_data_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_frame(max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 884, in read_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     extensions=self.extensions,
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/framing.py", line 99, in read
Jan 07 11:56:32 makerlog gunicorn[19800]:     data = yield from reader(2)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/usr/lib/python3.6/asyncio/streams.py", line 672, in readexactly
Jan 07 11:56:32 makerlog gunicorn[19800]:     raise IncompleteReadError(incomplete, n)
Jan 07 11:56:32 makerlog gunicorn[19800]: asyncio.streams.IncompleteReadError: 0 bytes read on a total of 2 expected bytes
Jan 07 11:56:32 makerlog gunicorn[19800]: The above exception was the direct cause of the following exception:
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 674, in transfer_data
Jan 07 11:56:32 makerlog gunicorn[19800]:     message = yield from self.read_message()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 742, in read_message
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_data_frame(max_size=self.max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 815, in read_data_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_frame(max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 884, in read_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     extensions=self.extensions,
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/framing.py", line 99, in read
Jan 07 11:56:32 makerlog gunicorn[19800]:     data = yield from reader(2)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/usr/lib/python3.6/asyncio/streams.py", line 672, in readexactly
Jan 07 11:56:32 makerlog gunicorn[19800]:     raise IncompleteReadError(incomplete, n)
Jan 07 11:56:32 makerlog gunicorn[19800]: asyncio.streams.IncompleteReadError: 0 bytes read on a total of 2 expected bytes
Jan 07 11:56:32 makerlog gunicorn[19800]: The above exception was the direct cause of the following exception:
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 674, in transfer_data
Jan 07 11:56:32 makerlog gunicorn[19800]:     message = yield from self.read_message()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 742, in read_message
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_data_frame(max_size=self.max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 815, in read_data_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_frame(max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 884, in read_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     extensions=self.extensions,
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/framing.py", line 99, in read
Jan 07 11:56:32 makerlog gunicorn[19800]:     data = yield from reader(2)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/usr/lib/python3.6/asyncio/streams.py", line 672, in readexactly
Jan 07 11:56:32 makerlog gunicorn[19800]:     raise IncompleteReadError(incomplete, n)
Jan 07 11:56:32 makerlog gunicorn[19800]: asyncio.streams.IncompleteReadError: 0 bytes read on a total of 2 expected bytes
Jan 07 11:56:32 makerlog gunicorn[19800]: The above exception was the direct cause of the following exception:
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19809] [INFO] None - "WebSocket /explore/stream/" [accepted]
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 674, in transfer_data
Jan 07 11:56:32 makerlog gunicorn[19800]:     message = yield from self.read_message()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 742, in read_message
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_data_frame(max_size=self.max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 815, in read_data_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_frame(max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 884, in read_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     extensions=self.extensions,
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/framing.py", line 99, in read
Jan 07 11:56:32 makerlog gunicorn[19800]:     data = yield from reader(2)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/usr/lib/python3.6/asyncio/streams.py", line 672, in readexactly
Jan 07 11:56:32 makerlog gunicorn[19800]:     raise IncompleteReadError(incomplete, n)
Jan 07 11:56:32 makerlog gunicorn[19800]: asyncio.streams.IncompleteReadError: 0 bytes read on a total of 2 expected bytes
Jan 07 11:56:32 makerlog gunicorn[19800]: The above exception was the direct cause of the following exception:
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await dispatch(result)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 73, in dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:     await handler(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 175, in websocket_connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.connect()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/makerlog2/notifications/sockets/consumers.py", line 19, in connect
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send_json(count)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 273, in send_json
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send(text_data=await self.encode_json(content), close=close)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/generic/websocket.py", line 211, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await super().send({"type": "websocket.send", "text": text_data})
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 81, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.base_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 232, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.real_send(message)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 198, in asgi_send
Jan 07 11:56:32 makerlog gunicorn[19800]:     await self.send(data)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 462, in send
Jan 07 11:56:32 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 11:56:32 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 11:56:32 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Jan 07 11:56:32 makerlog gunicorn[19800]: [2019-01-07 11:56:32 +0000] [19806] [ERROR] Exception in ASGI application
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 674, in transfer_data
Jan 07 11:56:32 makerlog gunicorn[19800]:     message = yield from self.read_message()
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 742, in read_message
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_data_frame(max_size=self.max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 815, in read_data_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     frame = yield from self.read_frame(max_size)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 884, in read_frame
Jan 07 11:56:32 makerlog gunicorn[19800]:     extensions=self.extensions,
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/framing.py", line 99, in read
Jan 07 11:56:32 makerlog gunicorn[19800]:     data = yield from reader(2)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/usr/lib/python3.6/asyncio/streams.py", line 672, in readexactly
Jan 07 11:56:32 makerlog gunicorn[19800]:     raise IncompleteReadError(incomplete, n)
Jan 07 11:56:32 makerlog gunicorn[19800]: asyncio.streams.IncompleteReadError: 0 bytes read on a total of 2 expected bytes
Jan 07 11:56:32 makerlog gunicorn[19800]: The above exception was the direct cause of the following exception:
Jan 07 11:56:32 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py", line 140, in run_asgi
Jan 07 11:56:32 makerlog gunicorn[19800]:     result = await asgi(self.asgi_receive, self.asgi_send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/sessions.py", line 179, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     return await self.inner(receive, self.send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/middleware.py", line 41, in coroutine_call
Jan 07 11:56:32 makerlog gunicorn[19800]:     await inner_instance(receive, send)
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/consumer.py", line 59, in __call__
Jan 07 11:56:32 makerlog gunicorn[19800]:     [receive, self.channel_receive], self.dispatch
Jan 07 11:56:32 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/channels/utils.py", line 52, in await_many_dispatch
Jan 07 11:57:19 makerlog gunicorn[19800]: [2019-01-07 11:57:19 +0000] [19808] [INFO] None - "HEAD /health HTTP/1.1" 200
Jan 07 11:57:24 makerlog gunicorn[19800]: [2019-01-07 11:57:24 +0000] [19806] [INFO] None - "WebSocket /notifications/" [accepted]
Jan 07 11:57:27 makerlog gunicorn[19800]: [2019-01-07 11:57:27 +0000] [19809] [INFO] None - "POST /apps/todoist/event/ HTTP/1.1" 400
Jan 07 11:57:30 makerlog gunicorn[19800]: [2019-01-07 11:57:30 +0000] [19806] [INFO] None - "WebSocket /notifications/" [accepted]
Jan 07 11:57:31 makerlog gunicorn[19800]: [2019-01-07 11:57:31 +0000] [19808] [INFO] None - "WebSocket /explore/stream/" [accepted]
Jan 07 11:57:32 makerlog gunicorn[19800]: [2019-01-07 11:57:32 +0000] [19809] [INFO] None - "POST /apps/todoist/event/ HTTP/1.1" 400
Jan 07 11:57:46 makerlog gunicorn[19800]: [2019-01-07 11:57:46 +0000] [19808] [INFO] None - "POST /apps/todoist/event/ HTTP/1.1" 400
Jan 07 11:57:55 makerlog gunicorn[19800]: [2019-01-07 11:57:55 +0000] [19808] [INFO] None - "POST /apps/todoist/event/ HTTP/1.1" 400
Jan 07 11:58:01 makerlog gunicorn[19800]: [2019-01-07 11:58:01 +0000] [19806] [INFO] None - "GET /health HTTP/1.1" 200
Jan 07 11:58:01 makerlog gunicorn[19800]: [2019-01-07 11:58:01 +0000] [19808] [INFO] None - "GET /explore/stream/ HTTP/1.1" 200
Jan 07 11:58:01 makerlog gunicorn[19800]: [2019-01-07 11:58:01 +0000] [19809] [INFO] None - "GET /explore/stream/2019/jan/7/ HTTP/1.1" 200
Jan 07 11:58:06 makerlog gunicorn[19800]: [2019-01-07 11:58:06 +0000] [19808] [INFO] None - "WebSocket /explore/stream/" [accepted]
Jan 07 11:58:08 makerlog gunicorn[19800]: [2019-01-07 11:58:08 +0000] [19806] [INFO] None - "POST /apps/todoist/event/ HTTP/1.1" 400
Jan 07 11:58:09 makerlog gunicorn[19800]: [2019-01-07 11:58:09 +0000] [19809] [INFO] None - "POST /apps/todoist/event/ HTTP/1.1" 400
Jan 07 11:58:20 makerlog gunicorn[19800]: [2019-01-07 11:58:20 +0000] [19808] [INFO] None - "WebSocket /explore/stream/" [accepted]
Jan 07 11:58:20 makerlog gunicorn[19800]: [2019-01-07 11:58:20 +0000] [19806] [INFO] None - "WebSocket /notifications/" [accepted]
Jan 07 11:58:49 makerlog gunicorn[19800]: [2019-01-07 11:58:49 +0000] [19806] [INFO] None - "GET /projects/408/related/ HTTP/1.1" 200
Jan 07 11:59:12 makerlog gunicorn[19800]: [2019-01-07 11:59:12 +0000] [19809] [INFO] None - "GET /health HTTP/1.1" 200
Jan 07 11:59:12 makerlog gunicorn[19800]: [2019-01-07 11:59:12 +0000] [19808] [INFO] None - "GET /products/books/ HTTP/1.1" 200
Jan 07 11:59:12 makerlog gunicorn[19800]: [2019-01-07 11:59:12 +0000] [19809] [INFO] None - "GET /products/books/stream/ HTTP/1.1" 200
Jan 07 11:59:12 makerlog gunicorn[19800]: [2019-01-07 11:59:12 +0000] [19809] [INFO] None - "GET /users/1338/ HTTP/1.1" 200
Jan 07 11:59:19 makerlog gunicorn[19800]: [2019-01-07 11:59:19 +0000] [19808] [INFO] None - "HEAD /health HTTP/1.1" 200
Jan 07 12:00:02 makerlog gunicorn[19800]: [2019-01-07 12:00:02 +0000] [19806] [INFO] None - "GET /health HTTP/1.1" 200
Jan 07 12:00:02 makerlog gunicorn[19800]: [2019-01-07 12:00:02 +0000] [19808] [INFO] None - "GET /products/use-makerlog-redesign/ HTTP/1.1" 200
Jan 07 12:00:02 makerlog gunicorn[19800]: [2019-01-07 12:00:02 +0000] [19809] [INFO] None - "GET /products/use-makerlog-redesign/stream/ HTTP/1.1" 200
Jan 07 12:00:02 makerlog gunicorn[19800]: [2019-01-07 12:00:02 +0000] [19809] [INFO] None - "GET /users/969/ HTTP/1.1" 200
Jan 07 12:00:02 makerlog gunicorn[19800]: [2019-01-07 12:00:02 +0000] [19808] [INFO] None - "GET /products/use-makerlog-redesign/2018/dec/23/ HTTP/1.1" 200
Jan 07 12:00:23 makerlog gunicorn[19800]: [2019-01-07 12:00:23 +0000] [19806] [INFO] None - "WebSocket /explore/stream/" [accepted]
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19808] [INFO] None - "GET /health HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19806] [INFO] None - "OPTIONS /tasks/sync/ HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19808] [INFO] None - "OPTIONS /me/stats/ HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19809] [INFO] None - "OPTIONS /projects/ HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19806] [INFO] None - "OPTIONS /notifications/ HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19808] [INFO] None - "OPTIONS /explore/stream/ HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19809] [INFO] None - "OPTIONS /me/following/ HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19806] [INFO] None - "OPTIONS /products/me/ HTTP/1.1" 200
Jan 07 12:00:36 makerlog gunicorn[19800]: [2019-01-07 12:00:36 +0000] [19809] [INFO] None - "GET /tasks/sync/ HTTP/1.1" 200
Jan 07 12:00:37 makerlog gunicorn[19800]: [2019-01-07 12:00:37 +0000] [19809] [INFO] None - "GET /projects/ HTTP/1.1" 200
Jan 07 12:00:37 makerlog gunicorn[19800]: [2019-01-07 12:00:37 +0000] [19808] [INFO] None - "GET /me/stats/ HTTP/1.1" 200
Jan 07 12:00:37 makerlog gunicorn[19800]: [2019-01-07 12:00:37 +0000] [19808] [INFO] None - "GET /me/following/ HTTP/1.1" 200
Jan 07 12:00:37 makerlog gunicorn[19800]: [2019-01-07 12:00:37 +0000] [19806] [INFO] None - "GET /explore/stream/ HTTP/1.1" 200
Jan 07 12:00:37 makerlog gunicorn[19800]: [2019-01-07 12:00:37 +0000] [19806] [INFO] None - "GET /notifications/ HTTP/1.1" 200
Jan 07 12:00:37 makerlog gunicorn[19800]: [2019-01-07 12:00:37 +0000] [19809] [INFO] None - "GET /products/me/ HTTP/1.1" 200
Jan 07 12:00:38 makerlog gunicorn[19800]: [2019-01-07 12:00:38 +0000] [19808] [INFO] None - "OPTIONS /stats/world/ HTTP/1.1" 200
Jan 07 12:00:38 makerlog gunicorn[19800]: [2019-01-07 12:00:38 +0000] [19806] [INFO] None - "OPTIONS /stats/world/ HTTP/1.1" 200
Jan 07 12:00:38 makerlog gunicorn[19800]: [2019-01-07 12:00:38 +0000] [19806] [INFO] None - "OPTIONS /explore/stream/2019/jan/7/ HTTP/1.1" 200
Jan 07 12:00:39 makerlog gunicorn[19800]: [2019-01-07 12:00:39 +0000] [19808] [INFO] None - "GET /stats/world/ HTTP/1.1" 200
Jan 07 12:00:39 makerlog gunicorn[19800]: [2019-01-07 12:00:39 +0000] [19809] [INFO] None - "GET /explore/stream/2019/jan/7/ HTTP/1.1" 200
Jan 07 12:00:39 makerlog gunicorn[19800]: [2019-01-07 12:00:39 +0000] [19809] [INFO] None - "GET /stats/world/ HTTP/1.1" 200
Jan 07 12:00:39 makerlog gunicorn[19800]: [2019-01-07 12:00:39 +0000] [19808] [INFO] None - "OPTIONS /discussions/recent_questions/ HTTP/1.1" 200
Jan 07 12:00:39 makerlog gunicorn[19800]: [2019-01-07 12:00:39 +0000] [19806] [INFO] None - "GET /discussions/recent_questions/ HTTP/1.1" 200
Jan 07 12:00:41 makerlog gunicorn[19800]: [2019-01-07 12:00:41 +0000] [19808] [INFO] None - "WebSocket /notifications/" [accepted]
Jan 07 12:00:42 makerlog gunicorn[19800]: [2019-01-07 12:00:42 +0000] [19806] [INFO] None - "WebSocket /explore/stream/" [accepted]
Jan 07 12:00:45 makerlog gunicorn[19800]: [2019-01-07 12:00:45 +0000] [19809] [INFO] None - "GET /health HTTP/1.1" 200
Jan 07 12:00:45 makerlog gunicorn[19800]: [2019-01-07 12:00:45 +0000] [19808] [INFO] None - "GET /users/username/dexter/ HTTP/1.1" 200
Jan 07 12:00:45 makerlog gunicorn[19800]: [2019-01-07 12:00:45 +0000] [19809] [INFO] None - "GET /users/1008/stats/ HTTP/1.1" 200
Jan 07 12:00:45 makerlog gunicorn[19800]: [2019-01-07 12:00:45 +0000] [19806] [INFO] None - "GET /users/1008/stream/ HTTP/1.1" 200
Jan 07 12:00:45 makerlog gunicorn[19800]: [2019-01-07 12:00:45 +0000] [19808] [INFO] None - "GET /users/1008/products/ HTTP/1.1" 200
Jan 07 12:00:45 makerlog gunicorn[19800]: [2019-01-07 12:00:45 +0000] [19809] [INFO] None - "GET /users/1008/stream/2019/jan/2/ HTTP/1.1" 200
Jan 07 12:00:47 makerlog gunicorn[19800]: [2019-01-07 12:00:47 +0000] [19808] [INFO] None - "OPTIONS /projects/408/related/ HTTP/1.1" 200
Jan 07 12:00:47 makerlog gunicorn[19800]: [2019-01-07 12:00:47 +0000] [19806] [INFO] None - "GET /projects/408/related/ HTTP/1.1" 200
Jan 07 12:00:49 makerlog gunicorn[19800]: [2019-01-07 12:00:49 +0000] [19808] [INFO] None - "OPTIONS /tasks/26850/can_praise/ HTTP/1.1" 200
Jan 07 12:00:49 makerlog gunicorn[19800]: [2019-01-07 12:00:49 +0000] [19806] [INFO] None - "OPTIONS /tasks/26850/comments/ HTTP/1.1" 200
Jan 07 12:00:49 makerlog gunicorn[19800]: [2019-01-07 12:00:49 +0000] [19809] [INFO] None - "GET /tasks/26850/can_praise/ HTTP/1.1" 200
Jan 07 12:00:49 makerlog gunicorn[19800]: [2019-01-07 12:00:49 +0000] [19808] [INFO] None - "GET /tasks/26850/comments/ HTTP/1.1" 200
Jan 07 12:00:53 makerlog gunicorn[19800]: [2019-01-07 12:00:53 +0000] [19809] [INFO] None - "GET /tasks/26850/can_praise/ HTTP/1.1" 200
Jan 07 12:00:59 makerlog gunicorn[19800]: [2019-01-07 12:00:59 +0000] [19808] [INFO] None - "GET /tasks/26850/can_praise/ HTTP/1.1" 200
Jan 07 12:00:59 makerlog gunicorn[19800]: [2019-01-07 12:00:59 +0000] [19809] [INFO] None - "GET /tasks/26850/comments/ HTTP/1.1" 200
Jan 07 12:01:07 makerlog gunicorn[19800]: [2019-01-07 12:01:07 +0000] [19808] [INFO] None - "GET / HTTP/1.1" 200
Jan 07 12:01:16 makerlog gunicorn[19800]: [2019-01-07 12:01:16 +0000] [19809] [INFO] None - "GET / HTTP/1.1" 200
Jan 07 12:01:19 makerlog gunicorn[19800]: [2019-01-07 12:01:19 +0000] [19809] [INFO] None - "GET /users/ HTTP/1.1" 200
Jan 07 12:01:19 makerlog gunicorn[19800]: [2019-01-07 12:01:19 +0000] [19809] [INFO] None - "HEAD /health HTTP/1.1" 200
Jan 07 12:01:19 makerlog gunicorn[19800]: [2019-01-07 12:01:19 +0000] [19809] [INFO] None - "GET /notifications/ HTTP/1.1" 200
Jan 07 12:01:20 makerlog gunicorn[19800]: [2019-01-07 12:01:20 +0000] [19809] [INFO] None - "OPTIONS /notifications/mark_all_read/ HTTP/1.1" 200
Jan 07 12:01:20 makerlog gunicorn[19800]: [2019-01-07 12:01:20 +0000] [19809] [INFO] None - "GET /notifications/mark_all_read/ HTTP/1.1" 200
Jan 07 12:01:22 makerlog gunicorn[19800]: [2019-01-07 12:01:22 +0000] [19808] [INFO] None - "GET /v1/docs/ HTTP/1.1" 200
Jan 07 12:01:23 makerlog gunicorn[19800]: [2019-01-07 12:01:23 +0000] [19809] [INFO] None - "GET /v1/docs/ HTTP/1.1" 200
Jan 07 12:01:29 makerlog gunicorn[19800]: [2019-01-07 12:01:29 +0000] [19809] [INFO] None - "GET / HTTP/1.1" 200
Jan 07 12:01:31 makerlog gunicorn[19800]: Error in data transfer
Jan 07 12:01:31 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 674, in transfer_data
Jan 07 12:01:31 makerlog gunicorn[19800]:     message = yield from self.read_message()
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 742, in read_message
Jan 07 12:01:31 makerlog gunicorn[19800]:     frame = yield from self.read_data_frame(max_size=self.max_size)
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 825, in read_data_frame
Jan 07 12:01:31 makerlog gunicorn[19800]:     yield from self.write_close_frame(frame.data)
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 958, in write_close_frame
Jan 07 12:01:31 makerlog gunicorn[19800]:     True, OP_CLOSE, data, _expected_state=State.CLOSING
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 919, in write_frame
Jan 07 12:01:31 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 12:01:31 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 12:01:31 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1001 (going away), no reason
Jan 07 12:01:31 makerlog gunicorn[19800]: Error in data transfer
Jan 07 12:01:31 makerlog gunicorn[19800]: Traceback (most recent call last):
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 674, in transfer_data
Jan 07 12:01:31 makerlog gunicorn[19800]:     message = yield from self.read_message()
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 742, in read_message
Jan 07 12:01:31 makerlog gunicorn[19800]:     frame = yield from self.read_data_frame(max_size=self.max_size)
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 825, in read_data_frame
Jan 07 12:01:31 makerlog gunicorn[19800]:     yield from self.write_close_frame(frame.data)
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 958, in write_close_frame
Jan 07 12:01:31 makerlog gunicorn[19800]:     True, OP_CLOSE, data, _expected_state=State.CLOSING
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 919, in write_frame
Jan 07 12:01:31 makerlog gunicorn[19800]:     yield from self.ensure_open()
Jan 07 12:01:31 makerlog gunicorn[19800]:   File "/home/sergio/server/lib/python3.6/site-packages/websockets/protocol.py", line 646, in ensure_open
Jan 07 12:01:31 makerlog gunicorn[19800]:     ) from self.transfer_data_exc
Jan 07 12:01:31 makerlog gunicorn[19800]: websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1001 (going away), no reason
matteing picture matteing on 7 Jan 2019

Still facing this issue.

matteing picture matteing on 8 Apr 2019

Okay - can someone break this issue down to something smaller, not involving channels.
Also does the issue replicate on both websocket implementations or just one?

(Use --ws wsproto and --ws websockets to switch between the two implementations.)

tomchristie picture tomchristie on 8 Apr 2019

Hi, I think we have the same problem in our app:

TypeError: An asyncio.Future, a coroutine or an awaitable is required
at ensure_future (/usr/local/lib/python3.6/asyncio/tasks.py:526)
at <setcomp> (/usr/local/lib/python3.6/asyncio/tasks.py:311)
at wait (/usr/local/lib/python3.6/asyncio/tasks.py:311)
at recv (/usr/local/lib/python3.6/site-packages/websockets/protocol.py:419)
at asgi_receive (/usr/local/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py:227)
at await_many_dispatch (/usr/local/lib/python3.6/site-packages/channels/utils.py:51)
at await_many_dispatch (/usr/local/lib/python3.6/site-packages/channels/utils.py:59)
at __call__ (/usr/local/lib/python3.6/site-packages/channels/consumer.py:59)
at run_asgi (/usr/local/lib/python3.6/site-packages/uvicorn/protocols/websockets/websockets_impl.py:147)
sergicolladosopra picture sergicolladosopra on 11 Apr 2019

@sergicolladosopra Okay, with Channels or something else?

What's the smallest possible codebase someone can reduce this down too, so that I've got a good place to start digging from?

tomchristie picture tomchristie on 12 Apr 2019

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

ostcar picture ostcar on 14 Apr 2019
👍5

Channels allows to call close() during connection handshake in connect(), but in example above with wsproto it doesn't, neither does websockets protocol which doesn't handle websocket.close (closed_event is set) in asgi_receive.

I took a look into websockets docs which says:

calls process_request() which may abort the WebSocket handshake and return a HTTP response instead; this hook only makes sense on the server side;

and seems like it's implemented on the web servers and maybe also in channels' middlewares.

So calling close() when connection handshaking is not a right thing to do?

mozartilize picture mozartilize on 17 May 2019

I also have this issue, using uvicorn 0.8.6 and channels 2.2.0. My channels consumers don't call .close() anywhere. I'm getting various errors whether I use wsproto or not. The problem doesn't occur with Daphne. The app works fine in the browser but I am concerned about all the tracebacks.

In websockets/server.py, the handshake stops at this line in WebSocketServerProtocol.handshake:

        if self.state != State.CONNECTING:
            raise CancelHandshake()

At that point, self.state is State.CLOSED. It was set to CLOSED here:

  c:\users\wicke\appdata\local\programs\python\python37-32\lib\runpy.py(85)_run_code()
-> exec(code, run_globals)
  c:\otree\ve-channels2\scripts\uvicorn.exe\__main__.py(9)<module>()
-> sys.exit(main())
  c:\otree\ve-channels2\lib\site-packages\click\core.py(764)__call__()
-> return self.main(*args, **kwargs)
  c:\otree\ve-channels2\lib\site-packages\click\core.py(717)main()
-> rv = self.invoke(ctx)
  c:\otree\ve-channels2\lib\site-packages\click\core.py(956)invoke()
-> return ctx.invoke(self.callback, **ctx.params)
  c:\otree\ve-channels2\lib\site-packages\click\core.py(555)invoke()
-> return callback(*args, **kwargs)
  c:\otree\ve-channels2\lib\site-packages\uvicorn\main.py(258)main()
-> run(**kwargs)
  c:\otree\ve-channels2\lib\site-packages\uvicorn\main.py(279)run()
-> server.run()
  c:\otree\ve-channels2\lib\site-packages\uvicorn\main.py(307)run()
-> loop.run_until_complete(self.serve(sockets=sockets))
  c:\users\wicke\appdata\local\programs\python\python37-32\lib\asyncio\base_events.py(571)run_until_complete()
-> self.run_forever()
  c:\users\wicke\appdata\local\programs\python\python37-32\lib\asyncio\base_events.py(539)run_forever()
-> self._run_once()
  c:\users\wicke\appdata\local\programs\python\python37-32\lib\asyncio\base_events.py(1775)_run_once()
-> handle._run()
  c:\users\wicke\appdata\local\programs\python\python37-32\lib\asyncio\events.py(88)_run()
-> self._context.run(self._callback, *self._args)
  c:\users\wicke\appdata\local\programs\python\python37-32\lib\asyncio\selector_events.py(913)_call_connection_lost()
-> super()._call_connection_lost(exc)
  c:\users\wicke\appdata\local\programs\python\python37-32\lib\asyncio\selector_events.py(687)_call_connection_lost()
-> self._protocol.connection_lost(exc)
  c:\otree\ve-channels2\lib\site-packages\uvicorn\protocols\websockets\websockets_impl.py(65)connection_lost()
-> super().connection_lost(exc)
> c:\otree\ve-channels2\lib\site-packages\websockets\protocol.py(1236)connection_lost()
-> logger.debug("%s - state = CLOSED", self.side)

The exc variable in the above traceback is:

ConnectionAbortedError(10053, 'An established connection was aborted by the software in your host machine', None, 10053, None)

I also see this:

('%s ! failing WebSocket connection in the %s state: %d %s', 'server', 'CLOSED', 1006, '[no reason]')

I tested on Linux (WSL) and I get basically the same traceback.

Happy to provide any additional info to troubleshoot this.

oTree-org picture oTree-org on 11 Aug 2019

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.

tomchristie picture tomchristie on 22 Oct 2019

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

matteing picture matteing on 22 Oct 2019
👍2

Is there any update or workaround for this? I can post more info about what I'm seeing, but it looks like the connection closes and things are fine browser side, but if I call .close() in the .connect() function I end up with type errors in the logs. Having stack traces in the logs is obviously not ideal, but it would help to clarify that's the extent of the issue...

bjornSayers picture bjornSayers on 11 Dec 2019

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

ostcar picture ostcar on 14 Dec 2019
👍3

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.

adamhooper picture adamhooper on 19 Jun 2020
❤1

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? :)

adamhooper picture adamhooper on 8 Sep 2020
👍5

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.

adamhooper picture adamhooper on 26 Oct 2020

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

This has been the only way so far to silence the uvicorn errors we are seeing.

cb109 picture cb109 on 23 Nov 2020

Hi all,

I'm taking a look at this given pings on #704.

I was able to reproduce the TypeError from OP using this setup.

async def app(scope, receive, send):
    assert scope["type"] == "websocket"

    # Pull up first recv message.
    message = await receive()
    assert message["type"] == "websocket.connect"

    # Reject the connection.
    await send({"type": "websocket.close"})
    # -- At this point websockets' recv() is unusable. --

    # This raises the `TypeError` on the server.
    message = await receive()
    # But we would expect it to succeed and return this:
    assert message["type"] == "websocket.disconnect"

Client:

$ python -m asyncio
>>> import websockets
>>> await websockets.connect("ws://localhost:8000")
websockets.exceptions.InvalidStatusCode: server rejected WebSocket connection: HTTP 403

The client sees the 403 after we sent websocket.close, which is expected, but it's the server that's having an issue with the extra TypeError there.

florimondmanca picture florimondmanca on 8 Dec 2020

maybe this is relevant too:

https://github.com/aaugustin/websockets/pull/670

euri10 picture euri10 on 9 Dec 2020
Was this page helpful?
0 / 5 - 0 ratings

Related issues

tomchristie picture tomchristie  路  4Comments
madkote picture madkote  路  7Comments
HenrikOssipoff picture HenrikOssipoff  路  5Comments
itayperl picture itayperl  路  3Comments
unitto1 picture unitto1  路  7Comments