From d7e508dd5243bb0d65a6cd341a15f37b547f8400 Mon Sep 17 00:00:00 2001 From: Ilya Shakhat Date: Mon, 4 Aug 2014 16:46:27 +0400 Subject: [PATCH] Make log level in linux.utils.execute configurable Function linux.utils.execute always logs failures on error level. Some callers use this function to check resource existance and interpret failure as normal flow. Log level is made configurable for such cases. Change-Id: I8e4cd7b42234426f8fe58d353a64e898f02f8998 Closes-bug: 1339045 --- neutron/agent/linux/ip_lib.py | 26 +++++++--- neutron/agent/linux/utils.py | 10 ++-- .../agent/linuxbridge_neutron_agent.py | 5 +- neutron/tests/unit/test_agent_linux_utils.py | 8 +++ neutron/tests/unit/test_linux_ip_lib.py | 51 ++++++++++++------- 5 files changed, 70 insertions(+), 30 deletions(-) diff --git a/neutron/agent/linux/ip_lib.py b/neutron/agent/linux/ip_lib.py index afc27f788e..02fe154747 100644 --- a/neutron/agent/linux/ip_lib.py +++ b/neutron/agent/linux/ip_lib.py @@ -36,9 +36,11 @@ VLAN_INTERFACE_DETAIL = ['vlan protocol 802.1q', class SubProcessBase(object): - def __init__(self, root_helper=None, namespace=None): + def __init__(self, root_helper=None, namespace=None, + log_fail_as_error=True): self.root_helper = root_helper self.namespace = namespace + self.log_fail_as_error = log_fail_as_error try: self.force_root = cfg.CONF.ip_lib_force_root except cfg.NoSuchOptError: @@ -52,9 +54,11 @@ class SubProcessBase(object): elif self.force_root: # Force use of the root helper to ensure that commands # will execute in dom0 when running under XenServer/XCP. - return self._execute(options, command, args, self.root_helper) + return self._execute(options, command, args, self.root_helper, + log_fail_as_error=self.log_fail_as_error) else: - return self._execute(options, command, args) + return self._execute(options, command, args, + log_fail_as_error=self.log_fail_as_error) def _as_root(self, options, command, args, use_root_namespace=False): if not self.root_helper: @@ -66,18 +70,23 @@ class SubProcessBase(object): command, args, self.root_helper, - namespace) + namespace, + log_fail_as_error=self.log_fail_as_error) @classmethod def _execute(cls, options, command, args, root_helper=None, - namespace=None): + namespace=None, log_fail_as_error=True): opt_list = ['-%s' % o for o in options] if namespace: ip_cmd = ['ip', 'netns', 'exec', namespace, 'ip'] else: ip_cmd = ['ip'] return utils.execute(ip_cmd + opt_list + [command] + list(args), - root_helper=root_helper) + root_helper=root_helper, + log_fail_as_error=log_fail_as_error) + + def set_log_fail_as_error(self, fail_with_error): + self.log_fail_as_error = fail_with_error class IPWrapper(SubProcessBase): @@ -550,7 +559,9 @@ class IpNetnsCommand(IpCommandBase): def device_exists(device_name, root_helper=None, namespace=None): try: - address = IPDevice(device_name, root_helper, namespace).link.address + dev = IPDevice(device_name, root_helper, namespace) + dev.set_log_fail_as_error(False) + address = dev.link.address except RuntimeError: return False return bool(address) @@ -558,6 +569,7 @@ def device_exists(device_name, root_helper=None, namespace=None): def ensure_device_is_ready(device_name, root_helper=None, namespace=None): dev = IPDevice(device_name, root_helper, namespace) + dev.set_log_fail_as_error(False) try: # Ensure the device is up, even if it is already up. If the device # doesn't exist, a RuntimeError will be raised. diff --git a/neutron/agent/linux/utils.py b/neutron/agent/linux/utils.py index c01884245d..2d6c4f5230 100644 --- a/neutron/agent/linux/utils.py +++ b/neutron/agent/linux/utils.py @@ -60,7 +60,7 @@ def create_process(cmd, root_helper=None, addl_env=None): def execute(cmd, root_helper=None, process_input=None, addl_env=None, - check_exit_code=True, return_stderr=False): + check_exit_code=True, return_stderr=False, log_fail_as_error=True): try: obj, cmd = create_process(cmd, root_helper=root_helper, addl_env=addl_env) @@ -71,12 +71,14 @@ def execute(cmd, root_helper=None, process_input=None, addl_env=None, m = _("\nCommand: %(cmd)s\nExit code: %(code)s\nStdout: %(stdout)r\n" "Stderr: %(stderr)r") % {'cmd': cmd, 'code': obj.returncode, 'stdout': _stdout, 'stderr': _stderr} - if obj.returncode: + + if obj.returncode and log_fail_as_error: LOG.error(m) - if check_exit_code: - raise RuntimeError(m) else: LOG.debug(m) + + if obj.returncode and check_exit_code: + raise RuntimeError(m) finally: # NOTE(termie): this appears to be necessary to let the subprocess # call clean something up in between calls, without diff --git a/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py b/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py index f5a4507f6e..9af0c105f4 100755 --- a/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py +++ b/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py @@ -281,6 +281,7 @@ class LinuxBridgeManager: def _bridge_exists_and_ensure_up(self, bridge_name): """Check if the bridge exists and make sure it is up.""" br = ip_lib.IPDevice(bridge_name, self.root_helper) + br.set_log_fail_as_error(False) try: # If the device doesn't exist this will throw a RuntimeError br.link.set_up() @@ -537,7 +538,7 @@ class LinuxBridgeManager: utils.execute( cmd=['bridge', 'fdb', 'append', constants.FLOODING_ENTRY[0], 'dev', test_iface, 'dst', '1.1.1.1'], - root_helper=self.root_helper) + root_helper=self.root_helper, log_fail_as_error=False) return True except RuntimeError: return False @@ -563,7 +564,7 @@ class LinuxBridgeManager: def vxlan_module_supported(self): try: - utils.execute(cmd=['modinfo', 'vxlan']) + utils.execute(cmd=['modinfo', 'vxlan'], log_fail_as_error=False) return True except RuntimeError: return False diff --git a/neutron/tests/unit/test_agent_linux_utils.py b/neutron/tests/unit/test_agent_linux_utils.py index d54d9f1ebd..894643a79e 100644 --- a/neutron/tests/unit/test_agent_linux_utils.py +++ b/neutron/tests/unit/test_agent_linux_utils.py @@ -110,6 +110,14 @@ class AgentUtilsExecuteTest(base.BaseTestCase): utils.execute(['ls']) self.assertTrue(log.debug.called) + def test_return_code_raise_runtime_do_not_log_fail_as_error(self): + with mock.patch.object(utils, 'create_process') as create_process: + create_process.return_value = FakeCreateProcess(1), 'ls' + with mock.patch.object(utils, 'LOG') as log: + self.assertRaises(RuntimeError, utils.execute, + ['ls'], log_fail_as_error=False) + self.assertTrue(log.debug.called) + class AgentUtilsGetInterfaceMAC(base.BaseTestCase): def test_get_interface_mac(self): diff --git a/neutron/tests/unit/test_linux_ip_lib.py b/neutron/tests/unit/test_linux_ip_lib.py index 08dc98fb63..fe283c525f 100644 --- a/neutron/tests/unit/test_linux_ip_lib.py +++ b/neutron/tests/unit/test_linux_ip_lib.py @@ -151,39 +151,45 @@ class TestSubProcessBase(base.BaseTestCase): ip_lib.SubProcessBase._execute('o', 'link', ('list',), 'sudo') self.execute.assert_called_once_with(['ip', '-o', 'link', 'list'], - root_helper='sudo') + root_helper='sudo', + log_fail_as_error=True) def test_execute_wrapper_int_options(self): ip_lib.SubProcessBase._execute([4], 'link', ('list',)) self.execute.assert_called_once_with(['ip', '-4', 'link', 'list'], - root_helper=None) + root_helper=None, + log_fail_as_error=True) def test_execute_wrapper_no_options(self): ip_lib.SubProcessBase._execute([], 'link', ('list',)) self.execute.assert_called_once_with(['ip', 'link', 'list'], - root_helper=None) + root_helper=None, + log_fail_as_error=True) def test_run_no_namespace(self): base = ip_lib.SubProcessBase('sudo') base._run([], 'link', ('list',)) self.execute.assert_called_once_with(['ip', 'link', 'list'], - root_helper=None) + root_helper=None, + log_fail_as_error=True) def test_run_namespace(self): base = ip_lib.SubProcessBase('sudo', 'ns') base._run([], 'link', ('list',)) self.execute.assert_called_once_with(['ip', 'netns', 'exec', 'ns', 'ip', 'link', 'list'], - root_helper='sudo') + root_helper='sudo', + log_fail_as_error=True) def test_as_root_namespace(self): base = ip_lib.SubProcessBase('sudo', 'ns') base._as_root([], 'link', ('list',)) self.execute.assert_called_once_with(['ip', 'netns', 'exec', 'ns', 'ip', 'link', 'list'], - root_helper='sudo') + root_helper='sudo', + log_fail_as_error=True) def test_as_root_no_root_helper(self): base = ip_lib.SubProcessBase() @@ -257,20 +263,23 @@ class TestIpWrapper(base.BaseTestCase): ip_lib.IPWrapper('sudo').add_tuntap('tap0') self.execute.assert_called_once_with('', 'tuntap', ('add', 'tap0', 'mode', 'tap'), - 'sudo', None) + 'sudo', None, + log_fail_as_error=True) def test_add_veth(self): ip_lib.IPWrapper('sudo').add_veth('tap0', 'tap1') self.execute.assert_called_once_with('', 'link', ('add', 'tap0', 'type', 'veth', 'peer', 'name', 'tap1'), - 'sudo', None) + 'sudo', None, + log_fail_as_error=True) def test_del_veth(self): ip_lib.IPWrapper('sudo').del_veth('fpr-1234') self.execute.assert_called_once_with('', 'link', ('del', 'fpr-1234'), - 'sudo', None) + 'sudo', None, + log_fail_as_error=True) def test_add_veth_with_namespaces(self): ns2 = 'ns2' @@ -281,7 +290,8 @@ class TestIpWrapper(base.BaseTestCase): ('add', 'tap0', 'type', 'veth', 'peer', 'name', 'tap1', 'netns', ns2), - 'sudo', None) + 'sudo', None, + log_fail_as_error=True) def test_get_device(self): dev = ip_lib.IPWrapper('sudo', 'ns').device('eth0') @@ -297,7 +307,8 @@ class TestIpWrapper(base.BaseTestCase): ns_exists.return_value = False ip.ensure_namespace('ns') self.execute.assert_has_calls( - [mock.call([], 'netns', ('add', 'ns'), 'sudo', None)]) + [mock.call([], 'netns', ('add', 'ns'), 'sudo', None, + log_fail_as_error=True)]) ip_dev.assert_has_calls([mock.call('lo', 'sudo', 'ns'), mock.call().link.set_up()]) @@ -390,7 +401,8 @@ class TestIpWrapper(base.BaseTestCase): 'ttl', 'ttl0', 'tos', 'tos0', 'local', 'local0', 'proxy', 'port', '1', '2'], - 'sudo', None) + 'sudo', None, + log_fail_as_error=True) def test_add_vxlan_invalid_port_length(self): wrapper = ip_lib.IPWrapper('sudo') @@ -422,13 +434,15 @@ class TestIpRule(base.BaseTestCase): self.execute.assert_called_once_with('', 'rule', ('add', 'from', '192.168.45.100', 'lookup', 2, 'priority', 100), - 'sudo', None) + 'sudo', None, + log_fail_as_error=True) def test_delete_rule_priority(self): ip_lib.IpRule('sudo').delete_rule_priority(100) self.execute.assert_called_once_with('', 'rule', ('del', 'priority', 100), - 'sudo', None) + 'sudo', None, + log_fail_as_error=True) class TestIPDevice(base.BaseTestCase): @@ -794,7 +808,8 @@ class TestIpNetnsCommand(TestIPCmdBase): self.assertTrue( netns_cmd.exists('bbbbbbbb-bbbb-bbbb-bbbb-bbbbbbbbbbbb')) execute.assert_called_once_with(['ip', '-o', 'netns', 'list'], - root_helper=None) + root_helper=None, + log_fail_as_error=True) def test_namespace_doest_not_exist(self): retval = '\n'.join(NETNS_SAMPLE) @@ -805,7 +820,8 @@ class TestIpNetnsCommand(TestIPCmdBase): self.assertFalse( netns_cmd.exists('bbbbbbbb-1111-2222-3333-bbbbbbbbbbbb')) execute.assert_called_once_with(['ip', '-o', 'netns', 'list'], - root_helper=None) + root_helper=None, + log_fail_as_error=True) def test_execute(self): self.parent.namespace = 'ns' @@ -832,7 +848,8 @@ class TestDeviceExists(base.BaseTestCase): with mock.patch.object(ip_lib.IPDevice, '_execute') as _execute: _execute.return_value = LINK_SAMPLE[1] self.assertTrue(ip_lib.device_exists('eth0')) - _execute.assert_called_once_with('o', 'link', ('show', 'eth0')) + _execute.assert_called_once_with('o', 'link', ('show', 'eth0'), + log_fail_as_error=False) def test_device_does_not_exist(self): with mock.patch.object(ip_lib.IPDevice, '_execute') as _execute: