Repository: tornadoweb/tornado
Pull request #1615 (2015-12-21 04:12:44)

Differentiate HTTPError(599, "Timeout") raised by SimpleAsyncHTTPClient
#### There may be three different Timeout in SimpleAsyncHTTPClient

They all raise "HTTP 599: Timeout", it would be more convenient to debug timeout problem with more detailed information. In this pull request, different timeout type will have different error message. Those messages are:

1. "HTTP 599: Timeout in request queue"
2. "HTTP 599: Timeout while connecting"
3. "HTTP 599: Timeout during request"


Patch:
diff --git a/tornado/simple_httpclient.py b/tornado/simple_httpclient.py
index 37b0bc27..44e45c43 100644
--- a/tornado/simple_httpclient.py
+++ b/tornado/simple_httpclient.py
@@ -126,7 +126,7 @@ class SimpleAsyncHTTPClient(AsyncHTTPClient):
             timeout_handle = self.io_loop.add_timeout(
                 self.io_loop.time() + min(request.connect_timeout,
                                           request.request_timeout),
-                functools.partial(self._on_timeout, key))
+                functools.partial(self._on_timeout, key, "in request queue"))
         else:
             timeout_handle = None
         self.waiting[key] = (request, callback, timeout_handle)
@@ -167,11 +167,20 @@ class SimpleAsyncHTTPClient(AsyncHTTPClient):
                 self.io_loop.remove_timeout(timeout_handle)
             del self.waiting[key]
 
-    def _on_timeout(self, key):
+    def _on_timeout(self, key, info=None):
+        """Timeout callback of request.
+
+        Construct a timeout HTTPResponse when a timeout occurs.
+
+        :arg object key: A simple object to mark the request.
+        :info string key: More detailed timeout information.
+        """
         request, callback, timeout_handle = self.waiting[key]
         self.queue.remove((key, request, callback))
+
+        error_message = "Timeout {0}".format(info) if info else "Timeout"
         timeout_response = HTTPResponse(
-            request, 599, error=HTTPError(599, "Timeout"),
+            request, 599, error=HTTPError(599, error_message),
             request_time=self.io_loop.time() - request.start_time)
         self.io_loop.add_callback(callback, timeout_response)
         del self.waiting[key]
@@ -229,7 +238,7 @@ class _HTTPConnection(httputil.HTTPMessageDelegate):
             if timeout:
                 self._timeout = self.io_loop.add_timeout(
                     self.start_time + timeout,
-                    stack_context.wrap(self._on_timeout))
+                    stack_context.wrap(functools.partial(self._on_timeout, "while connecting")))
             self.tcp_client.connect(host, port, af=af,
                                     ssl_options=ssl_options,
                                     max_buffer_size=self.max_buffer_size,
@@ -284,10 +293,17 @@ class _HTTPConnection(httputil.HTTPMessageDelegate):
             return ssl_options
         return None
 
-    def _on_timeout(self):
+    def _on_timeout(self, info=None):
+        """Timeout callback of _HTTPConnection instance.
+
+        Raise a timeout HTTPError when a timeout occurs.
+
+        :info string key: More detailed timeout information.
+        """
         self._timeout = None
+        error_message = "Timeout {0}".format(info) if info else "Timeout"
         if self.final_callback is not None:
-            raise HTTPError(599, "Timeout")
+            raise HTTPError(599, error_message)
 
     def _remove_timeout(self):
         if self._timeout is not None:
@@ -307,7 +323,7 @@ class _HTTPConnection(httputil.HTTPMessageDelegate):
         if self.request.request_timeout:
             self._timeout = self.io_loop.add_timeout(
                 self.start_time + self.request.request_timeout,
-                stack_context.wrap(self._on_timeout))
+                stack_context.wrap(functools.partial(self._on_timeout, "during request")))
         if (self.request.method not in self._SUPPORTED_METHODS and
                 not self.request.allow_nonstandard_methods):
             raise KeyError("unknown method %s" % self.request.method)


Test patch:
diff --git a/tornado/test/simple_httpclient_test.py b/tornado/test/simple_httpclient_test.py
index da11abbe..0f60aba7 100644
--- a/tornado/test/simple_httpclient_test.py
+++ b/tornado/test/simple_httpclient_test.py
@@ -17,6 +17,7 @@ from tornado.httpclient import AsyncHTTPClient
 from tornado.httputil import HTTPHeaders, ResponseStartLine
 from tornado.ioloop import IOLoop
 from tornado.log import gen_log
+from tornado.concurrent import Future
 from tornado.netutil import Resolver, bind_sockets
 from tornado.simple_httpclient import SimpleAsyncHTTPClient
 from tornado.test.httpclient_test import ChunkHandler, CountdownHandler, HelloWorldHandler, RedirectHandler
@@ -237,6 +238,24 @@ class SimpleHTTPClientTestMixin(object):
             # request is the original request, is a POST still
             self.assertEqual("POST", response.request.method)
 
+    @skipOnTravis
+    def test_connect_timeout(self):
+        timeout = 0.1
+        timeout_min, timeout_max = 0.099, 1.0
+
+        class TimeoutResolver(Resolver):
+            def resolve(self, *args, **kwargs):
+                return Future()  # never completes
+
+        with closing(self.create_client(resolver=TimeoutResolver())) as client:
+            client.fetch(self.get_url('/hello'), self.stop,
+                         connect_timeout=timeout)
+            response = self.wait()
+            self.assertEqual(response.code, 599)
+            self.assertTrue(timeout_min < response.request_time < timeout_max,
+                            response.request_time)
+            self.assertEqual(str(response.error), "HTTP 599: Timeout while connecting")
+
     @skipOnTravis
     def test_request_timeout(self):
         timeout = 0.1
@@ -249,7 +268,7 @@ class SimpleHTTPClientTestMixin(object):
         self.assertEqual(response.code, 599)
         self.assertTrue(timeout_min < response.request_time < timeout_max,
                         response.request_time)
-        self.assertEqual(str(response.error), "HTTP 599: Timeout")
+        self.assertEqual(str(response.error), "HTTP 599: Timeout during request")
         # trigger the hanging request to let it clean up after itself
         self.triggers.popleft()()
 
@@ -357,7 +376,7 @@ class SimpleHTTPClientTestMixin(object):
 
             self.assertEqual(response.code, 599)
             self.assertTrue(response.request_time < 1, response.request_time)
-            self.assertEqual(str(response.error), "HTTP 599: Timeout")
+            self.assertEqual(str(response.error), "HTTP 599: Timeout in request queue")
             self.triggers.popleft()()
             self.wait()