Closed pwuertz closed 1 month ago
Also got some TCP dumps from the good and bad test case:
aiohttp 3.6, good
$ sudo tcpdump -A -s 0 'tcp port 9000' -i lo
tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on lo, link-type EN10MB (Ethernet), snapshot length 262144 bytes
11:25:44.653129 IP localhost.47218 > localhost.9000: Flags [S], seq 648149401, win 65495, options [mss 65495,sackOK,TS val 4120277942 ecr 0,nop,wscale 7], length 0
E..<.y@.@..@.........r#(&............0.........
..s.........
11:25:44.653136 IP localhost.9000 > localhost.47218: Flags [S.], seq 1401724688, ack 648149402, win 65483, options [mss 65495,sackOK,TS val 4120277942 ecr 4120277942,nop,wscale 7], length 0
E..<..@.@.<.........#(.rS...&........0.........
..s...s.....
11:25:44.653144 IP localhost.47218 > localhost.9000: Flags [.], ack 1, win 512, options [nop,nop,TS val 4120277942 ecr 4120277942], length 0
E..4.z@.@..G.........r#(&...S........(.....
..s...s.
11:25:44.653269 IP localhost.47218 > localhost.9000: Flags [P.], seq 1:285, ack 1, win 512, options [nop,nop,TS val 4120277942 ecr 4120277942], length 284
E..P.{@.@..*.........r#(&...S........D.....
..s...s.POST / HTTP/1.1
Host: localhost:9000
Content-Type: text/plain;charset=UTF-8
Content-Length: 11
Accept-Encoding: gzip, deflate
Accept-Language: en-US,*
User-Agent: Mozilla/5.0
Connection: Keep-Alive, Upgrade, HTTP2-Settings
Upgrade: h2c
HTTP2-Settings: AAIAAAAA
Hello World
11:25:44.653273 IP localhost.9000 > localhost.47218: Flags [.], ack 285, win 510, options [nop,nop,TS val 4120277942 ecr 4120277942], length 0
E..4 T@.@..n........#(.rS...&........(.....
..s...s.
11:25:44.653708 IP localhost.9000 > localhost.47218: Flags [P.], seq 1:151, ack 285, win 512, options [nop,nop,TS val 4120277942 ecr 4120277942], length 150
E... U@.@...........#(.rS...&..............
..s...s.HTTP/1.1 200 OK
Content-Length: 11
Content-Type: application/octet-stream
Date: Tue, 21 Dec 2021 10:25:44 GMT
Server: Python/3.9 aiohttp/3.6.0
11:25:44.653715 IP localhost.47218 > localhost.9000: Flags [.], ack 151, win 511, options [nop,nop,TS val 4120277942 ecr 4120277942], length 0
E..4.|@.@..E.........r#(&...S........(.....
..s...s.
11:25:44.653731 IP localhost.9000 > localhost.47218: Flags [P.], seq 151:162, ack 285, win 512, options [nop,nop,TS val 4120277942 ecr 4120277942], length 11
E..? V@.@..a........#(.rS...&........3.....
..s...s.Hello World
11:25:44.653734 IP localhost.47218 > localhost.9000: Flags [.], ack 162, win 511, options [nop,nop,TS val 4120277942 ecr 4120277942], length 0
E..4.}@.@..D.........r#(&...S........(.....
..s...s.
11:25:44.653956 IP localhost.47218 > localhost.9000: Flags [F.], seq 285, ack 162, win 512, options [nop,nop,TS val 4120277943 ecr 4120277942], length 0
E..4.~@.@..C.........r#(&...S........(.....
..s...s.
11:25:44.654020 IP localhost.9000 > localhost.47218: Flags [F.], seq 162, ack 286, win 512, options [nop,nop,TS val 4120277943 ecr 4120277943], length 0
E..4 W@.@..k........#(.rS...&........(.....
..s...s.
11:25:44.654027 IP localhost.47218 > localhost.9000: Flags [.], ack 163, win 512, options [nop,nop,TS val 4120277943 ecr 4120277943], length 0
E..4..@.@..B.........r#(&...S........(.....
..s...s.
^C
12 packets captured
24 packets received by filter
0 packets dropped by kernel
aiohttp >= 3.7, bad
$ sudo tcpdump -A -s 0 'tcp port 9000' -i lo
tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on lo, link-type EN10MB (Ethernet), snapshot length 262144 bytes
11:28:15.060735 IP localhost.47220 > localhost.9000: Flags [S], seq 933826246, win 65495, options [mss 65495,sackOK,TS val 4120428349 ecr 0,nop,wscale 7], length 0
E..<..@.@.?..........t#(7............0.........
...=........
11:28:15.060746 IP localhost.9000 > localhost.47220: Flags [S.], seq 2668135700, ack 933826247, win 65483, options [mss 65495,sackOK,TS val 4120428349 ecr 4120428349,nop,wscale 7], length 0
E..<..@.@.<.........#(.t....7........0.........
...=...=....
11:28:15.060754 IP localhost.47220 > localhost.9000: Flags [.], ack 1, win 512, options [nop,nop,TS val 4120428349 ecr 4120428349], length 0
E..4..@.@.?..........t#(7............(.....
...=...=
11:28:15.060877 IP localhost.47220 > localhost.9000: Flags [P.], seq 1:285, ack 1, win 512, options [nop,nop,TS val 4120428350 ecr 4120428349], length 284
E..P..@.@.>..........t#(7............D.....
...>...=POST / HTTP/1.1
Host: localhost:9000
Content-Type: text/plain;charset=UTF-8
Content-Length: 11
Accept-Encoding: gzip, deflate
Accept-Language: en-US,*
User-Agent: Mozilla/5.0
Connection: Keep-Alive, Upgrade, HTTP2-Settings
Upgrade: h2c
HTTP2-Settings: AAIAAAAA
Hello World
11:28:15.060882 IP localhost.9000 > localhost.47220: Flags [.], ack 285, win 510, options [nop,nop,TS val 4120428350 ecr 4120428350], length 0
E..4t.@.@...........#(.t....7........(.....
...>...>
11:28:15.061779 IP localhost.9000 > localhost.47220: Flags [F.], seq 1, ack 285, win 512, options [nop,nop,TS val 4120428350 ecr 4120428350], length 0
E..4t.@.@...........#(.t....7........(.....
...>...>
11:28:15.061804 IP localhost.47220 > localhost.9000: Flags [F.], seq 285, ack 2, win 512, options [nop,nop,TS val 4120428351 ecr 4120428350], length 0
E..4..@.@.?..........t#(7............(.....
...?...>
11:28:15.061812 IP localhost.9000 > localhost.47220: Flags [.], ack 286, win 512, options [nop,nop,TS val 4120428351 ecr 4120428351], length 0
E..4t.@.@...........#(.t....7........(.....
...?...?
11:28:15.061875 IP localhost.47222 > localhost.9000: Flags [S], seq 632459119, win 65495, options [mss 65495,sackOK,TS val 4120428351 ecr 0,nop,wscale 7], length 0
E..<.S@.@..f.........v#(%..o.........0.........
...?........
11:28:15.061878 IP localhost.9000 > localhost.47222: Flags [S.], seq 401720488, ack 632459120, win 65483, options [mss 65495,sackOK,TS val 4120428351 ecr 4120428351,nop,wscale 7], length 0
E..<..@.@.<.........#(.v....%..p.....0.........
...?...?....
11:28:15.061881 IP localhost.47222 > localhost.9000: Flags [.], ack 1, win 512, options [nop,nop,TS val 4120428351 ecr 4120428351], length 0
E..4.T@.@..m.........v#(%..p.........(.....
...?...?
11:28:15.061924 IP localhost.47222 > localhost.9000: Flags [P.], seq 1:310, ack 1, win 512, options [nop,nop,TS val 4120428351 ecr 4120428351], length 309
E..i.U@.@..7.........v#(%..p.........].....
...?...?POST / HTTP/1.1
Host: localhost:9000
Content-Type: text/plain;charset=UTF-8
Content-Length: 11
Accept-Encoding: gzip, deflate
Accept-Language: en-US,*
User-Agent: Mozilla/5.0
Connection: Keep-Alive, Upgrade, HTTP2-Settings, Upgrade, HTTP2-Settings
Upgrade: h2c
HTTP2-Settings: AAIAAAAA
Hello World
11:28:15.061927 IP localhost.9000 > localhost.47222: Flags [.], ack 310, win 510, options [nop,nop,TS val 4120428351 ecr 4120428351], length 0
E..4..@.@...........#(.v....%........(.....
...?...?
11:28:15.062145 IP localhost.9000 > localhost.47222: Flags [F.], seq 1, ack 310, win 512, options [nop,nop,TS val 4120428351 ecr 4120428351], length 0
E..4..@.@...........#(.v....%........(.....
...?...?
11:28:15.062162 IP localhost.47222 > localhost.9000: Flags [F.], seq 310, ack 2, win 512, options [nop,nop,TS val 4120428351 ecr 4120428351], length 0
E..4.V@.@..k.........v#(%............(.....
...?...?
11:28:15.062167 IP localhost.9000 > localhost.47222: Flags [.], ack 311, win 512, options [nop,nop,TS val 4120428351 ecr 4120428351], length 0
E..4..@.@...........#(.v....%........(.....
...?...?
^C
16 packets captured
32 packets received by filter
0 packets dropped by kernel
All right, it seems that this problem is solely triggered by this line in the request header:
Upgrade: h2c
When this header is present, aiohttp to fails and drops the connection.
HTTP/2 is not supported at the moment. But you could contribute it: https://github.com/aio-libs/aiohttp/issues/5999.
HTTP/2 is not supported at the moment. But you could contribute it: #5999.
Description said that the connection works with aiohttp 3.6. So there is presumably some kind of regression that is not related to supporting HTTP/2.
HTTP/2 is not supported at the moment. But you could contribute it: #5999.
Missing HTTP/2 support is not the issue here. The client did send a perfectly valid HTTP/1.1 request with the suggestion of switching to another protocol the server may or may not support.
If the server supports and agrees to switching to a suggested protocol, the server replies with a HTTP/1.1 101 Switching Protocols
response. If the server doesn't support the protocol (or doesn't want to switch) it should just continue talking to the client using the already established HTTP/1.1 protocol in an orderly fashion (i.e. not just drop the connection).
The server doesn't decide if a protocol upgrade is mandatory. It's the clients decision to either continue using the non-upgraded protocol or to drop the connection and report the absence of a 101 reply as sort of a MissingProtocolError
.
Well, then it would be useful to get a PR with a failing regression test.
Here is a minimal aiohttp.test_utils
based test that triggers the observed behavior on aiohttp >= 3.7
from aiohttp import web, test_utils
async def test_unsupported_upgrade() -> None:
# don't fail if a client probes for an unsupported protocol upgrade
# https://github.com/aio-libs/aiohttp/issues/6446#issuecomment-999032039
async def post_handler(request: web.Request):
return web.Response(body=await request.read())
upgrade_headers = {"Connection": "Upgrade", "Upgrade": "unsupported_proto"}
app = web.Application()
app.add_routes([web.post("/", post_handler)])
async with test_utils.TestServer(app) as server:
async with test_utils.TestClient(server) as cli:
resp = await cli.post("/", data=b"Test", headers=upgrade_headers)
assert resp.status == 200
assert (await resp.read()) == b"Test"
# asyncio.run(test_unsupported_upgrade()) or similar
Oddly enough, no error is triggered when running this function as part of the aiohttp tests, e.g. by adding it to aiohttp/tests/test_web_server.py
. The aiohttp testing environment appears to differ from the 'real' environment in some significant way.
Could you submit that as a pull request? It'd give us visibility into the behavior in multiple envs, not just your laptop.
As for the difference, it is possible that you're running the tests with pure-Python fallback parser implementation which may be different from the Cython-based one. If this is true, we'd need to make sure to make the behavior equivalent too.
Oddly enough, no error is triggered when running this function as part of the aiohttp tests, e.g. by adding it to
aiohttp/tests/test_web_server.py
. The aiohttp testing environment appears to differ from the 'real' environment in some significant way.
Maybe also double check what versions you are testing with. Maybe the issue is not present on master, but only in the 3.8/3.9 branches..
Maybe also double check what versions you are testing with. Maybe the issue is not present on master, but only in the 3.8/3.9 branches..
Right, I assumed this could be the case, but I'm pretty sure I excluded this possibility by checking out 3.8.1 (still no error in tests) + installing from source and running the code (error is triggered) :shrug:
Could you submit that as a pull request? It'd give us visibility into the behavior in multiple envs, not just your laptop.
Added PR #6451 for the regression test. Sorry, I didn't understand the need for PR earlier because the snippet in https://github.com/aio-libs/aiohttp/issues/6446#issuecomment-999214392 already provided visibility beyond my PC, while the testing framework doesn't seem to do the 'right' thing at this time.
As for the difference, it is possible that you're running the tests with pure-Python fallback parser implementation which may be different from the Cython-based one. If this is true, we'd need to make sure to make the behavior equivalent too.
Oh, that sounds reasonable, that difference kept me bamboozled for quite some time.
As for the difference, it is possible that you're running the tests with pure-Python fallback parser implementation which may be different from the Cython-based one. If this is true, we'd need to make sure to make the behavior equivalent too.
Oh, that is exactly what happened here! The tests were performed against aiohttp
from the source tree, so they used the pure-python implementation. After copying over all .so
files from build
the compiled parsers are picked up and the test does indeed fail now.
After copying over all
.so
files frombuild
the compiled parsers are picked up and the test does indeed fail now.
FYI it should be enough to run make cythonize
+ make test
to that the C-extensions built.
Meanwhile, I've approved the CI run and we should soon have the logs of how it fails there. If everything goes as expected, that test can be marked as xfail and merged per https://pganssle-talks.github.io/xfail-lightning.
So, I think the change that caused this is probably switching to llhttp for the parsing. I'm not familiar with this, so not sure if the bug needs to be reported upstream to llhttp or if there's something we can fix here.
Maybe @derlih might know more.
So, I think the change that caused this is probably switching to llhttp for the parsing.
I don't think so. The reporter claims that the error started happening in aiohttp 3.7 but the switch hasn't happened until aiohttp 3.8.
Here's the log from the CI failure for history:
=================================== FAILURES ===================================
_______________________ test_unsupported_upgrade[pyloop] _______________________
aiohttp_raw_server = <function aiohttp_raw_server.<locals>.go at 0x7f077f28ec80>
aiohttp_client = <function aiohttp_client.<locals>.go at 0x7f077f28e0d0>
async def test_unsupported_upgrade(aiohttp_raw_server, aiohttp_client) -> None:
# don't fail if a client probes for an unsupported protocol upgrade
# aio-libs/aiohttp/issues/6446#issuecomment-999032039
async def handler(request: web.Request):
return web.Response(body=await request.read())
upgrade_headers = {"Connection": "Upgrade", "Upgrade": "unsupported_proto"}
server = await aiohttp_raw_server(handler)
cli = await aiohttp_client(server)
test_data = b"Test"
> resp = await cli.post("/path/to", data=test_data, headers=upgrade_headers)
aiohttp_client = <function aiohttp_client.<locals>.go at 0x7f077f28e0d0>
aiohttp_raw_server = <function aiohttp_raw_server.<locals>.go at 0x7f077f28ec80>
cli = <aiohttp.test_utils.TestClient object at 0x7f077f2dd7f0>
handler = <function test_unsupported_upgrade.<locals>.handler at 0x7f077f28e510>
server = <aiohttp.test_utils.RawTestServer object at 0x7f077f03f4e0>
test_data = b'Test'
upgrade_headers = {'Connection': 'Upgrade', 'Upgrade': 'unsupported_proto'}
tests/test_web_server.py:31:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
aiohttp/test_utils.py:324: in _request
resp = await self._session.request(method, self.make_url(path), **kwargs)
kwargs = {'data': b'Test',
'headers': {'Connection': 'Upgrade', 'Upgrade': 'unsupported_proto'}}
method = 'POST'
path = '/path/to'
self = <aiohttp.test_utils.TestClient object at 0x7f077f2dd7f0>
aiohttp/client.py:559: in _request
await resp.start(conn)
all_cookies = <SimpleCookie: >
allow_redirects = True
auth = None
auth_from_url = None
chunked = None
compress = None
conn = Connection<ConnectionKey(host='127.0.0.1', port=42413, is_ssl=False, ssl=None, proxy=None, proxy_auth=None, proxy_headers_hash=None)>
cookies = None
data = b'Test'
expect100 = False
fingerprint = None
handle = None
headers = <CIMultiDict('Connection': 'Upgrade', 'Upgrade': 'unsupported_proto')>
history = []
json = None
max_redirects = 10
method = 'POST'
params = None
proxy = None
proxy_auth = None
proxy_headers = <CIMultiDict()>
raise_for_status = None
read_bufsize = 65536
read_until_eof = True
real_timeout = ClientTimeout(total=300, connect=None, sock_read=None, sock_connect=None)
redirects = 0
req = <aiohttp.client_reqrep.ClientRequest object at 0x7f077f2dd4a8>
resp = <ClientResponse(http://127.0.0.1:42413/path/to) [None None]>
None
self = <aiohttp.client.ClientSession object at 0x7f077f2dd320>
skip_auto_headers = None
skip_headers = set()
ssl = None
ssl_context = None
str_or_url = URL('http://127.0.0.1:42413/path/to')
timeout = <object object at 0x7f0785b8d6d0>
timer = <aiohttp.helpers.TimerContext object at 0x7f077f2ddc50>
tm = <aiohttp.helpers.TimeoutHandle object at 0x7f077f2dda90>
trace_request_ctx = None
traces = []
url = URL('http://127.0.0.1:42413/path/to')
verify_ssl = None
version = HttpVersion(major=1, minor=1)
aiohttp/client_reqrep.py:896: in start
message, payload = await protocol.read() # type: ignore[union-attr]
connection = Connection<ConnectionKey(host='127.0.0.1', port=42413, is_ssl=False, ssl=None, proxy=None, proxy_auth=None, proxy_headers_hash=None)>
protocol = <aiohttp.client_proto.ResponseHandler object at 0x7f077f087ce0>
self = <ClientResponse(http://127.0.0.1:42413/path/to) [None None]>
None
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <aiohttp.client_proto.ResponseHandler object at 0x7f077f087ce0>
async def read(self) -> _T:
if not self._buffer and not self._eof:
assert not self._waiter
self._waiter = self._loop.create_future()
try:
> await self._waiter
E aiohttp.client_exceptions.ServerDisconnectedError: Server disconnected
self = <aiohttp.client_proto.ResponseHandler object at 0x7f077f087ce0>
aiohttp/streams.py:616: ServerDisconnectedError
------------------------------ Captured log call -------------------------------
ERROR aiohttp.server:web_protocol.py:405 Unhandled exception
Traceback (most recent call last):
File "/home/runner/work/aiohttp/aiohttp/aiohttp/web_protocol.py", line 514, in start
resp, reset = await task
File "/home/runner/work/aiohttp/aiohttp/aiohttp/web_protocol.py", line 460, in _handle_request
reset = await self.finish_response(request, resp, start_time)
File "/home/runner/work/aiohttp/aiohttp/aiohttp/web_protocol.py", line 599, in finish_response
self._request_parser.feed_data(self._message_tail)
File "aiohttp/_http_parser.pyx", line 551, in aiohttp._http_parser.HttpParser.feed_data
raise ex
aiohttp.http_exceptions.BadStatusLine: 400, message="Bad status line 'Invalid method encountered'"
It shows that the server seems to attempt sending HTTP 400 (BadStatusLine
exception) but somehow ends up sending a reset on a lower level (supposedly TCP RST). And on the client-side, it gets translated to the ServerDisconnectedError
exception. This makes me wonder if there's some sort of a race condition that decides that the transport layer needs to drop the connection...
Ah, OK. I just looked at the last line:
File "aiohttp/_http_parser.pyx", line 551, in aiohttp._http_parser.HttpParser.feed_data raise ex aiohttp.http_exceptions.BadStatusLine: 400, message="Bad status line 'Invalid method encountered'"
And noticed that it comes from some llhttp thing a few lines earlier (plus the error doesn't occur without extensions): https://github.com/aio-libs/aiohttp/blob/master/aiohttp/_http_parser.pyx#L531
So, I thought that was it.
It shows that the server seems to attempt sending HTTP 400 (
BadStatusLine
exception) but somehow ends up sending a reset on a lower level (supposedly TCP RST). And on the client-side, it gets translated to theServerDisconnectedError
exception.
Actually, isn't that 2 separate issues? If the connection works correctly in aiohttp 3.6, then raising a BadStatusLine is a regression. Then failing to send the 400 response is another issue.
Yep, maybe it's two issues. I don't have time to look into that right now but I've taken care of adding the xfailing test to the supported branches. The original PR added it to 3.8
but it's of course necessary in 3.9
and master
which should get auto merged soon.
This was fixed relatively recently.
Describe the bug
I'm experiencing problems when trying to handle HTTP requests sent by Qt6 clients. It looks like Qt now sends additional HTTP2 related headers by default. HTTP servers based on
aiohttp 3.6
and pythonhttp.server
are handling those requests just fine, butaiohttp 3.7
and3.8
are showing irregularities in the parsed headers, are unable to read request bodies, and fail to send replies.Test code and examples for good/bad observations are attached to this issue.
To Reproduce
Qt6 / Qt5 client test code:
Aiohttp test server:
Expected behavior
aiohttp server should be able to handle the requests.
Logs/tracebacks
Good result with aiohttp 3.6:
Bad result with aiohttp 3.7 and 3.8:
Python Version
aiohttp Version
multidict Version
yarl Version
OS
Ubuntu 21.10
Related component
Server
Additional context
No response
Code of Conduct