Have scenario tests retrive guest log on error

As an aid to debug guest failures, a Metaclass was added
to the TestRunner class that allows failed tests to
pull back and echo the guest log from 'registered'
instances.

This uses the guest-log feature that is available for
all datastores.

IDs for instances created in the tests were registered
to report on failures.

Two guest-log tests were also commented out, as they
seem to not work properly: see
https://bugs.launchpad.net/trove/+bug/1653614
This was discovered while testing the new retrieval
code.  Other tests were also modified so that
'SkipTest' exceptions would be raised properly.

Change-Id: I448bd2f0181351ef1536e20c41f9d45f95478587
Partial-Bug: 1652964

trove/tests/scenario/runners/__init__.py

@@ -1,3 +1,4 @@
 BUG_EJECT_VALID_MASTER = 1622014
 BUG_WRONG_API_VALIDATION = 1498573
 BUG_STOP_DB_IN_CLUSTER = 1645096
+BUG_UNAUTH_TEST_WRONG = 1653614

trove/tests/scenario/runners/backup_runners.py

@@ -313,6 +313,7 @@ class BackupRunner(TestRunner):
         self.assert_client_code(client, expected_http_code)
         self.assert_equal('BUILD', result.status,
                           'Unexpected instance status')
+        self.register_debug_inst_ids(result.id)
         return result.id
 
     def _restore_from_backup(self, client, backup_ref, suffix=''):

trove/tests/scenario/runners/cluster_runners.py

@@ -103,6 +103,8 @@ class ClusterRunner(TestRunner):
                 instances=instances_def, locality=locality)
             self.assert_client_code(client, expected_http_code)
             self._assert_cluster_values(cluster, expected_task_name)
+            for instance in cluster.instances:
+                self.register_debug_inst_ids(instance['id'])
         return cluster.id
 
     def run_cluster_create_wait(self,

trove/tests/scenario/runners/configuration_runners.py

@@ -533,6 +533,7 @@ class ConfigurationRunner(TestRunner):
             configuration=config_id)
         self.assert_client_code(client, 200)
         self.assert_equal("BUILD", result.status, 'Unexpected inst status')
