Aiohttp: Can't make 40k requests from client to server

Created on 5 Sep 2016  路  16Comments  路  Source: aio-libs/aiohttp

Long story short

I cannot make 40k requests using a semaphore to limit concurrency.

This is based on code from here though actual code is in-lined below.

Expected behaviour

I should be able to make unlimited requests from an aiohttp client to an aiohttp server.

Actual behaviour

Exceptions are thrown. See below.

I was able to make 1 million requests to a locally running httpbin server running under gunicorn.

I dug into it a bit and wondered if ayncio it self didn't like having 40k tasks running, so I faked out the response by modifying aiohttp/client.py with the following code and make ClientSession.get() return this FakeResponseContextManager. It worked just fine when I did this.

So the problem isn't that I'm creating 40,000 or 1,000,000 tasks. Python's asyncio seems to handle that many tasks just fine. Something blows up with this aiohttp client in conjunction with the aiohttp server (again, because serving httpbin test server worked just fine too).

class FakeResponse:
    def __init__(self, url):
        self._url = url

    async def read(self):
        await asyncio.sleep(0.01)
        return self._url

class FakeResponseContextManager:
    def __init__(self, url):
        self._url = url

    async def __aenter__(self):
        await asyncio.sleep(0.01)
        return FakeResponse(self._url)

    async def __aexit__(self, exc_type, exc, tb):
        await asyncio.sleep(0.01)

Steps to reproduce

  • run the server
  • run the client
  • see exceptions

    server

#!/usr/bin/env python3

from aiohttp import web

async def handle(request):
    name = request.match_info.get('name', "Anonymous")
    text = "Hello, " + name
    return web.Response(body=text.encode('utf-8'))

app = web.Application()
app.router.add_route('GET', '/{name}', handle)

web.run_app(app)

client

#!/usr/bin/env python3

import random
import asyncio
from aiohttp import ClientSession

async def fetch(url):
    async with ClientSession() as session:
        async with session.get(url) as response:
            print(url)
            return await response.read()


async def bound_fetch(sem, url):
    # getter function with semaphore
    async with sem:
        await fetch(url)


async def run(loop,  r):
    url = "http://localhost:8080/{}"
    tasks = []
    # create instance of Semaphore
    sem = asyncio.Semaphore(10)
    for i in range(r):
        # pass Semaphore to every GET request
        task = asyncio.ensure_future(bound_fetch(sem, url.format(i)))
        tasks.append(task)

    responses = asyncio.gather(*tasks)
    await responses

number = 40000
loop = asyncio.get_event_loop()

future = asyncio.ensure_future(run(loop, number))
loop.run_until_complete(future)

Your environment

  • Linux Mint 18 (based on Ubuntu 16.04)
  • Out of the box Python 3.5.2
  • aiohttp installed within virtualenv
client outdated question
Source
picture ericfrederich

All 16 comments

Hi,
can you also include the output of exceptions that are occurring because I couldn't reproduce it

My Environment
  • Gnome Ubuntu 16.04
  • Python 3.5.2
  • aiohttp installed within virtualenv
zsrinivas picture zsrinivas on 6 Sep 2016

Hi,
First, you create new ClientSession for each request this is absolutely wrong -- it creates new tcp connection for each request.
Also Ubuntu has small ulimit by default (ulimit -n) that is why you have "Too many open files" error

popravich picture popravich on 6 Sep 2016
👍1

ClientSession must be initialized in run and passed into fetch:

async def run(loop,  r):
    url = "http://localhost:8080/{}"
    tasks = []
    # create instance of Semaphore
    sem = asyncio.Semaphore(10)
    async with ClientSession() as session
        for i in range(r):
            # pass Semaphore to every GET request
            task = asyncio.ensure_future(bound_fetch(sem, url.format(i), session))
            tasks.append(task)
            ...

You can check and set file descriptors limit like so

$ ulimit -n
$ sudo  ulimit -n 10000
popravich picture popravich on 6 Sep 2016

Also BaseConnector has limit parameter, 20 by default. Increasing the value may help very well.

asvetlov picture asvetlov on 6 Sep 2016

@eightnoteight here is the exceptions...

Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 607, in _create_connection
    local_addr=self._local_addr)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 695, in create_connection
    raise exceptions[0]
  File "/usr/lib/python3.5/asyncio/base_events.py", line 682, in create_connection
    yield from self.sock_connect(sock, address)
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 402, in sock_connect
    return (yield from fut)
  File "/usr/lib/python3.5/asyncio/futures.py", line 363, in __iter__
    return self.result()  # May raise too.
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 407, in _sock_connect
    sock.connect(address)
OSError: [Errno 99] Cannot assign requested address

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 321, in connect
    yield from self._create_connection(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 630, in _create_connection
    (req.host, req.port, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Can not connect to localhost:8080 [Cannot assign requested address]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "./client.py", line 37, in <module>
    loop.run_until_complete(future)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 387, in run_until_complete
    return future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 241, in _step
    result = coro.throw(exc)
  File "./client.py", line 31, in run
    await responses
  File "/usr/lib/python3.5/asyncio/futures.py", line 361, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 296, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "./client.py", line 17, in bound_fetch
    await fetch(url)
  File "./client.py", line 9, in fetch
    async with session.get(url) as response:
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 537, in __aenter__
    self._resp = yield from self._coro
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 186, in _request
    conn = yield from self._connector.connect(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 331, in connect
    .format(key, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Cannot connect to host localhost:8080 ssl:False [Can not connect to localhost:8080 [Cannot assign requested address]]
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28241)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task exception was never retrieved
future: <Task finished coro=<bound_fetch() done, defined at ./client.py:14> exception=ClientOSError(99, 'Cannot connect to host localhost:8080 ssl:False [Can not connect to localhost:8080 [Cannot assign requested address]]')>
Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 607, in _create_connection
    local_addr=self._local_addr)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 695, in create_connection
    raise exceptions[0]
  File "/usr/lib/python3.5/asyncio/base_events.py", line 682, in create_connection
    yield from self.sock_connect(sock, address)
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 402, in sock_connect
    return (yield from fut)
  File "/usr/lib/python3.5/asyncio/futures.py", line 363, in __iter__
    return self.result()  # May raise too.
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 407, in _sock_connect
    sock.connect(address)
OSError: [Errno 99] Cannot assign requested address

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 321, in connect
    yield from self._create_connection(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 630, in _create_connection
    (req.host, req.port, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Can not connect to localhost:8080 [Cannot assign requested address]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "./client.py", line 17, in bound_fetch
    await fetch(url)
  File "./client.py", line 9, in fetch
    async with session.get(url) as response:
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 537, in __aenter__
    self._resp = yield from self._coro
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 186, in _request
    conn = yield from self._connector.connect(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 331, in connect
    .format(key, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Cannot connect to host localhost:8080 ssl:False [Can not connect to localhost:8080 [Cannot assign requested address]]
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28242)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task exception was never retrieved
future: <Task finished coro=<bound_fetch() done, defined at ./client.py:14> exception=ClientOSError(99, 'Cannot connect to host localhost:8080 ssl:False [Can not connect to localhost:8080 [Cannot assign requested address]]')>
Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 607, in _create_connection
    local_addr=self._local_addr)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 695, in create_connection
    raise exceptions[0]
  File "/usr/lib/python3.5/asyncio/base_events.py", line 682, in create_connection
    yield from self.sock_connect(sock, address)
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 402, in sock_connect
    return (yield from fut)
  File "/usr/lib/python3.5/asyncio/futures.py", line 363, in __iter__
    return self.result()  # May raise too.
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 407, in _sock_connect
    sock.connect(address)
OSError: [Errno 99] Cannot assign requested address

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 321, in connect
    yield from self._create_connection(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 630, in _create_connection
    (req.host, req.port, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Can not connect to localhost:8080 [Cannot assign requested address]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "./client.py", line 17, in bound_fetch
    await fetch(url)
  File "./client.py", line 9, in fetch
    async with session.get(url) as response:
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 537, in __aenter__
    self._resp = yield from self._coro
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 186, in _request
    conn = yield from self._connector.connect(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 331, in connect
    .format(key, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Cannot connect to host localhost:8080 ssl:False [Can not connect to localhost:8080 [Cannot assign requested address]]
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28243)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task exception was never retrieved
future: <Task finished coro=<bound_fetch() done, defined at ./client.py:14> exception=ClientOSError(99, 'Cannot connect to host localhost:8080 ssl:False [Can not connect to localhost:8080 [Cannot assign requested address]]')>
Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 607, in _create_connection
    local_addr=self._local_addr)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 695, in create_connection
    raise exceptions[0]
  File "/usr/lib/python3.5/asyncio/base_events.py", line 682, in create_connection
    yield from self.sock_connect(sock, address)
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 402, in sock_connect
    return (yield from fut)
  File "/usr/lib/python3.5/asyncio/futures.py", line 363, in __iter__
    return self.result()  # May raise too.
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 407, in _sock_connect
    sock.connect(address)
OSError: [Errno 99] Cannot assign requested address

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 321, in connect
    yield from self._create_connection(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 630, in _create_connection
    (req.host, req.port, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Can not connect to localhost:8080 [Cannot assign requested address]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "./client.py", line 17, in bound_fetch
    await fetch(url)
  File "./client.py", line 9, in fetch
    async with session.get(url) as response:
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 537, in __aenter__
    self._resp = yield from self._coro
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 186, in _request
    conn = yield from self._connector.connect(req)
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 331, in connect
    .format(key, exc.strerror)) from exc
aiohttp.errors.ClientOSError: [Errno 99] Cannot connect to host localhost:8080 ssl:False [Can not connect to localhost:8080 [Cannot assign requested address]]
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:17> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28237)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:17> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28238)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:17> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28231)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a24d00>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 450, in acquire
  File "/usr/lib/python3.5/asyncio/locks.py", line 424, in _wake_up_next
  File "/usr/lib/python3.5/asyncio/futures.py", line 332, in set_result
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a24d58>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 450, in acquire
  File "/usr/lib/python3.5/asyncio/locks.py", line 424, in _wake_up_next
  File "/usr/lib/python3.5/asyncio/futures.py", line 332, in set_result
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a24db0>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 450, in acquire
  File "/usr/lib/python3.5/asyncio/locks.py", line 424, in _wake_up_next
  File "/usr/lib/python3.5/asyncio/futures.py", line 332, in set_result
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a24ba0>
Traceback (most recent call last):
  File "./client.py", line 17, in bound_fetch
  File "/usr/lib/python3.5/asyncio/coroutines.py", line 206, in coro
  File "/usr/lib/python3.5/asyncio/locks.py", line 86, in __aexit__
  File "/usr/lib/python3.5/asyncio/locks.py", line 461, in release
  File "/usr/lib/python3.5/asyncio/locks.py", line 424, in _wake_up_next
  File "/usr/lib/python3.5/asyncio/futures.py", line 332, in set_result
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a24bf8>
Traceback (most recent call last):
  File "./client.py", line 17, in bound_fetch
  File "/usr/lib/python3.5/asyncio/coroutines.py", line 206, in coro
  File "/usr/lib/python3.5/asyncio/locks.py", line 86, in __aexit__
  File "/usr/lib/python3.5/asyncio/locks.py", line 461, in release
  File "/usr/lib/python3.5/asyncio/locks.py", line 424, in _wake_up_next
  File "/usr/lib/python3.5/asyncio/futures.py", line 332, in set_result
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a24990>
Traceback (most recent call last):
  File "./client.py", line 17, in bound_fetch
  File "/usr/lib/python3.5/asyncio/coroutines.py", line 206, in coro
  File "/usr/lib/python3.5/asyncio/locks.py", line 86, in __aexit__
  File "/usr/lib/python3.5/asyncio/locks.py", line 461, in release
  File "/usr/lib/python3.5/asyncio/locks.py", line 424, in _wake_up_next
  File "/usr/lib/python3.5/asyncio/futures.py", line 332, in set_result
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(39999)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(39998)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(39997)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(39996)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(39995)() at /usr/lib/python3.5/asyncio/tasks.py:637]>

# ...
# 23,480 more lines just like these
# ...

Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28254)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28253)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28252)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28251)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28250)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28249)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28248)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28247)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28246)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28245)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:16> wait_for=<Future finished result=None> cb=[gather.<locals>._done_callback(28244)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:17> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28240)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:17> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28239)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:17> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28230)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Task was destroyed but it is pending!
task: <Task pending coro=<bound_fetch() running at ./client.py:17> wait_for=<Future pending cb=[Task._wakeup()]> cb=[gather.<locals>._done_callback(28229)() at /usr/lib/python3.5/asyncio/tasks.py:637]>
Exception ignored in: <coroutine object bound_fetch at 0x7f6991da86d0>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 448, in acquire
  File "/usr/lib/python3.5/asyncio/futures.py", line 227, in cancel
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6991da8678>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 448, in acquire
  File "/usr/lib/python3.5/asyncio/futures.py", line 227, in cancel
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6991da8620>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 448, in acquire
  File "/usr/lib/python3.5/asyncio/futures.py", line 227, in cancel
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed

# ...
# 11,745 more stack traces just like these (129,195 lines)
# ...

Exception ignored in: <coroutine object bound_fetch at 0x7f6992a320a0>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 448, in acquire
  File "/usr/lib/python3.5/asyncio/futures.py", line 227, in cancel
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a32048>
Traceback (most recent call last):
  File "./client.py", line 16, in bound_fetch
  File "/usr/lib/python3.5/asyncio/locks.py", line 79, in __aenter__
  File "/usr/lib/python3.5/asyncio/locks.py", line 448, in acquire
  File "/usr/lib/python3.5/asyncio/futures.py", line 227, in cancel
  File "/usr/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a24938>
Traceback (most recent call last):
  File "./client.py", line 17, in bound_fetch
  File "./client.py", line 9, in fetch
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 537, in __aenter__
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 193, in _request
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 84, in close
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 395, in _release
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 566, in close
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <coroutine object bound_fetch at 0x7f6992a248e0>
Traceback (most recent call last):
  File "./client.py", line 17, in bound_fetch
  File "./client.py", line 9, in fetch
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 537, in __aenter__
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/client.py", line 193, in _request
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 84, in close
  File "/home/eric/src/test/env/lib/python3.5/site-packages/aiohttp/connector.py", line 395, in _release
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 566, in close
  File "/usr/lib/python3.5/asyncio/base_events.py", line 497, in call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon
  File "/usr/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed
