From 2a0446724b6be1ef8d507d1bf3067abae8168c72 Mon Sep 17 00:00:00 2001 From: Paul Oppenheim Date: Thu, 28 Mar 2013 00:23:20 -0700 Subject: [PATCH] wsgi: handle connection socket timeouts Fixes https://bitbucket.org/eventlet/eventlet/issue/143 --- eventlet/wsgi.py | 10 +- tests/wsgi_test.py | 26 +++++- tests/wsgi_test_conntimeout.py | 163 +++++++++++++++++++++++++++++++++ 3 files changed, 196 insertions(+), 3 deletions(-) create mode 100644 tests/wsgi_test_conntimeout.py diff --git a/eventlet/wsgi.py b/eventlet/wsgi.py index 4a6cc3c..5c5b67a 100644 --- a/eventlet/wsgi.py +++ b/eventlet/wsgi.py @@ -574,14 +574,20 @@ class Server(BaseHTTPServer.HTTPServer): d.update(self.environ) return d - def process_request(self, (socket, address)): + def process_request(self, (sock, address)): # The actual request handling takes place in __init__, so we need to # set minimum_chunk_size before __init__ executes and we don't want to modify # class variable proto = types.InstanceType(self.protocol) if self.minimum_chunk_size is not None: proto.minimum_chunk_size = self.minimum_chunk_size - proto.__init__(socket, address, self) + try: + proto.__init__(sock, address, self) + except socket.timeout: + # Expected exceptions are not exceptional + if self.debug: + # similar to logging "accepted" in server() + self.log_message('(%s) timed out %r' % (self.pid, address)) def log_message(self, message): self.log.write(message + '\n') diff --git a/tests/wsgi_test.py b/tests/wsgi_test.py index ffab3a4..a30baa3 100644 --- a/tests/wsgi_test.py +++ b/tests/wsgi_test.py @@ -14,7 +14,7 @@ from eventlet.green import socket as greensocket from eventlet import wsgi from eventlet.support import get_errno -from tests import find_command +from tests import find_command, run_python httplib = eventlet.import_patched('httplib') @@ -1172,6 +1172,27 @@ class TestHttpd(_TestBase): request_thread.wait() server_sock.close() + def test_server_connection_timeout_exception(self): + # Handle connection socket timeouts + # https://bitbucket.org/eventlet/eventlet/issue/143/ + # Runs tests.wsgi_test_conntimeout in a separate process. + testcode_path = os.path.join( + os.path.dirname(os.path.abspath(__file__)), + 'wsgi_test_conntimeout.py') + output = run_python(testcode_path) + sections = output.split("SEPERATOR_SENTINEL") + # first section is empty + self.assertEqual(3, len(sections), output) + # if the "BOOM" check fails, it's because our timeout didn't happen + # (if eventlet stops using file.readline() to read HTTP headers, + # for instance) + for runlog in sections[1:]: + debug = False if "debug set to: False" in runlog else True + if debug: + self.assertTrue("timed out" in runlog) + self.assertTrue("BOOM" in runlog) + self.assertFalse("Traceback" in runlog) + def read_headers(sock): fd = sock.makefile() @@ -1201,6 +1222,7 @@ def read_headers(sock): headers[key.lower()] = value return response_line, headers + class IterableAlreadyHandledTest(_TestBase): def set_site(self): self.site = IterableSite() @@ -1227,6 +1249,7 @@ class IterableAlreadyHandledTest(_TestBase): self.assertEqual(headers.get('transfer-encoding'), 'chunked') self.assertEqual(body, '0\r\n\r\n') # Still coming back chunked + class ProxiedIterableAlreadyHandledTest(IterableAlreadyHandledTest): # same thing as the previous test but ensuring that it works with tpooled # results as well as regular ones @@ -1240,6 +1263,7 @@ class ProxiedIterableAlreadyHandledTest(IterableAlreadyHandledTest): tpool.killall() super(ProxiedIterableAlreadyHandledTest, self).tearDown() + class TestChunkedInput(_TestBase): dirt = "" validator = None diff --git a/tests/wsgi_test_conntimeout.py b/tests/wsgi_test_conntimeout.py new file mode 100644 index 0000000..bf3fb30 --- /dev/null +++ b/tests/wsgi_test_conntimeout.py @@ -0,0 +1,163 @@ +"""Issue #143 - Socket timeouts in wsgi server not caught. +https://bitbucket.org/eventlet/eventlet/issue/143/ + +This file intentionally ignored by nose. +Caller process (tests.wsgi_test.TestWsgiConnTimeout) handles success / failure + + +Simulate server connection socket timeout without actually waiting. +Logs 'timed out' if server debug=True (similar to 'accepted' logging) + +FAIL: if log (ie, _spawn_n_impl 'except:' catches timeout, logs TB) +NOTE: timeouts are NOT on server_sock, but on the conn sockets produced +by the socket.accept() call + +server's socket.listen() sock - NaughtySocketAcceptWrap + / | \ + | | | (1 - many) + V V V +server / client accept() conn - ExplodingConnectionWrap + / | \ + | | | (1 - many) + V V V +connection makefile() file objects - ExplodingSocketFile <-- these raise +""" +# This code relies on a subclass of unittest.TestCase, but is NOT a test. +# Should NOT be run by nose to avoid potential monkeypatch contamination. +# - Not just @skipped; nose must not consider this a test at all: +__test__ = False + +import eventlet + +import socket +import sys +from cStringIO import StringIO + +import tests.wsgi_test + + +# This test might make you wince +class NaughtySocketAcceptWrap(object): + # server's socket.accept(); patches resulting connection sockets + + def __init__(self, sock): + self.sock = sock + self.sock._really_accept = self.sock.accept + self.sock.accept = self + self.conn_reg = [] + + def unwrap(self): + self.sock.accept = self.sock._really_accept + del self.sock._really_accept + for conn_wrap in self.conn_reg: + conn_wrap.unwrap() + + def arm(self): + print "ca-click" + for i in self.conn_reg: + i.arm() + + def __call__(self): + print self.__class__.__name__ + ".__call__" + conn, addr = self.sock._really_accept() + self.conn_reg.append(ExplodingConnectionWrap(conn)) + return conn, addr + + +class ExplodingConnectionWrap(object): + # new connection's socket.makefile + # eventlet *tends* to use socket.makefile, not raw socket methods. + # need to patch file operations + + def __init__(self, conn): + self.conn = conn + self.conn._really_makefile = self.conn.makefile + self.conn.makefile = self + self.armed = False + self.file_reg = [] + + def unwrap(self): + self.conn.makefile = self.conn._really_makefile + del self.conn._really_makefile + + def arm(self): + print "tick" + for i in self.file_reg: + i.arm() + + def __call__(self, mode='r', bufsize=-1): + print self.__class__.__name__ + ".__call__" + # file_obj = self.conn._really_makefile(*args, **kwargs) + file_obj = ExplodingSocketFile(self.conn._sock, mode, bufsize) + self.file_reg.append(file_obj) + return file_obj + + +class ExplodingSocketFile(socket._fileobject): + + def __init__(self, sock, mode='rb', bufsize=-1, close=False): + super(self.__class__, self).__init__(sock, mode, bufsize, close) + self.armed = False + + def arm(self): + print "beep" + self.armed = True + + def _fuse(self): + if self.armed: + print "=== ~* BOOM *~ ===" + raise socket.timeout("timed out") + + def readline(self, *args, **kwargs): + print self.__class__.__name__ + ".readline" + self._fuse() + return super(self.__class__, self).readline(*args, **kwargs) + + +for debug in (False, True): + print "SEPERATOR_SENTINEL" + print "debug set to: %s" % debug + + server_sock = eventlet.listen(('localhost', 0)) + server_addr = server_sock.getsockname() + sock_wrap = NaughtySocketAcceptWrap(server_sock) + + eventlet.spawn_n( + eventlet.wsgi.server, + debug=debug, + log=sys.stdout, + max_size=128, + site=tests.wsgi_test.Site(), + sock=server_sock, + ) + + try: + # req #1 - normal + sock1 = eventlet.connect(server_addr) + sock1.settimeout(0.1) + fd1 = sock1.makefile('rw') + fd1.write('GET / HTTP/1.1\r\nHost: localhost\r\n\r\n') + fd1.flush() + tests.wsgi_test.read_http(sock1) + + # let the server socket ops catch up, set bomb + eventlet.sleep(0) + print "arming..." + sock_wrap.arm() + + # req #2 - old conn, post-arm - timeout + fd1.write('GET / HTTP/1.1\r\nHost: localhost\r\n\r\n') + fd1.flush() + try: + tests.wsgi_test.read_http(sock1) + assert False, 'Expected ConnectionClosed exception' + except tests.wsgi_test.ConnectionClosed: + pass + + fd1.close() + sock1.close() + finally: + # reset streams, then output trapped tracebacks + sock_wrap.unwrap() + # check output asserts in tests.wsgi_test.TestHttpd + # test_143_server_connection_timeout_exception