MagicStack / uvloop

Ultra fast asyncio event loop.
Apache License 2.0
10.46k stars 550 forks source link

loop.stop() different behavior with loop.run_forever() in asyncio vs. uvloop #517

Open TheoBabilon opened 2 years ago

TheoBabilon commented 2 years ago

Hi @1st1,

First of all thank you for your work on uvloop, it's been really useful.

I maintain an application that makes heavy usage of asyncio. Whilst migrating to uvloop, I noticed a weird behavior with loop.stop and loop.run_forever methods in uvloop.

From the asyncio docs: If stop() is called while run_forever() is running, the loop will run the current batch of callbacks and then exit. Note that new callbacks scheduled by callbacks will not run in this case; instead, they will run the next time run_forever() or run_until_complete() is called.

I believe that the highlighted sentence is false and doesn't apply to uvloop (which makes its behavior differ from asyncio): Note that new callbacks scheduled by callbacks will not run in this case.

Consider the (really convoluted, sorry about that - didn't find an easier/better way to reproduce even though I'm pretty sure there is) following code:

import asyncio

async def dummy(aw):
    try:
        while True:
            print('Sending')
            future = aw.send(None)
            if not future:
                print('Yield')
                await asyncio.sleep(0)
            else:
                print('Whatever')
    except StopIteration as e:
        return e.value

class Waiter:
    def __init__(self) -> None:
        self.started = False
        self.done = False

    async def wait_on(self, aw):
        self.started = True
        print('Starting')
        await dummy(aw)
        print('Done')
        self.done = True

async def suspend():
    print('Suspending')
    await asyncio.sleep(0)
    print('Suspended')
    return True

waiter = Waiter()
loop = asyncio.get_event_loop()
loop.create_task(waiter.wait_on(suspend()))
loop.call_soon(loop.stop)
print('Running forever')
loop.run_forever()
assert not waiter.done
print('Exit')

I added some print statements to better see what happens - we're pretty much doing some dark magic but the important part is what we're trying to achieve: We want to run one iteration of the event loop (until the cb loop.stop is called - which will make loop.run_forever return). Therefore the stdout for above asyncio code is as follow:

Running forever
Starting
Sending
Suspending
Yield
Exit

Notice that no AssertionError is raised. The asyncio.sleep(0) in dummy gives a chance to run the cb loop.stop whichs makes run_forever method return and we gracefully exit. The "callbacks scheduled by callbacks" do not run, as mentioned in the asyncio docs.

Now let's make usage of uvloop, by simply adding it at the beginning of our run statements:

uvloop.install()   # <--- JUST ADDED THIS
waiter = Waiter()
loop = asyncio.get_event_loop()
loop.create_task(waiter.wait_on(suspend()))
loop.call_soon(loop.stop)
print('Running forever')
loop.run_forever()
assert not waiter.done
print('Exit')

Here is the stdout:

Running forever
Starting
Sending
Suspending
Yield
Sending
Suspended
Done
Traceback (most recent call last):
  File "./xxxxx.py", line 47, in <module>
    assert not waiter.done
AssertionError

We now have a completely different behavior. After some debugging, the loop.stop is still indeed being called when the Yield statement is printed but instead of making the loop.run_forever return immediately, it seems that uvloop gives a chance to other callbacks to run before - which is ultimately why we see that stdout and the AssertionError is being raised. That makes the asyncio statement false: Note that new callbacks scheduled by callbacks will not run in this case;

I'm not saying this is a bug - this might be one of the area where you made a well-thought decision for uvloop; The docstring for the stop method in uvloop seems to indicate it. Maybe it is documented somewhere?

The question: Am I missing something/doing something wrong (besides all the dark magic indeed)? Is there a way to really pause execution of callbacks when using run_forever (and resume it later) with uvloop just like we can with the asyncio method described by @asvetlov in this stackoverflow post?

For the sake of completeness (even though I'm not sure this will help), I added a loop.print_debug_info() right before the assert when using uvloop - here is the output:

---- Process info: -----
Process memory:            13964
Number of signals:         0

--- Loop debug info: ---
Loop time:                 9854077.307
Errors logged:             0

Callback handles:          2        | 7
Timer handles:             0        | 0

                        alive  | closed  |
UVHandles               python | libuv   | total
                        objs   | handles |
-------------------------------+---------+---------
    UVAsync                  1 |       0 |       1
    UVCheck                  1 |       0 |       1
    UVIdle                   1 |       0 |       1
    UVPoll                   1 |       0 |       1

uv_handle_t (current: 4; freed: 0; total: 4)

--- Streams debug info: ---
Write errors:              0
Write without poll:        0
Write contexts:            0        | 0
Write failed callbacks:    0

Read errors:               0
Read callbacks:            0
Read failed callbacks:     0
Read EOFs:                 0
Read EOF failed callbacks: 0

Listen errors:             0
Shutdown errors            0

--- Polls debug info: ---
Read events:               0
Read callbacks failed:     0
Write events:              0
Write callbacks failed:    0

--- Sock ops successful on 1st try: ---
Socket try-writes:         0