gbulb tests fail for short-lived contexts
Closed this issue · 1 comments
chrysn commented
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 = <tests.test_protocol.TestProtocolSetup testMethod=test_multiple_contexts>, function = <function TestProtocolSetup.test_multiple_contexts at 0x7f678799a4c0>, 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(<Future cance...events.py:595>)\nhandle: <GLibHandle ReadTransport._loop_reading(<Future cance...events.py:595>) 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: (<gbulb.transports.DatagramTransport object at 0x7f67877761e0>, <aiocoap.transports.tinydtls_server._DatagramServerSocketSimpleDTLS object at 0x7f67878ba360>)
INFO asyncio:base_events.py:1553 <Server sockets=(<asyncio.TransportSocket fd=15, family=10, type=1, proto=6, laddr=('::1', 5683, 0, 0)>,)> is serving
INFO asyncio:base_events.py:1553 <Server sockets=(<asyncio.TransportSocket fd=16, family=10, type=1, proto=6, laddr=('::1', 8683, 0, 0)>,)> 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=<SocketKind.SOCK_DGRAM: 2>, proto=17, flags=<AddressInfo.AI_ADDRCONFIG: 32>
DEBUG asyncio:base_events.py:857 Getting address info ::1:5683, type=<SocketKind.SOCK_DGRAM: 2>, proto=17, flags=<AddressInfo.AI_ADDRCONFIG: 32> took 0.193ms: [(<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 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 <aiocoap.transports.tcp.TCPServer object at 0x7f67878bb080>
DEBUG coap-server:tcp.py:421 Shutting down any outgoing connections on on <aiocoap.transports.tcp.TCPClient object at 0x7f67878bb8a0>
DEBUG coap-server:tcp.py:421 Shutting down any outgoing connections on on <aiocoap.transports.tls.TLSClient object at 0x7f67878bb7b0>
DEBUG coap-server:ws.py:355 Shutting down any connections on <aiocoap.transports.ws.WSPool object at 0x7f67878bb9e0>
ERROR asyncio:base_events.py:1771 Exception in callback ReadTransport._loop_reading(<Future cance...events.py:595>)
handle: <GLibHandle ReadTransport._loop_reading(<Future cance...events.py:595>) 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
Closing as gbulb support is being phased out in favor of pygobject's upcoming native asyncio support.