asyncio.wait very slow with FIRST_COMPLETED

[samuelcolvin]

BPO	30556
Nosy	@asvetlov, @1st1, @samuelcolvin
Files	asyncio_wait_test.py

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = None
created_at = <Date 2017-06-02.17:47:13.306>
labels = ['expert-asyncio', 'performance']
title = 'asyncio.wait very slow with FIRST_COMPLETED'
updated_at = <Date 2022-03-05.06:57:40.362>
user = 'https://github.com/samuelcolvin'

bugs.python.org fields:

activity = <Date 2022-03-05.06:57:40.362>
actor = 'kumaraditya'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['asyncio']
creation = <Date 2017-06-02.17:47:13.306>
creator = 'samuelcolvin'
dependencies = []
files = ['46920']
hgrepos = []
issue_num = 30556
keywords = []
message_count = 1.0
messages = ['295045']
nosy_count = 3.0
nosy_names = ['asvetlov', 'yselivanov', 'samuelcolvin']
pr_nums = []
priority = 'normal'
resolution = None
stage = None
status = 'open'
superseder = None
type = 'performance'
url = 'https://bugs.python.org/issue30556'
versions = ['Python 3.6']

[samuelcolvin]

This is best described the script at https://gist.github.com/samuelcolvin/00f01793c118bf9aafae886ffbc81a58.

Basically, completing a set of tasks using asyncio.wait(...return_when=asyncio.FIRST_COMPLETED) in a loop to wait for them to finish is much much slower than completing the same set of tasks using just asyncio.wait(pending_tasks, loop=loop, return_when=asyncio.ALL_COMPLETED).

In my example, the ALL_COMPLETED case takes ~5s, but the FIRST_COMPLETED case takes 18 - 47s.

The screenshot on the gist shows network usage with a very long tail, in other words very few tasks are taking a long time to complete.

This example uses aiohttp get a url as the test case but I'm pretty sure this isn't an issue with aiohttp.

I tried the same thing with uvloop but got broadly the same result.

[kumaraditya303]

I tried the script and don't see much difference in performance of FIRST_COMPLETED and ALL_COMPLETED on wikipedia.

import asyncio
from statistics import mean, stdev
from time import time

from aiohttp import ClientSession

request_count = 1500
url = 'https://www.wikipedia.org/'


async def main(use_first_complete=False):
    loop = asyncio.get_running_loop()
    print(f'using FIRST_COMPLETED: {use_first_complete}')
    start_time = time()
    async with ClientSession() as session:
        async def run(v, _create_time):
            _start_time = time()
            async with session.get(url) as r:
                assert r.status == 200
            wait, request = _start_time - _create_time, time() - _start_time
            # print(f'{v:>5} wait: {wait:0.3f}s, request: {request:0.3f}s')
            return wait, request

        pending_tasks = {loop.create_task(run(i, time())) for i in range(request_count)}
        if use_first_complete:
            complete_tasks = set()
            while pending_tasks:
                done, pending_tasks = await asyncio.wait(pending_tasks, return_when=asyncio.FIRST_COMPLETED)
                complete_tasks.update(done)
        else:
            complete_tasks, pending_tasks = await asyncio.wait(pending_tasks)
            assert not pending_tasks

    time_taken = time() - start_time
    print(f'total time taken {time_taken:0.2f}')
    results = [t.result() for t in complete_tasks]
    wait_times, request_times = zip(*results)
    print(f'wait times:    mean {mean(wait_times):0.3f}s, stdev {stdev(wait_times):0.3f}s')
    print(f'request times: mean {mean(request_times):0.3f}s, stdev {stdev(request_times):0.3f}s')


asyncio.run(main(use_first_complete=False))

[AlexWaygood]

Cc. @samuelcolvin — I believe you might not be subscribed to this issue any more due to the migration to GitHub

[kumaraditya303]

Closing as the bug report is very old and the implementation has changed significantly since then especially with the new rewritten ssl implementation. Create a new issue if required.

[samuelcolvin]

Agreed, sorry for the noise.