When a function on the IOLoop returns a Future, log its exception.

diff --git a/tornado/ioloop.py b/tornado/ioloop.py
index 1a51fb0c45a0ca3ca5e8a2220dd8dcf241c6f9b2..ca309232d17ab872ec19cc5c7dd6cadbb3dfdedc 100644 (file)
--- a/tornado/ioloop.py
+++ b/tornado/ioloop.py
@@ -504,7 +504,13 @@ class IOLoop(Configurable):
         For use in subclasses.
         """
         try:
-            callback()
+            ret = callback()
+            if ret is not None and is_future(ret):
+                # Functions that return Futures typically swallow all
+                # exceptions and store them in the Future.  If a Future
+                # makes it out to the IOLoop, ensure its exception (if any)
+                # gets logged too.
+                self.add_future(ret, lambda f: f.result())
         except Exception:
             self.handle_callback_exception(callback)
 

diff --git a/tornado/platform/asyncio.py b/tornado/platform/asyncio.py
index 552476bc0800a8e0eed7f88caa782b980a8fec07..6518dea55900d7cec82407861376df5b004908be 100644 (file)
--- a/tornado/platform/asyncio.py
+++ b/tornado/platform/asyncio.py
@@ -109,12 +109,6 @@ class BaseAsyncIOLoop(IOLoop):
     def stop(self):
         self.asyncio_loop.stop()
 
-    def _run_callback(self, callback, *args, **kwargs):
-        try:
-            callback(*args, **kwargs)
-        except Exception:
-            self.handle_callback_exception(callback)
-
     def add_timeout(self, deadline, callback):
         if isinstance(deadline, (int, float)):
             delay = max(deadline - self.time(), 0)
@@ -131,13 +125,9 @@ class BaseAsyncIOLoop(IOLoop):
     def add_callback(self, callback, *args, **kwargs):
         if self.closing:
             raise RuntimeError("IOLoop is closing")
-        if kwargs:
-            self.asyncio_loop.call_soon_threadsafe(functools.partial(
-                self._run_callback, stack_context.wrap(callback),
-                *args, **kwargs))
-        else:
-            self.asyncio_loop.call_soon_threadsafe(
-                self._run_callback, stack_context.wrap(callback), *args)
+        self.asyncio_loop.call_soon_threadsafe(
+            self._run_callback,
+            functools.partial(stack_context.wrap(callback), *args, **kwargs))
 
     add_callback_from_signal = add_callback
 

diff --git a/tornado/platform/twisted.py b/tornado/platform/twisted.py
index 889aa3c450dfe389a3928ea28fdc64aa89c4df30..18263dd943e8d86601c5a9045db707e782065054 100644 (file)
--- a/tornado/platform/twisted.py
+++ b/tornado/platform/twisted.py
@@ -475,12 +475,6 @@ class TwistedIOLoop(tornado.ioloop.IOLoop):
     def stop(self):
         self.reactor.crash()
 
-    def _run_callback(self, callback, *args, **kwargs):
-        try:
-            callback(*args, **kwargs)
-        except Exception:
-            self.handle_callback_exception(callback)
-
     def add_timeout(self, deadline, callback):
         if isinstance(deadline, (int, long, float)):
             delay = max(deadline - self.time(), 0)
@@ -495,8 +489,9 @@ class TwistedIOLoop(tornado.ioloop.IOLoop):
             timeout.cancel()
 
     def add_callback(self, callback, *args, **kwargs):
-        self.reactor.callFromThread(self._run_callback,
-                                    wrap(callback), *args, **kwargs)
+        self.reactor.callFromThread(
+            self._run_callback,
+            functools.partial(wrap(callback), *args, **kwargs))
 
     def add_callback_from_signal(self, callback, *args, **kwargs):
         self.add_callback(callback, *args, **kwargs)

diff --git a/tornado/test/ioloop_test.py b/tornado/test/ioloop_test.py
index e187cc1813fe30e93452e3f7c6051afabb22ee5a..03b4fddfb32633e4d494bbce4925a100c40e688d 100644 (file)
--- a/tornado/test/ioloop_test.py
+++ b/tornado/test/ioloop_test.py
@@ -12,8 +12,9 @@ import time
 
 from tornado import gen
 from tornado.ioloop import IOLoop, TimeoutError
+from tornado.log import app_log
 from tornado.stack_context import ExceptionStackContext, StackContext, wrap, NullContext
-from tornado.testing import AsyncTestCase, bind_unused_port
+from tornado.testing import AsyncTestCase, bind_unused_port, ExpectLog
 from tornado.test.util import unittest, skipIfNonUnix, skipOnTravis
 
 try:
@@ -251,6 +252,27 @@ class TestIOLoop(AsyncTestCase):
         self.assertTrue(got_exception[0])
         self.assertFalse(returned_from_start[0])
 
+    def test_exception_logging(self):
+        """Uncaught exceptions get logged by the IOLoop."""
+        # Use a NullContext to keep the exception from being caught by
+        # AsyncTestCase.
+        with NullContext():
+            self.io_loop.add_callback(lambda: 1/0)
+            self.io_loop.add_callback(self.stop)
+            with ExpectLog(app_log, "Exception in callback"):
+                self.wait()
+
+    def test_exception_logging_future(self):
+        """The IOLoop examines exceptions from Futures and logs them."""
+        with NullContext():
+            @gen.coroutine
+            def callback():
+                self.io_loop.add_callback(self.stop)
+                1/0
+            self.io_loop.add_callback(callback)
+            with ExpectLog(app_log, "Exception in callback"):
+                self.wait()
+
 
 # Deliberately not a subclass of AsyncTestCase so the IOLoop isn't
 # automatically set as current.