diff options
| -rw-r--r-- | nova/tests/unit/test_utils.py | 182 | ||||
| -rw-r--r-- | nova/utils.py | 150 | ||||
| -rw-r--r-- | setup.cfg | 1 |
3 files changed, 327 insertions, 6 deletions
diff --git a/nova/tests/unit/test_utils.py b/nova/tests/unit/test_utils.py index e86d7acf36..f4482b19a2 100644 --- a/nova/tests/unit/test_utils.py +++ b/nova/tests/unit/test_utils.py @@ -16,6 +16,7 @@ import datetime import functools import hashlib import importlib +import logging import os import os.path import socket @@ -34,7 +35,6 @@ from oslo_utils import timeutils from oslo_utils import units import six - import nova from nova import context from nova import exception @@ -192,6 +192,21 @@ class GenericUtilsTestCase(test.NoDBTestCase): cmd = utils.get_root_helper() self.assertEqual('sudo nova-rootwrap foo', cmd) + @mock.patch('nova.utils.RootwrapProcessHelper') + def test_get_root_helper_proc(self, mock_proc_helper): + self.flags(use_rootwrap_daemon=False) + self.flags(rootwrap_config="/path/to/conf") + utils._get_rootwrap_helper() + mock_proc_helper.assert_called_once_with() + + @mock.patch('nova.utils.RootwrapDaemonHelper') + def test_get_root_helper_daemon(self, mock_daemon_helper): + conf_path = '/path/to/conf' + self.flags(use_rootwrap_daemon=True) + self.flags(rootwrap_config=conf_path) + utils._get_rootwrap_helper() + mock_daemon_helper.assert_called_once_with(conf_path) + def test_use_sudo(self): self.flags(disable_rootwrap=True, group='workarounds') cmd = utils.get_root_helper() @@ -248,6 +263,171 @@ class TestCachedFile(test.NoDBTestCase): self.assertNotIn(filename, utils._FILE_CACHE) +class RootwrapDaemonTesetCase(test.TestCase): + @mock.patch('oslo_rootwrap.client.Client') + def test_get_client(self, mock_client): + mock_conf = mock.MagicMock() + utils.RootwrapDaemonHelper(mock_conf) + mock_client.assert_called_once_with( + ["sudo", "nova-rootwrap-daemon", mock_conf]) + + @mock.patch('nova.utils.LOG.info') + def test_execute(self, mock_info): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(0, None, None)) + + daemon.execute('a', 1, foo='bar', run_as_root=True) + daemon.client.execute.assert_called_once_with(['a', '1'], None) + mock_info.assert_has_calls([mock.call( + u'Executing RootwrapDaemonHelper.execute cmd=[%(cmd)r] ' + u'kwargs=[%(kwargs)r]', + {'cmd': u'a 1', 'kwargs': {'run_as_root': True, 'foo': 'bar'}})]) + + def test_execute_with_kwargs(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(0, None, None)) + + daemon.execute('a', 1, foo='bar', run_as_root=True, process_input=True) + daemon.client.execute.assert_called_once_with(['a', '1'], True) + + def test_execute_fail(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(-2, None, None)) + + self.assertRaises(processutils.ProcessExecutionError, + daemon.execute, 'b', 2) + + def test_execute_pass_with_check_exit_code(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(-2, None, None)) + daemon.execute('b', 2, check_exit_code=[-2]) + + def test_execute_fail_with_retry(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(-2, None, None)) + + self.assertRaises(processutils.ProcessExecutionError, + daemon.execute, 'b', 2, attempts=2) + daemon.client.execute.assert_has_calls( + [mock.call(['b', '2'], None), + mock.call(['b', '2'], None)]) + + @mock.patch('nova.utils.LOG.log') + def test_execute_fail_and_logging(self, mock_log): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(-2, None, None)) + + self.assertRaises(processutils.ProcessExecutionError, + daemon.execute, 'b', 2, + attempts=2, + loglevel=logging.CRITICAL, + log_errors=processutils.LOG_ALL_ERRORS) + mock_log.assert_has_calls( + [ + mock.call(logging.CRITICAL, u'Running cmd (subprocess): %s', + u'b 2'), + mock.call(logging.CRITICAL, + 'CMD "%(sanitized_cmd)s" returned: %(return_code)s ' + 'in %(end_time)0.3fs', + {'sanitized_cmd': u'b 2', 'return_code': -2, + 'end_time': mock.ANY}), + mock.call(logging.CRITICAL, + u'%(desc)r\ncommand: %(cmd)r\nexit code: %(code)r' + u'\nstdout: %(stdout)r\nstderr: %(stderr)r', + {'code': -2, 'cmd': u'b 2', 'stdout': u'None', + 'stderr': u'None', 'desc': None}), + mock.call(logging.CRITICAL, u'%r failed. Retrying.', u'b 2'), + mock.call(logging.CRITICAL, u'Running cmd (subprocess): %s', + u'b 2'), + mock.call(logging.CRITICAL, + 'CMD "%(sanitized_cmd)s" returned: %(return_code)s ' + 'in %(end_time)0.3fs', + {'sanitized_cmd': u'b 2', 'return_code': -2, + 'end_time': mock.ANY}), + mock.call(logging.CRITICAL, + u'%(desc)r\ncommand: %(cmd)r\nexit code: %(code)r' + u'\nstdout: %(stdout)r\nstderr: %(stderr)r', + {'code': -2, 'cmd': u'b 2', 'stdout': u'None', + 'stderr': u'None', 'desc': None}), + mock.call(logging.CRITICAL, u'%r failed. Not Retrying.', + u'b 2')] + ) + + def test_trycmd(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(0, None, None)) + + daemon.trycmd('a', 1, foo='bar', run_as_root=True) + daemon.client.execute.assert_called_once_with(['a', '1'], None) + + def test_trycmd_with_kwargs(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.execute = mock.Mock(return_value=('out', 'err')) + + daemon.trycmd('a', 1, foo='bar', run_as_root=True, + loglevel=logging.WARN, + log_errors=True, + process_input=True, + delay_on_retry=False, + attempts=5, + check_exit_code=[200]) + daemon.execute.assert_called_once_with('a', 1, attempts=5, + check_exit_code=[200], + delay_on_retry=False, foo='bar', + log_errors=True, loglevel=30, + process_input=True, + run_as_root=True) + + def test_trycmd_fail(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(-2, None, None)) + + expected_err = six.text_type('''\ +Unexpected error while running command. +Command: a 1 +Exit code: -2''') + + out, err = daemon.trycmd('a', 1, foo='bar', run_as_root=True) + daemon.client.execute.assert_called_once_with(['a', '1'], None) + self.assertIn(expected_err, err) + + def test_trycmd_fail_with_rety(self): + mock_conf = mock.MagicMock() + daemon = utils.RootwrapDaemonHelper(mock_conf) + daemon.client = mock.MagicMock() + daemon.client.execute = mock.Mock(return_value=(-2, None, None)) + + expected_err = six.text_type('''\ +Unexpected error while running command. +Command: a 1 +Exit code: -2''') + + out, err = daemon.trycmd('a', 1, foo='bar', run_as_root=True, + attempts=3) + self.assertIn(expected_err, err) + daemon.client.execute.assert_has_calls( + [mock.call(['a', '1'], None), + mock.call(['a', '1'], None), + mock.call(['a', '1'], None)]) + + class VPNPingTestCase(test.NoDBTestCase): """Unit tests for utils.vpn_ping().""" def setUp(self): diff --git a/nova/utils.py b/nova/utils.py index 4290711d99..e5c4922418 100644 --- a/nova/utils.py +++ b/nova/utils.py @@ -25,6 +25,7 @@ import functools import hashlib import hmac import inspect +import logging as std_logging import os import pyclbr import random @@ -34,6 +35,7 @@ import socket import struct import sys import tempfile +import time from xml.sax import saxutils import eventlet @@ -47,13 +49,14 @@ import oslo_messaging as messaging from oslo_utils import encodeutils from oslo_utils import excutils from oslo_utils import importutils +from oslo_utils import strutils from oslo_utils import timeutils from oslo_utils import units import six from six.moves import range from nova import exception -from nova.i18n import _, _LE, _LW +from nova.i18n import _, _LE, _LI, _LW notify_decorator = 'nova.notifications.notify_decorator' @@ -76,6 +79,11 @@ utils_opts = [ default='month', help='Time period to generate instance usages for. ' 'Time period must be hour, day, month or year'), + cfg.BoolOpt('use_rootwrap_daemon', default=False, + help="Start and use a daemon that can run the commands that " + "need to be run with root privileges. This option is " + "usually enabled on nodes that run nova compute " + "processes"), cfg.StrOpt('rootwrap_config', default="/etc/nova/rootwrap.conf", help='Path to the rootwrap configuration file to use for ' @@ -247,10 +255,138 @@ def get_root_helper(): return cmd +def _get_rootwrap_helper(): + if CONF.use_rootwrap_daemon: + return RootwrapDaemonHelper(CONF.rootwrap_config) + else: + return RootwrapProcessHelper() + + +class RootwrapProcessHelper(object): + def trycmd(self, *cmd, **kwargs): + kwargs['root_helper'] = get_root_helper() + return processutils.trycmd(*cmd, **kwargs) + + def execute(self, *cmd, **kwargs): + kwargs['root_helper'] = get_root_helper() + return processutils.execute(*cmd, **kwargs) + + +class RootwrapDaemonHelper(RootwrapProcessHelper): + _clients = {} + + @synchronized('daemon-client-lock') + def _get_client(cls, rootwrap_config): + try: + return cls._clients[rootwrap_config] + except KeyError: + from oslo_rootwrap import client + new_client = client.Client([ + "sudo", "nova-rootwrap-daemon", rootwrap_config]) + cls._clients[rootwrap_config] = new_client + return new_client + + def __init__(self, rootwrap_config): + self.client = self._get_client(rootwrap_config) + + def trycmd(self, *args, **kwargs): + discard_warnings = kwargs.pop('discard_warnings', False) + try: + out, err = self.execute(*args, **kwargs) + failed = False + except processutils.ProcessExecutionError as exn: + out, err = '', six.text_type(exn) + failed = True + if not failed and discard_warnings and err: + # Handle commands that output to stderr but otherwise succeed + err = '' + return out, err + + def execute(self, *cmd, **kwargs): + # NOTE(dims): This method is to provide compatibility with the + # processutils.execute interface. So that calling daemon or direct + # rootwrap to honor the same set of flags in kwargs and to ensure + # that we don't regress any current behavior. + cmd = [str(c) for c in cmd] + loglevel = kwargs.pop('loglevel', std_logging.DEBUG) + log_errors = kwargs.pop('log_errors', None) + process_input = kwargs.pop('process_input', None) + delay_on_retry = kwargs.pop('delay_on_retry', True) + attempts = kwargs.pop('attempts', 1) + check_exit_code = kwargs.pop('check_exit_code', [0]) + ignore_exit_code = False + if isinstance(check_exit_code, bool): + ignore_exit_code = not check_exit_code + check_exit_code = [0] + elif isinstance(check_exit_code, int): + check_exit_code = [check_exit_code] + + sanitized_cmd = strutils.mask_password(' '.join(cmd)) + LOG.info(_LI('Executing RootwrapDaemonHelper.execute ' + 'cmd=[%(cmd)r] kwargs=[%(kwargs)r]'), + {'cmd': sanitized_cmd, 'kwargs': kwargs}) + + while attempts > 0: + attempts -= 1 + try: + start_time = time.time() + LOG.log(loglevel, _('Running cmd (subprocess): %s'), + sanitized_cmd) + + (returncode, out, err) = self.client.execute( + cmd, process_input) + + end_time = time.time() - start_time + LOG.log(loglevel, + 'CMD "%(sanitized_cmd)s" returned: %(return_code)s ' + 'in %(end_time)0.3fs', + {'sanitized_cmd': sanitized_cmd, + 'return_code': returncode, + 'end_time': end_time}) + + if not ignore_exit_code and returncode not in check_exit_code: + out = strutils.mask_password(out) + err = strutils.mask_password(err) + raise processutils.ProcessExecutionError( + exit_code=returncode, + stdout=out, + stderr=err, + cmd=sanitized_cmd) + return (out, err) + + except processutils.ProcessExecutionError as err: + # if we want to always log the errors or if this is + # the final attempt that failed and we want to log that. + if log_errors == processutils.LOG_ALL_ERRORS or ( + log_errors == processutils.LOG_FINAL_ERROR and + not attempts): + format = _('%(desc)r\ncommand: %(cmd)r\n' + 'exit code: %(code)r\nstdout: %(stdout)r\n' + 'stderr: %(stderr)r') + LOG.log(loglevel, format, {"desc": err.description, + "cmd": err.cmd, + "code": err.exit_code, + "stdout": err.stdout, + "stderr": err.stderr}) + if not attempts: + LOG.log(loglevel, _('%r failed. Not Retrying.'), + sanitized_cmd) + raise + else: + LOG.log(loglevel, _('%r failed. Retrying.'), + sanitized_cmd) + if delay_on_retry: + time.sleep(random.randint(20, 200) / 100.0) + + def execute(*cmd, **kwargs): """Convenience wrapper around oslo's execute() method.""" - if 'run_as_root' in kwargs and 'root_helper' not in kwargs: - kwargs['root_helper'] = get_root_helper() + if 'run_as_root' in kwargs and kwargs.get('run_as_root'): + if CONF.use_rootwrap_daemon: + return RootwrapDaemonHelper(CONF.rootwrap_config).execute( + *cmd, **kwargs) + else: + return RootwrapProcessHelper().execute(*cmd, **kwargs) return processutils.execute(*cmd, **kwargs) @@ -264,8 +400,12 @@ def ssh_execute(dest, *cmd, **kwargs): def trycmd(*args, **kwargs): """Convenience wrapper around oslo's trycmd() method.""" - if 'run_as_root' in kwargs and 'root_helper' not in kwargs: - kwargs['root_helper'] = get_root_helper() + if kwargs.get('run_as_root', False): + if CONF.use_rootwrap_daemon: + return RootwrapDaemonHelper(CONF.rootwrap_config).trycmd( + *args, **kwargs) + else: + return RootwrapProcessHelper().trycmd(*args, **kwargs) return processutils.trycmd(*args, **kwargs) @@ -63,6 +63,7 @@ console_scripts = nova-novncproxy = nova.cmd.novncproxy:main nova-objectstore = nova.cmd.objectstore:main nova-rootwrap = oslo_rootwrap.cmd:main + nova-rootwrap-daemon = oslo_rootwrap.cmd:daemon nova-scheduler = nova.cmd.scheduler:main nova-serialproxy = nova.cmd.serialproxy:main nova-spicehtml5proxy = nova.cmd.spicehtml5proxy:main |