+        self.register_debug_inst_ids(result.id)
         return result.id
 
     def run_wait_for_conf_instance(

trove/tests/scenario/runners/guest_log_runners.py

@@ -22,6 +22,8 @@ from trove.guestagent.common import operating_system
 from trove.guestagent import guest_log
 from trove.tests.config import CONFIG
 from trove.tests.scenario.helpers.test_helper import DataType
+from trove.tests.scenario import runners
+from trove.tests.scenario.runners.test_runners import SkipKnownBug
 from trove.tests.scenario.runners.test_runners import TestRunner
 
 
@@ -71,6 +73,7 @@ class GuestLogRunner(TestRunner):
         log_list = list(client.instances.log_list(self.instance_info.id))
         log_names = list(ll.name for ll in log_list)
         self.assert_list_elements_equal(expected_list, log_names)
+        self.register_debug_inst_ids(self.instance_info.id)
 
     def run_test_admin_log_list(self):
         self.assert_log_list(self.admin_client,
@@ -78,8 +81,9 @@ class GuestLogRunner(TestRunner):
 
     def run_test_log_show(self):
         log_pending = self._set_zero_or_none()
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_show(self.auth_client,
-                             self._get_exposed_user_log_name(),
+                             log_name,
                              expected_published=0,
                              expected_pending=log_pending)
 
@@ -294,54 +298,51 @@ class GuestLogRunner(TestRunner):
     def run_test_log_enable_sys(self,
                                 expected_exception=exceptions.BadRequest,
                                 expected_http_code=400):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_enable_fails(
             self.admin_client,
             expected_exception, expected_http_code,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def assert_log_enable_fails(self, client,
                                 expected_exception, expected_http_code,
                                 log_name):
-        self.assert_raises(expected_exception, None,
+        self.assert_raises(expected_exception, expected_http_code,
                            client, client.instances.log_enable,
                            self.instance_info.id, log_name)
-        # we may not be using the main client, so check explicitly here
-        self.assert_client_code(client, expected_http_code)
 
     def run_test_log_disable_sys(self,
                                  expected_exception=exceptions.BadRequest,
                                  expected_http_code=400):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_disable_fails(
             self.admin_client,
             expected_exception, expected_http_code,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def assert_log_disable_fails(self, client,
                                  expected_exception, expected_http_code,
                                  log_name, discard=None):
-        self.assert_raises(expected_exception, None,
+        self.assert_raises(expected_exception, expected_http_code,
                            client, client.instances.log_disable,
                            self.instance_info.id, log_name,
                            discard=discard)
-        # we may not be using the main client, so check explicitly here
-        self.assert_client_code(client, expected_http_code)
 
     def run_test_log_show_unauth_user(self,
                                       expected_exception=exceptions.NotFound,
                                       expected_http_code=404):
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_show_fails(
             self.unauth_client,
             expected_exception, expected_http_code,
-            self._get_exposed_user_log_name())
+            log_name)
 
     def assert_log_show_fails(self, client,
                               expected_exception, expected_http_code,
                               log_name):
-        self.assert_raises(expected_exception, None,
+        self.assert_raises(expected_exception, expected_http_code,
                            client, client.instances.log_show,
                            self.instance_info.id, log_name)
-        # we may not be using the main client, so check explicitly here
-        self.assert_client_code(client, expected_http_code)
 
     def run_test_log_list_unauth_user(self,
                                       expected_exception=exceptions.NotFound,
@@ -351,73 +352,85 @@ class GuestLogRunner(TestRunner):
                            client, client.instances.log_list,
                            self.instance_info.id)
 
-    def run_test_log_generator_unauth_user(self):
+    def run_test_log_generator_unauth_user(
+            self, expected_exception=exceptions.NotFound,
+            expected_http_code=404):
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_generator_unauth_user(
-            self.unauth_client, self._get_exposed_user_log_name())
+            self.unauth_client, log_name,
+            expected_exception, expected_http_code)
 
-    def assert_log_generator_unauth_user(self, client, log_name, publish=None):
+    def assert_log_generator_unauth_user(self, client, log_name,
-        try:
+                                         expected_exception,
-            client.instances.log_generator(
+                                         expected_http_code,
-                self.instance_info.id, log_name, publish=publish)
+                                         publish=None):
-            raise("Client allowed unauthorized access to log_generator")
+        raise SkipKnownBug(runners.BUG_UNAUTH_TEST_WRONG)
-        except Exception:
+        # self.assert_raises(expected_exception, expected_http_code,
-            pass
+        #                    client, client.instances.log_generator,
+        #                    self.instance_info.id, log_name, publish=publish)
 
-    def run_test_log_generator_publish_unauth_user(self):
+    def run_test_log_generator_publish_unauth_user(
+            self, expected_exception=exceptions.NotFound,
+            expected_http_code=404):
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_generator_unauth_user(
-            self.unauth_client, self._get_exposed_user_log_name(),
+            self.unauth_client, log_name,
+            expected_exception, expected_http_code,
             publish=True)
 
     def run_test_log_show_unexposed_user(
             self, expected_exception=exceptions.BadRequest,
             expected_http_code=400):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_show_fails(
             self.auth_client,
             expected_exception, expected_http_code,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def run_test_log_enable_unexposed_user(
             self, expected_exception=exceptions.BadRequest,
             expected_http_code=400):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_enable_fails(
             self.auth_client,
             expected_exception, expected_http_code,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def run_test_log_disable_unexposed_user(
             self, expected_exception=exceptions.BadRequest,
             expected_http_code=400):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_disable_fails(
             self.auth_client,
             expected_exception, expected_http_code,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def run_test_log_publish_unexposed_user(
             self, expected_exception=exceptions.BadRequest,
             expected_http_code=400):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_publish_fails(
             self.auth_client,
             expected_exception, expected_http_code,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def assert_log_publish_fails(self, client,
                                  expected_exception, expected_http_code,
                                  log_name,
                                  disable=None, discard=None):
-        self.assert_raises(expected_exception, None,
+        self.assert_raises(expected_exception, expected_http_code,
                            client, client.instances.log_publish,
                            self.instance_info.id, log_name,
                            disable=disable, discard=discard)
-        # we may not be using the main client, so check explicitly here
-        self.assert_client_code(client, expected_http_code)
 
     def run_test_log_discard_unexposed_user(
             self, expected_exception=exceptions.BadRequest,
             expected_http_code=400):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_discard_fails(
             self.auth_client,
             expected_exception, expected_http_code,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def assert_log_discard_fails(self, client,
                                  expected_exception, expected_http_code,
@@ -615,8 +628,9 @@ class GuestLogRunner(TestRunner):
                 expected_published=0, expected_pending=1)
 
     def run_test_log_show_after_stop_details(self):
+        log_name = self._get_exposed_user_log_name()
         self.stopped_log_details = self.auth_client.instances.log_show(
-            self.instance_info.id, self._get_exposed_user_log_name())
+            self.instance_info.id, log_name)
         self.assert_is_not_none(self.stopped_log_details)
 
     def run_test_add_data_again_after_stop(self):
@@ -627,8 +641,9 @@ class GuestLogRunner(TestRunner):
         self.test_helper.verify_data(DataType.micro3, self.get_instance_host())
 
     def run_test_log_show_after_stop(self):
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_show(
-            self.auth_client, self._get_exposed_user_log_name(),
+            self.auth_client, log_name,
             expected_published=self.stopped_log_details.published,
             expected_pending=self.stopped_log_details.pending)
 
@@ -638,9 +653,10 @@ class GuestLogRunner(TestRunner):
         if self.test_helper.log_enable_requires_restart():
             expected_status = guest_log.LogStatus.Restart_Required.name
 
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_enable(
             self.auth_client,
-            self._get_exposed_user_log_name(),
+            log_name,
             expected_status=expected_status,
             expected_published=0, expected_pending=expected_pending)
 
@@ -665,16 +681,18 @@ class GuestLogRunner(TestRunner):
         expected_status = guest_log.LogStatus.Disabled.name
         if self.test_helper.log_enable_requires_restart():
             expected_status = guest_log.LogStatus.Restart_Required.name
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_disable(
             self.auth_client,
-            self._get_exposed_user_log_name(), discard=True,
+            log_name, discard=True,
             expected_status=expected_status,
             expected_published=0, expected_pending=1)
 
     def run_test_log_show_sys(self):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_show(
             self.admin_client,
-            self._get_unexposed_sys_log_name(),
+            log_name,
             expected_type=guest_log.LogType.SYS.name,
             expected_status=guest_log.LogStatus.Ready.name,
             expected_published=0, expected_pending=1)
@@ -699,39 +717,45 @@ class GuestLogRunner(TestRunner):
             expected_pending=1)
 
     def run_test_log_generator_sys(self):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_generator(
             self.admin_client,
-            self._get_unexposed_sys_log_name(),
+            log_name,
             lines=4, expected_lines=4)
 
     def run_test_log_generator_publish_sys(self):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_generator(
             self.admin_client,
-            self._get_unexposed_sys_log_name(), publish=True,
+            log_name, publish=True,
             lines=4, expected_lines=4)
 
     def run_test_log_generator_swift_client_sys(self):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_generator(
             self.admin_client,
-            self._get_unexposed_sys_log_name(), publish=True,
+            log_name, publish=True,
             lines=4, expected_lines=4,
             swift_client=self.swift_client)
 
     def run_test_log_save_sys(self):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_test_log_save(
             self.admin_client,
-            self._get_unexposed_sys_log_name())
+            log_name)
 
     def run_test_log_save_publish_sys(self):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_test_log_save(
             self.admin_client,
-            self._get_unexposed_sys_log_name(),
+            log_name,
             publish=True)
 
     def run_test_log_discard_sys(self):
+        log_name = self._get_unexposed_sys_log_name()
         self.assert_log_discard(
             self.admin_client,
-            self._get_unexposed_sys_log_name(),
+            log_name,
             expected_type=guest_log.LogType.SYS.name,
             expected_status=guest_log.LogStatus.Ready.name,
             expected_published=0, expected_pending=1)
@@ -740,7 +764,8 @@ class GuestLogRunner(TestRunner):
 class CassandraGuestLogRunner(GuestLogRunner):
 
     def run_test_log_show(self):
+        log_name = self._get_exposed_user_log_name()
         self.assert_log_show(self.auth_client,
-                             self._get_exposed_user_log_name(),
+                             log_name,
                              expected_published=0,
                              expected_pending=None)

trove/tests/scenario/runners/instance_create_runners.py

@@ -197,6 +197,7 @@ class InstanceCreateRunner(TestRunner):
                 locality=locality)
             self.assert_client_code(client, expected_http_code)
             self.assert_instance_action(instance.id, expected_states[0:1])
+            self.register_debug_inst_ids(instance.id)
 
         instance_info.id = instance.id
 

trove/tests/scenario/runners/module_runners.py

@@ -949,6 +949,7 @@ class ModuleRunner(TestRunner):
             modules=[module_id],
         )
         self.assert_client_code(client, expected_http_code)
+        self.register_debug_inst_ids(inst.id)
         return inst.id
 
     def run_module_delete_applied(

trove/tests/scenario/runners/replication_runners.py

@@ -72,6 +72,7 @@ class ReplicationRunner(TestRunner):
             nics=self.instance_info.nics,
             locality='anti-affinity').id
         self.assert_client_code(client, expected_http_code)
+        self.register_debug_inst_ids(self.non_affinity_master_id)
 
     def run_create_single_replica(self, expected_http_code=200):
         self.master_backup_count = len(
@@ -91,6 +92,7 @@ class ReplicationRunner(TestRunner):
             nics=self.instance_info.nics,
             replica_count=replica_count)
         self.assert_client_code(client, expected_http_code)
+        self.register_debug_inst_ids(replica.id)
         return replica.id
 
     def run_wait_for_single_replica(self, expected_states=['BUILD', 'ACTIVE']):
@@ -153,6 +155,7 @@ class ReplicationRunner(TestRunner):
             replica_of=self.non_affinity_master_id,
             replica_count=1).id
         self.assert_client_code(client, expected_http_code)
+        self.register_debug_inst_ids(self.non_affinity_repl_id)
 
     def run_create_multiple_replicas(self, expected_http_code=200):
         self.replica_2_id = self.assert_replica_create(

trove/tests/scenario/runners/test_runners.py

@@ -18,7 +18,9 @@ import inspect
 import netaddr
 import os
 import proboscis
+import six
 import time as timer
+import types
 
 from oslo_config.cfg import NoSuchOptError
 from proboscis import asserts
@@ -179,6 +181,105 @@ class InstanceTestInfo(object):
         self.helper_database = None  # Test helper database if exists.
 
 
+class LogOnFail(type):
+
+    """Class to log info on failure.
+    This will decorate all methods that start with 'run_' with a log wrapper
+    that will do a show and attempt to pull back the guest log on all
+    registered IDs.
+    Use by setting up as a metaclass and calling the following:
+       add_inst_ids(): Instance ID or list of IDs to report on
+       set_client(): Admin client object
+       set_report(): Report object
+    The TestRunner class shows how this can be done in register_debug_inst_ids.
+    """
+
+    _data = {}
+
+    def __new__(mcs, name, bases, attrs):
+        for attr_name, attr_value in attrs.items():
+            if (isinstance(attr_value, types.FunctionType) and
+                    attr_name.startswith('run_')):
+                attrs[attr_name] = mcs.log(attr_value)
+        return super(LogOnFail, mcs).__new__(mcs, name, bases, attrs)
+
+    @classmethod
+    def get_inst_ids(mcs):
+        return set(mcs._data.get('inst_ids', []))
+
+    @classmethod
+    def add_inst_ids(mcs, inst_ids):
+        if not utils.is_collection(inst_ids):
+            inst_ids = [inst_ids]
+        debug_inst_ids = mcs.get_inst_ids()
+        debug_inst_ids |= set(inst_ids)
+        mcs._data['inst_ids'] = debug_inst_ids
+
+    @classmethod
+    def reset_inst_ids(mcs):
+        mcs._data['inst_ids'] = []
+
+    @classmethod
+    def set_client(mcs, client):
+        mcs._data['client'] = client
+
+    @classmethod
+    def get_client(mcs):
+        return mcs._data['client']
+
+    @classmethod
+    def set_report(mcs, report):
+        mcs._data['report'] = report
+
+    @classmethod
+    def get_report(mcs):
+        return mcs._data['report']
+
+    @classmethod
+    def log(mcs, fn):
+
+        def wrapper(*args, **kwargs):
+            inst_ids = mcs.get_inst_ids()
+            client = mcs.get_client()
+            report = mcs.get_report()
+            try:
+                return fn(*args, **kwargs)
+            except proboscis.SkipTest:
+                raise
+            except Exception as test_ex:
+                msg_prefix = "*** LogOnFail: "
+                if inst_ids:
+                    report.log(msg_prefix + "Exception detected, "
+                               "dumping info for IDs: %s." % inst_ids)
+                else:
+                    report.log(msg_prefix + "Exception detected, "
+                               "but no instance IDs are registered to log.")
+
+                for inst_id in inst_ids:
+                    try:
+                        client.instances.get(inst_id)
+                    except Exception as ex:
+                        report.log(msg_prefix + "Error in instance show "
+                                   "for %s:\n%s" % (inst_id, ex))
+                    try:
+                        log_gen = client.instances.log_generator(
+                            inst_id, 'guest',
+                            publish=True, lines=0, swift=None)
+                        log_contents = "".join([chunk for chunk in log_gen()])
+                        report.log(msg_prefix + "Guest log for %s:\n%s" %
+                                   (inst_id, log_contents))
+                    except Exception as ex:
+                        report.log(msg_prefix + "Error in guest log "
+                                   "retrieval for %s:\n%s" % (inst_id, ex))
+
+                # Only report on the first error that occurs
+                mcs.reset_inst_ids()
+                raise test_ex
+
+        return wrapper
+
+
+@six.add_metaclass(LogOnFail)
 class TestRunner(object):
 
     """
@@ -246,6 +347,14 @@ class TestRunner(object):
         self._test_helper = None
         self._servers = {}
 
+        # Attempt to register the main instance.  If it doesn't
+        # exist, this will still set the 'report' and 'client' objects
+        # correctly in LogOnFail
+        inst_ids = []
+        if hasattr(self.instance_info, 'id') and self.instance_info.id:
+            inst_ids = [self.instance_info.id]
+        self.register_debug_inst_ids(inst_ids)
+
     @classmethod
     def fail(cls, message):
         asserts.fail(message)
@@ -372,6 +481,15 @@ class TestRunner(object):
     def nova_client(self):
         return create_nova_client(self.instance_info.user)
 
+    def register_debug_inst_ids(self, inst_ids):
+        """Method to 'register' an instance ID (or list of instance IDs)
+        for debug purposes on failure.  Note that values are only appended
+        here, not overridden.  The LogOnFail class will handle 'missing' IDs.
+        """
+        LogOnFail.add_inst_ids(inst_ids)
+        LogOnFail.set_client(self.admin_client)
+        LogOnFail.set_report(self.report)
+
     def get_client_tenant(self, client):
         tenant_name = client.real_client.client.tenant
         service_url = client.real_client.client.service_url