Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

gbulb tests fail for short-lived contexts #321

Closed
chrysn opened this issue Sep 21, 2023 · 1 comment
Closed

gbulb tests fail for short-lived contexts #321

chrysn opened this issue Sep 21, 2023 · 1 comment

Comments

@chrysn
Copy link
Owner

chrysn commented Sep 21, 2023

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 added a commit that referenced this issue Sep 23, 2023
chrysn added a commit that referenced this issue Oct 23, 2023
@chrysn
Copy link
Owner Author

chrysn commented May 13, 2024

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

@chrysn chrysn closed this as completed May 13, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant