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

Fixed #30015 -- Ensured request body is properly consumed for keep-alive connections. #10732

Merged
merged 1 commit into from Dec 19, 2018

Conversation

Projects
None yet
7 participants
@kalekseev
Copy link
Contributor

commented Dec 6, 2018

Django 2.1.4 affected.
Commit that enabled keep-alive connections 934acf1
Bug: if you make two requests in one keep-alive connection and first request posted data that wasn't read in the view
then on second request that data will be read alongside with first line of the new request.
As a result request.method will contain "..data from previous request...POST"

$ ./runtests.py 
======================================================================
FAIL: test_keep_alive_connection_clears_previous_request_data (servers.tests.LiveServerViews)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/wtf/github/django/tests/servers/tests.py", line 127, in test_keep_alive_connection_clears_previous_request_data
    self.assertEqual(response.read(), b'POST')
AssertionError: b'{}POST' != b'POST'

@kalekseev kalekseev force-pushed the kalekseev:server-keep-alive branch from cbe081d to 4c7dc27 Dec 6, 2018

@kalekseev kalekseev changed the title Fix keep-alive connection not clearing previous request data. Fixed #30015 -- Keep-alive connection not clearing previous request data. Dec 6, 2018

@charettes

This comment has been minimized.

Copy link
Member

commented Dec 6, 2018

/cc @apollo13

if not self.request_handler.close_connection:
for obj in self.result._closable_objects:
if isinstance(obj, WSGIRequest) and not obj._read_started:
obj._stream.read()

This comment has been minimized.

Copy link
@apollo13

apollo13 Dec 6, 2018

Contributor

Nice catch @kalekseev -- I have a few improvements for it, but I didn't test them yet; do you think you could incorporate the following list?

  • This seems to work (tm) because the _stream object is a limited stream, otherwise we could (in the worst case) already read data from the new request.
  • The read() call results in a realloc of self.buffer; a more performant option would be to add a discard() method to LimitedStream which simple discards data after reading; ie def discard(self): self._read_limited()
  • Is the check for read_started actually correct? Shouldn't we even read the stream to end if reading was not started?
  • .read() might fail with an IOError? I realize that the data should already be in local buffers due to the fact that we wouldn't be able to generate a response otherwise, but still
  • Does it make sense to always exhaust the stream? In that case we could move it into a close() of WSGIRequest and do not need special casing here.

What do flask and others do?

@apollo13

This comment has been minimized.

Copy link
Contributor

commented Dec 6, 2018

Werkzeug uses exhaust: https://github.com/pallets/werkzeug/blob/d129d17066768238139b8f8a5d667d9a4f4d68db/werkzeug/formparser.py#L105 -- they also always exhaust the stream, might be a good idea to do something similar

@kalekseev

This comment has been minimized.

Copy link
Contributor Author

commented Dec 6, 2018

do you think you could incorporate the following list?

Hi @apollo13, thanks for review, I agree it's quite naive, just pushed first working solution to start discussion and make sure that the right way to go, I'll improve it in the following days.

Is the check for read_started actually correct? Shouldn't we even read the stream to end if reading was not started?

Yes, that's incorrect.

@kalekseev kalekseev force-pushed the kalekseev:server-keep-alive branch from 4c7dc27 to 5dbe183 Dec 6, 2018

@apollo13

This comment has been minimized.

Copy link
Contributor

commented Dec 6, 2018

It is definitely heading towards the correct direction, thanks!

@kalekseev kalekseev force-pushed the kalekseev:server-keep-alive branch from 5dbe183 to 068e268 Dec 7, 2018

@kalekseev

This comment has been minimized.

Copy link
Contributor Author

commented Dec 10, 2018

Does it make sense to always exhaust the stream? In that case we could move it into a close() of WSGIRequest and do not need special casing here.

What do flask and others do?

Werkzeug uses exhaust: https://github.com/pallets/werkzeug/blob/d129d17066768238139b8f8a5d667d9a4f4d68db/werkzeug/formparser.py#L105 -- they also always exhaust the stream, might be a good idea to do something similar

I've looked into werkzeug and it doesn't support http/1.1 protocol so they always close connection.
Their exhaust logic in finally block is useful only in case of exception otherwise the stream is already empty. And in case like we are trying to fix here, their exhaust logic won't be executed at all because we don't access request form data in view.

I've also looked at the gunicorn, it uses http 1.0 for sync workers because nginx like proxies communicate with the upstream via 1.0 protocol and for async workers it implements cleanup of unread body https://github.com/benoitc/gunicorn/blob/6db35f66a321942690224e8fd11d1fac176e5c89/gunicorn/http/parser.py#L33. Notice how they discard request body on the start of the next request not at the end of the current request.

Having that in mind I think that if we move stream exhaust inside request close function then we introduce extra overhead for http 1.0 so better to discard unread body inside our server.

@apollo13

This comment has been minimized.

Copy link
Contributor

commented Dec 10, 2018

Having that in mind I think that if we move stream exhaust inside request close function then we introduce extra overhead for http 1.0 so better to discard unread body inside our server.

Imo we have to exhaust inside the request close function, otherwise http/1.1 proxies will see this behavior, the current fix fixes it only in runserver, no?

@kalekseev

This comment has been minimized.

Copy link
Contributor Author

commented Dec 10, 2018

otherwise http/1.1 proxies will see this behavior, the current fix fixes it only in runserver, no?

yes but we introduced keep-alive support only to runserver and django was working with other servers without such problem.

otherwise http/1.1 proxies will see this behavior

based on my research (gunicorn only though) I assume that servers with http/1.1 have to discard previous request data on their own in case of keep-alive connection and proxies like nginx don't uses keep-alive to upstream, check that comment in gunicorn sync worker https://github.com/benoitc/gunicorn/blob/6db35f66a321942690224e8fd11d1fac176e5c89/gunicorn/workers/sync.py#L162.

@apollo13

This comment has been minimized.

Copy link
Contributor

commented Dec 10, 2018

Fair enough, the code still looks somewhat ugly due to all the hasattr magic. Is there any way we could wrap environ[wsgi.input] instead in runserver and have some cleanup/flush logic there?

@kalekseev

This comment has been minimized.

Copy link
Contributor Author

commented Dec 10, 2018

the code still looks somewhat ugly due to all the hasattr magic.

agree, I'll try to refactor it when I have time

charettes referenced this pull request Dec 14, 2018

Fixed keep-alive support in manage.py runserver.
Ticket #25619 changed the default protocol to HTTP/1.1 but did not
properly implement keep-alive. As a "fix" keep-alive was disabled in
ticket #28440 to prevent clients from hanging (they expect the server to
send more data if the connection is not closed and there is no content
length set).

The combination of those two fixes resulted in yet another problem:
HTTP/1.1 by default allows a client to assume that keep-alive is
supported unless the server disables it via 'Connection: close' -- see
RFC2616 8.1.2.1 for details on persistent connection negotiation. Now if
the client receives a response from Django without 'Connection: close'
and immediately sends a new request (on the same tcp connection) before
our server closes the tcp connection, it will error out at some point
because the connection does get closed a few milli seconds later.

This patch fixes the mentioned issues by always sending 'Connection:
close' if we cannot determine a content length. The code is inefficient
in the sense that it does not allow for persistent connections when
chunked responses are used, but that should not really cause any
problems (Django does not generate those) and it only affects the
development server anyways.

Refs #25619, #28440.

@apollo13 apollo13 force-pushed the kalekseev:server-keep-alive branch 3 times, most recently from 227e174 to edc9012 Dec 15, 2018

@apollo13

This comment has been minimized.

Copy link
Contributor

commented Dec 15, 2018

@kalekseev I hope you are okay with me pushing into your branch, I've added my changes as extra commit (we can squash them when merging). What do you think of this approach?

@krabtal Can you please verify that this patch fixes your issue?

@krabtal

This comment has been minimized.

Copy link

commented Dec 15, 2018

works properly now

@apollo13 apollo13 force-pushed the kalekseev:server-keep-alive branch from edc9012 to b08ada3 Dec 17, 2018

@apollo13 apollo13 requested a review from carltongibson Dec 17, 2018

@apollo13

This comment has been minimized.

Copy link
Contributor

commented Dec 17, 2018

@carltongibson This patch seems good to go; could you give it a final review (there is nothing specific to look out for, should be a rather straight forward patch).

@carltongibson

This comment has been minimized.

Copy link
Member

commented Dec 17, 2018

Awesome. Thanks for the work all. I will have a look tomorrow.

@carltongibson
Copy link
Member

left a comment

This is a bit fiddly. I had to think it though to be sure.

ServerHandler is only used in handle_one_request(). As such I'd be inclined to move the use of LimitedStream inside the ServerHandler class (It always wants a LimitedStream.)

  • That way we remove the try...except around the _read_limited() call in close()
  • And it's a little more _coherent_™: the comment block in handle_one_request() can become a docstring, in e.g. ServerHandler.__init__().
  • Hopefully then it's more obvious that we are always advancing the input stream at the end of each request.

The fix is correct though. Good work.

@kalekseev kalekseev force-pushed the kalekseev:server-keep-alive branch from b08ada3 to 550072d Dec 18, 2018

@kalekseev

This comment has been minimized.

Copy link
Contributor Author

commented Dec 18, 2018

I've pushed requested changes, @apollo13 please review

@carltongibson
Copy link
Member

left a comment

Thanks for the quick turnaround @kalekseev. Just the one comment, but this looks good to me. 👍

Show resolved Hide resolved django/core/servers/basehttp.py

@carltongibson carltongibson force-pushed the kalekseev:server-keep-alive branch from 550072d to 49313a2 Dec 19, 2018

@kalekseev

This comment has been minimized.

Copy link
Contributor Author

commented Dec 19, 2018

@carltongibson @apollo13 thanks guys!

@apollo13

This comment has been minimized.

Copy link
Contributor

commented Dec 19, 2018

Regarding the ordering: I prefer to exhaust the stream before calling the parent close to ensure that it is actually exhausted, otherwise we'd need a try/finally to ensure that the next request is not broken. Technically we might wanna add a try/finally either way to ensure that the parent close is called even if exhausting fails… No strong feelings though since it is just the runserver…

@carltongibson

This comment has been minimized.

Copy link
Member

commented Dec 19, 2018

...we might wanna add a try/finally either way...

I'd not expect an error here. Sure maybe one comes up, but I'd like to see that before we add handling for it.

@carltongibson carltongibson merged commit b514dc1 into django:master Dec 19, 2018

19 checks passed

docs Build #17945 ended
Details
flake8 Build #18054 ended
Details
isort Build #18090 succeeded in 23 sec
Details
pr-mariadb/database=mysql,label=mariadb,python=python3.7 Build #2534 ended
Details
pr-mariadb/database=mysql_gis,label=mariadb,python=python3.7 Build #2534 ended
Details
pull-requests-bionic/database=mysql,label=bionic-pr,python=python3.5 Build #3015 ended
Details
pull-requests-bionic/database=mysql,label=bionic-pr,python=python3.7 Build #3015 ended
Details
pull-requests-bionic/database=mysql_gis,label=bionic-pr,python=python3.5 Build #3015 ended
Details
pull-requests-bionic/database=mysql_gis,label=bionic-pr,python=python3.7 Build #3015 ended
Details
pull-requests-bionic/database=postgis,label=bionic-pr,python=python3.5 Build #3015 ended
Details
pull-requests-bionic/database=postgis,label=bionic-pr,python=python3.7 Build #3015 ended
Details
pull-requests-bionic/database=postgres,label=bionic-pr,python=python3.5 Build #3015 ended
Details
pull-requests-bionic/database=postgres,label=bionic-pr,python=python3.7 Build #3015 ended
Details
pull-requests-bionic/database=spatialite,label=bionic-pr,python=python3.5 Build #3015 ended
Details
pull-requests-bionic/database=spatialite,label=bionic-pr,python=python3.7 Build #3015 ended
Details
pull-requests-bionic/database=sqlite3,label=bionic-pr,python=python3.5 Build #3015 ended
Details
pull-requests-bionic/database=sqlite3,label=bionic-pr,python=python3.7 Build #3015 ended
Details
pull-requests-javascript Build #14449 ended
Details
pull-requests-windows/database=sqlite3,label=windows,python=Python35 Build #10054 ended
Details
@timgraham
Copy link
Member

left a comment

My understanding is that this is supposed to be backported to stable/2.1.x per "Version: 2.1" and "release blocker" flags on the ticket. A release note for docs/releases/2.1.5.txt should be added.

@@ -80,6 +81,20 @@ class ThreadedWSGIServer(socketserver.ThreadingMixIn, WSGIServer):
class ServerHandler(simple_server.ServerHandler):
http_version = '1.1'

def __init__(self, stdin, stdout, stderr, environ, **kwargs):
"""
Setup a limited stream, so we can discard unread request data

This comment has been minimized.

Copy link
@timgraham

timgraham Dec 19, 2018

Member

Avoid use of "we" in comments per our style guide.

def test_keep_alive_connection_clears_previous_request_data(self):
conn = HTTPConnection(LiveServerViews.server_thread.host, LiveServerViews.server_thread.port)
try:
conn.request('POST', '/method_view/', b'{}', headers={"Connection": "keep-alive"})

This comment has been minimized.

Copy link
@timgraham

timgraham Dec 19, 2018

Member

I see this is copied from the other test, but single quotes should be preferred per the style guide.

@carltongibson

This comment has been minimized.

Copy link
Member

commented Dec 19, 2018

Ei, yes. That's my oversight. I will pick those up in the morning. Thanks Tim!

@timgraham timgraham changed the title Fixed #30015 -- Keep-alive connection not clearing previous request data. Fixed #30015 -- Ensured request body is properly consumed for keep-alive connections. Dec 21, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.