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
This commit is contained in:
Ilya Shakhat 2014-08-04 16:46:27 +04:00
parent 33a5518bee
commit d7e508dd52
5 changed files with 70 additions and 30 deletions

View File

@ -36,9 +36,11 @@ VLAN_INTERFACE_DETAIL = ['vlan protocol 802.1q',
class SubProcessBase(object): 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.root_helper = root_helper
self.namespace = namespace self.namespace = namespace
self.log_fail_as_error = log_fail_as_error
try: try:
self.force_root = cfg.CONF.ip_lib_force_root self.force_root = cfg.CONF.ip_lib_force_root
except cfg.NoSuchOptError: except cfg.NoSuchOptError:
@ -52,9 +54,11 @@ class SubProcessBase(object):
elif self.force_root: elif self.force_root:
# Force use of the root helper to ensure that commands # Force use of the root helper to ensure that commands
# will execute in dom0 when running under XenServer/XCP. # 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: 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): def _as_root(self, options, command, args, use_root_namespace=False):
if not self.root_helper: if not self.root_helper:
@ -66,18 +70,23 @@ class SubProcessBase(object):
command, command,
args, args,
self.root_helper, self.root_helper,
namespace) namespace,
log_fail_as_error=self.log_fail_as_error)
@classmethod @classmethod
def _execute(cls, options, command, args, root_helper=None, 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] opt_list = ['-%s' % o for o in options]
if namespace: if namespace:
ip_cmd = ['ip', 'netns', 'exec', namespace, 'ip'] ip_cmd = ['ip', 'netns', 'exec', namespace, 'ip']
else: else:
ip_cmd = ['ip'] ip_cmd = ['ip']
return utils.execute(ip_cmd + opt_list + [command] + list(args), 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): class IPWrapper(SubProcessBase):
@ -550,7 +559,9 @@ class IpNetnsCommand(IpCommandBase):
def device_exists(device_name, root_helper=None, namespace=None): def device_exists(device_name, root_helper=None, namespace=None):
try: 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: except RuntimeError:
return False return False
return bool(address) 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): def ensure_device_is_ready(device_name, root_helper=None, namespace=None):
dev = IPDevice(device_name, root_helper, namespace) dev = IPDevice(device_name, root_helper, namespace)
dev.set_log_fail_as_error(False)
try: try:
# Ensure the device is up, even if it is already up. If the device # Ensure the device is up, even if it is already up. If the device
# doesn't exist, a RuntimeError will be raised. # doesn't exist, a RuntimeError will be raised.

View File

@ -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, 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: try:
obj, cmd = create_process(cmd, root_helper=root_helper, obj, cmd = create_process(cmd, root_helper=root_helper,
addl_env=addl_env) 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" m = _("\nCommand: %(cmd)s\nExit code: %(code)s\nStdout: %(stdout)r\n"
"Stderr: %(stderr)r") % {'cmd': cmd, 'code': obj.returncode, "Stderr: %(stderr)r") % {'cmd': cmd, 'code': obj.returncode,
'stdout': _stdout, 'stderr': _stderr} 'stdout': _stdout, 'stderr': _stderr}
if obj.returncode:
if obj.returncode and log_fail_as_error:
LOG.error(m) LOG.error(m)
if check_exit_code:
raise RuntimeError(m)
else: else:
LOG.debug(m) LOG.debug(m)
if obj.returncode and check_exit_code:
raise RuntimeError(m)
finally: finally:
# NOTE(termie): this appears to be necessary to let the subprocess # NOTE(termie): this appears to be necessary to let the subprocess
# call clean something up in between calls, without # call clean something up in between calls, without

View File

@ -281,6 +281,7 @@ class LinuxBridgeManager:
def _bridge_exists_and_ensure_up(self, bridge_name): def _bridge_exists_and_ensure_up(self, bridge_name):
"""Check if the bridge exists and make sure it is up.""" """Check if the bridge exists and make sure it is up."""
br = ip_lib.IPDevice(bridge_name, self.root_helper) br = ip_lib.IPDevice(bridge_name, self.root_helper)
br.set_log_fail_as_error(False)
try: try:
# If the device doesn't exist this will throw a RuntimeError # If the device doesn't exist this will throw a RuntimeError
br.link.set_up() br.link.set_up()
@ -537,7 +538,7 @@ class LinuxBridgeManager:
utils.execute( utils.execute(
cmd=['bridge', 'fdb', 'append', constants.FLOODING_ENTRY[0], cmd=['bridge', 'fdb', 'append', constants.FLOODING_ENTRY[0],
'dev', test_iface, 'dst', '1.1.1.1'], '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 return True
except RuntimeError: except RuntimeError:
return False return False
@ -563,7 +564,7 @@ class LinuxBridgeManager:
def vxlan_module_supported(self): def vxlan_module_supported(self):
try: try:
utils.execute(cmd=['modinfo', 'vxlan']) utils.execute(cmd=['modinfo', 'vxlan'], log_fail_as_error=False)
return True return True
except RuntimeError: except RuntimeError:
return False return False

View File

@ -110,6 +110,14 @@ class AgentUtilsExecuteTest(base.BaseTestCase):
utils.execute(['ls']) utils.execute(['ls'])
self.assertTrue(log.debug.called) 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): class AgentUtilsGetInterfaceMAC(base.BaseTestCase):
def test_get_interface_mac(self): def test_get_interface_mac(self):

View File

@ -151,39 +151,45 @@ class TestSubProcessBase(base.BaseTestCase):
ip_lib.SubProcessBase._execute('o', 'link', ('list',), 'sudo') ip_lib.SubProcessBase._execute('o', 'link', ('list',), 'sudo')
self.execute.assert_called_once_with(['ip', '-o', 'link', 'list'], 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): def test_execute_wrapper_int_options(self):
ip_lib.SubProcessBase._execute([4], 'link', ('list',)) ip_lib.SubProcessBase._execute([4], 'link', ('list',))
self.execute.assert_called_once_with(['ip', '-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): def test_execute_wrapper_no_options(self):
ip_lib.SubProcessBase._execute([], 'link', ('list',)) ip_lib.SubProcessBase._execute([], 'link', ('list',))
self.execute.assert_called_once_with(['ip', '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): def test_run_no_namespace(self):
base = ip_lib.SubProcessBase('sudo') base = ip_lib.SubProcessBase('sudo')
base._run([], 'link', ('list',)) base._run([], 'link', ('list',))
self.execute.assert_called_once_with(['ip', '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): def test_run_namespace(self):
base = ip_lib.SubProcessBase('sudo', 'ns') base = ip_lib.SubProcessBase('sudo', 'ns')
base._run([], 'link', ('list',)) base._run([], 'link', ('list',))
self.execute.assert_called_once_with(['ip', 'netns', 'exec', 'ns', self.execute.assert_called_once_with(['ip', 'netns', 'exec', 'ns',
'ip', 'link', 'list'], 'ip', 'link', 'list'],
root_helper='sudo') root_helper='sudo',
log_fail_as_error=True)
def test_as_root_namespace(self): def test_as_root_namespace(self):
base = ip_lib.SubProcessBase('sudo', 'ns') base = ip_lib.SubProcessBase('sudo', 'ns')
base._as_root([], 'link', ('list',)) base._as_root([], 'link', ('list',))
self.execute.assert_called_once_with(['ip', 'netns', 'exec', 'ns', self.execute.assert_called_once_with(['ip', 'netns', 'exec', 'ns',
'ip', 'link', 'list'], 'ip', 'link', 'list'],
root_helper='sudo') root_helper='sudo',
log_fail_as_error=True)
def test_as_root_no_root_helper(self): def test_as_root_no_root_helper(self):
base = ip_lib.SubProcessBase() base = ip_lib.SubProcessBase()
@ -257,20 +263,23 @@ class TestIpWrapper(base.BaseTestCase):
ip_lib.IPWrapper('sudo').add_tuntap('tap0') ip_lib.IPWrapper('sudo').add_tuntap('tap0')
self.execute.assert_called_once_with('', 'tuntap', self.execute.assert_called_once_with('', 'tuntap',
('add', 'tap0', 'mode', 'tap'), ('add', 'tap0', 'mode', 'tap'),
'sudo', None) 'sudo', None,
log_fail_as_error=True)
def test_add_veth(self): def test_add_veth(self):
ip_lib.IPWrapper('sudo').add_veth('tap0', 'tap1') ip_lib.IPWrapper('sudo').add_veth('tap0', 'tap1')
self.execute.assert_called_once_with('', 'link', self.execute.assert_called_once_with('', 'link',
('add', 'tap0', 'type', 'veth', ('add', 'tap0', 'type', 'veth',
'peer', 'name', 'tap1'), 'peer', 'name', 'tap1'),
'sudo', None) 'sudo', None,
log_fail_as_error=True)
def test_del_veth(self): def test_del_veth(self):
ip_lib.IPWrapper('sudo').del_veth('fpr-1234') ip_lib.IPWrapper('sudo').del_veth('fpr-1234')
self.execute.assert_called_once_with('', 'link', self.execute.assert_called_once_with('', 'link',
('del', 'fpr-1234'), ('del', 'fpr-1234'),
'sudo', None) 'sudo', None,
log_fail_as_error=True)
def test_add_veth_with_namespaces(self): def test_add_veth_with_namespaces(self):
ns2 = 'ns2' ns2 = 'ns2'
@ -281,7 +290,8 @@ class TestIpWrapper(base.BaseTestCase):
('add', 'tap0', 'type', 'veth', ('add', 'tap0', 'type', 'veth',
'peer', 'name', 'tap1', 'peer', 'name', 'tap1',
'netns', ns2), 'netns', ns2),
'sudo', None) 'sudo', None,
log_fail_as_error=True)
def test_get_device(self): def test_get_device(self):
dev = ip_lib.IPWrapper('sudo', 'ns').device('eth0') dev = ip_lib.IPWrapper('sudo', 'ns').device('eth0')
@ -297,7 +307,8 @@ class TestIpWrapper(base.BaseTestCase):
ns_exists.return_value = False ns_exists.return_value = False
ip.ensure_namespace('ns') ip.ensure_namespace('ns')
self.execute.assert_has_calls( 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'), ip_dev.assert_has_calls([mock.call('lo', 'sudo', 'ns'),
mock.call().link.set_up()]) mock.call().link.set_up()])
@ -390,7 +401,8 @@ class TestIpWrapper(base.BaseTestCase):
'ttl', 'ttl0', 'tos', 'tos0', 'ttl', 'ttl0', 'tos', 'tos0',
'local', 'local0', 'proxy', 'local', 'local0', 'proxy',
'port', '1', '2'], 'port', '1', '2'],
'sudo', None) 'sudo', None,
log_fail_as_error=True)
def test_add_vxlan_invalid_port_length(self): def test_add_vxlan_invalid_port_length(self):
wrapper = ip_lib.IPWrapper('sudo') wrapper = ip_lib.IPWrapper('sudo')
@ -422,13 +434,15 @@ class TestIpRule(base.BaseTestCase):
self.execute.assert_called_once_with('', 'rule', self.execute.assert_called_once_with('', 'rule',
('add', 'from', '192.168.45.100', ('add', 'from', '192.168.45.100',
'lookup', 2, 'priority', 100), 'lookup', 2, 'priority', 100),
'sudo', None) 'sudo', None,
log_fail_as_error=True)
def test_delete_rule_priority(self): def test_delete_rule_priority(self):
ip_lib.IpRule('sudo').delete_rule_priority(100) ip_lib.IpRule('sudo').delete_rule_priority(100)
self.execute.assert_called_once_with('', 'rule', self.execute.assert_called_once_with('', 'rule',
('del', 'priority', 100), ('del', 'priority', 100),
'sudo', None) 'sudo', None,
log_fail_as_error=True)
class TestIPDevice(base.BaseTestCase): class TestIPDevice(base.BaseTestCase):
@ -794,7 +808,8 @@ class TestIpNetnsCommand(TestIPCmdBase):
self.assertTrue( self.assertTrue(
netns_cmd.exists('bbbbbbbb-bbbb-bbbb-bbbb-bbbbbbbbbbbb')) netns_cmd.exists('bbbbbbbb-bbbb-bbbb-bbbb-bbbbbbbbbbbb'))
execute.assert_called_once_with(['ip', '-o', 'netns', 'list'], 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): def test_namespace_doest_not_exist(self):
retval = '\n'.join(NETNS_SAMPLE) retval = '\n'.join(NETNS_SAMPLE)
@ -805,7 +820,8 @@ class TestIpNetnsCommand(TestIPCmdBase):
self.assertFalse( self.assertFalse(
netns_cmd.exists('bbbbbbbb-1111-2222-3333-bbbbbbbbbbbb')) netns_cmd.exists('bbbbbbbb-1111-2222-3333-bbbbbbbbbbbb'))
execute.assert_called_once_with(['ip', '-o', 'netns', 'list'], execute.assert_called_once_with(['ip', '-o', 'netns', 'list'],
root_helper=None) root_helper=None,
log_fail_as_error=True)
def test_execute(self): def test_execute(self):
self.parent.namespace = 'ns' self.parent.namespace = 'ns'
@ -832,7 +848,8 @@ class TestDeviceExists(base.BaseTestCase):
with mock.patch.object(ip_lib.IPDevice, '_execute') as _execute: with mock.patch.object(ip_lib.IPDevice, '_execute') as _execute:
_execute.return_value = LINK_SAMPLE[1] _execute.return_value = LINK_SAMPLE[1]
self.assertTrue(ip_lib.device_exists('eth0')) 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): def test_device_does_not_exist(self):
with mock.patch.object(ip_lib.IPDevice, '_execute') as _execute: with mock.patch.object(ip_lib.IPDevice, '_execute') as _execute: