aiohttp

aiohttp copied to clipboard

Describe the bug

Basically, looks like aiohttp does not wait for the read timeout before raising the exception, or it could be also that it raises the wrong exception.

Let me try to explain, we're using Auth0 python that in its implementation of asyncio uses aiohttp as library to implement non-blocking HTTP calls.

Auth0 python let you define a timeout on the rest-client as the following:

class AsyncRestClient(RestClient):
    """Provides simple methods for handling all RESTful api endpoints.

    Args:
        telemetry (bool, optional): Enable or disable Telemetry
            (defaults to True)
        timeout (float or tuple, optional): Change the requests
            connect and read timeout. Pass a tuple to specify
            both values separately or a float to set both to it.
            (defaults to 5.0 for both)
        options (RestClientOptions): Pass an instance of
            RestClientOptions to configure additional RestClient
            options, such as rate-limit retries. Overrides matching
            options passed to the constructor.
            (defaults to 3)
    """

    def __init__(self, *args, **kwargs):
        super(AsyncRestClient, self).__init__(*args, **kwargs)
        self._session = None
        sock_connect, sock_read = (
            self.timeout
            if isinstance(self.timeout, tuple)
            else (self.timeout, self.timeout)
        )
        self.timeout = aiohttp.ClientTimeout(
            sock_connect=sock_connect, sock_read=sock_read
        )
`
``

And then use it as kwargs of the request call:

async def _request(self, *args, **kwargs):
    kwargs["headers"] = kwargs.get("headers", self.base_headers)
    kwargs["timeout"] = self.timeout
    if self._session is not None:
        # Request with re-usable session
        async with self._session.request(*args, **kwargs) as response:
            return await self._process_response(response)
    else:
        # Request without re-usable session
        async with aiohttp.ClientSession() as session:
            async with session.request(*args, **kwargs) as response:
                return await self._process_response(response)

Given this, we have an HTTP call set up with 5 seconds of connect timeout and 30seconds of reading timeout.

Looking at our APM, we have several calls that end in 5 seconds + a bunch of milliseconds with the following error:

 
Is aiohttp raising the wrong exception or does it have a bug which does not honour the read timeout?



### To Reproduce

Uses auth0-python with different connect/read timeouts 

### Expected behavior

I would expect aiohttp to wait to 30 seconds (the read timeout) before raising the `ServerTimeoutError`

### Logs/tracebacks

```python-traceback
12
File "/usr/local/lib/python3.8/site-packages/auth0/v3/asyncify.py" line 10 in closure [locals]
return await m(*args, **kwargs)
13
File "/usr/local/lib/python3.8/site-packages/auth0/v3/rest_async.py" line 109 in patch [args] [locals]
return await self._request("patch", url, json=data)
14
File "/usr/local/lib/python3.8/site-packages/auth0/v3/rest_async.py" line 59 in _request [args] [locals]
async with self._session.request(*args, **kwargs) as response:
15
File "/usr/local/lib/python3.8/site-packages/aiohttp/client.py" line 1138 in __aenter__ [args] [locals]
self._resp = await self._coro
16
File "/usr/local/lib/python3.8/site-packages/ddtrace/contrib/trace_utils_async.py" line 35 in wrapper [args] [locals]
return await func(mod, pin, wrapped, instance, args, kwargs)
17
File "/usr/local/lib/python3.8/site-packages/ddtrace/contrib/aiohttp/patch.py" line 84 in _traced_clientsession_request [args] [locals]
resp = await func(*args, **kwargs)  # type: aiohttp.ClientResponse
18
File "/usr/local/lib/python3.8/site-packages/aiohttp/client.py" line 559 in _request [args] [locals]
await resp.start(conn)
19
File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py" line 898 in start [args] [locals]
message, payload = await protocol.read()  # type: ignore[union-attr]
20
File "/usr/local/lib/python3.8/site-packages/aiohttp/streams.py" line 616 in read [args] [locals]
await self._waiter
ServerTimeoutError: Timeout on reading data from socket

Python Version

$ python --version
3.8.13

aiohttp Version

$ python -m pip show aiohttp
Name: aiohttp
Version: 3.8.1
Summary: Async http client/server framework (asyncio)
Home-page: https://github.com/aio-libs/aiohttp
Author: 
Author-email: 
License: Apache 2
Requires: aiosignal, async-timeout, attrs, charset-normalizer, frozenlist, multidict, yarl
Required-by: aiobotocore

multidict Version

$ python -m pip show multidict
Name: multidict
Version: 6.0.2
Summary: multidict implementation
Home-page: https://github.com/aio-libs/multidict
Author: Andrew Svetlov
Author-email: [email protected]
License: Apache 2
Requires: 
Required-by: aiohttp, yarl

yarl Version

$ python -m pip show yarl
Name: yarl
Version: 1.7.2
Summary: Yet another URL library
Home-page: https://github.com/aio-libs/yarl/
Author: Andrew Svetlov
Author-email: [email protected]
License: Apache 2
Requires: idna, multidict
Required-by: aiohttp

OS

OS inherited from python 3.8 docker image

Related component

Client

Additional context

No response

Code of Conduct

• [X] I agree to follow the aio-libs Code of Conduct

I wonder if maybe there are some long running tasks that cause the timeout to be hit, just because the reading task didn't get executed within the 5 seconds.

Maybe ensure you are running with python -Wall -X dev and check for any suspicious warnings, in particular anything that says a callback took x seconds.

I have similar problem but other way around. My timeout is set to 1 sec and when I turn off my WIFI and run below script it takes 20 sec to raise timeout error:

import aiohttp
import asyncio

async def main():
    async with aiohttp.ClientSession(timeout=aiohttp.ClientTimeout(1)) as session:
        async with session.get('http://httpbin.org/get') as resp:
            print(resp.status)
            print(await resp.text())

asyncio.run(main())

asyncio.exceptions.TimeoutError
python test2.py  0,13s user 0,01s system 0% cpu 20,152 total

Same here. read timeout of 5 and takes almost 60s to raise a ServerTimeoutError