[Qemu-devel] [RFC 2/6] device-crash-test: Log detailed info on success too

[Eduardo Habkost]

Instead of making checkOneCase() return None on success, return
detailed info even if no problems were found.  This will make
handling of device_add errors simpler, and improve debug output.

As logFailure() won't handle only failures, rename it to
logResult() and make it a bit more flexible about missing fields.

Signed-off-by: Eduardo Habkost <address@hidden>
---
 scripts/device-crash-test | 61 ++++++++++++++++++++++-------------------------
 1 file changed, 29 insertions(+), 32 deletions(-)

diff --git a/scripts/device-crash-test b/scripts/device-crash-test
index 598720ffa9..782d7fd6c2 100755
--- a/scripts/device-crash-test
+++ b/scripts/device-crash-test
@@ -234,6 +234,9 @@ ERROR_WHITELIST = [
     {'exitcode':-11, 'device':'arm-gicv3', 'loglevel':logging.ERROR, 
'expected':True},
     {'exitcode':-11, 'machine':'isapc', 'device':'.*-iommu', 
'loglevel':logging.ERROR, 'expected':True},
 
+    # 0 exit code means test succeeded, so we just log it as logging.DEBUG:
+    {'exitcode':0},
+
     # everything else (including SIGABRT and SIGSEGV) will be a fatal error:
     {'exitcode':None, 'fatal':True, 'loglevel':logging.FATAL},
 ]
@@ -381,8 +384,7 @@ def getBinaryInfo(args, binary):
 def checkOneCase(args, testcase):
     """Check one specific case
 
-    Returns a dictionary containing failure information on error,
-    or None on success
+    Returns a dictionary containing results of test case.
     """
     binary = testcase['binary']
     accel = testcase['accel']
@@ -397,26 +399,21 @@ def checkOneCase(args, testcase):
     dbg("will launch QEMU: %s", cmdline)
     vm = QEMUMachine(binary=binary, args=args)
 
-    exc_traceback = None
+    r = {'testcase':testcase,
+         'cmdline':cmdline}
+
     try:
         vm.launch()
     except KeyboardInterrupt:
         raise
     except:
-        exc_traceback = traceback.format_exc()
+        r['exc_traceback'] = traceback.format_exc()
         dbg("Exception while running test case")
-    finally:
-        vm.shutdown()
-        ec = vm.exitcode()
-        log = vm.get_log()
-
-    if exc_traceback is not None or ec != 0:
-        return {'exc_traceback':exc_traceback,
-                'exitcode':ec,
-                'log':log,
-                'testcase':testcase,
-                'cmdline':cmdline}
 
+    vm.shutdown()
+    r['exitcode'] = vm.exitcode()
+    r['log'] = vm.get_log()
+    return r
 
 def binariesToTest(args, testcase):
     if args.qemu:
@@ -490,17 +487,18 @@ def casesToTest(args, testcase):
     return cases
 
 
-def logFailure(f, level):
+def logResult(f, level):
     t = f['testcase']
-    logger.log(level, "failed: %s", formatTestCase(t))
+    logger.log(level, "result: %s", formatTestCase(t))
     logger.log(level, "cmdline: %s", f['cmdline'])
-    for l in f['log'].strip().split('\n'):
+    for l in f.get('log', '').strip().split('\n'):
         logger.log(level, "log: %s", l)
-    logger.log(level, "exit code: %r", f['exitcode'])
-    if f['exc_traceback']:
+    logger.log(level, "exit code: %r", f.get('exitcode'))
+    if 'exc_traceback' in f:
         logger.log(level, "exception:")
         for l in f['exc_traceback'].split('\n'):
             logger.log(level, "  %s", l.rstrip('\n'))
+    dbg('raw result dictionary: %r', f)
 
 
 def main():
@@ -579,18 +577,17 @@ def main():
         except KeyboardInterrupt:
             break
 
-        if f:
-            i, wl = checkResultWhitelist(f)
-            dbg("testcase: %r, whitelist match: %r", t, wl)
-            wl_stats.setdefault(i, []).append(f)
-            level = wl.get('loglevel', logging.DEBUG)
-            logFailure(f, level)
-            if wl.get('fatal') or (args.strict and level >= logging.WARN):
-                fatal_failures.append(f)
-        else:
-            dbg("success: %s", formatTestCase(t))
-            if expected_match:
-                logger.warn("Didn't fail as expected: %s", formatTestCase(t))
+        i, wl = checkResultWhitelist(f)
+        dbg("testcase: %r, whitelist match: %r", t, wl)
+        wl_stats.setdefault(i, []).append(f)
+        level = wl.get('loglevel', logging.DEBUG)
+        logResult(f, level)
+
+        if wl.get('fatal') or (args.strict and level >= logging.WARN):
+            fatal_failures.append(f)
+
+        if expected_match and expected_match[0] != i:
+            logger.warn("Didn't fail as expected: %s", formatTestCase(t))
 
     logger.info("Total: %d test cases", total)
     if skipped:
-- 
2.13.5