RuntimeError: Event loop is closed
ericfrederich picture ericfrederich on 7 Sep 2016

@popravich

2 questions then I guess...

  • In the code I posted, shouldn't the semaphore also limit the number of sessions object at any given time?

There should only be 10 right? Maybe something isn't being cleaned up?

  • Why would the same client work against a httpbin server without incident?
ericfrederich picture ericfrederich on 7 Sep 2016

In the code I posted, shouldn't the semaphore also limit the number of sessions object at any given time?
There should only be 10 right? Maybe something isn't being cleaned up?

I can confirm this as I have personally checked /proc/<pid>/fd/ directory which contains at most 15 file i.e including all file descriptors used by this process.

So there is small chance of not being cleaned up as both our environments are almost same.

But can you(@ericfrederich) go to that directory and check how many files does it have?

PS: I saw an eventfd too, never thought event loop depends on this special file :)

zsrinivas picture zsrinivas on 7 Sep 2016

@ericfrederich,
It looks like using single-shot ClientSessions leaves unclean connections
(just run your code and count connections netstat -n | grep :8080 -c).
Using single session for all requests works fine (no matter 40k or 1m requests you perform).

Why would the same client work against a httpbin server without incident?

I guess it performs a little bit slower than requests to localhost and TIME_WAIT connections are being recycled

popravich picture popravich on 7 Sep 2016

@ericfrederich
how much time does httpbin / aiohttp server take to serve these requests?

based on @popravich input and if your httpbin server takes more time to perform the requests than the aiohttp server, then one possible explanation is that TIME_WAIT connections expire after some time, so if local httpbin server takes more time then more ports are available and if aiohttp server takes less time to serve the requests then TIME_WAIT connections are not yet freed.

zsrinivas picture zsrinivas on 7 Sep 2016

@eightnoteight and @popravich

I added this to the top of my client.py to capture a log of the number of open files every 0.1 seconds.
After running sort /tmp/n_files | uniq I saw the most I ever got was 20 files open at a time.

cmd = 'gnome-terminal -e \'watch -n 0.1 "ls -al /proc/%d/fd | wc -l >> /tmp/n_files"\'' % os.getpid()
os.system(cmd)

I'm at work now on a CentOS7 VM... same behavior.

Also, with httpbin I was running it locally via gunicorn like their webpage instructs.

