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

tests/test_asyncio/test_connect.py hangs on Python 3.12 #167

Open
mgorny opened this issue Jun 26, 2023 · 0 comments
Open

tests/test_asyncio/test_connect.py hangs on Python 3.12 #167

mgorny opened this issue Jun 26, 2023 · 0 comments

Comments

@mgorny
Copy link
Contributor

mgorny commented Jun 26, 2023

The newly added tests in tests/test_asyncio/test_connect.py are hanging for me on Python 3.12.0b3. This is the traceback after running with pytest-timeout plugin to force them to time out:

$ python -m pytest tests/test_asyncio/test_connect.py --timeout 60
========================================================= test session starts =========================================================
platform linux -- Python 3.12.0b3, pytest-7.4.0, pluggy-1.2.0
rootdir: /tmp/redis-py
configfile: tox.ini
plugins: timeout-2.1.0, asyncio-0.21.0
timeout: 60.0s
timeout method: signal
timeout func_only: False
asyncio: mode=Mode.AUTO
collected 3 items                                                                                                                     

tests/test_asyncio/test_connect.py FFF

============================================================== FAILURES ===============================================================
__________________________________________________________ test_tcp_connect ___________________________________________________________

args = (), kwargs = {'tcp_address': ('127.0.0.1', 51823)}, coro = <coroutine object test_tcp_connect at 0x7f10327f2a70>
task = <Task pending name='Task-1' coro=<test_tcp_connect() running at /tmp/redis-py/tests/test_asyncio/test_connect.py:42> wait_for=<Future pending cb=[Task.task_wakeup()]>>

    @functools.wraps(func)
    def inner(*args, **kwargs):
        coro = func(*args, **kwargs)
        if not inspect.isawaitable(coro):
            pyfuncitem.warn(
                pytest.PytestWarning(
                    f"The test {pyfuncitem} is marked with '@pytest.mark.asyncio' "
                    "but it is not an async function. "
                    "Please remove asyncio marker. "
                    "If the test is not marked explicitly, "
                    "check for global markers applied via 'pytestmark'."
                )
            )
            return
        task = asyncio.ensure_future(coro, loop=_loop)
        try:
>           _loop.run_until_complete(task)

.venv/lib/python3.12/site-packages/pytest_asyncio/plugin.py:525: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
/usr/lib/python3.12/asyncio/base_events.py:651: in run_until_complete
    self.run_forever()
/usr/lib/python3.12/asyncio/base_events.py:618: in run_forever
    self._run_once()
/usr/lib/python3.12/asyncio/base_events.py:1913: in _run_once
    event_list = self._selector.select(timeout)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <selectors.EpollSelector object at 0x7f103277b740>, timeout = -1

    def select(self, timeout=None):
        if timeout is None:
            timeout = -1
        elif timeout <= 0:
            timeout = 0
        else:
            # epoll_wait() has a resolution of 1 millisecond, round away
            # from zero to wait *at least* timeout seconds.
            timeout = math.ceil(timeout * 1e3) * 1e-3
    
        # epoll_wait() expects `maxevents` to be greater than zero;
        # we want to make sure that `select()` can be called when no
        # FD is registered.
        max_ev = max(len(self._fd_to_key), 1)
    
        ready = []
        try:
>           fd_event_list = self._selector.poll(timeout, max_ev)
E           Failed: Timeout >60.0s

/usr/lib/python3.12/selectors.py:468: Failed
__________________________________________________________ test_uds_connect ___________________________________________________________

