Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bad status line 'Invalid method encountered' when sending a request with comperss=True #6566

Open
1 task done
theSonOfMan opened this issue Jan 27, 2022 · 12 comments
Open
1 task done
Labels

Comments

@theSonOfMan
Copy link

theSonOfMan commented Jan 27, 2022

Describe the bug

We were trying to use gzip compression in requests between python applications, both using aiohttp (aiohttp.ClientSession on client side, somewhat modded aiohttp.web.Application on server side). Setting compress parameter in aiohttp.ClientSession.request to True (or "gzip" as we first tried) results in strange errors in the server app:

aiohttp.http_exceptions.BadStatusLine: 400, message="Bad status line 'Invalid method encountered'"

The request was actually processed and client app got the correct response, but those errors still appear in server logs. Sometimes (not actually sure, when) requests fail with 400 Bad Request HTTP error. Adding HTTP header {'Content-Encoding': 'gzip'} doesn't fix the problem in any way.

To Reproduce

  1. Run a basic aiohttp server:
from aiohttp import web


routes = web.RouteTableDef()


@routes.get('/')
async def hello(request):
    return web.Response(text="Hello, world")

app = web.Application()
app.add_routes(routes)
web.run_app(app)
  1. Create a basic aiohttp client request script (suppose server runs on localhost:8080):
import aiohttp
import asyncio


async def main():
    async with aiohttp.ClientSession() as session:
        async with session.get(
            "http://localhost:8080/",
            compress=True,
        ) as resp:
            resp.raise_for_status()
            print(await resp.text())

if __name__ == "__main__":
    asyncio.run(main())
  1. Run the client script
    Client prints Hello, world and resp.raise_for_status() didn't raise any errors.
    Server prints the following:
Error handling request
Traceback (most recent call last):
  File "/Users/19840383/venvs/test/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 334, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp/_http_parser.pyx", line 551, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: 400, message="Bad status line 'Invalid method encountered'"

Expected behavior

The server is supposed to process the request and not give any errors.

Logs/tracebacks

======== Running on http://0.0.0.0:8080 ========
(Press CTRL+C to quit)
Error handling request
Traceback (most recent call last):
  File "/Users/19840383/venvs/test/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 334, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp/_http_parser.pyx", line 551, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: 400, message="Bad status line 'Invalid method encountered'"

Python Version

$ python --version

Python 3.9.9

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
Location: /Users/19840383/venvs/test/lib/python3.9/site-packages
Requires: async-timeout, yarl, aiosignal, charset-normalizer, frozenlist, multidict, attrs
Required-by:

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: andrew.svetlov@gmail.com
License: Apache 2
Location: /Users/19840383/venvs/test/lib/python3.9/site-packages
Requires:
Required-by: yarl, aiohttp

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: andrew.svetlov@gmail.com
License: Apache 2
Location: /Users/19840383/venvs/test/lib/python3.9/site-packages
Requires: multidict, idna
Required-by: aiohttp

OS

macOS Monterey 12.1

Related component

Server, Client

Additional context

No response

Code of Conduct

  • I agree to follow the aio-libs Code of Conduct
@thisisamardeep
Copy link

i was able to reproduce the bug.Will raise fix in next 2-3 days.

@theSonOfMan
Copy link
Author

Hi, @thisisamardeep! Have you been able to make a fix for the bug? I've done some more research and it seems to me that the errors only happen when request method is GET or request body is empty (which makes sense cause there is nothing to actually compress). The workaround is pretty simple but the error is still pretty annoying :(

@Madelinot
Copy link

Has this been fixed?

@kerlyn-bsd3
Copy link

Is it possible to handle this exception in middleware?

@Kluezesh
Copy link

Kluezesh commented Jun 9, 2022

I meet this problem, too.
In my test, BadStatusLine occurs only when using aiohttp client session to request.
If log level is setted, aiohttp will print one more request message(e.g. 2022-06-09 14:20:54 [aiohttp.access] INFO: 127.0.0.1 [09/Jun/2022:06:20:54 +0000] "UNKNOWN / HTTP/1.0" 400 204 "-" "-" ) which I haven't requested.
After replacing aiohttp.ClientSession with aiohttp.request never show the BadStatusLine message

@nobody4t
Copy link

I got this a lot these days.
Any idea?
Error handling request Traceback (most recent call last): File "/usr/local/lib/python3.8/dist-packages/aiohttp/web_protocol.py", line 334, in data_received messages, upgraded, tail = self._request_parser.feed_data(data) File "aiohttp/_http_parser.pyx", line 551, in aiohttp._http_parser.HttpParser.feed_data aiohttp.http_exceptions.BadStatusLine: 400, message="Bad status line 'Invalid method encountered'"

@TheDeadOne
Copy link

Faced the same problem when I pass headers.

@occasionallydavid
Copy link

occasionallydavid commented Jul 16, 2022

It looks like a problem with the server rather than the client, for keepalive connections.

The messages sent by the client seem correct.

I wonder if it's related to the use of compression somehow.

Here is an example Wireshark trace, ignore the extra headers in the last request, they're wrong but they're unrelated to this problem

Wireshark follow TCP stream
GET /mail/inbox/ HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
Accept-Language: en-GB
Accept-Encoding: gzip, deflate, br
Content-Type: application/x-www-form-urlencoded
Content-Length: 75
Origin: http://localhost:8080
DNT: 1
Connection: keep-alive
Referer: http://localhost:8080/account/login/
Cookie: si="27X41k5NQBLQRbrHZMf/Sbut58bxNd622J8VDgDfZQnQkV8SehHEKaTpyvvCQe37G3aY9UK36+rz"
Upgrade-Insecure-Requests: 1
Sec-Fetch-Dest: document
Sec-Fetch-Mode: navigate
Sec-Fetch-Site: same-origin
Sec-Fetch-User: ?1
X-Forwarded-for: 127.0.0.1

HTTP/1.1 200 OK
Content-type: text/html; charset=utf8
X-Content-Type-Options: nosniff
Content-Encoding: br
Transfer-Encoding: chunked
Date: Sat, 16 Jul 2022 19:51:57 GMT
Server: Python/3.10 aiohttp/3.8.1

7c
.c..d...YL.6...T..B.L..T..T..v......9.*g.Dq#a...W.....#........\{.....%... .22.....*...t.....0p.....$}v.\....fE...;W..\..j. 16f ..@6u.w..<.. .v.........y..S.r!.....Esc...k.^m....s.+.........@...<f.dw@.,1k
.?`.....[.6E.....].:....d!. ^.Y6;.......z...V;N.FC.rE.....w9.q
S.."w...n....
1c
h..@.p.%x.....x.E...5.,..z..
1
.
0

GET /mail/inbox/ HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,/;q=0.8
Accept-Language: en-GB
Accept-Encoding: gzip, deflate, br
Content-Type: application/x-www-form-urlencoded
Content-Length: 75
Origin: http://localhost:8080
DNT: 1
Connection: keep-alive
Referer: http://localhost:8080/account/login/
Cookie: si="aul5XCBTFqjAG7VVXEqUAg2FopDC7OOwzT4IBi9RA9HI8gb44JLGMSHoBqo2T9ncEDtIXAcEbEez"
Upgrade-Insecure-Requests: 1
Sec-Fetch-Dest: document
Sec-Fetch-Mode: navigate
Sec-Fetch-Site: same-origin
Sec-Fetch-User: ?1
X-Forwarded-for: 127.0.0.1

HTTP/1.0 400 Bad Request
Content-Type: text/plain; charset=utf-8
Content-Length: 44
Date: Sat, 16 Jul 2022 19:52:00 GMT
Server: Python/3.10 aiohttp/3.8.1

Bad status line 'Invalid method encountered'

@sunbinzhu
Copy link

Facing the same issue after we enabled TLS 1.3 in the server.
The issue disappears if we Hardcode tls 1.2 in either client side or server side.

@Dreamsorcerer
Copy link
Member

Some behavior may be platform dependent, since calls are made to the operating system socket APIs. The installed version of OpenSSL may also cause variations in behavior. For example, TLSv1.3 comes with OpenSSL version 1.1.1.
https://docs.python.org/3/library/ssl.html?highlight=tls

I'd check openssl version, I've no idea what the problem would be otherwise. If on a supported version, then it'd probably be a good idea to hack some aiohttp code and try and print out the raw data, to see what's coming through.

@sunbinzhu
Copy link

sunbinzhu commented Jan 16, 2024

Thanks @Dreamsorcerer I was able to capture the net packages and decrypt the TLS records, The http request was sent in two TLS records: one contains the http header part, the other contains the payload part, I can confirm the content of both header part and payload part are correct. From the error message, my wild guess is that the server didn't assembly them together and was trying to parse the payload part as a whole http request. While when using TLS 1.2, though the http request was also sent in the same way (header and payload contained in two TLS records), seems the server was able to assembly them together before parsing.

header:
b'PUT / HTTP/1.1\r\nx-ms-client-request-id: 962f2514-e22d-4e9d-83f6-e241dfb1fe72\r\nContent-Type: application/octet-stream\r\nHost: 10.8.0.100:29876\r\nContent-Length: 283\r\nConnection: Keep-Alive\r\n\r\n'

payload:
b'<payload content>'

Error:
Error handling request□Traceback (most recent call last):□ File "aiohttp\web_protocol.py", line 332, in data_received□ File "aiohttp\_http_parser.pyx", line 557, in aiohttp._http_parser.HttpParser.feed_data□aiohttp.http_exceptions.BadStatusLine: 400, message:□ Invalid method encountered:□□ b'<payload content>'□ ^

@Dreamsorcerer
Copy link
Member

I don't have time to look at anything yet, but if you could debug further and figure out exactly what's happening in the code, that'd be great. I'd start by printing data at https://github.com/aio-libs/aiohttp/blob/master/aiohttp/_http_parser.pyx#L522
So we can be sure what is actually being sent to the parser and then figuring out where the difference is.
Instructions to compile that is: https://github.com/aio-libs/aiohttp/blob/master/vendor/README.rst
Note that I've only been able to get the C parser to import if I install aiohttp, it never seems to find it when running from the source directory.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

10 participants