Uncaught `LocalProtocolError` (wsproto >= 1.2.0)

[notonamap]

Hey there, first of all many thanks for providing this great library! I'm running version 0.9.2 but I think it might be still relevant. Websocket server had some ongoing maintenance and was dropping connections from time to time. Looks like this lead to the issue seen below. Should this wsproto error maybe be mapped to ConnectionClosed?

File "/pex-app/lib/python3.10/site-packages/trio_websocket/_impl.py", line 937, in send_message
      await self._send(event)
    File "/pex-app/lib/python3.10/site-packages/trio_websocket/_impl.py", line 1249, in _send
      data = self._wsproto.send(event)
    File "/pex-app/lib/python3.10/site-packages/wsproto/__init__.py", line 64, in send
      data += self.connection.send(event)
    File "/pex-app/lib/python3.10/site-packages/wsproto/connection.py", line 107, in send
      raise LocalProtocolError(
  wsproto.utilities.LocalProtocolError: Event TextMessage(data='...', frame_finished=True, message_finished=True) cannot be sent in state ConnectionState.REMOTE_CLOSING.

[belm0]

I guess so, but the definition of that exception is quite blurry. If it's a programming error, I wouldn't want it suppressed as ConnectionClosed.

    Indicates an error due to local/programming errors.

    This is raised when the connection is asked to do something that
    is either incompatible with the state or the websocket standard.

For what it's worth, our app has never hit this exception, running 1000's of instances for years.

[notonamap]

I'm just speculating here since I'm not really deep in the wsproto code, but maybe the "programming error" here refers to calling connection.send despite the connection.state being REMOTE_CLOSING. I think it's not meant to indicate an error in wsproto itself but by trio-websocket doing an operation that is invalid with the websocket state.

[belm0]

I notice there are only two calls of wsproto.send(), and the other one checks state first:

https://github.com/HyperionGray/trio-websocket/blob/5613f20ab47c653633a08f73788f7bb459853d20/trio_websocket/_impl.py#L999-L1000

it's a little troubling that this send-when-closing case isn't exposed by the autobahn test suite, but perhaps it's very timing sensitive.

[belm0]

And I don't understand this code, explicitly calling send if the state is REMOTE_CLOSING:

https://github.com/HyperionGray/trio-websocket/blob/5613f20ab47c653633a08f73788f7bb459853d20/trio_websocket/_impl.py#L1100-L1101

[belm0]

And I don't understand this code, explicitly calling send if the state is REMOTE_CLOSING:

apparently sending CloseConnection is allowed during REMOTE_CLOSING:

https://github.com/python-hyper/wsproto/blob/88d5efaa16c798747522781d625f137bae2ca15b/src/wsproto/connection.py#L97-L105

[belm0]

For what it's worth, our app has never hit this exception, running 1000's of instances for years.

I see, we're running an old wsproto (0.14), but the change of raising LocalProtocolError for a text message is very recent (1.2.0):

https://github.com/python-hyper/wsproto/commit/b0efe554cca8ac24dcf82940137d04c90351c9c1

[belm0]

It might be a race condition. When trio-websocket receives a CloseConnection event, it doesn't set its local state to closed (via _close_web_socket(), which sets _close_reason) immediately. First it sends the CloseConnection reply to the peer. So if send_message() is called during this period, it would cause a LocalProtocolError with wsproto >= 1.2.0.

https://github.com/HyperionGray/trio-websocket/blob/5613f20ab47c653633a08f73788f7bb459853d20/trio_websocket/_impl.py#L1092-L1102

[belm0]

For good measure, I'm asking wsproto to clarify connection state change timing.

https://github.com/python-hyper/wsproto/issues/181

[belm0]

autobahn client test hits a LocalProtocolError, but it's a different connection state (ConnectionState.CLOSED):

ERROR:client:  runtime exception during test case 7.1.6
Traceback (most recent call last):
  File "client.py", line 72, in run_tests
    await run_case(args.url, case)
  File "client.py", line 40, in run_case
    await conn.send_message(data)
  File "/.../trio_websocket/_impl.py", line 945, in send_message
    await self._send(event)
  File "/.../trio_websocket/_impl.py", line 1257, in _send
    data = self._wsproto.send(event)
  File "/.../venv/lib/python3.7/site-packages/wsproto/__init__.py", line 64, in send
    data += self.connection.send(event)
  File "/.../venv/lib/python3.7/site-packages/wsproto/connection.py", line 108, in send
    f"Event {event} cannot be sent in state {self.state}."
wsproto.utilities.LocalProtocolError: Event TextMessage(data='Hello World!', frame_finished=True, message_finished=True) cannot be sent in state ConnectionState.CLOSED.

[belm0]

Unfortunately, send_message() is defined as raising ConnectionClosed if a connection is closed, but the case where a close is in progress is left undefined. The current implementation (with wsproto < 1.2.0) silently ignores the send.

Redefining this close-in-progress case to raise ConnectionClosed would be a breaking change for users of wsproto < 1.2.0.

https://github.com/HyperionGray/trio-websocket/blob/ad402206a801b668cc0c0a80dd0ea994b96aa041/trio_websocket/_impl.py#L929-L936

Interestingly, ConnectionClosed is defined as covering "in the process of closing", contradicting the send_message() implementation.

https://github.com/HyperionGray/trio-websocket/blob/ad402206a801b668cc0c0a80dd0ea994b96aa041/trio_websocket/_impl.py#L444-L448

[notonamap]

Hey @belm0. Just wanted to thank you for taking care of this so quickly!