args = (), kwargs = {'uds_address': local('/tmp/pytest-of-mgorny/pytest-0/test_uds_connect0/uds.sock')}
coro = <coroutine object test_uds_connect at 0x7f103283da80>
task = <Task pending name='Task-5' coro=<test_uds_connect() running at /tmp/redis-py/tests/test_asyncio/test_connect.py:50> wait_for=<Future pending cb=[Task.task_wakeup()]>>

    @functools.wraps(func)
    def inner(*args, **kwargs):
        coro = func(*args, **kwargs)
        if not inspect.isawaitable(coro):
            pyfuncitem.warn(
                pytest.PytestWarning(
                    f"The test {pyfuncitem} is marked with '@pytest.mark.asyncio' "
                    "but it is not an async function. "
                    "Please remove asyncio marker. "
                    "If the test is not marked explicitly, "
                    "check for global markers applied via 'pytestmark'."
                )
            )
            return
        task = asyncio.ensure_future(coro, loop=_loop)
        try:
>           _loop.run_until_complete(task)

.venv/lib/python3.12/site-packages/pytest_asyncio/plugin.py:525: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
/usr/lib/python3.12/asyncio/base_events.py:651: in run_until_complete
    self.run_forever()
/usr/lib/python3.12/asyncio/base_events.py:618: in run_forever
    self._run_once()
/usr/lib/python3.12/asyncio/base_events.py:1913: in _run_once
    event_list = self._selector.select(timeout)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <selectors.EpollSelector object at 0x7f1032833fb0>, timeout = -1

    def select(self, timeout=None):
        if timeout is None:
            timeout = -1
        elif timeout <= 0:
            timeout = 0
        else:
            # epoll_wait() has a resolution of 1 millisecond, round away
            # from zero to wait *at least* timeout seconds.
            timeout = math.ceil(timeout * 1e3) * 1e-3
    
        # epoll_wait() expects `maxevents` to be greater than zero;
        # we want to make sure that `select()` can be called when no
        # FD is registered.
        max_ev = max(len(self._fd_to_key), 1)
    
        ready = []
        try:
>           fd_event_list = self._selector.poll(timeout, max_ev)
E           Failed: Timeout >60.0s

/usr/lib/python3.12/selectors.py:468: Failed
________________________________________________________ test_tcp_ssl_connect _________________________________________________________

tcp_address = ('127.0.0.1', 39515)

    @pytest.mark.ssl
    async def test_tcp_ssl_connect(tcp_address):
        host, port = tcp_address
        certfile = get_ssl_filename("server-cert.pem")
        keyfile = get_ssl_filename("server-key.pem")
        conn = SSLConnection(
            host=host,
            port=port,
            client_name=_CLIENT_NAME,
            ssl_ca_certs=certfile,
            socket_timeout=10,
        )
>       await _assert_connect(conn, tcp_address, certfile=certfile, keyfile=keyfile)

tests/test_asyncio/test_connect.py:65: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
tests/test_asyncio/test_connect.py:94: in _assert_connect
    await conn.disconnect()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = SSLConnection<host=127.0.0.1,port=39515,db=0,client_name=test-suite-client>, nowait = False

    async def disconnect(self, nowait: bool = False) -> None:
        """Disconnects from the Redis server"""
        try:
            async with async_timeout(self.socket_connect_timeout):
                self._parser.on_disconnect()
                if not self.is_connected:
                    return
                try:
                    if os.getpid() == self.pid:
                        self._writer.close()  # type: ignore[union-attr]
                        # wait for close to finish, except when handling errors and
                        # forcefully disconnecting.
                        if not nowait:
                            await self._writer.wait_closed()  # type: ignore[union-attr]
                except OSError:
                    pass
                finally:
                    self._reader = None
                    self._writer = None
        except asyncio.TimeoutError:
>           raise TimeoutError(
                f"Timed out closing connection after {self.socket_connect_timeout}"
            ) from None
E           redis.exceptions.TimeoutError: Timed out closing connection after 10

redis/asyncio/connection.py:683: TimeoutError
---------------------------------------------------------- Captured log call ----------------------------------------------------------
ERROR    asyncio:base_events.py:1785 Task was destroyed but it is pending!
task: <Task pending name='Task-1' coro=<test_tcp_connect() done, defined at /tmp/redis-py/tests/test_asyncio/test_connect.py:39> wait_for=<Future pending cb=[Task.task_wakeup()]>>
ERROR    asyncio:base_events.py:1785 Task was destroyed but it is pending!
task: <Task pending name='Task-5' coro=<test_uds_connect() done, defined at /tmp/redis-py/tests/test_asyncio/test_connect.py:45> wait_for=<Future pending cb=[Task.task_wakeup()]>>
ERROR    asyncio:base_events.py:1785 Task exception was never retrieved
future: <Task finished name='Task-11' coro=<_assert_connect.<locals>._handler() done, defined at /tmp/redis-py/tests/test_asyncio/test_connect.py:72> exception=Timeout >60.0s>
Traceback (most recent call last):
  File "/tmp/redis-py/tests/test_asyncio/test_connect.py", line 74, in _handler
    return await _redis_request_handler(reader, writer, stop_event)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/tmp/redis-py/tests/test_asyncio/test_connect.py", line 110, in _redis_request_handler
    buffer += await asyncio.wait_for(reader.read(1024), timeout=0.5)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/tasks.py", line 509, in wait_for
    async with timeouts.timeout(timeout):
               ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 142, in timeout
    return Timeout(loop.time() + delay if delay is not None else None)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 33, in __init__
    def __init__(self, when: Optional[float]) -> None:
    
  File "/tmp/redis-py/.venv/lib/python3.12/site-packages/pytest_timeout.py", line 241, in handler
    timeout_sigalrm(item, settings.timeout)
  File "/tmp/redis-py/.venv/lib/python3.12/site-packages/pytest_timeout.py", line 409, in timeout_sigalrm
    pytest.fail("Timeout >%ss" % timeout)
  File "/tmp/redis-py/.venv/lib/python3.12/site-packages/_pytest/outcomes.py", line 198, in fail
    raise Failed(msg=reason, pytrace=pytrace)
Failed: Timeout >60.0s
========================================================== warnings summary ===========================================================
tests/test_asyncio/test_connect.py::test_tcp_ssl_connect
  /tmp/redis-py/.venv/lib/python3.12/site-packages/_pytest/unraisableexception.py:78: PytestUnraisableExceptionWarning: Exception ignored in: <coroutine object test_uds_connect at 0x7f103283da80>
  
  Traceback (most recent call last):
    File "/tmp/redis-py/tests/test_asyncio/test_connect.py", line 50, in test_uds_connect
      await _assert_connect(conn, path)
  RuntimeError: coroutine ignored GeneratorExit
  
    warnings.warn(pytest.PytestUnraisableExceptionWarning(msg))

tests/test_asyncio/test_connect.py::test_tcp_ssl_connect
  /tmp/redis-py/.venv/lib/python3.12/site-packages/_pytest/stash.py:104: RuntimeWarning: coroutine 'StreamReader.read' was never awaited
    del self._storage[key]
  Enable tracemalloc to get traceback where the object was allocated.
  See https://docs.pytest.org/en/stable/how-to/capture-warnings.html#resource-warnings for more info.

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
======================================================= short test summary info =======================================================
FAILED tests/test_asyncio/test_connect.py::test_tcp_connect - Failed: Timeout >60.0s
FAILED tests/test_asyncio/test_connect.py::test_uds_connect - Failed: Timeout >60.0s
FAILED tests/test_asyncio/test_connect.py::test_tcp_ssl_connect - redis.exceptions.TimeoutError: Timed out closing connection after 10
============================================== 3 failed, 2 warnings in 181.81s (0:03:01) ==============================================

For comparison, the tests pass immediately on Python 3.11.4. Tested with 9f503578d1ffed20d63e8023bcd8a7dccd15ecc5 (v4.6.0).

$ redis-server --version
Redis server v=7.0.11 sha=00000000:0 malloc=libc bits=64 build=b139f629ad687728
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