Log exceptions inside spawned functions

eventlet pool will discards all exception raised inside spawn(_n), it is
hard to discover problems inside spawned green-threads, it is better to
add a function wrapper to log the exceptions raised inside spawned
function.

Change-Id: I753df36c4614759f49134667a55f2a91f0c08317
Closes-bug: #1340708

neutron/agent/dhcp_agent.py

@@ -176,6 +176,7 @@ class DhcpAgent(manager.Manager):
             self.schedule_resync(e)
             LOG.exception(_('Unable to sync network state.'))
 
+    @utils.exception_logger()
     def _periodic_resync_helper(self):
         """Resync the dhcp state at the configured interval."""
         while True:
@@ -210,6 +211,7 @@ class DhcpAgent(manager.Manager):
         if network:
             self.configure_dhcp_for_network(network)
 
+    @utils.exception_logger()
     def safe_configure_dhcp_for_network(self, network):
         try:
             self.configure_dhcp_for_network(network)

neutron/agent/l3_agent.py

@@ -697,6 +697,7 @@ class L3NATAgent(firewall_l3_agent.FWaaSL3AgentRpcCallback, manager.Manager):
         ip_devs = ip_wrapper.get_devices(exclude_loopback=True)
         return [ip_dev.name for ip_dev in ip_devs]
 
+    @common_utils.exception_logger()
     def process_router(self, ri):
         # TODO(mrsmith) - we shouldn't need to check here
         if 'distributed' not in ri.router:

neutron/common/utils.py

@@ -33,6 +33,7 @@ from eventlet.green import subprocess
 from oslo.config import cfg
 
 from neutron.common import constants as q_const
+from neutron.openstack.common import excutils
 from neutron.openstack.common import lockutils
 from neutron.openstack.common import log as logging
 
@@ -308,3 +309,29 @@ def cpu_count():
         return multiprocessing.cpu_count()
     except NotImplementedError:
         return 1
+
+
+class exception_logger(object):
+    """Wrap a function and log raised exception
+
+    :param logger: the logger to log the exception default is LOG.exception
+
+    :returns: origin value if no exception raised; re-raise the exception if
+              any occurred
+
+    """
+    def __init__(self, logger=None):
+        self.logger = logger
+
+    def __call__(self, func):
+        if self.logger is None:
+            LOG = logging.getLogger(func.__module__)
+            self.logger = LOG.exception
+
+        def call(*args, **kwargs):
+            try:
+                return func(*args, **kwargs)
+            except Exception as e:
+                with excutils.save_and_reraise_exception():
+                    self.logger(e)
+        return call

neutron/tests/unit/test_common_utils.py

@@ -12,6 +12,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import eventlet
 import mock
 import testtools
 
@@ -381,3 +382,85 @@ class TestDict2Tuples(base.BaseTestCase):
         expected = ((42, 'baz'), ('aaa', 'zzz'), ('foo', 'bar'))
         output_tuple = utils.dict2tuple(input_dict)
         self.assertEqual(expected, output_tuple)
+
+
+class TestExceptionLogger(base.BaseTestCase):
+    def test_normal_call(self):
+        result = "Result"
+
+        @utils.exception_logger()
+        def func():
+            return result
+
+        self.assertEqual(result, func())
+
+    def test_raise(self):
+        result = "Result"
+
+        @utils.exception_logger()
+        def func():
+            raise RuntimeError(result)
+
+        self.assertRaises(RuntimeError, func)
+
+    def test_spawn_normal(self):
+        result = "Result"
+        logger = mock.Mock()
+
+        @utils.exception_logger(logger=logger)
+        def func():
+            return result
+
+        gt = eventlet.spawn(func)
+        self.assertEqual(result, gt.wait())
+        self.assertFalse(logger.called)
+
+    def test_spawn_raise(self):
+        result = "Result"
+        logger = mock.Mock()
+
+        @utils.exception_logger(logger=logger)
+        def func():
+            raise RuntimeError(result)
+
+        gt = eventlet.spawn(func)
+        self.assertRaises(RuntimeError, gt.wait)
+        self.assertTrue(logger.called)
+
+    def test_pool_spawn_normal(self):
+        logger = mock.Mock()
+        calls = mock.Mock()
+
+        @utils.exception_logger(logger=logger)
+        def func(i):
+            calls(i)
+
+        pool = eventlet.GreenPool(4)
+        for i in range(0, 4):
+            pool.spawn(func, i)
+        pool.waitall()
+
+        calls.assert_has_calls([mock.call(0), mock.call(1),
+                                mock.call(2), mock.call(3)],
+                               any_order=True)
+        self.assertFalse(logger.called)
+
+    def test_pool_spawn_raise(self):
+        logger = mock.Mock()
+        calls = mock.Mock()
+
+        @utils.exception_logger(logger=logger)
+        def func(i):
+            if i == 2:
+                raise RuntimeError(2)
+            else:
+                calls(i)
+
+        pool = eventlet.GreenPool(4)
+        for i in range(0, 4):
+            pool.spawn(func, i)
+        pool.waitall()
+
+        calls.assert_has_calls([mock.call(0), mock.call(1), mock.call(3)],
+                               any_order=True)
+        self.assertTrue(logger.called)