Skip to content

Test failure, test_backpressure.py: TransitWebSockets.test_buffer_fills #45

@riastradh

Description

@riastradh

Version: 0.4.0

The immediate error is:

  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/abstract.py", line 213, in connectionLost
    self.producer.stopProducing()
builtins.AttributeError: 'ProduceMessages' object has no attribute 'stopProducing'

And I see that, indeed, the only class ProduceMessages I can find in the tree does not implement stopProducing, even though it is part of Twisted's IPullProducer inherited from IProducer:

        @implementer(IPullProducer)
        class ProduceMessages:
            def __init__(self, ws, on_produce):
...
            def resumeProducing(self):
...

https://github.com/magic-wormhole/magic-wormhole-transit-relay/blob/0.4.0/src/wormhole_transit_relay/test/test_backpressure.py#L155-L171

class IProducer(Interface):
...
    def stopProducing() -> None:
...
class IPullProducer(IProducer):
...

https://github.com/twisted/twisted/blob/twisted-24.11.0/src/twisted/internet/interfaces.py#L1818-L1832
https://github.com/twisted/twisted/blob/twisted-24.11.0/src/twisted/internet/interfaces.py#L1861

However, I have no idea whether the bug is that ProduceMessages doesn't implement stopProducing, or the bug that anything is calling stopProducing in the first place; perhaps the missing stopProducing method is merely compounding an underlying problem that is not obvious to me.


Full test output:

============================= test session starts ==============================
platform netbsd9 -- Python 3.12.7, pytest-8.3.3, pluggy-1.5.0
rootdir: /home/riastradh/pkgsrc/current/work/net/py-magic-wormhole-transit-relay/work/magic-wormhole-transit-relay-0.4.0
collected 91 items

src/wormhole_transit_relay/test/test_backpressure.py FE                  [  1%]
src/wormhole_transit_relay/test/test_config.py .....                     [  6%]
src/wormhole_transit_relay/test/test_database.py ..........              [ 17%]
src/wormhole_transit_relay/test/test_rlimits.py .                        [ 18%]
src/wormhole_transit_relay/test/test_service.py .....                    [ 24%]
src/wormhole_transit_relay/test/test_stats.py .....                      [ 29%]
src/wormhole_transit_relay/test/test_transit_server.py ................. [ 48%]
...............................................                          [100%]

==================================== ERRORS ====================================
___________ ERROR at teardown of TransitWebSockets.test_buffer_fills ___________

logger = <<class 'twisted.internet.tcp.Client'> to ('127.0.0.1', 8088) at 784110591f10>
func = <bound method _PollLikeMixin._doReadOrWrite of <twisted.internet.pollreactor.PollReactor object at 0x7841110efa40>>
args = (<<class 'twisted.internet.tcp.Client'> to ('127.0.0.1', 8088) at 784110591f10>, 20, 5)
kw = {}, lp = 'Sender,client'

    def callWithLogger(logger, func, *args, **kw):
        """
        Utility method which wraps a function in a try:/except:, logs a failure if
        one occurs, and uses the system's logPrefix.
        """
        try:
            lp = logger.logPrefix()
        except KeyboardInterrupt:
            raise
        except BaseException:
            lp = "(buggy logPrefix method)"
            err(system=lp)
        try:
>           return callWithContext({"system": lp}, func, *args, **kw)

../../../../../pkg/lib/python3.12/site-packages/twisted/python/log.py:96:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
../../../../../pkg/lib/python3.12/site-packages/twisted/python/log.py:80: in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
../../../../../pkg/lib/python3.12/site-packages/twisted/python/context.py:117: in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
../../../../../pkg/lib/python3.12/site-packages/twisted/python/context.py:82: in callWithContext
    return func(*args, **kw)
../../../../../pkg/lib/python3.12/site-packages/twisted/internet/posixbase.py:504: in _doReadOrWrite
    self._disconnectSelectable(selectable, why, inRead)
../../../../../pkg/lib/python3.12/site-packages/twisted/internet/posixbase.py:112: in _disconnectSelectable
    selectable.connectionLost(f)
../../../../../pkg/lib/python3.12/site-packages/twisted/internet/tcp.py:521: in connectionLost
    self._commonConnection.connectionLost(self, reason)
