| msg250606 - (view) |
Author: Terry J. Reedy (terry.reedy) *  |
Date: 2015-09-14 03:56 |
| test_httpservers ok on 3.4.3, hangs indefinitely (over an hour) on 3.5.0, win 7. |
|
|
| msg250721 - (view) |
Author: Martin Panter (martin.panter) * |
Date: 2015-09-15 04:12 |
| Can you identify which test case hangs? E.g. on Linux I can run the following to see each test case run: ./python -m unittest -v test.test_httpservers |
|
|
| msg250725 - (view) |
Author: Terry J. Reedy (terry.reedy) * |
Date: 2015-09-15 06:37 |
| test_get (test.test_httpservers.RequestHandlerLoggingTestCase) ... same on repeat |
|
|
| msg250739 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2015-09-15 08:38 |
| Where does it hang? For example, try to run the test using: python.exe -m test -v --timeout=10 test_httpservers Can it be a firewall or antivirus issue? Try to add some print() in TestServerThread.run() to check if the HTTP server is running or not. |
|
|
| msg250751 - (view) |
Author: Terry J. Reedy (terry.reedy) * |
Date: 2015-09-15 09:58 |
| test_get (test.test_httpservers.RequestHandlerLoggingTestCase) ... Timeout (0:00:10)! Thread 0x00001654 (most recent call first): File "C:\Programs\Python35\lib\socket.py", line 571 in readinto File "C:\Programs\Python35\lib\http\server.py", line 383 in handle_one_request File "C:\Programs\Python35\lib\http\server.py", line 417 in handle File "C:\Programs\Python35\lib\socketserver.py", line 684 in __init__ File "C:\Programs\Python35\lib\socketserver.py", line 357 in finish_request File "C:\Programs\Python35\lib\socketserver.py", line 344 in process_request File "C:\Programs\Python35\lib\socketserver.py", line 318 in _handle_request_noblock File "C:\Programs\Python35\lib\socketserver.py", line 239 in serve_forever File "C:\Programs\Python35\lib\test\test_httpservers.py", line 47 in run File "C:\Programs\Python35\lib\threading.py", line 923 in _bootstrap_inner File "C:\Programs\Python35\lib\threading.py", line 891 in _bootstrap Thread 0x000017f8 (most recent call first): File "C:\Programs\Python35\lib\socket.py", line 571 in readinto File "C:\Programs\Python35\lib\http\client.py", line 243 in _read_status File "C:\Programs\Python35\lib\http\client.py", line 282 in begin File "C:\Programs\Python35\lib\http\client.py", line 1174 in getresponse File "C:\Programs\Python35\lib\test\test_httpservers.py", line 257 in test_get File "C:\Programs\Python35\lib\unittest\case.py", line 597 in run File "C:\Programs\Python35\lib\unittest\case.py", line 645 in __call__ File "C:\Programs\Python35\lib\unittest\suite.py", line 122 in run File "C:\Programs\Python35\lib\unittest\suite.py", line 84 in __call__ File "C:\Programs\Python35\lib\unittest\suite.py", line 122 in run File "C:\Programs\Python35\lib\unittest\suite.py", line 84 in __call__ File "C:\Programs\Python35\lib\unittest\runner.py", line 176 in run File "C:\Programs\Python35\lib\test\support\__init__.py", line 1775 in _run_suite File "C:\Programs\Python35\lib\test\support\__init__.py", line 1809 in run_unittest File "C:\Programs\Python35\lib\test\test_httpservers.py", line 890 in test_main File "C:\Programs\Python35\lib\test\regrtest.py", line 1281 in runtest_inner File "C:\Programs\Python35\lib\test\regrtest.py", line 979 in runtest File "C:\Programs\Python35\lib\test\regrtest.py", line 763 in main File "C:\Programs\Python35\lib\test\regrtest.py", line 1565 in main_in_temp_cwd File "C:\Programs\Python35\lib\test\__main__.py", line 3 in File "C:\Programs\Python35\lib\runpy.py", line 85 in _run_code File "C:\Programs\Python35\lib\runpy.py", line 170 in _run_module_as_main |
|
|
| msg250845 - (view) |
Author: Martin Panter (martin.panter) * |
Date: 2015-09-16 12:38 |
| According to those back traces, the server has apparently already handled one request and is waiting for a second request. However the client is still waiting for a response from its original request. Some things I might try would be to disable the server, and make my own dummy server to see if it responds to that. Similarly, disable the client and manually make a request to the server and see what the response is. On Linux the “socat” or “netcat” programs are useful for this stuff, or you can just use the Python interactive interpreter to create a socket and send and receive. Client connection is made at <https://hg.python.org/cpython/file/v3.5.0/Lib/test/test_httpservers.py#l252>. Server is constructed at <https://hg.python.org/cpython/file/v3.5.0/Lib/test/test_httpservers.py#l42>. You could also try adding self.con.set_debuglevel(99) to the test_get() method, though I suspect it will just output the request sent, and not report any reply or headers. In my case the test works, and I see: send: b'GET / HTTP/1.1\r\nHost: 127.0.0.1:48059\r\nAccept-Encoding: identity\r\n\r\n' reply: 'HTTP/1.1 200 OK\r\n' [Unit test output] header: Server header: Date $ |
|
|
| msg250846 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2015-09-16 12:47 |
| You may try "hg bisect" to find which revision broke test_httpservers. It can be slow if you have to recompile manually Python :-( |
|
|
| msg309467 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-04 14:27 |
| Adding onto this issue, I believe I tracked down the change that caused the issue: https://github.com/python/cpython/commit/c0a23e63207984304027f298eefc738b6b3c94b1 This issue also affects the test with Python 3.6 |
|
|
| msg309470 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-04 14:56 |
| I believe I found the issue, might be an issue between sending the request + calling get_response() and the time it takes for server to process response, my print cases: test_err (test.test_httpservers.RequestHandlerLoggingTestCase) ... Creating a new connection to 127.0.0.1:50141 Connecting to server Sending ERROR request, captured stderr instance is <_io.StringIO object at 0x05E5EC00> HANDLING AN ERROR REQUEST! SENDING RESPONSE! Request sent, starting to read response <http.client.HTTPResponse object at 0x05E6D7E0> RESPONSE SENT! Response obtained, err should be set, <_io.StringIO object at 0x05E5EC00> Running test's assert ok test_get (test.test_httpservers.RequestHandlerLoggingTestCase) ... Creating a new connection to 127.0.0.1:50143 Connecting to server Sending GET request, captured stderr instance is <_io.StringIO object at 0x05E5EC00> Request sent, starting to read response HANDLING A GET REQUEST! SENDING RESPONSE! RESPONSE SENT! ENDING HEADERS! HEADERS ENDED! |
|
|
| msg309473 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-04 17:28 |
| Scratch the previous message about the possible cause, I found the true cause, getresponse() is waiting for a specific header, one that BaseHTTPRequestHandler.send_error sends and BaseHTTPRequestHandler.send_response() doesn't, that header is "Connection" with message "close" (http.server#450), adding that to RequestHandlerLoggingTestCase.request_handler.do_GET before self.end_headers() fixes the deadlock. |
|
|
| msg309480 - (view) |
Author: Berker Peksag (berker.peksag) * |
Date: 2018-01-04 20:14 |
| Thank you for tracking down the problem, William! I just took a quick look at your patch and it seems reasonable to me. Setting protocol_version to 'HTTP/1.1' means setting the close_connection attribute of BaseHTTPRequestHandler to False which is expected and a feature of HTTP/1.1 (persistent connections) Quoting RFC 2616: HTTP/1.1 defines the "close" connection option for the sender to signal that the connection will be closed after completion of the response. HTTP/1.1 applications that do not support persistent connections MUST include the "close" connection option in every message. So I think it's OK to send a "Connection: close" header in the test (it would be nice to add a comment though) |
|
|
| msg309498 - (view) |
Author: Martin Panter (martin.panter) * |
Date: 2018-01-05 10:32 |
| In the server, the send_header("Connection", "close") call sets the “close_connection” flag. This shuts down the connection once “do_GET” returns. Without the flag set, the server will wait and read another request. If you want the server to shut the connection down, I suggest to be explicit in setting “close_connection”. It should work even if no “Connection: close” appears in the HTTP protocol. The special behaviour of “send_header” I think you are relying on is not documented. On my Linux computer with the original code, I think the client shuts the connection down. This causes the server to see an empty “raw_requestline” and return from “handle_one_request”. It returns to “serve_forever” where it polls the “__shutdown_request” flag and sees that it should stop. The client shuts down the connection only because of subtleties in how the HTTP client manages the socket and how sockets are garbage collected. The response does not have Content-Length nor Transfer-Encoding fields, and would be terminated by the server shutting the connection down. So the HTTPConnection object cannot reuse the TCP connection and hands ownership to the HTTPResponse object returned by “getresponse”. Since this object is not saved anywhere, it gets garbage collected, which closes the socket and shuts the connection down. But perhaps on Windows the shutdown doesn’t happen, or perhaps the garbage collector is too slow. If I am right, closing the HTTPResponse object would also fix the deadlock. It is good practice to close the underlying socket anyway: with support.captured_stderr() as err: self.con.request('GET', '/') res = self.con.getresponse() # Shut down connection to stop the server reading from it res.close() self.con.close() |
|
|
| msg309499 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-05 11:49 |
| Martin, your suggestion will never work as if you look at the trace back posted terry.reedy and my test print statements, both the client and server get stuck waiting to read data their respective socket, hence the deadlock. Adding the header "Connection" with value of "close" is logic taken from the method "send_error()" which is what test_err executes (same test class), that header along with send_error() adding the Content-Type and Content-Length headers, those headers are what is different between do_ERROR and do_GET, I've already tried locally having do_GET set both Content-Type and Content-Length headers without the Connection header, no difference (deadlock continued). |
|
|
| msg309515 - (view) |
Author: Terry J. Reedy (terry.reedy) * |
Date: 2018-01-05 19:10 |
| Today, at least, python -m test -v test_httpservers does not hang for me on any of 3.5, 3.6, or 3.7, installed or repository debug. I don't know if the offending test was just disabled or somehow fixed. |
|
|
| msg309516 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-05 19:12 |
| It hangs for me on Windows 10 Professional running on a MSI gaming laptop for debug and PGO builds (Python 3.6) |
|
|
| msg309522 - (view) |
Author: Martin Panter (martin.panter) * |
Date: 2018-01-05 20:49 |
| Sorry William, I forgot the client was waiting to read. But I don’t understand why your Connection field (which comes after the status line) allows the Python client to read the status line. Perhaps there is some malware scanner, firewall, or other proxy that intercepts the HTTP protocol? (I encountered something similar at work recently.) You said “my suggestion will never work”, but did you try setting “close_connection” on its own: def do_GET(self): self.send_response(HTTPStatus.OK) self.end_headers() self.close_connection = True # Terminate response body to proxy You tried adding Content-Length, but did you try “Content-Length: 0”: def do_GET(self): self.send_response(HTTPStatus.OK) self.send_header("Content-Length", "0") # Stop proxy reading body self.end_headers() |
|
|
| msg309528 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-05 21:03 |
| I have tried value 0 for "Content-Length" (along with "text/plain" for "Content-Type"), it was when I said I tried both "Content-Length" and "Content-Type", while I haven't tried directly setting "close_connection" in the handler, my solution is based on how "send_error()" works internally, not only that, but send_header is public API (by convention) and the "Connection" header is part of HTTP 1.1 so it should be documented ( reference: https://www.w3.org/Protocols/rfc2616/rfc2616-sec8.html ), so I don't really understand why my initial solution is consider "undocumented logic" |
|
|
| msg309530 - (view) |
Author: Martin Panter (martin.panter) * |
Date: 2018-01-05 23:06 |
| Thanks, although the fact that “Content-Length: 0” doesn’t work kills my theory about the proxy. The “close_connection” flag is also a documented public API of Python: <https://docs.python.org/3/library/http.server.html#http.server.BaseHTTPRequestHandler.close_connection>. According to the rules for framing the message body in <https://tools.ietf.org/html/rfc7230#section-3.3.3>, the presence of “Connection: close” is not important. The server actually shutting down the connection is the key. That is why I prefer to explicitly set the flag (if it works). Anyway, your current proposal makes the server send a valid full HTTP response. |
|
|
| msg310867 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-27 16:10 |
| Ok, I found another way to apply the solution to this issue, that is by adding the "Connection" header (with value of "close") to the client's request instead of the server's response. I'm going to use this other method as the client is expected to expect the server to shutdown the connection (as it asked the server to). |
|
|
| msg310885 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-01-27 19:53 |
| Alright, the PR is ready for review. |
|
|
| msg322839 - (view) |
Author: Martin Panter (martin.panter) * |
Date: 2018-08-01 04:32 |
| I reproduced the problem on a Windows computer, and now understand why my "Content-Length: 0" suggestion isn't good enough on its own. It does solve the initial deadlock, but there is a further deadlock. The main thread is waiting for the server to shut down while it is holding the HTTP connection open, and the server is still trying to read a second request on that connection. Setting "self.close_connection = True" in the server (or using "Connection: close") solves both deadlocks. But it seems cleaner for the client to close the connection and response objects anyway, before shutting down the server. I would modify the "test_get" method: with support.captured_stderr() as err: self.con.request('GET', '/') res = self.con.getresponse() res.close() # Not needed but cleans up socket if no Content-Length self.con.close() # Needed to shut down connection with Content-Length I think my Windows computer has a firewall that holds TCP data if it looks like an unfinished HTTP request or response. I suspect Terry and William had a similar firewall. Here is a demonstration of the socket behaviour it causes: >>> from socket import * >>> listener = socket() >>> listener.bind(("127.1", 0)) >>> listener.listen() >>> outgoing = create_connection(listener.getsockname()) >>> [incoming, address] = listener.accept() >>> outgoing.sendall(b"GET / HTTP/1.1\r\n") # Unfinished HTTP request >>> incoming.settimeout(3) >>> incoming.recv(300) # Partial request should normally be received Traceback (most recent call last): File "", line 1, in socket.timeout: timed out >>> outgoing.sendall(b"\r\n") # Complete the request >>> incoming.recv(300) # Only now is the request received b'GET / HTTP/1.1\r\n\r\n' >>> incoming.sendall(b"HTTP/1.1 200 OK\r\n") # Unfinished response >>> outgoing.settimeout(3) >>> outgoing.recv(300) # Should normally be received Traceback (most recent call last): File "", line 1, in socket.timeout: timed out >>> incoming.sendall(b"Content-Length: 0\r\n\r\n") # Complete the response >>> outgoing.recv(300) # Only now received b'HTTP/1.1 200 OK\r\nContent-Length: 0\r\n\r\n' |
|
|
| msg322856 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2018-08-01 11:40 |
| My computer was running BitDefender Total Security 2018 (At the time, currently running the 2019 edition) and MalwareBytes 3 Premium. BitDefender has both a built-in firewall and a web protection module while MalwareBytes has a web protection module. |
|
|
| msg326626 - (view) |
Author: Martin Panter (martin.panter) * |
Date: 2018-09-28 10:34 |
| Hi William, when I mentioned “Content-Length”, I meant adding it to the response from the server. See the second version of “do_GET” in my earlier comment <https://bugs.python.org/issue25095#msg309522>. But that is no good without also adding the “self.con.close()” line to the client I mentioned in two of my other comments. In your latest rev. e6b09d4 (and earlier rev. 2022b6f) you send “Content-Length: 0” in a GET _request_, which doesn’t make much sense. GET requests never have bodies of any length. It is the “200 OK” _response_ that should have a body according to HTTP. The server has to shut down the connection or add “Content-Length: 0” (or use chunked encoding) to indicate the end of the body to the proxy. So I would prefer to either adjust the “do_GET” server function as well as adding “self.con.close()” to the client, or just go back to rev. c1afa6b (“Connection: close”). |
|
|
| msg369666 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2020-05-22 23:04 |
| I'll get to it Saturday. |
|
|
| msg369751 - (view) |
Author: William Pickard (WildCard65) * |
Date: 2020-05-23 22:05 |
| I've made the changes you've requested. |
|
|