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

@@ -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"]

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()
 

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),

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