trio-websocket icon indicating copy to clipboard operation
trio-websocket copied to clipboard

`test_handshake_subprotocol` sometimes fails on MacOS

Open mehaase opened this issue 7 years ago • 1 comments

This tests fails intermittently. It might have some race condition. I haven't noticed this behavior on Linux yet.

================================================= test session starts ==================================================
platform darwin -- Python 3.7.0, pytest-3.8.2, py-1.6.0, pluggy-0.7.1
rootdir: /Volumes/Case_Sensitive/trio-websocket, inifile: pytest.ini
plugins: trio-0.5.1, cov-2.6.0
collected 27 items

tests/test_connection.py ..............F............                                                             [100%]

======================================================= FAILURES =======================================================
______________________________________________ test_handshake_subprotocol ______________________________________________

self = <trio._core._run.NurseryManager object at 0x103a0a518>, etype = None, exc = None, tb = None

    @enable_ki_protection
    async def __aexit__(self, etype, exc, tb):
        new_exc = await self._nursery._nested_child_finished(exc)
        # Tracebacks show the 'raise' line below out of context, so let's give
        # this variable a name that makes sense out of context.
        combined_error_from_nursery = self._scope._close(new_exc)
        if combined_error_from_nursery is None:
            return True
        elif combined_error_from_nursery is exc:
            return False
        else:
            # Copied verbatim from MultiErrorCatcher.  Python doesn't
            # allow us to encapsulate this __context__ fixup.
            old_context = combined_error_from_nursery.__context__
            try:
>               raise combined_error_from_nursery

venv/lib/python3.7/site-packages/trio/_core/_run.py:397:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
trio_websocket/__init__.py:255: in serve_websocket
    await server.run(task_status=task_status)
trio_websocket/__init__.py:960: in run
    await trio.sleep_forever()
venv/lib/python3.7/site-packages/trio/_core/_run.py:397: in __aexit__
    raise combined_error_from_nursery
venv/lib/python3.7/site-packages/trio/_highlevel_serve_listeners.py:129: in serve_listeners
    task_status.started(listeners)
venv/lib/python3.7/site-packages/trio/_core/_run.py:397: in __aexit__
    raise combined_error_from_nursery
venv/lib/python3.7/site-packages/trio/_highlevel_serve_listeners.py:27: in _run_handler
    await handler(stream)
trio_websocket/__init__.py:976: in _handle_connection
    await self._handler(request)
venv/lib/python3.7/site-packages/trio/_core/_run.py:397: in __aexit__
    raise combined_error_from_nursery
trio_websocket/__init__.py:826: in _reader_task
    self._wsproto.receive_bytes(data)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <wsproto.connection.WSConnection object at 0x1034df208>, data = b'\x88\x82\x99\xd2tS\x9a:'

    def receive_bytes(self, data):
        """
            Pass some received data to the connection for handling.

            A list of events that the remote peer triggered by sending this data can
            be retrieved with :meth:`~wsproto.connection.WSConnection.events`.

            :param data: The data received from the remote peer on the network.
            :type data: ``bytes``
            """

        if data is None and self._state is ConnectionState.OPEN:
            # "If _The WebSocket Connection is Closed_ and no Close control
            # frame was received by the endpoint (such as could occur if the
            # underlying transport connection is lost), _The WebSocket
            # Connection Close Code_ is considered to be 1006."
            self._events.append(ConnectionClosed(CloseReason.ABNORMAL_CLOSURE))
            self._state = ConnectionState.CLOSED
            return

        if self._state is ConnectionState.CONNECTING:
            event, data = self._process_upgrade(data)
            if event is not None:
                self._events.append(event)

        if self._state in (ConnectionState.OPEN, ConnectionState.CLOSING):
            self._proto.receive_bytes(data)
        elif self._state is ConnectionState.CLOSED:
>           raise ValueError('Connection already closed.')
E           ValueError: Connection already closed.

venv/lib/python3.7/site-packages/wsproto/connection.py:231: ValueError

---------- coverage: platform darwin, python 3.7.0-final-0 -----------
Name                         Stmts   Miss  Cover
------------------------------------------------
trio_websocket/__init__.py     369     31    92%
trio_websocket/version.py        1      0   100%
------------------------------------------------
TOTAL                          370     31    92%

========================================= 1 failed, 26 passed in 0.77 seconds ==========================================
(venv) trio-websocket (create_docs) $ pytest --cov=trio_websocket
================================================= test session starts ==================================================
platform darwin -- Python 3.7.0, pytest-3.8.2, py-1.6.0, pluggy-0.7.1
rootdir: /Volumes/Case_Sensitive/trio-websocket, inifile: pytest.ini
plugins: trio-0.5.1, cov-2.6.0
collected 27 items

tests/test_connection.py ...........................                                                             [100%]

---------- coverage: platform darwin, python 3.7.0-final-0 -----------
Name                         Stmts   Miss  Cover
------------------------------------------------
trio_websocket/__init__.py     369     33    91%
trio_websocket/version.py        1      0   100%
------------------------------------------------
TOTAL                          370     33    91%


============================================== 27 passed in 0.57 seconds ===============================================

mehaase avatar Oct 24 '18 15:10 mehaase

The strange thing about this issue is that this particular test isn't extremely dependent on timing: it's only supposed to test the negotiation of the subprotocol. What makes this test unique? The only thing I can think of is that it's one of the few tests where neither side really does anything with the connection. In fact, both sides contain the same assertion and then close. Maybe the race occurs when both sides close simultaneously?

mehaase avatar Nov 12 '18 18:11 mehaase