wait_for raises CancelledError

[commonism]

Bug report

Bug description:

Problem is, wait_for sometimes raises CancelledError instead of TimeoutError.
Had a look on recent changes and updated Lib/asyncio/timeouts.py with #113819 by @serhiy-storchaka which seemed similar.

I failed to do to reproduce with sleep only/without httpx.
As the exception raised is either TimeoutError or CancelledError, I consider this an cpython issue.

import pytest
import httpx
import asyncio
import asyncio.timeouts
import random
import logging

@pytest.mark.asyncio
async def test_wait_for():

    async def step() -> bool:
        """
        :return True if finished. False if not stalled
        """
        while True:
            try:
                c = httpx.AsyncClient()
                if False: # works
                    async with asyncio.timeout(6):
                        await asyncio.sleep(random.randrange(1, 5))

                async with c.stream("get", "https://git.kernel.org/torvalds/t/linux-6.8-rc1.tar.gz") as r:
                    async for i in r.aiter_bytes(100):
                        await asyncio.sleep(random.randrange(1, 5))
            except Exception as e:
                logging.exception(e)

    async def install() -> None:
        while True:
            try:
                await asyncio.wait_for(step(), timeout=random.randrange(1,4))
            except (asyncio.TimeoutError, TimeoutError):
                pass
            except asyncio.CancelledError as x:
                logging.exception(x)
                # assert False, "Cancellation"
                raise

    await install()

Traceback (most recent call last):
  File "/tmp/the_test.py", line 576, in install
    await asyncio.wait_for(step(), timeout=random.randrange(1,4))
  File "/usr/lib/python3.12/asyncio/tasks.py", line 520, in wait_for
    return await fut
           ^^^^^^^^^
  File "/tmp/the_test.py", line 569, in step
    await asyncio.sleep(random.randrange(1, 5))
  File "/usr/lib/python3.12/asyncio/tasks.py", line 665, in sleep
    return await future
           ^^^^^^^^^^^^
asyncio.exceptions.CancelledError

CPython versions tested on:

3.12

Operating systems tested on:

Linux

[gvanrossum]

Can someone (doesn't have to be the OP) please supply an example that doesn't depend on an external library?

From the traceback it looks like wait_for() uses CancelledError to trigger the timeout and somehow the code that normally turns that into a TimeoutError doesn't run. But in order to track down the issue it would be nice to have a simpler repro.

[commonism]

Using asyncio.timeout directly:

    async def install() -> None:
        while True:
            try:
                async with asyncio.timeout(random.randrange(1,4)):
                    await step()
            except (asyncio.TimeoutError, TimeoutError):
                pass
            except asyncio.CancelledError as x:
                logging.exception(x)
                # assert False, "Cancellation"
                raise

I think the conversion to TimeoutError is not done due to

self._task.uncancel() <= self._cancelling being unmet here (self._task.cancelling() = 2, self._canceling = 0)

cpython/Lib/asyncio/timeouts.py

Lines 109 to 115 in 1e4f00e

	if self._state is _State.EXPIRING:
	self._state = _State.EXPIRED
	if self._task.uncancel() <= self._cancelling and exc_type is not None:
	# Since there are no new cancel requests, we're
	# handling this.
	if issubclass(exc_type, exceptions.CancelledError):

Not using the c-module for asyncio to see who cancels gets me to

    async def try_connect(remote_host: str, event: Event) -> None:
        nonlocal connected_stream
        try:
            stream = await asynclib.connect_tcp(remote_host, remote_port, local_address)
        except OSError as exc:
            oserrors.append(exc)
            return
        else:
            if connected_stream is None:
                connected_stream = stream
                tg.cancel_scope.cancel()
            else:
                await stream.aclose()
        finally:
            event.set()

anyio canceling via tg.cancel_scope.cancel()
https://github.com/agronholm/anyio/blob/3f14df89fe4c6d5edebae345a95d04c30334bba2/src/anyio/_core/_sockets.py#L167-L181

I may be wrong wrt. to cpython causing this.

@gvanrossum Given the opportunity. We've had an argument about tulip/asyncio ~10 years ago. I disagreed, lack of experience/vision. You were right.

[khac]

I tried to look at this,

def req_step() -> bool:

        url = "https://git.kernel.org/torvalds/t/linux-6.8-rc1.tar.gz/"
        out_file = './linux-6.8-rc1.tar.gz'

        try:
            stream = urllib.request.urlopen(url)
            with stream as response:
                with open(out_file, "wb") as f:
                    f.write(response.read())
            return True

        except Exception as e:
            print(e)
            return False

This downloads the tar file as a data stream and stores in the tar format. This example uses urllib.request.urlopen instead of asyncio.

While looking at the documentation for asyncio.wait_for here, it specifically mentions that to avoid task cancellation, wrap with shield() and when I tried to do this, I did not see any Cancellation errors.

async def install() -> None:
        while True:
            try:
                await asyncio.wait_for(shield(step()), timeout=random.randrange(10, 40))
            except (asyncio.TimeoutError, TimeoutError):
                pass
            except asyncio.CancelledError as x:
                logging.exception(x)
                # assert False, "Cancellation"
                raise

I am not too aware of the inner working of asyncio, thanks @commonism for explaining that.

[commonism]

The problem we have is the CancelledError is not converted to a TimeoutError.
As shown before, I currently suspect anyio CancelScope modifies the tasks cancellation count.
According to @agronholm agronholm/anyio#374 co-existence of anyio and asyncio should not cause any problems for anyio >= 4.x.
I use 4.2.0.

[agronholm]

AnyIO does uncancel the task when exiting cancelled cancel scopes (as of v4), so it shouldn't pose a problem. Could someone create a minimal reproducing example of the problem? I don't have a lot of bandwidth to dedicate to this.

[gvanrossum]

I still don't see a simple repro that doesn't use a 3rd party module. (Also, the code snippets presented as "repro" are incomplete, they lack the needed imports and the asyncio.run() call that starts things.)

I may just close this issue for lack of information if the situation doesn't improve within a week.

PS. @commonism I don't know who you are (or who you were 10 years ago) so I cannot comment on the disagreement we had then -- I have no idea what it was about. :-)

[sunmy2019]

Looks like the behavior is expected.

1. anyio cancelled the task one more time.
2. asyncio does not convert CancelledError to TimeoutError due to that extra cancel.

Seems no bug here.

[commonism]

I agree with anyIO causing this.