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

diff --git a/neutron/agent/linux/ip_lib.py b/neutron/agent/linux/ip_lib.py
index afc27f788ec29429ec8e698c4d4218f8170e3689..02fe154747f49ecf3ca9f8875bdf863824a824f0 100644 (file)
--- 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 c01884245ddcc3e70cffc438caab57117794c972..2d6c4f5230737f4f37115727c1cc1c4faf2c1a95 100644 (file)
--- 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 f5a4507f6eb8d27e7a75f403f5fbdd3ac1ac8692..9af0c105f43eecf73baf73d1a724c46b2429b886 100755 (executable)
--- 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 d54d9f1ebd622a7f8e81890e96ac6d6da57c954e..894643a79e3f875e1b617b779f7bda209412b961 100644 (file)
--- 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 08dc98fb63570337dec580ca87df869f0c8694ae..fe283c525ff6d69127266ee48c43593bde6393d1 100644 (file)
--- 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: