When a test fails with exception, actually print out the reason why.

[riscv-tests.git] / debug / testlib.py

diff --git a/debug/testlib.py b/debug/testlib.py
index 2aab8ab484d70349a358547121968dfbf0d6b4e1..b81b4cdd7806358773e5c926d77eb22f3a7f15ec 100644 (file)
--- a/debug/testlib.py
+++ b/debug/testlib.py
@@ -116,6 +116,8 @@ class Spike(object):
         return self.process.wait(*args, **kwargs)
 
 class VcsSim(object):
+    logname = "simv.log"
+
     def __init__(self, sim_cmd=None, debug=False):
         if sim_cmd:
             cmd = shlex.split(sim_cmd)
@@ -125,10 +127,10 @@ class VcsSim(object):
         if debug:
             cmd[0] = cmd[0] + "-debug"
             cmd += ["+vcdplusfile=output/gdbserver.vpd"]
-        logfile = open("simv.log", "w")
+        logfile = open(self.logname, "w")
         logfile.write("+ %s\n" % " ".join(cmd))
         logfile.flush()
-        listenfile = open("simv.log", "r")
+        listenfile = open(self.logname, "r")
         listenfile.seek(0, 2)
         self.process = subprocess.Popen(cmd, stdin=subprocess.PIPE,
                 stdout=logfile, stderr=logfile)
@@ -200,29 +202,35 @@ class Openocd(object):
         self.process = subprocess.Popen(cmd, stdin=subprocess.PIPE,
                 stdout=logfile, stderr=logfile)
 
-        # Wait for OpenOCD to have made it through riscv_examine(). When using
-        # OpenOCD to communicate with a simulator this may take a long time,
-        # and gdb will time out when trying to connect if we attempt too early.
-        start = time.time()
-        messaged = False
-        while True:
-            log = open(Openocd.logname).read()
-            m = re.search("Listening on port (\d+) for gdb connections", log)
-            if m:
-                self.port = int(m.group(1))
-                break;
-
-            if not self.process.poll() is None:
-                header("OpenOCD log")
-                sys.stdout.write(log)
-                raise Exception(
-                        "OpenOCD exited before completing riscv_examine()")
-            if not messaged and time.time() - start > 1:
-                messaged = True
-                print "Waiting for OpenOCD to start..."
-            if time.time() - start > 60:
-                raise Exception("ERROR: Timed out waiting for OpenOCD to "
-                        "listen for gdb")
+        try:
+            # Wait for OpenOCD to have made it through riscv_examine(). When
+            # using OpenOCD to communicate with a simulator this may take a
+            # long time, and gdb will time out when trying to connect if we
+            # attempt too early.
+            start = time.time()
+            messaged = False
+            while True:
+                log = open(Openocd.logname).read()
+                m = re.search(r"Listening on port (\d+) for gdb connections",
+                        log)
+                if m:
+                    self.port = int(m.group(1))
+                    break
+
+                if not self.process.poll() is None:
+                    raise Exception(
+                            "OpenOCD exited before completing riscv_examine()")
+                if not messaged and time.time() - start > 1:
+                    messaged = True
+                    print "Waiting for OpenOCD to start..."
+                if time.time() - start > 60:
+                    raise Exception("ERROR: Timed out waiting for OpenOCD to "
+                            "listen for gdb")
+
+        except Exception:
+            header("OpenOCD log")
+            sys.stdout.write(log)
+            raise
 
     def __del__(self):
         try:
@@ -412,7 +420,7 @@ def run_tests(parsed, target, todo):
         log_name = os.path.join(parsed.logs, "%s-%s-%s.log" %
                 (time.strftime("%Y%m%d-%H%M%S"), type(target).__name__, name))
         log_fd = open(log_name, 'w')
-        print "Running", name, "...",
+        print "Running %s > %s ..." % (name, log_name),
         sys.stdout.flush()
         log_fd.write("Test: %s\n" % name)
         log_fd.write("Target: %s\n" % type(target).__name__)
@@ -426,8 +434,10 @@ def run_tests(parsed, target, todo):
             sys.stdout = real_stdout
             log_fd.write("Time elapsed: %.2fs\n" % (time.time() - start))
         print "%s in %.2fs" % (result, time.time() - start)
+        if result not in good_results and parsed.print_failures:
+            sys.stdout.write(open(log_name).read())
         sys.stdout.flush()
-        results.setdefault(result, []).append(name)
+        results.setdefault(result, []).append((name, log_name))
         count += 1
         if result not in good_results and parsed.fail_fast:
             break
@@ -440,17 +450,18 @@ def print_results(results):
         print "%d tests returned %s" % (len(value), key)
         if key not in good_results:
             result = 1
-            for test in value:
-                print "   ", test
+            for name, log_name in value:
+                print "   %s > %s" % (name, log_name)
 
     return result
 
 def add_test_run_options(parser):
-
     parser.add_argument("--logs", default="logs",
             help="Store logs in the specified directory.")
     parser.add_argument("--fail-fast", "-f", action="store_true",
             help="Exit as soon as any test fails.")
+    parser.add_argument("--print-failures", action="store_true",
+            help="When a test fails, print the log file to stdout.")
     parser.add_argument("test", nargs='*',
             help="Run only tests that are named here.")
     parser.add_argument("--gdb",
@@ -549,6 +560,8 @@ class BaseTest(object):
                 result = "fail"
             else:
                 result = "exception"
+                header ("Backtrace")
+                print e
             if isinstance(e, TestFailed):
                 header("Message")
                 print e.message