../../../../../pkg/lib/python3.12/site-packages/twisted/internet/tcp.py:322: in connectionLost
    abstract.FileDescriptor.connectionLost(self, reason)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <<class 'twisted.internet.tcp.Client'> to ('127.0.0.1', 8088) at 784110591f10>
reason = <twisted.python.failure.Failure twisted.internet.error.ConnectionLost: Connection to the other side was lost in a non-clean fashion.>

    def connectionLost(self, reason):
        """The connection was lost.

        This is called when the connection on a selectable object has been
        lost.  It will be called whether the connection was closed explicitly,
        an exception occurred in an event handler, or the other end of the
        connection closed it first.

        Clean up state here, but make sure to call back up to FileDescriptor.
        """
        self.disconnected = 1
        self.connected = 0
        if self.producer is not None:
>           self.producer.stopProducing()
E           AttributeError: 'ProduceMessages' object has no attribute 'stopProducing'. Did you mean: 'resumeProducing'?

../../../../../pkg/lib/python3.12/site-packages/twisted/internet/abstract.py:213: AttributeError
----------------------------- Captured stdout call -----------------------------
ERR: Removing stale pidfile /home/riastradh/pkgsrc/current/work/net/py-magic-wormhole-transit-relay/work/magic-wormhole-transit-relay-0.4.0/twistd.pid

Using WebSocket URL 'ws://localhost:8088/'
2025-04-07T18:00:58+0000 [-] Removing stale pidfile /home/riastradh/pkgsrc/current/work/net/py-magic-wormhole-transit-relay/work/magic-wormhole-transit-relay-0.4.0/twistd.pid
2025-04-07T18:00:58+0000 [-] changing RLIMIT_NOFILE from (3404,3404) to (3404,3404)
2025-04-07T18:00:58+0000 [-] setrlimit successful
2025-04-07T18:00:58+0000 [-] not blurring access times
2025-04-07T18:00:58+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] twistd 24.11.0 (/home/riastradh/pkgsrc/current/pkg/bin/python3.12 3.12.7) starting up.
2025-04-07T18:00:58+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] reactor class: twisted.internet.pollreactor.PollReactor.
2025-04-07T18:00:58+0000 [-] ServerFactory starting on 4001
2025-04-07T18:00:58+0000 [twisted.internet.protocol.ServerFactory#info] Starting factory <twisted.internet.protocol.ServerFactory object at 0x731177c545a0>
2025-04-07T18:00:58+0000 [-] WebSocketServerFactory starting on 8088
Transit running
2025-04-07T18:00:58+0000 [autobahn.twisted.websocket.WebSocketServerFactory#info] Starting factory <autobahn.twisted.websocket.WebSocketServerFactory object at 0x731177c544b0>
recv: 3
onMessage
sent 1048576, total 1048576
sent 1048576, total 2097152
send: ok

Sent 2.0MiB of 100.0MiB before backpressure
close: False 1006 connection was closed uncleanly ("WebSocket closing handshake timeout (peer did not finish the closing handshake in time)")
2025-04-07T18:01:03+0000 [autobahn.twisted.websocket.WebSocketServerProtocol#warn] dropping connection to peer tcp4:127.0.0.1:60865 with abort=True: WebSocket closing handshake timeout (peer did not finish the closing handshake in time)
----------------------------- Captured stderr call -----------------------------
Unhandled Error
Traceback (most recent call last):
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/log.py", line 96, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/log.py", line 80, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/context.py", line 117, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/context.py", line 82, in callWithContext
    return func(*args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/posixbase.py", line 504, in _doReadOrWrite
    self._disconnectSelectable(selectable, why, inRead)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/posixbase.py", line 112, in _disconnectSelectable
    selectable.connectionLost(f)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/tcp.py", line 521, in connectionLost
    self._commonConnection.connectionLost(self, reason)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/tcp.py", line 322, in connectionLost
    abstract.FileDescriptor.connectionLost(self, reason)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/abstract.py", line 213, in connectionLost
    self.producer.stopProducing()
builtins.AttributeError: 'ProduceMessages' object has no attribute 'stopProducing'

=================================== FAILURES ===================================
_____________________ TransitWebSockets.test_buffer_fills ______________________
'NoneType' object is not iterable

During handling of the above exception, another exception occurred:
NOTE: Incompatible Exception Representation, displaying natively:

twisted.internet.defer.TimeoutError: <wormhole_transit_relay.test.test_backpressure.TransitWebSockets testMethod=test_buffer_fills> (test_buffer_fills) still running at 120.0 secs
----------------------------- Captured stdout call -----------------------------
ERR: Removing stale pidfile /home/riastradh/pkgsrc/current/work/net/py-magic-wormhole-transit-relay/work/magic-wormhole-transit-relay-0.4.0/twistd.pid

Using WebSocket URL 'ws://localhost:8088/'
2025-04-07T18:00:58+0000 [-] Removing stale pidfile /home/riastradh/pkgsrc/current/work/net/py-magic-wormhole-transit-relay/work/magic-wormhole-transit-relay-0.4.0/twistd.pid
2025-04-07T18:00:58+0000 [-] changing RLIMIT_NOFILE from (3404,3404) to (3404,3404)
2025-04-07T18:00:58+0000 [-] setrlimit successful
2025-04-07T18:00:58+0000 [-] not blurring access times
2025-04-07T18:00:58+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] twistd 24.11.0 (/home/riastradh/pkgsrc/current/pkg/bin/python3.12 3.12.7) starting up.
2025-04-07T18:00:58+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] reactor class: twisted.internet.pollreactor.PollReactor.
2025-04-07T18:00:58+0000 [-] ServerFactory starting on 4001
2025-04-07T18:00:58+0000 [twisted.internet.protocol.ServerFactory#info] Starting factory <twisted.internet.protocol.ServerFactory object at 0x731177c545a0>
2025-04-07T18:00:58+0000 [-] WebSocketServerFactory starting on 8088
Transit running
2025-04-07T18:00:58+0000 [autobahn.twisted.websocket.WebSocketServerFactory#info] Starting factory <autobahn.twisted.websocket.WebSocketServerFactory object at 0x731177c544b0>
recv: 3
onMessage
sent 1048576, total 1048576
sent 1048576, total 2097152
send: ok

Sent 2.0MiB of 100.0MiB before backpressure
close: False 1006 connection was closed uncleanly ("WebSocket closing handshake timeout (peer did not finish the closing handshake in time)")
2025-04-07T18:01:03+0000 [autobahn.twisted.websocket.WebSocketServerProtocol#warn] dropping connection to peer tcp4:127.0.0.1:60865 with abort=True: WebSocket closing handshake timeout (peer did not finish the closing handshake in time)
----------------------------- Captured stderr call -----------------------------
Unhandled Error
Traceback (most recent call last):
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/log.py", line 96, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/log.py", line 80, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/context.py", line 117, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/python/context.py", line 82, in callWithContext
    return func(*args, **kw)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/posixbase.py", line 504, in _doReadOrWrite
    self._disconnectSelectable(selectable, why, inRead)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/posixbase.py", line 112, in _disconnectSelectable
    selectable.connectionLost(f)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/tcp.py", line 521, in connectionLost
    self._commonConnection.connectionLost(self, reason)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/tcp.py", line 322, in connectionLost
    abstract.FileDescriptor.connectionLost(self, reason)
  File "/home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/twisted/internet/abstract.py", line 213, in connectionLost
    self.producer.stopProducing()
builtins.AttributeError: 'ProduceMessages' object has no attribute 'stopProducing'

=============================== warnings summary ===============================
src/wormhole_transit_relay/database.py:4
  /home/riastradh/pkgsrc/current/work/net/py-magic-wormhole-transit-relay/work/magic-wormhole-transit-relay-0.4.0/src/wormhole_transit_relay/database.py:4: DeprecationWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html
    from pkg_resources import resource_string

../../../../../pkg/lib/python3.12/site-packages/pkg_resources/__init__.py:3147
  /home/riastradh/pkgsrc/current/pkg/lib/python3.12/site-packages/pkg_resources/__init__.py:3147: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('zope')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages
    declare_namespace(pkg)

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
=========================== short test summary info ============================
FAILED src/wormhole_transit_relay/test/test_backpressure.py::TransitWebSockets::test_buffer_fills - Failed: NOTE: Incompatible Exception Representation, displaying natively:
ERROR src/wormhole_transit_relay/test/test_backpressure.py::TransitWebSockets::test_buffer_fills - AttributeError: 'ProduceMessages' object has no attribute 'stopProducing'. ...
======== 1 failed, 90 passed, 2 warnings, 1 error in 124.84s (0:02:04) =========

Metadata

Metadata

Assignees

No one assigned

    Labels

    needs-investigationmore work is needed to understand the problem

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions