JING
JING

Reputation: 25

A question about the result of asyncio & Async/Await application in python

When I run code:

import asyncio
async def foo(text):
    print(text)
    await asyncio.sleep(1)  
    print(text)
async def main():
    print("tim")
    task = asyncio.create_task(foo("text"))  
    await asyncio.sleep(1)
    print("finished")
asyncio.run(main())  

The output is:

tim
text
finished
text

However, when I change the sleep time in the main() function to 0.5:

import asyncio
async def foo(text):
    print(text)
    await asyncio.sleep(1)  
    print(text)
async def main():
    print("tim")
    task = asyncio.create_task(foo("text"))  
    await asyncio.sleep(0.5)
    print("finished")
asyncio.run(main())  

The output is:

tim
text
finished

Then, when I change the sleep time in the main() function to 0.99:

import asyncio
async def foo(text):
    print(text)
    await asyncio.sleep(1)  
    print(text)
async def main():
    print("tim")
    task = asyncio.create_task(foo("text"))  
    await asyncio.sleep(0.99)
    print("finished")
asyncio.run(main())  

The output is:

tim
text
finished
text

May I ask why the final 'text' is printed in the first and third cases but not printed in the second case? Thank you.

One more question:

In the first case, if asyncio.run() ends after print("finished") in the main() function, why print(text) in the foo() task is still executed. Is this because of the granularity of about 15 milliseconds as said in @Paul Cornelius's answer?

Furthermore, I add an additional time.sleep() in the main() function, so the await in the foo() task ends obviously earlier than the finish of the main() task. The program does not execute foo() task after print("finished") in this case:

async def foo(text):
    print(text)
    await asyncio.sleep(1)
    print(text)
async def main():
    print("tim")
    task = asyncio.create_task(foo("text"))
    await asyncio.sleep(0.5)
    time.sleep(1)
    print("finished")
asyncio.run(main())

The output is:

tim
text
finished

However, the program does execute foo() task after print("finished") in this case:

async def foo(text):
    print(text)
    await asyncio.sleep(1)
    print(text)
async def main():
    print("tim")
    task = asyncio.create_task(foo("text"))
    await asyncio.sleep(1)
    time.sleep(1)
    print("finished")
asyncio.run(main())

The output is:

tim
text
finished
text

Upvotes: 1

Views: 451

Answers (1)

Paul Cornelius
Paul Cornelius

Reputation: 11009

An excellent question.

It has a lot to do with the asyncio.run function, which does several things:

  • It creates and starts an event loop
  • It converts its argument (main()) into a task and schedules it for execution by the event loop
  • It waits for the task to complete
  • It closes the event loop, returns the result from the task

The run() function doesn't return until this is all finished.

Of your three cases, I think the first one is pretty simple and doesn't require much explanation. The main function takes at least 1 second to complete. The two tasks (main and foo) yield back and forth at their await statements.

In the second case, the main task takes only 0.5 seconds to run. At that point the main task is finished and so the asyncio.run() function returns. The foo task is still running, but asyncio.run() closes the event loop as it exits. So the foo task never gets to finish, and you never see the second "text" output. There is no heirarchial relationship between main and foo, even though main() started foo(); all tasks are peers. So main() does not wait for foo() to finish.

The third case is most interesting of all. You would think that the third case and the second case are the same, since 0.99 seconds is less than 1.0 seconds. But the timings in asyncio are not exact. My experience is that there is a granularity of about 15 milliseconds or slightly more, at least on Windows. So for all practical purposes, 0.99 seconds == 1.0 seconds. As an experiment, I changed your 0.99s to 0.98s and an interesting thing happened: the program did not always produce the same output! Sometimes it printed "text" twice, like in your first example, and sometimes once, like your second example. So depending on when the internal clock "ticks", 0.98 seconds is sometimes less than 1.0 seconds and sometimes it's equal.

Upvotes: 1

Related Questions