Report what failed in metabox tests (infra) (#1655)

* Init

* Report steps that failed

* Actually return something in all operators and check for False

This will avoid me breaking again Metabox with None == True, None means
an api forgot to return, lets mark the step as failed

* Also catch NotFound from Put

* Better logging

Co-authored-by: Fernando Bravo <[email protected]>

* Also return on Send, Sleep and Signal

---------

Co-authored-by: Fernando Bravo <[email protected]>

Author: Hook25

metabox/metabox/core/actions.py

@@ -20,6 +20,7 @@
 This module defines the Actions classes.
 
 """
+import pprint
 
 __all__ = [
     "Start",
@@ -52,7 +53,17 @@ def __init__(self, *args, **kwargs):
 
     def __call__(self, scn):
         assert self.handler is not None
-        getattr(scn, self.handler)(*self.args, **self.kwargs)
+        return getattr(scn, self.handler)(*self.args, **self.kwargs)
+
+    def __str__(self):
+        kwargs_str = ", ".join(
+            f"{key}={pprint.pformat(value)}"
+            for key, value in self.kwargs.items()
+        )
+        args_str = ", ".join(pprint.pformat(arg) for arg in self.args)
+        # if both are defined, separate them with a comma, else nothing
+        arg_repr_str = ", ".join(arg for arg in (args_str, kwargs_str) if arg)
+        return "{}({})".format(type(self).__name__, arg_repr_str)
 
 
 class Start(ActionBase):

metabox/metabox/core/runner.py

@@ -284,15 +284,20 @@ def run(self):
                 )
             )
             scn.run()
-            if not scn.has_passed():
+            if scn.failures:
                 self.failed = True
                 logger.error(scenario_description + " scenario has failed.")
 
-                # let's escape < from the output to avoid confusing loguru
+                # let's escape < from the all outputs to avoid confusing loguru
                 # loguru assumes that <> is used for colorizing
-                output = scn.get_output_streams().strip().replace("<", r"\<")
+                logger.error("The following steps failed")
+                for failed_steps in scn.failures:
+                    step = str(failed_steps).replace("<", r"\<")
+                    logger.error("  - {}".format(step))
 
+                output = scn.get_output_streams().strip().replace("<", r"\<")
                 logger.error("Scenario output:\n" + output)
+
                 if self.hold_on_fail:
                     if scn.mode == "remote":
                         msg = (

metabox/metabox/core/scenario.py

@@ -27,6 +27,8 @@
 import time
 import shlex
 
+from pylxd.exceptions import NotFound
+
 from metabox.core.actions import Start, Expect, Send, SelectTestPlan
 from metabox.core.aggregator import aggregator
 
@@ -70,7 +72,7 @@ def __init__(
         self.agent_machine = None
         self.agent_revision = agent_revision
         self.start_session = True
-        self._checks = []
+        self.failures = []
         self._ret_code = None
         self._stdout = ""
         self._stderr = ""
@@ -82,10 +84,6 @@ def get_output_streams(self):
             return self._pts.stdout_data_full
         return self._outstr_full
 
-    def has_passed(self):
-        """Check whether all the assertions passed."""
-        return all(self._checks)
-
     def run(self):
         # Simple scenarios don't need to specify a START step
         # If there's no START step, add one unless the scenario
@@ -109,9 +107,11 @@ def run(self):
                         break
                 step.kwargs["interactive"] = interactive
             try:
-                step(self)
-            except (TimeoutError, ConnectionError):
-                self._checks.append(False)
+                # step that fail explicitly return false or raise an exception
+                if not step(self):
+                    self.failures.append(step)
+            except (TimeoutError, ConnectionError, NotFound):
+                self.failures.append(step)
                 break
         if self._pts:
             self._stdout = self._pts.stdout_data_full
@@ -126,17 +126,15 @@ def _assign_outcome(self, ret_code, stdout, stderr, outstr_full):
         self._stderr = stderr
         self._outstr_full = outstr_full
 
-    # TODO: add storing of what actually failed in the assert methods
     def assert_printed(self, pattern):
         """
         Check if during Checkbox execution a line produced that matches the
         pattern.
         :param patter: regular expresion to check against the lines.
         """
         regex = re.compile(pattern)
-        self._checks.append(
-            bool(regex.search(self._stdout))
-            or bool(regex.search(self._stderr))
+        return bool(regex.search(self._stdout)) or bool(
+            regex.search(self._stderr)
         )
 
     def assert_not_printed(self, pattern):
@@ -150,20 +148,20 @@ def assert_not_printed(self, pattern):
             found = regex.search(self._pts.stdout_data_full)
         else:
             found = regex.search(self._stdout) or regex.search(self._stderr)
-        self._checks.append(not found)
+        return not found
 
     def assert_ret_code(self, code):
         """Check if Checkbox returned given code."""
-        self._checks.append(code == self._ret_code)
+        return code == self._ret_code
 
     def assertIn(self, member, container):
-        self._checks.append(member in container)
+        return member in container
 
     def assertEqual(self, first, second):
-        self._checks.append(first == second)
+        return first == second
 
     def assertNotEqual(self, first, second):
-        self._checks.append(first != second)
+        return first != second
 
     def start(self, cmd="", interactive=False, timeout=0):
         if self.mode == "remote":
@@ -185,6 +183,7 @@ def start(self, cmd="", interactive=False, timeout=0):
                 self._pts = outcome
             else:
                 self._assign_outcome(*outcome)
+        return True  # return code is checked with a different operator
 
     def start_all(self, interactive=False, timeout=0):
         self.start_agent()
@@ -214,28 +213,33 @@ def start_agent(self, force=False):
     def expect(self, data, timeout=60):
         assert self._pts is not None
         outcome = self._pts.expect(data, timeout)
-        self._checks.append(outcome)
+        return outcome
 
     def expect_not(self, data, timeout=60):
         assert self._pts is not None
         outcome = self._pts.expect_not(data, timeout)
-        self._checks.append(outcome)
+        return outcome
 
     def send(self, data):
         assert self._pts is not None
         self._pts.send(data.encode("utf-8"), binary=True)
+        # send raises an exception on failure
+        return True
 
     def sleep(self, secs):
         time.sleep(secs)
+        return True
 
     def signal(self, signal):
         assert self._pts is not None
         self._pts.send_signal(signal)
+        # same as send, this uses send under the hood
+        return True
 
     def select_test_plan(self, testplan_id, timeout=60):
         assert self._pts is not None
         outcome = self._pts.select_test_plan(testplan_id, timeout)
-        self._checks.append(outcome)
+        return outcome
 
     def run_cmd(self, cmd, env={}, interactive=False, timeout=0, target="all"):
         if self.mode == "remote":
@@ -268,6 +272,7 @@ def reboot(self, timeout=0, target="all"):
                 self.agent_machine.reboot(timeout)
         else:
             self.local_machine.reboot(timeout)
+        return True
 
     def put(self, filepath, data, mode=None, uid=1000, gid=1000, target="all"):
         if self.mode == "remote":
@@ -280,6 +285,8 @@ def put(self, filepath, data, mode=None, uid=1000, gid=1000, target="all"):
                 self.agent_machine.put(filepath, data, mode, uid, gid)
         else:
             self.local_machine.put(filepath, data, mode, uid, gid)
+        # put raises an exception on failure
+        return True
 
     def switch_on_networking(self, target="all"):
         if self.mode == "remote":
@@ -292,6 +299,7 @@ def switch_on_networking(self, target="all"):
                 self.agent_machine.switch_on_networking()
         else:
             self.local_machine.switch_on_networking()
+        return True
 
     def switch_off_networking(self, target="all"):
         if self.mode == "remote":
@@ -304,6 +312,7 @@ def switch_off_networking(self, target="all"):
                 self.agent_machine.switch_off_networking()
         else:
             self.local_machine.switch_off_networking()
+        return True
 
     def stop_agent(self):
         return self.agent_machine.stop_agent()
@@ -322,15 +331,15 @@ def mktree(self, path, privileged=False, timeout=0, target="all"):
         if privileged:
             cmd = ["sudo"] + cmd
         cmd_str = shlex.join(cmd)
-        self.run_cmd(cmd_str, target=target, timeout=timeout)
+        return self.run_cmd(cmd_str, target=target, timeout=timeout)
 
     def run_manage(self, args, timeout=0, target="all"):
         """
         Runs the manage.py script with some arguments
         """
         path = "/home/ubuntu/checkbox/metabox/metabox/metabox-provider"
         cmd = f"bash -c 'cd {path} ; python3 manage.py {args}'"
-        self.run_cmd(cmd, target=target, timeout=timeout)
+        return self.run_cmd(cmd, target=target, timeout=timeout)
 
     def assert_in_file(self, pattern, path):
         """
@@ -344,4 +353,4 @@ def assert_in_file(self, pattern, path):
 
         result = self.run_cmd(f"cat {path}")
         regex = re.compile(pattern)
-        self._checks.append(bool(regex.search(result.stdout)))
+        return bool(regex.search(result.stdout))