From f5eb5bb6e4efadd3fa6d6b4681ec1609b5ec803c Mon Sep 17 00:00:00 2001 From: Ilya Shakhat Date: Mon, 27 Feb 2017 16:51:27 +0400 Subject: [PATCH] Fix logging in shaker-all-in-one Logging reconfiguration does not work in recent oslo.log versions. Attempt to update config results in complete loss of logs (both in stderr and file). With this patch all logs are written into 1 file in artifacts dir. Also improve logging when no auth url is provided (os-client-config blindly tries to use the value resulting in AttributeError. Change-Id: Icc1fc22cd6658d9b782c761ddf79f93e39c9b4be --- Dockerfile | 2 +- shaker/engine/all_in_one.py | 16 ++-------------- shaker/engine/utils.py | 13 ++++++++++++- shaker/tests/test_server.py | 12 +++++++++--- 4 files changed, 24 insertions(+), 19 deletions(-) diff --git a/Dockerfile b/Dockerfile index 39ca108..213b8c2 100644 --- a/Dockerfile +++ b/Dockerfile @@ -10,4 +10,4 @@ VOLUME /artifacts STOPSIGNAL SIGTERM -ENTRYPOINT ["/usr/local/bin/shaker-all-in-one", "--artifacts-dir", "/artifacts"] +ENTRYPOINT ["/usr/local/bin/shaker-all-in-one", "--artifacts-dir", "/artifacts", "--log-dir", "/artifacts"] diff --git a/shaker/engine/all_in_one.py b/shaker/engine/all_in_one.py index acf4262..e900ce0 100644 --- a/shaker/engine/all_in_one.py +++ b/shaker/engine/all_in_one.py @@ -24,16 +24,11 @@ from shaker.engine import utils LOG = logging.getLogger(__name__) -def _configure_log_file(log_file): - cfg.CONF.set_override('log_file', log_file) - logging.setup(cfg.CONF, 'shaker') - cfg.CONF.log_opt_values(LOG, logging.DEBUG) - - def main(): utils.init_config_and_logging( config.COMMON_OPTS + config.OPENSTACK_OPTS + config.SERVER_OPTS + - config.REPORT_OPTS + config.IMAGE_BUILDER_OPTS + config.CLEANUP_OPTS + config.REPORT_OPTS + config.IMAGE_BUILDER_OPTS + config.CLEANUP_OPTS, + use_stderr=True ) artifacts_dir = cfg.CONF.artifacts_dir @@ -42,15 +37,10 @@ def main(): cfg.CONF.set_override('artifacts_dir', artifacts_dir) # image-builder - _configure_log_file(utils.join_folder_prefix_ext( - artifacts_dir, 'image_builder', 'log')) LOG.info('Building the image') image_builder.build_image() # core - _configure_log_file(utils.join_folder_prefix_ext( - artifacts_dir, 'execution', 'log')) - if len(cfg.CONF.scenario) > 1: cfg.CONF.set_override( 'output', utils.join_folder_prefix_ext( @@ -68,8 +58,6 @@ def main(): server.act() # cleanup - _configure_log_file(utils.join_folder_prefix_ext( - artifacts_dir, 'cleanup', 'log')) LOG.info('Cleaning up') image_builder.cleanup() diff --git a/shaker/engine/utils.py b/shaker/engine/utils.py index 8ba792f..17f4c35 100644 --- a/shaker/engine/utils.py +++ b/shaker/engine/utils.py @@ -54,12 +54,15 @@ def validate_required_opts(conf, opts): raise cfg.RequiredOptError(opt.name) -def init_config_and_logging(opts): +def init_config_and_logging(opts, **conf_overrides): conf = cfg.CONF conf.register_cli_opts(opts) conf.register_opts(opts) logging.register_options(conf) + for k, v in conf_overrides.items(): + conf.set_override(k, v) + # requests to OpenStack services should be visible at DEBUG level default_log_levels = [l for l in conf.default_log_levels if not l.startswith('keystoneauth')] @@ -266,7 +269,15 @@ def copy_value_by_path(src, src_param, dst, dst_param): return False +class MisconfigurationException(Exception): + pass + + def pack_openstack_params(conf): + if not conf.os_auth_url: + raise MisconfigurationException( + 'OpenStack authentication endpoint is missing') + params = dict(auth=dict(username=conf.os_username, password=conf.os_password, auth_url=conf.os_auth_url), diff --git a/shaker/tests/test_server.py b/shaker/tests/test_server.py index b200461..42a20da 100644 --- a/shaker/tests/test_server.py +++ b/shaker/tests/test_server.py @@ -135,11 +135,13 @@ class TestServerPlayScenario(testtools.TestCase): s = 'Output should not contain record similar to: %s' % expected self.assertFalse(has, msg=s) + @mock.patch('shaker.engine.server._under_openstack') @mock.patch('shaker.engine.server.execute') @mock.patch('shaker.engine.deploy.Deployment') - def test_play_scenario(self, deploy_clz_mock, execute_mock): + def test_play_scenario(self, deploy_clz_mock, execute_mock, under_mock): deploy_obj = mock.Mock() deploy_clz_mock.return_value = deploy_obj + under_mock.return_value = False def _execute(output, quorum, execution, agents, matrix=None): output['records'].update({'UUID': {'id': 'UUID', 'status': 'ok'}}) @@ -194,10 +196,12 @@ class TestServerPlayScenario(testtools.TestCase): ['8.8.8.8', '8.8.4.4']) deploy_obj.cleanup.assert_called_once_with() + @mock.patch('shaker.engine.server._under_openstack') @mock.patch('shaker.engine.deploy.Deployment') - def test_play_scenario_no_agents(self, deploy_clz_mock): + def test_play_scenario_no_agents(self, deploy_clz_mock, under_mock): deploy_obj = mock.Mock() deploy_clz_mock.return_value = deploy_obj + under_mock.return_value = False deploy_obj.deploy.return_value = {} @@ -212,10 +216,12 @@ class TestServerPlayScenario(testtools.TestCase): server_endpoint='127.0.0.1:5999') deploy_obj.cleanup.assert_called_once_with() + @mock.patch('shaker.engine.server._under_openstack') @mock.patch('shaker.engine.deploy.Deployment') - def test_play_scenario_interrupted(self, deploy_clz_mock): + def test_play_scenario_interrupted(self, deploy_clz_mock, under_mock): deploy_obj = mock.Mock() deploy_clz_mock.return_value = deploy_obj + under_mock.return_value = False deploy_obj.deploy.side_effect = KeyboardInterrupt