Log more uncaught exceptions instead of suppressing them.

Add more docs about Future exception logging.

diff --git a/tornado/concurrent.py b/tornado/concurrent.py
index c49e01f7022f7deb0cba1b799ed11f509f9d949a..acfbcd83e820dfd1ff1e6eb9be8af961d5ae0084 100644 (file)
--- a/tornado/concurrent.py
+++ b/tornado/concurrent.py
@@ -149,6 +149,14 @@ class Future(object):
        if that package was available and fall back to the thread-unsafe
        implementation if it was not.
 
+    .. versionchanged:: 4.1
+       If a `.Future` contains an error but that error is never observed
+       (by calling ``result()``, ``exception()``, or ``exc_info()``),
+       a stack trace will be logged when the `.Future` is garbage collected.
+       This normally indicates an error in the application, but in cases
+       where it results in undesired logging it may be necessary to
+       suppress the logging by ensuring that the exception is observed:
+       ``f.add_done_callback(lambda f: f.exception())``.
     """
     def __init__(self):
         self._done = False
@@ -412,11 +420,7 @@ def return_future(f):
             # If the initial synchronous part of f() raised an exception,
             # go ahead and raise it to the caller directly without waiting
             # for them to inspect the Future.
-            #
-            # "Consume" the exception from the future so it will not be logged
-            # as uncaught.
-            future.exception()
-            raise_exc_info(exc_info)
+            future.result()
 
         # If the caller passed in a callback, schedule it to be called
         # when the future resolves.  It is important that this happens

diff --git a/tornado/gen.py b/tornado/gen.py
index b9b63419582294460f0df753922efa18b41c26bf..e332d7a933a56e32f1b00ccdaae8dd2348256372 100644 (file)
--- a/tornado/gen.py
+++ b/tornado/gen.py
@@ -56,6 +56,7 @@ import types
 
 from tornado.concurrent import Future, TracebackFuture, is_future, chain_future
 from tornado.ioloop import IOLoop
+from tornado.log import app_log
 from tornado import stack_context
 
 
@@ -504,7 +505,7 @@ def maybe_future(x):
         return fut
 
 
-def with_timeout(timeout, future, io_loop=None):
+def with_timeout(timeout, future, io_loop=None, quiet_exceptions=()):
     """Wraps a `.Future` in a timeout.
 
     Raises `TimeoutError` if the input future does not complete before
@@ -512,9 +513,17 @@ def with_timeout(timeout, future, io_loop=None):
     `.IOLoop.add_timeout` (i.e. a `datetime.timedelta` or an absolute time
     relative to `.IOLoop.time`)
 
+    If the wrapped `.Future` fails after it has timed out, the exception
+    will be logged unless it is of a type contained in ``quiet_exceptions``
+    (which may be an exception type or a sequence of types).
+
     Currently only supports Futures, not other `YieldPoint` classes.
 
     .. versionadded:: 4.0
+
+    .. versionchanged:: 4.1
+       Added the ``quiet_exceptions`` argument and the logging of unhandled
+       exceptions.
     """
     # TODO: allow yield points in addition to futures?
     # Tricky to do with stack_context semantics.
@@ -528,9 +537,17 @@ def with_timeout(timeout, future, io_loop=None):
     chain_future(future, result)
     if io_loop is None:
         io_loop = IOLoop.current()
+    def error_callback(future):
+        try:
+            future.result()
+        except Exception as e:
+            if not isinstance(e, quiet_exceptions):
+                app_log.error("Exception in Future %r after timeout",
+                              future, exc_info=True)
     def timeout_callback():
         result.set_exception(TimeoutError("Timeout"))
-        future.add_done_callback(lambda f: f.exception())
+        # In case the wrapped future goes on to fail, log it.
+        future.add_done_callback(error_callback)
     timeout_handle = io_loop.add_timeout(
         timeout, timeout_callback)
     if isinstance(future, Future):

diff --git a/tornado/http1connection.py b/tornado/http1connection.py
index 8f105d034541ce2fc356e1bf00fba74b46d3e947..2d5fccd947c6f0da618e5333a5f0db225d2b2939 100644 (file)
--- a/tornado/http1connection.py
+++ b/tornado/http1connection.py
@@ -162,7 +162,8 @@ class HTTP1Connection(httputil.HTTPConnection):
                     header_data = yield gen.with_timeout(
                         self.stream.io_loop.time() + self.params.header_timeout,
                         header_future,
-                        io_loop=self.stream.io_loop)
+                        io_loop=self.stream.io_loop,
+                        quiet_exceptions=iostream.StreamClosedError)
                 except gen.TimeoutError:
                     self.close()
                     raise gen.Return(False)
@@ -221,7 +222,8 @@ class HTTP1Connection(httputil.HTTPConnection):
                         try:
                             yield gen.with_timeout(
                                 self.stream.io_loop.time() + self._body_timeout,
-                                body_future, self.stream.io_loop)
+                                body_future, self.stream.io_loop,
+                                quiet_exceptions=iostream.StreamClosedError)
                         except gen.TimeoutError:
                             gen_log.info("Timeout reading body from %s",
                                          self.context)
@@ -453,7 +455,9 @@ class HTTP1Connection(httputil.HTTPConnection):
             self._pending_write.add_done_callback(self._finish_request)
 
     def _on_write_complete(self, future):
-        future.exception()
+        exc = future.exception()
+        if exc is not None and not isinstance(exc, iostream.StreamClosedError):
+            future.result()
         if self._write_callback is not None:
             callback = self._write_callback
             self._write_callback = None

diff --git a/tornado/iostream.py b/tornado/iostream.py
index e13d4bacbd4b908ec7396c1945e050c8d09fd2a9..3cd905067423436079d5fb83b3c7733a0ff30766 100644 (file)
--- a/tornado/iostream.py
+++ b/tornado/iostream.py
@@ -232,6 +232,8 @@ class BaseIOStream(object):
             return future
         except:
             if future is not None:
+                # Ensure that the future doesn't log an error because its
+                # failure was never examined.
                 future.add_done_callback(lambda f: f.exception())
             raise
         return future

diff --git a/tornado/web.py b/tornado/web.py
index 36032bd146fdc9cef787bb084edfaced3c2fa62f..fb4d439adff41aaef83564bd10607bf733ba33f8 100755 (executable)
--- a/tornado/web.py
+++ b/tornado/web.py
@@ -1915,9 +1915,10 @@ class _RequestDispatcher(httputil.HTTPMessageDelegate):
         # trapped in the Future it returns (which we are ignoring here).
         # However, that shouldn't happen because _execute has a blanket
         # except handler, and we cannot easily access the IOLoop here to
-        # call add_future.
+        # call add_future (because of the requirement to remain compatible
+        # with WSGI)
         f = self.handler._execute(transforms, *self.path_args, **self.path_kwargs)
-        f.add_done_callback(lambda f: f.exception()) # XXX
+        f.add_done_callback(lambda f: f.exception())
         # If we are streaming the request body, then execute() is finished
         # when the handler has prepared to receive the body.  If not,
         # it doesn't matter when execute() finishes (so we return None)