From: Ben Darnell <ben@bendarnell.com>
Date: Sun, 15 Jun 2014 15:32:11 +0000 (-0400)
Subject: When a function on the IOLoop returns a Future, log its exception.
X-Git-Tag: v4.0.0b1~22
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=99aa924c468c5ed8a52feae4f6e59c54c6f5fd07;p=thirdparty%2Ftornado.git

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

diff --git a/tornado/ioloop.py b/tornado/ioloop.py
index 1a51fb0c4..ca309232d 100644
--- 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 552476bc0..6518dea55 100644
--- 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 889aa3c45..18263dd94 100644
--- 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 e187cc181..03b4fddfb 100644
--- 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.