Client: _request.timeout cancels the current AND the next request #1879

seperman · 2017-05-09T23:42:24Z

Long story short

_request.timeout will cancel the current request AND the next request.

Expected behaviour

I expected it to behave the same way as aiohttp.Timeout. In other words it should not leak the cancellation to the next request.

Actual behaviour

_request.timeout will call TimeoutHandle.__call__ which runs TimeoutHandle._callbacks which runs TimerContext.timeout which sets self._cancelled=True and somehow it leads to the cancellation of the next call of the coroutine too.
aiohttp.Timeout does NOT call TimeoutHandle.__call__

Steps to reproduce

Run a local server on port 8888 (I left a sample code for it below). Make it slow to cause timeout errors from the client. In this example 2 seconds cause timeout error.
In order to see the difference between the behaviors, switch from fetch = fetch_cancells to fetch = fetch_works and vice verca.

Client

import asyncio
import aiohttp


async def fetch_cancells(session, url):
    async with session.get(url, timeout=2) as response:
        return response.status, await response.text()


async def fetch_works(session, url):
    with aiohttp.Timeout(2, loop=session.loop):
        async with session.get(url) as response:
            return response.status, await response.text()

# Change this line to fetch=fetch_works to see it working.
fetch = fetch_cancells
# fetch = fetch_works
print(fetch.__name__)


async def hit_url(loop):
    print('Hitting')
    async with aiohttp.ClientSession(loop=loop) as session:
        status, body = await fetch(session, 'http://localhost:8888')
        return status, body


async def master(loop):
    print('----------')
    while True:
        try:
            status, body = await hit_url(loop)
        except asyncio.CancelledError:
            print('Cancelled!')
        except asyncio.TimeoutError:
            print('Time Out!!')
        except Exception:
            raise
        else:
            print(status)
            print(body)
        # await asyncio.sleep(.5)  # <--


def main():
    loop = asyncio.get_event_loop()
    loop.set_debug(True)
    try:
        loop.run_until_complete(master(loop))
    finally:
        loop.close()


if __name__ == '__main__':
    main()

Results

This is what you get with fetch = fetch_works, aka expected behavior:

fetch_works
----------
Hitting
TimerContext._cancelled=False
Time Out!!
----------
Hitting
TimerContext._cancelled=False
Time Out!!
----------
Hitting
TimerContext._cancelled=False
Time Out!!

And this is when fetch=fetch_cancells

fetch_cancells
----------
Hitting
TimeoutHandle.__call__ is called
TimerContext.timeout is called
TimerContext._cancelled=True
TimerContext._cancelled=True
Time Out!!
----------
Hitting
TimerContext._cancelled=False
Cancelled!
----------
Hitting
TimeoutHandle.__call__ is called
TimerContext.timeout is called
TimerContext._cancelled=True
TimerContext._cancelled=True
Time Out!!
----------
Hitting
TimerContext._cancelled=False
Cancelled!

Basically with every new hit, the response alternates between Timeout and Cancelled instead of only staying on Timeout.

The sample server used

In case it helps, here is the server I used:

#!/usr/bin/env python
"""
Very simple HTTP server in python.

Usage::
    ./dummy-web-server.py [<port>]

Send a GET request::
    curl http://localhost

Send a HEAD request::
    curl -I http://localhost

Send a POST request::
    curl -d "foo=bar&bin=baz" http://localhost

"""
from http.server import BaseHTTPRequestHandler, HTTPServer


class Server(BaseHTTPRequestHandler):
    def _set_headers(self):
        self.send_response(200)
        self.send_header(b'Content-type', 'text/html')
        self.end_headers()

    def do_GET(self):
        import pdb; pdb.set_trace()
        self._set_headers()
        self.wfile.write(b"<html><body><h1>hi!</h1></body></html>")

    def do_HEAD(self):
        self._set_headers()

    def do_POST(self):
        # Doesn't do anything with posted data
        self._set_headers()
        self.wfile.write(b"<html><body><h1>POST!</h1></body></html>")


def run(server_class=HTTPServer, handler_class=Server, port=8888):
    server_address = ('', port)
    httpd = server_class(server_address, handler_class)
    print('Starting httpd...')
    httpd.serve_forever()


if __name__ == "__main__":
    from sys import argv

    if len(argv) == 2:
        run(port=int(argv[1]))
    else:
        run()

Your environment

MacOs Sierra
Python 3.6.0
Aiohttp 2.0.7

The text was updated successfully, but these errors were encountered:

fafhrd91 · 2017-05-12T20:01:51Z

thanks for report! should be fixed in master

seperman · 2017-05-14T17:07:05Z

Cool. Thanks!

gjthompson1 · 2017-08-21T19:33:10Z

Was this actually fixed?
https://stackoverflow.com/questions/45800857/aiohttp-error-rate-increases-with-number-of-connections#45803926

lock · 2019-10-28T17:01:53Z

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].
[new issue]: https://github.com/aio-libs/aiohttp/issues/new

fafhrd91 mentioned this issue May 12, 2017

Unexpected CancelledError raised via TCPConnector._create_direct_connection #1863

Closed

fafhrd91 added a commit that referenced this issue May 12, 2017

fix second cancellation after timeout #1879

ab8efa4

fafhrd91 closed this as completed May 12, 2017

fafhrd91 mentioned this issue May 18, 2017

[Investigation] Leaking of timeout task cancellation #1904

Closed

zmedico mentioned this issue May 24, 2017

Client Session Timeouts - Usage Question #1686

Closed

fafhrd91 mentioned this issue Jun 19, 2017

ClientSession CancelledError in old versions #1991

Closed

aio-libs-bot mentioned this issue Dec 3, 2018

client: GET request continues after cancelling the task #3426

Closed

lock bot added the outdated label Oct 28, 2019

lock bot locked as resolved and limited conversation to collaborators Oct 28, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Client: _request.timeout cancels the current AND the next request #1879

Client: _request.timeout cancels the current AND the next request #1879

seperman commented May 9, 2017 •

edited

Loading

fafhrd91 commented May 12, 2017

seperman commented May 14, 2017

gjthompson1 commented Aug 21, 2017 •

edited

Loading

lock bot commented Oct 28, 2019

Client: _request.timeout cancels the current AND the next request #1879

Client: _request.timeout cancels the current AND the next request #1879

Comments

seperman commented May 9, 2017 • edited Loading

Long story short

Expected behaviour

Actual behaviour

Steps to reproduce

Client

Results

The sample server used

Your environment

fafhrd91 commented May 12, 2017

seperman commented May 14, 2017

gjthompson1 commented Aug 21, 2017 • edited Loading

lock bot commented Oct 28, 2019

seperman commented May 9, 2017 •

edited

Loading

gjthompson1 commented Aug 21, 2017 •

edited

Loading