Merged the hostap_2.6 updates, and the Leap of Faith work, from the hostap_update...
[mech_eap.git] / libeap / tests / hwsim / vm / parallel-vm.py
diff --git a/libeap/tests/hwsim/vm/parallel-vm.py b/libeap/tests/hwsim/vm/parallel-vm.py
new file mode 100755 (executable)
index 0000000..40bbb76
--- /dev/null
@@ -0,0 +1,535 @@
+#!/usr/bin/env python2
+#
+# Parallel VM test case executor
+# Copyright (c) 2014-2015, Jouni Malinen <j@w1.fi>
+#
+# This software may be distributed under the terms of the BSD license.
+# See README for more details.
+
+import curses
+import fcntl
+import logging
+import os
+import subprocess
+import sys
+import time
+
+logger = logging.getLogger()
+
+# Test cases that take significantly longer time to execute than average.
+long_tests = [ "ap_roam_open",
+               "wpas_mesh_password_mismatch_retry",
+               "wpas_mesh_password_mismatch",
+               "hostapd_oom_wpa2_psk_connect",
+               "ap_hs20_fetch_osu_stop",
+               "ap_roam_wpa2_psk",
+               "ibss_wpa_none_ccmp",
+               "nfc_wps_er_handover_pk_hash_mismatch_sta",
+               "go_neg_peers_force_diff_freq",
+               "p2p_cli_invite",
+               "sta_ap_scan_2b",
+               "ap_pmf_sta_unprot_deauth_burst",
+               "ap_bss_add_remove_during_ht_scan",
+               "wext_scan_hidden",
+               "autoscan_exponential",
+               "nfc_p2p_client",
+               "wnm_bss_keep_alive",
+               "ap_inactivity_disconnect",
+               "scan_bss_expiration_age",
+               "autoscan_periodic",
+               "discovery_group_client",
+               "concurrent_p2pcli",
+               "ap_bss_add_remove",
+               "wpas_ap_wps",
+               "wext_pmksa_cache",
+               "ibss_wpa_none",
+               "ap_ht_40mhz_intolerant_ap",
+               "ibss_rsn",
+               "discovery_pd_retries",
+               "ap_wps_setup_locked_timeout",
+               "ap_vht160",
+               "dfs_radar",
+               "dfs",
+               "dfs_ht40_minus",
+               "grpform_cred_ready_timeout",
+               "hostapd_oom_wpa2_eap_connect",
+               "wpas_ap_dfs",
+               "autogo_many",
+               "hostapd_oom_wpa2_eap",
+               "ibss_open",
+               "proxyarp_open_ebtables",
+               "radius_failover",
+               "obss_scan_40_intolerant",
+               "dbus_connect_oom",
+               "proxyarp_open",
+               "ap_wps_iteration",
+               "ap_wps_iteration_error",
+               "ap_wps_pbc_timeout",
+               "ap_wps_http_timeout",
+               "p2p_go_move_reg_change",
+               "p2p_go_move_active",
+               "p2p_go_move_scm",
+               "p2p_go_move_scm_peer_supports",
+               "p2p_go_move_scm_peer_does_not_support",
+               "p2p_go_move_scm_multi" ]
+
+def get_failed(vm):
+    failed = []
+    for i in range(num_servers):
+        failed += vm[i]['failed']
+    return failed
+
+def vm_read_stdout(vm, i):
+    global total_started, total_passed, total_failed, total_skipped
+    global rerun_failures
+
+    ready = False
+    try:
+        out = vm['proc'].stdout.read()
+    except:
+        return False
+    logger.debug("VM[%d] stdout.read[%s]" % (i, out))
+    pending = vm['pending'] + out
+    lines = []
+    while True:
+        pos = pending.find('\n')
+        if pos < 0:
+            break
+        line = pending[0:pos].rstrip()
+        pending = pending[(pos + 1):]
+        logger.debug("VM[%d] stdout full line[%s]" % (i, line))
+        if line.startswith("READY"):
+            ready = True
+        elif line.startswith("PASS"):
+            ready = True
+            total_passed += 1
+        elif line.startswith("FAIL"):
+            ready = True
+            total_failed += 1
+            vals = line.split(' ')
+            if len(vals) < 2:
+                logger.info("VM[%d] incomplete FAIL line: %s" % (i, line))
+                name = line
+            else:
+                name = vals[1]
+            logger.debug("VM[%d] test case failed: %s" % (i, name))
+            vm['failed'].append(name)
+        elif line.startswith("NOT-FOUND"):
+            ready = True
+            total_failed += 1
+            logger.info("VM[%d] test case not found" % i)
+        elif line.startswith("SKIP"):
+            ready = True
+            total_skipped += 1
+        elif line.startswith("START"):
+            total_started += 1
+            if len(vm['failed']) == 0:
+                vals = line.split(' ')
+                if len(vals) >= 2:
+                    vm['fail_seq'].append(vals[1])
+        vm['out'] += line + '\n'
+        lines.append(line)
+    vm['pending'] = pending
+    return ready
+
+def show_progress(scr):
+    global num_servers
+    global vm
+    global dir
+    global timestamp
+    global tests
+    global first_run_failures
+    global total_started, total_passed, total_failed, total_skipped
+
+    total_tests = len(tests)
+    logger.info("Total tests: %d" % total_tests)
+
+    scr.leaveok(1)
+    scr.addstr(0, 0, "Parallel test execution status", curses.A_BOLD)
+    for i in range(0, num_servers):
+        scr.addstr(i + 1, 0, "VM %d:" % (i + 1), curses.A_BOLD)
+        scr.addstr(i + 1, 10, "starting VM")
+    scr.addstr(num_servers + 1, 0, "Total:", curses.A_BOLD)
+    scr.addstr(num_servers + 1, 20, "TOTAL={} STARTED=0 PASS=0 FAIL=0 SKIP=0".format(total_tests))
+    scr.refresh()
+
+    completed_first_pass = False
+    rerun_tests = []
+
+    while True:
+        running = False
+        first_running = False
+        updated = False
+
+        for i in range(0, num_servers):
+            if completed_first_pass:
+                continue
+            if vm[i]['first_run_done']:
+                continue
+            if not vm[i]['proc']:
+                continue
+            if vm[i]['proc'].poll() is not None:
+                vm[i]['proc'] = None
+                scr.move(i + 1, 10)
+                scr.clrtoeol()
+                log = '{}/{}.srv.{}/console'.format(dir, timestamp, i + 1)
+                with open(log, 'r') as f:
+                    if "Kernel panic" in f.read():
+                        scr.addstr("kernel panic")
+                        logger.info("VM[%d] kernel panic" % i)
+                    else:
+                        scr.addstr("unexpected exit")
+                        logger.info("VM[%d] unexpected exit" % i)
+                updated = True
+                continue
+
+            running = True
+            first_running = True
+            try:
+                err = vm[i]['proc'].stderr.read()
+                vm[i]['err'] += err
+                logger.debug("VM[%d] stderr.read[%s]" % (i, err))
+            except:
+                pass
+
+            if vm_read_stdout(vm[i], i):
+                scr.move(i + 1, 10)
+                scr.clrtoeol()
+                updated = True
+                if not tests:
+                    vm[i]['first_run_done'] = True
+                    scr.addstr("completed first round")
+                    logger.info("VM[%d] completed first round" % i)
+                    continue
+                else:
+                    name = tests.pop(0)
+                    vm[i]['proc'].stdin.write(name + '\n')
+                    scr.addstr(name)
+                    logger.debug("VM[%d] start test %s" % (i, name))
+
+        if not first_running and not completed_first_pass:
+            logger.info("First round of testing completed")
+            if tests:
+                logger.info("Unexpected test cases remaining from first round: " + str(tests))
+                raise Exception("Unexpected test cases remaining from first round")
+            completed_first_pass = True
+            for name in get_failed(vm):
+                if rerun_failures:
+                    rerun_tests.append(name)
+                first_run_failures.append(name)
+
+        for i in range(num_servers):
+            if not completed_first_pass:
+                continue
+            if not vm[i]['proc']:
+                continue
+            if vm[i]['proc'].poll() is not None:
+                vm[i]['proc'] = None
+                scr.move(i + 1, 10)
+                scr.clrtoeol()
+                log = '{}/{}.srv.{}/console'.format(dir, timestamp, i + 1)
+                with open(log, 'r') as f:
+                    if "Kernel panic" in f.read():
+                        scr.addstr("kernel panic")
+                        logger.info("VM[%d] kernel panic" % i)
+                    else:
+                        scr.addstr("completed run")
+                        logger.info("VM[%d] completed run" % i)
+                updated = True
+                continue
+
+            running = True
+            try:
+                err = vm[i]['proc'].stderr.read()
+                vm[i]['err'] += err
+                logger.debug("VM[%d] stderr.read[%s]" % (i, err))
+            except:
+                pass
+
+            ready = False
+            if vm[i]['first_run_done']:
+                vm[i]['first_run_done'] = False
+                ready = True
+            else:
+                ready = vm_read_stdout(vm[i], i)
+            if ready:
+                scr.move(i + 1, 10)
+                scr.clrtoeol()
+                updated = True
+                if not rerun_tests:
+                    vm[i]['proc'].stdin.write('\n')
+                    scr.addstr("shutting down")
+                    logger.info("VM[%d] shutting down" % i)
+                else:
+                    name = rerun_tests.pop(0)
+                    vm[i]['proc'].stdin.write(name + '\n')
+                    scr.addstr(name + "(*)")
+                    logger.debug("VM[%d] start test %s (*)" % (i, name))
+
+        if not running:
+            break
+
+        if updated:
+            scr.move(num_servers + 1, 10)
+            scr.clrtoeol()
+            scr.addstr("{} %".format(int(100.0 * (total_passed + total_failed + total_skipped) / total_tests)))
+            scr.addstr(num_servers + 1, 20, "TOTAL={} STARTED={} PASS={} FAIL={} SKIP={}".format(total_tests, total_started, total_passed, total_failed, total_skipped))
+            failed = get_failed(vm)
+            if len(failed) > 0:
+                scr.move(num_servers + 2, 0)
+                scr.clrtoeol()
+                scr.addstr("Failed test cases: ")
+                count = 0
+                for f in failed:
+                    count += 1
+                    if count > 30:
+                        scr.addstr('...')
+                        scr.clrtoeol()
+                        break
+                    scr.addstr(f)
+                    scr.addstr(' ')
+
+            scr.move(0, 35)
+            scr.clrtoeol()
+            if rerun_tests:
+                scr.addstr("(RETRY FAILED %d)" % len(rerun_tests))
+            elif rerun_failures:
+                pass
+            elif first_run_failures:
+                scr.addstr("(RETRY FAILED)")
+
+            scr.refresh()
+
+        time.sleep(0.25)
+
+    scr.refresh()
+    time.sleep(0.3)
+
+def main():
+    import argparse
+    import os
+    global num_servers
+    global vm
+    global dir
+    global timestamp
+    global tests
+    global first_run_failures
+    global total_started, total_passed, total_failed, total_skipped
+    global rerun_failures
+
+    total_started = 0
+    total_passed = 0
+    total_failed = 0
+    total_skipped = 0
+
+    debug_level = logging.INFO
+    rerun_failures = True
+    timestamp = int(time.time())
+
+    scriptsdir = os.path.dirname(os.path.realpath(sys.argv[0]))
+
+    p = argparse.ArgumentParser(description='run multiple testing VMs in parallel')
+    p.add_argument('num_servers', metavar='number of VMs', type=int, choices=range(1, 100),
+                   help="number of VMs to start")
+    p.add_argument('-f', dest='testmodules', metavar='<test module>',
+                   help='execute only tests from these test modules',
+                   type=str, nargs='+')
+    p.add_argument('-1', dest='no_retry', action='store_const', const=True, default=False,
+                   help="don't retry failed tests automatically")
+    p.add_argument('--debug', dest='debug', action='store_const', const=True, default=False,
+                   help="enable debug logging")
+    p.add_argument('--codecov', dest='codecov', action='store_const', const=True, default=False,
+                   help="enable code coverage collection")
+    p.add_argument('--shuffle-tests', dest='shuffle', action='store_const', const=True, default=False,
+                   help="shuffle test cases to randomize order")
+    p.add_argument('--short', dest='short', action='store_const', const=True,
+                   default=False,
+                   help="only run short-duration test cases")
+    p.add_argument('--long', dest='long', action='store_const', const=True,
+                   default=False,
+                   help="include long-duration test cases")
+    p.add_argument('--valgrind', dest='valgrind', action='store_const',
+                   const=True, default=False,
+                   help="run tests under valgrind")
+    p.add_argument('params', nargs='*')
+    args = p.parse_args()
+
+    dir = os.environ.get('HWSIM_TEST_LOG_DIR', '/tmp/hwsim-test-logs')
+    try:
+        os.makedirs(dir)
+    except:
+        pass
+
+    num_servers = args.num_servers
+    rerun_failures = not args.no_retry
+    if args.debug:
+        debug_level = logging.DEBUG
+    extra_args = []
+    if args.valgrind:
+        extra_args += [ '--valgrind' ]
+    if args.long:
+        extra_args += [ '--long' ]
+    if args.codecov:
+        print "Code coverage - build separate binaries"
+        logdir = os.path.join(dir, str(timestamp))
+        os.makedirs(logdir)
+        subprocess.check_call([os.path.join(scriptsdir, 'build-codecov.sh'),
+                               logdir])
+        codecov_args = ['--codecov_dir', logdir]
+        codecov = True
+    else:
+        codecov_args = []
+        codecov = False
+
+    first_run_failures = []
+    if args.params:
+        tests = args.params
+    else:
+        tests = []
+        cmd = [ os.path.join(os.path.dirname(scriptsdir), 'run-tests.py'),
+                '-L' ]
+        if args.testmodules:
+            cmd += [ "-f" ]
+            cmd += args.testmodules
+        lst = subprocess.Popen(cmd, stdout=subprocess.PIPE)
+        for l in lst.stdout.readlines():
+            name = l.split(' ')[0]
+            tests.append(name)
+    if len(tests) == 0:
+        sys.exit("No test cases selected")
+
+    if args.shuffle:
+        from random import shuffle
+        shuffle(tests)
+    elif num_servers > 2 and len(tests) > 100:
+        # Move test cases with long duration to the beginning as an
+        # optimization to avoid last part of the test execution running a long
+        # duration test case on a single VM while all other VMs have already
+        # completed their work.
+        for l in long_tests:
+            if l in tests:
+                tests.remove(l)
+                tests.insert(0, l)
+    if args.short:
+        tests = [t for t in tests if t not in long_tests]
+
+    logger.setLevel(debug_level)
+    log_handler = logging.FileHandler('parallel-vm.log')
+    log_handler.setLevel(debug_level)
+    fmt = "%(asctime)s %(levelname)s %(message)s"
+    log_formatter = logging.Formatter(fmt)
+    log_handler.setFormatter(log_formatter)
+    logger.addHandler(log_handler)
+
+    vm = {}
+    for i in range(0, num_servers):
+        print("\rStarting virtual machine {}/{}".format(i + 1, num_servers)),
+        logger.info("Starting virtual machine {}/{}".format(i + 1, num_servers))
+        cmd = [os.path.join(scriptsdir, 'vm-run.sh'), '--delay', str(i),
+               '--timestamp', str(timestamp),
+               '--ext', 'srv.%d' % (i + 1),
+               '-i'] + codecov_args + extra_args
+        vm[i] = {}
+        vm[i]['first_run_done'] = False
+        vm[i]['proc'] = subprocess.Popen(cmd,
+                                         stdin=subprocess.PIPE,
+                                         stdout=subprocess.PIPE,
+                                         stderr=subprocess.PIPE)
+        vm[i]['out'] = ""
+        vm[i]['pending'] = ""
+        vm[i]['err'] = ""
+        vm[i]['failed'] = []
+        vm[i]['fail_seq'] = []
+        for stream in [ vm[i]['proc'].stdout, vm[i]['proc'].stderr ]:
+            fd = stream.fileno()
+            fl = fcntl.fcntl(fd, fcntl.F_GETFL)
+            fcntl.fcntl(fd, fcntl.F_SETFL, fl | os.O_NONBLOCK)
+    print
+
+    curses.wrapper(show_progress)
+
+    with open('{}/{}-parallel.log'.format(dir, timestamp), 'w') as f:
+        for i in range(0, num_servers):
+            f.write('VM {}\n{}\n{}\n'.format(i, vm[i]['out'], vm[i]['err']))
+
+    failed = get_failed(vm)
+
+    if first_run_failures:
+        print "To re-run same failure sequence(s):"
+        for i in range(0, num_servers):
+            if len(vm[i]['failed']) == 0:
+                continue
+            print "./vm-run.sh",
+            if args.long:
+                print "--long",
+            skip = len(vm[i]['fail_seq'])
+            skip -= min(skip, 30)
+            for t in vm[i]['fail_seq']:
+                if skip > 0:
+                    skip -= 1
+                    continue
+                print t,
+            print
+        print "Failed test cases:"
+        for f in first_run_failures:
+            print f,
+            logger.info("Failed: " + f)
+        print
+    double_failed = []
+    for name in failed:
+        double_failed.append(name)
+    for test in first_run_failures:
+        double_failed.remove(test)
+    if not rerun_failures:
+        pass
+    elif failed and not double_failed:
+        print "All failed cases passed on retry"
+        logger.info("All failed cases passed on retry")
+    elif double_failed:
+        print "Failed even on retry:"
+        for f in double_failed:
+            print f,
+            logger.info("Failed on retry: " + f)
+        print
+    res = "TOTAL={} PASS={} FAIL={} SKIP={}".format(total_started,
+                                                    total_passed,
+                                                    total_failed,
+                                                    total_skipped)
+    print(res)
+    logger.info(res)
+    print "Logs: " + dir + '/' + str(timestamp)
+    logger.info("Logs: " + dir + '/' + str(timestamp))
+
+    for i in range(0, num_servers):
+        if len(vm[i]['pending']) > 0:
+            logger.info("Unprocessed stdout from VM[%d]: '%s'" %
+                        (i, vm[i]['pending']))
+        log = '{}/{}.srv.{}/console'.format(dir, timestamp, i + 1)
+        with open(log, 'r') as f:
+            if "Kernel panic" in f.read():
+                print "Kernel panic in " + log
+                logger.info("Kernel panic in " + log)
+
+    if codecov:
+        print "Code coverage - preparing report"
+        for i in range(num_servers):
+            subprocess.check_call([os.path.join(scriptsdir,
+                                                'process-codecov.sh'),
+                                   logdir + ".srv.%d" % (i + 1),
+                                   str(i)])
+        subprocess.check_call([os.path.join(scriptsdir, 'combine-codecov.sh'),
+                               logdir])
+        print "file://%s/index.html" % logdir
+        logger.info("Code coverage report: file://%s/index.html" % logdir)
+
+    if double_failed or (failed and not rerun_failures):
+        logger.info("Test run complete - failures found")
+        sys.exit(2)
+    if failed:
+        logger.info("Test run complete - failures found on first run; passed on retry")
+        sys.exit(1)
+    logger.info("Test run complete - no failures")
+    sys.exit(0)
+
+if __name__ == "__main__":
+    main()