ericfrederich picture ericfrederich on 7 Sep 2016

Why aiohttp gives out the exception

after @popravich mentioned about netstat, I got to know that number of file descriptors and number of open ports are not same. file descriptors can be way less than number of ports owned by our client process. actually the process doesn't own them but OS keeps them in TIME_WAIT for the process.

Without a single client session the socket.connect will ask OS for an open port to start communication every time, and even if you close the socket connection, OS will keep the connection in TIME_WAIT state. but with a single session you will never close it i.e leave it for OS

by using a single ClientSession from the client side
you will be reusing the open connections, to be precise you will be continuously reusing 20 connections

https://github.com/KeepSafe/aiohttp/blob/master/aiohttp/connector.py#L114

the client will never create more than 20 connections, I suppose this is not the point of your experiment.

So the reason that you are getting that exception is because you don't have any free ports anymore.

Why gunicorn is working and aiohttp server not working

and about gunicorn working and aiohttp server not working, it is because gunicorn takes more time to serve requests, so some of those TIME_WAIT connections are freed by the OS when serving the nth request, but aiohttp is fast so before TIME_WAIT connections are freed by the OS the aiohttp performs nth request and fails. this is based on my observed readings on maximum number of TIME_WAIT connections in each test, with aiohttp server test system has more TIME_WAIT connections(19K) at some point, than with gunicorn test (12K)

the amount of time a connection stays in TIME_WAIT state can be found in this file /proc/sys/net/ipv4/tcp_fin_timeout

locally I used these commands to time them

time python client.py 2>&1 > _.log
watch -n 0.1 'netstat -n | grep :8080 | wc'  # this will give the number of ports which are still not freed

some articles on TIME_WAIT:
search for "TIME_WAIT resource starvation" in
http://blog.davidvassallo.me/2010/07/13/time_wait-and-port-reuse/
https://vincent.bernat.im/en/blog/2014-tcp-time-wait-state-linux.html

zsrinivas picture zsrinivas on 7 Sep 2016

Thanks for looking into this. I appreciate the answers. I know now not to create a new session for each request.

My /proc/sys/net/ipv4/tcp_fin_timeout is 60

I'm not sure that gunicorn takes more time to serve requests.
I changed it from 40k to 10k and gunicorn the client going against httpbin ran in 15.851s while going against the aiohttp server took 15.880 ... essentially the same.

Watching the netstat I that under both circumstances they hit exactly 10k.

but...

When I changed them to make 20k requests the open connections for httpbin plateaued around 14k... with aiohttp it hit exactly 20k. They both took right around 32 seconds to complete.

Maybe my understanding of this is wrong, but it seem http bin responds to requests just as fast (if not faster). Any idea why the number of open connections would plateau when going against a different server? Could the httpbin server clean these up better somehow?... though you said it isn't really the client or server but the OS?

ericfrederich picture ericfrederich on 8 Sep 2016

The difference between aiohttp server and gunicorn is that gunicorn
does not enable keep-alive by default. So it basically closes connection first.
If you use async worker for gunicorn you'll experience the same issue as with aiohttp --
worker will keep connections open.

popravich picture popravich on 8 Sep 2016

This seems well explained now. Thanks for that!

I have emailed the author of the blog asking him to update the code in it or at least reference this GitHub issue. Feel free to close it.

ericfrederich picture ericfrederich on 8 Sep 2016
👍1

Hello, I'm the author of blog post that started this discussion. Thanks for letting me know about the problem @ericfrederich . I updated my post and fixed usage of ClientSession see here: https://github.com/pawelmhm/pawelmhm.github.io/commit/8346f2589c440a2a338d2f91fc8ba99d15008e5d. After fixing session timings got much better.

pawelmhm picture pawelmhm on 10 Sep 2016

This thread has been automatically locked since there has not been
any recent activity after it was closed. Please open a [new issue] for
related bugs.

If you feel like there's important points made in this discussion,
please include those exceprts into that [new issue].

lock[bot] picture lock[bot] on 29 Oct 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

Smosker picture Smosker  路  3Comments
thehesiod picture thehesiod  路  4Comments
asvetlov picture asvetlov  路  4Comments
amsb picture amsb  路  3Comments
rubenvdham picture rubenvdham  路  5Comments