asyncio + aiohttp: overlapping IO with sleeping

Question

When all coroutines are waiting, asyncio listens for events to wake them up again. A common example would be asyncio.sleep(), which registers a timed event. In practice an event is usually an IO socket ready for receiving or sending new data.

To get a better understanding of this behaviour, I set up a simple test: It sends an http request to localhost and waits for the response. On localhost, I've set up a flask server which waits for 1 second before responding. After sending the request, the client sleeps for 1 second, then it awaits the response. I would expect this to return in rougly a second, since both my program and the server should sleep in parallel. But it takes 2 seconds:

import aiohttp
import asyncio
from time import perf_counter

async def main():
    async with aiohttp.ClientSession() as session:

        # this http request will take 1 second to respond
        async with session.get("http://127.0.0.1:5000/") as response:

            # yield control for 1 second
            await asyncio.sleep(1)

            # wait for the http request to return
            text = await response.text()
            return text

loop = asyncio.get_event_loop()

start = perf_counter()
results = loop.run_until_complete(main())
stop = perf_counter()

print(f"took {stop-start} seconds") # 2.01909

What is asyncio doing here, why can't I overlap waiting times ?

I'm not interested in the specific scenario of HTTP requests, aiohttp is only used to construct an example. Which is probably a bit dangerous: This could be related to aiohttp and not asyncio at all.

Actually, I expect this to be the case (hence the question title about both asyncio and aiohttp). My first intuition was that the request is maybe not sent before calling asyncio.sleep(). So I reordered things a bit:

# start coroutine
text = response.text()

# yield control for 1 second
await asyncio.sleep(1)

# wait for the http request to return
text = await text

But this still takes two seconds.

Ok, now to be really sure that the request was sent off before going to sleep, I added print("incoming") to the route on the server, before it goes to sleep. I also changed the length of sleeping time to 10 seconds on the client. The server prints incoming immediately after the client is run. The client takes 11 seconds in total.

@app.route('/')
def index():
    print("incoming")
    time.sleep(1)
    return 'done'

Since the HTTP request is made immediately, the server has definitely sent off an answer before the client wakes up from asyncio.sleep(). It seems to me that the socket providing the HTTP request should be ready as soon as the client wakes up. But still, the total runtime is always an addition of client and server waiting times.

Am I misusing asyncio somehow, or is this related to aiohttp after all ?

Answer 1

The problem is that one second happens in server is performed in async with session.get("http://127.0.0.1:5000/") as response:.

The http request finishes before you get this response object.

You can test it by:

...
async def main():
    async with aiohttp.ClientSession() as session:

        start = perf_counter()
        # this http request will take 1 second to respond
        async with session.get("http://127.0.0.1:5000/") as response:
            end = perf_counter()
            print(f"took {end-start} seconds to get response")
            # yield control for 1 second
            await asyncio.sleep(1)

            # wait for the http request to return
            text = await response.text()
            return text
...

And btw you can surely overlap this waiting time, as long as you have another running coroutine.