From 7d869a02b8245dbf9d22ddf73ff810d055581730 Mon Sep 17 00:00:00 2001 From: Zang MingJie Date: Wed, 16 Jul 2014 15:41:45 +0800 Subject: [PATCH] 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 | 2 + neutron/agent/l3_agent.py | 1 + neutron/common/utils.py | 27 ++++++++ neutron/tests/unit/test_common_utils.py | 83 +++++++++++++++++++++++++ 4 files changed, 113 insertions(+) diff --git a/neutron/agent/dhcp_agent.py b/neutron/agent/dhcp_agent.py index 29119799e..0ec9a8446 100644 --- a/neutron/agent/dhcp_agent.py +++ b/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) diff --git a/neutron/agent/l3_agent.py b/neutron/agent/l3_agent.py index 9d7ec1219..ae0124a78 100644 --- a/neutron/agent/l3_agent.py +++ b/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: diff --git a/neutron/common/utils.py b/neutron/common/utils.py index 8521ec7f9..72aff7064 100644 --- a/neutron/common/utils.py +++ b/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 diff --git a/neutron/tests/unit/test_common_utils.py b/neutron/tests/unit/test_common_utils.py index 2bcd6b45e..d42ce4e92 100644 --- a/neutron/tests/unit/test_common_utils.py +++ b/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) -- 2.45.2