chrysn / aiocoap

The Python CoAP library
Other
262 stars 119 forks source link

gbulb tests fail for short-lived contexts #321

Closed chrysn closed 1 month ago

chrysn commented 9 months ago

The test_multiple_contexts test is failing with gbulb.

I don't have the time to trace it down, so for the moment, that one is being set to expected-failure.

One observation debugging it so far was that it's not actually the presence of multiple contexts that is causing the issue (running the teste with c1/c2 commented out fails the same). It's also no race condition -- there is something about how this is set up and shut down that doesn't sit well with gbulb.

test logs when removing c1/c2 ``` ===================================================================================================================================================== test session starts ======================================================================================================================================================= platform linux -- Python 3.11.5, pytest-7.4.2, pluggy-1.3.0 cachedir: .tox/py311-gbulb/.pytest_cache rootdir: /home/chrysn/git/aiocoap collected 241 items / 240 deselected / 1 selected tests/test_protocol.py F [100%] ============================================================================================================================================================ FAILURES ============================================================================================================================================================ ____________________________________________________________________________________________________________________________________________ TestProtocolSetup.test_multiple_contexts ____________________________________________________________________________________________________________________________________________ self = , function = , args = (), startcount = 0, result = None def wrapped(self, *args, function=function): # assertLogs does not work as assertDoesntLog anyway without major # tricking, and it interacts badly with WithLogMonitoring as they both # try to change the root logger's level. startcount = len(self.handler.list) result = function(self, *args) messages = [m.getMessage() for m in self.handler.list[startcount:] if m.levelno >= logging.WARNING and 'There is no current event loop' not in m.getMessage()] if len(expected_warnings) != len(messages) or not all( e == m or (e.endswith('...') and m.startswith(e[:-3])) for (e, m) in zip(expected_warnings, messages)): > self.assertEqual(messages, expected_warnings, "Function %s had unexpected warnings"%function.__name__) E AssertionError: Lists differ: ['Exception in callback ReadTransport._loo[1658 chars]op)'] != [] E E First list contains 1 additional elements. E First extra element 0: E 'Exception in callback ReadTransport._loop_reading()\nhandle: ) created at /home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/glib_events.py:146>\nsource_traceback: Object created at (most recent call last):\n File "/usr/lib/python3.11/asyncio/events.py", line 80, in _run\n self._context.run(self._callback, *self._args)\n File "/home/chrysn/git/aiocoap/aiocoap/tokenmanager.py", line 61, in shutdown\n await self.token_interface.shutdown()\n File "/home/chrysn/git/aiocoap/aiocoap/messagemanager.py", line 71, in shutdown\n await self.message_interface.shutdown()\n File "/home/chrysn/git/aiocoap/aiocoap/transports/tinydtls_server.py", line 274, in shutdown\n await super().shutdown()\n File "/home/chrysn/git/aiocoap/aiocoap/transports/generic_udp.py", line 51, in shutdown\n await self._pool.shutdown()\n File "/home/chrysn/git/aiocoap/aiocoap/transports/simplesocketserver.py", line 124, in shutdown\n self._transport.abort()\n File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/transports.py", line 193, in abort\n self._force_close(None)\n File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/transports.py", line 68, in _force_close\n cancelable.cancel()\n File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/glib_events.py", line 876, in call_soon\n return GLibHandle(\n File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/glib_events.py", line 146, in __init__\n super().__init__(callback, args, loop)' E E Diff is 1941 characters long. Set self.maxDiff to None to see it. : Function test_multiple_contexts had unexpected warnings tests/fixtures.py:78: AssertionError ------------------------------------------------------------------------------------------------------------------------------------------------------- Captured log call -------------------------------------------------------------------------------------------------------------------------------------------------------- INFO asyncio:base_events.py:1394 Datagram endpoint local_addr=('::1', 5684) remote_addr=None created: (, ) INFO asyncio:base_events.py:1553 ,)> is serving INFO asyncio:base_events.py:1553 ,)> is serving INFO websockets.server:server.py:711 server listening on [::1]:8683 DEBUG asyncio:base_events.py:847 Get address info ::1:5683, type=, proto=17, flags= DEBUG asyncio:base_events.py:857 Getting address info ::1:5683, type=, proto=17, flags= took 0.193ms: [(, , 17, '', ('::1', 5683, 0, 0))] DEBUG coap-server:protocol.py:299 Server ready to receive requests DEBUG coap-server:protocol.py:315 Shutting down context DEBUG coap-server:tcp.py:321 Shutting down server DEBUG coap-server:tcp.py:421 Shutting down any outgoing connections on on DEBUG coap-server:tcp.py:421 Shutting down any outgoing connections on on DEBUG coap-server:ws.py:355 Shutting down any connections on ERROR asyncio:base_events.py:1771 Exception in callback ReadTransport._loop_reading() handle: ) created at /home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/glib_events.py:146> source_traceback: Object created at (most recent call last): File "/usr/lib/python3.11/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/home/chrysn/git/aiocoap/aiocoap/tokenmanager.py", line 61, in shutdown await self.token_interface.shutdown() File "/home/chrysn/git/aiocoap/aiocoap/messagemanager.py", line 71, in shutdown await self.message_interface.shutdown() File "/home/chrysn/git/aiocoap/aiocoap/transports/tinydtls_server.py", line 274, in shutdown await super().shutdown() File "/home/chrysn/git/aiocoap/aiocoap/transports/generic_udp.py", line 51, in shutdown await self._pool.shutdown() File "/home/chrysn/git/aiocoap/aiocoap/transports/simplesocketserver.py", line 124, in shutdown self._transport.abort() File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/transports.py", line 193, in abort self._force_close(None) File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/transports.py", line 68, in _force_close cancelable.cancel() File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/glib_events.py", line 876, in call_soon return GLibHandle( File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/glib_events.py", line 146, in __init__ super().__init__(callback, args, loop) Traceback (most recent call last): File "/usr/lib/python3.11/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/home/chrysn/git/aiocoap/.tox/py311-gbulb/lib/python3.11/site-packages/gbulb/transports.py", line 146, in _loop_reading data = fut.result() # Deliver data later in "finally" clause ^^^^^^^^^^^^ asyncio.exceptions.CancelledError INFO websockets.server:server.py:763 server closing INFO websockets.server:server.py:804 server closed ==================================================================================================================================================== short test summary info ===================================================================================================================================================== FAILED tests/test_protocol.py::TestProtocolSetup::test_multiple_contexts - AssertionError: Lists differ: ['Exception in callback ReadTransport._loo[1658 chars]op)'] != [] =============================================================================================================================================== 1 failed, 240 deselected in 0.68s ================================================================================================================================================ py311-gbulb: exit 1 (0.94 seconds) /home/chrysn/git/aiocoap> sh -c 'if python3 --version |grep -iq pypy ; then python -Xdev -m pytest "$@" ; else python -Xdev -m coverage run --parallel -m pytest "$@" ; fi' arbitrary-name-for-our-script -k multiple pid=11617 .pkg: _exit> python /usr/lib/python3/dist-packages/pyproject_api/_backend.py True setuptools.build_meta py311-gbulb: FAIL code 1 (4.22=setup[3.12]+cmd[0.15,0.94] seconds) evaluation failed :( (4.28 seconds) ```
chrysn commented 1 month ago

Closing as gbulb support is being phased out in favor of pygobject's upcoming native asyncio support.