1#!/usr/bin/env python3 2# 3# Parallel VM test case executor 4# Copyright (c) 2014-2024, Jouni Malinen <j@w1.fi> 5# 6# This software may be distributed under the terms of the BSD license. 7# See README for more details. 8 9from __future__ import print_function 10import curses 11import fcntl 12import logging 13import multiprocessing 14import os 15import selectors 16import shutil 17import signal 18import subprocess 19import sys 20import time 21import errno 22 23logger = logging.getLogger() 24 25# Test cases that take significantly longer time to execute than average. 26long_tests = ["ap_roam_open", 27 "hostapd_oom_wpa2_eap_connect_1", 28 "hostapd_oom_wpa2_eap_connect_2", 29 "hostapd_oom_wpa2_eap_connect_3", 30 "hostapd_oom_wpa2_eap_connect_4", 31 "hostapd_oom_wpa2_eap_connect_5", 32 "ap_wpa2_eap_eke_many", 33 "wpas_mesh_password_mismatch_retry", 34 "wpas_mesh_password_mismatch", 35 "hostapd_oom_wpa2_psk_connect", 36 "ap_hs20_fetch_osu_stop", 37 "ap_roam_wpa2_psk", 38 "ibss_wpa_none_ccmp", 39 "nfc_wps_er_handover_pk_hash_mismatch_sta", 40 "go_neg_peers_force_diff_freq", 41 "p2p_cli_invite", 42 "sta_ap_scan_2b", 43 "ap_pmf_sta_unprot_deauth_burst", 44 "ap_bss_add_remove_during_ht_scan", 45 "wext_scan_hidden", 46 "autoscan_exponential", 47 "nfc_p2p_client", 48 "wnm_bss_keep_alive", 49 "ap_inactivity_disconnect", 50 "scan_bss_expiration_age", 51 "autoscan_periodic", 52 "discovery_group_client", 53 "concurrent_p2pcli", 54 "ap_bss_add_remove", 55 "wpas_ap_wps", 56 "wext_pmksa_cache", 57 "ibss_wpa_none", 58 "ap_ht_40mhz_intolerant_ap", 59 "ibss_rsn", 60 "discovery_pd_retries", 61 "ap_wps_setup_locked_timeout", 62 "ap_vht160", 63 'he160', 64 'he160b', 65 "dfs_radar", 66 "dfs", 67 "dfs_ht40_minus", 68 "dfs_etsi", 69 "dfs_radar_vht80_downgrade", 70 "ap_acs_dfs", 71 "grpform_cred_ready_timeout", 72 "wpas_ap_dfs", 73 "autogo_many", 74 "hostapd_oom_wpa2_eap", 75 "ibss_open", 76 "proxyarp_open_ebtables", 77 "proxyarp_open_ebtables_ipv6", 78 "radius_failover", 79 "obss_scan_40_intolerant", 80 "dbus_connect_oom", 81 "proxyarp_open", 82 "proxyarp_open_ipv6", 83 "ap_wps_iteration", 84 "ap_wps_iteration_error", 85 "ap_wps_pbc_timeout", 86 "ap_wps_pbc_ap_timeout", 87 "ap_wps_pin_ap_timeout", 88 "ap_wps_http_timeout", 89 "p2p_go_move_reg_change", 90 "p2p_go_move_active", 91 "p2p_go_move_scm", 92 "p2p_go_move_scm_peer_supports", 93 "p2p_go_move_scm_peer_does_not_support", 94 "p2p_go_move_scm_multi"] 95 96# Test cases that have common, but random, issues with UML. 97uml_issue_tests = ["eht_connect_invalid_link", 98 "eht_mld_connect_probes", 99 "gas_anqp_address3_ap_forced", 100 "gas_anqp_address3_ap_non_compliant", 101 "gas_anqp_address3_not_assoc", 102 "gas_anqp_address3_assoc", 103 "p2p_channel_random_social_with_op_class_change", 104 "ap_open_ps_mc_buf", 105 "wmediumd_path_rann", 106 "mbo_assoc_disallow", 107 "ieee8021x_reauth_wep"] 108 109# Test cases that depend on dumping full process memory 110memory_read_tests = ["ap_wpa2_eap_fast_pac_lifetime", 111 "wpa2_eap_ttls_pap_key_lifetime_in_memory", 112 "wpa2_eap_peap_gtc_key_lifetime_in_memory", 113 "ft_psk_key_lifetime_in_memory", 114 "wpa2_psk_key_lifetime_in_memory", 115 "ap_wpa2_tdls_long_lifetime", 116 "ap_wpa2_tdls_wrong_lifetime_resp", 117 "erp_key_lifetime_in_memory", 118 "sae_key_lifetime_in_memory", 119 "sae_okc_pmk_lifetime", 120 "sae_pmk_lifetime", 121 "wpas_ap_lifetime_in_memory", 122 "wpas_ap_lifetime_in_memory2"] 123 124def get_failed(vm): 125 failed = [] 126 for i in range(num_servers): 127 failed += vm[i]['failed'] 128 return failed 129 130def vm_read_stdout(vm, test_queue): 131 global total_started, total_passed, total_failed, total_skipped 132 global rerun_failures 133 global first_run_failures 134 global all_failed 135 136 ready = False 137 try: 138 out = vm['proc'].stdout.read() 139 if out == None: 140 return False 141 out = out.decode() 142 except IOError as e: 143 if e.errno == errno.EAGAIN: 144 return False 145 raise 146 vm['last_stdout'] = time.time() 147 logger.debug("VM[%d] stdout.read[%s]" % (vm['idx'], out.rstrip())) 148 pending = vm['pending'] + out 149 lines = [] 150 while True: 151 pos = pending.find('\n') 152 if pos < 0: 153 break 154 line = pending[0:pos].rstrip() 155 pending = pending[(pos + 1):] 156 logger.debug("VM[%d] stdout full line[%s]" % (vm['idx'], line)) 157 if line.startswith("READY"): 158 vm['starting'] = False 159 vm['started'] = True 160 ready = True 161 elif line.startswith("PASS"): 162 ready = True 163 total_passed += 1 164 vm['current_name'] = None 165 elif line.startswith("FAIL"): 166 ready = True 167 total_failed += 1 168 vals = line.split(' ') 169 if len(vals) < 2: 170 logger.info("VM[%d] incomplete FAIL line: %s" % (vm['idx'], 171 line)) 172 name = line 173 else: 174 name = vals[1] 175 logger.debug("VM[%d] test case failed: %s" % (vm['idx'], name)) 176 vm['failed'].append(name) 177 all_failed.append(name) 178 if name != vm['current_name']: 179 logger.info("VM[%d] test result mismatch: %s (expected %s)" % (vm['idx'], name, vm['current_name'])) 180 else: 181 vm['current_name'] = None 182 count = vm['current_count'] 183 if count == 0: 184 first_run_failures.append(name) 185 if rerun_failures and count < 1: 186 logger.debug("Requeue test case %s" % name) 187 test_queue.append((name, vm['current_count'] + 1)) 188 elif line.startswith("NOT-FOUND"): 189 ready = True 190 total_failed += 1 191 logger.info("VM[%d] test case not found" % vm['idx']) 192 elif line.startswith("SKIP"): 193 ready = True 194 total_skipped += 1 195 vm['current_name'] = None 196 elif line.startswith("REASON"): 197 vm['skip_reason'].append(line[7:]) 198 elif line.startswith("START"): 199 total_started += 1 200 if len(vm['failed']) == 0: 201 vals = line.split(' ') 202 if len(vals) >= 2: 203 vm['fail_seq'].append(vals[1]) 204 vm['out'] += line + '\n' 205 lines.append(line) 206 vm['pending'] = pending 207 return ready 208 209def start_vm(vm, sel): 210 logger.info("VM[%d] starting up" % (vm['idx'] + 1)) 211 vm['starting'] = True 212 vm['proc'] = subprocess.Popen(vm['cmd'], 213 stdin=subprocess.PIPE, 214 stdout=subprocess.PIPE, 215 stderr=subprocess.PIPE) 216 vm['cmd'] = None 217 for stream in [vm['proc'].stdout, vm['proc'].stderr]: 218 fd = stream.fileno() 219 fl = fcntl.fcntl(fd, fcntl.F_GETFL) 220 fcntl.fcntl(fd, fcntl.F_SETFL, fl | os.O_NONBLOCK) 221 sel.register(stream, selectors.EVENT_READ, vm) 222 223def num_vm_starting(): 224 count = 0 225 for i in range(num_servers): 226 if vm[i]['starting']: 227 count += 1 228 return count 229 230def vm_read_stderr(vm): 231 try: 232 err = vm['proc'].stderr.read() 233 if err != None: 234 err = err.decode() 235 if len(err) > 0: 236 vm['err'] += err 237 logger.info("VM[%d] stderr.read[%s]" % (vm['idx'], err)) 238 except IOError as e: 239 if e.errno != errno.EAGAIN: 240 raise 241 242def vm_next_step(_vm, scr, test_queue): 243 max_y, max_x = scr.getmaxyx() 244 status_line = num_servers 245 if status_line >= max_y: 246 status_line = max_y - 1 247 if _vm['idx'] < status_line: 248 scr.move(_vm['idx'], 10) 249 scr.clrtoeol() 250 if not test_queue: 251 _vm['proc'].stdin.write(b'\n') 252 _vm['proc'].stdin.flush() 253 if _vm['idx'] < status_line: 254 scr.addstr("shutting down") 255 logger.info("VM[%d] shutting down" % _vm['idx']) 256 return 257 (name, count) = test_queue.pop(0) 258 _vm['current_name'] = name 259 _vm['current_count'] = count 260 _vm['proc'].stdin.write(name.encode() + b'\n') 261 _vm['proc'].stdin.flush() 262 if _vm['idx'] < status_line: 263 scr.addstr(name) 264 logger.debug("VM[%d] start test %s" % (_vm['idx'], name)) 265 266def check_vm_start(scr, sel, test_queue): 267 running = False 268 max_y, max_x = scr.getmaxyx() 269 status_line = num_servers 270 if status_line >= max_y: 271 status_line = max_y - 1 272 for i in range(num_servers): 273 if vm[i]['proc']: 274 running = True 275 continue 276 277 # Either not yet started or already stopped VM 278 max_start = multiprocessing.cpu_count() 279 if max_start > 4: 280 max_start /= 2 281 num_starting = num_vm_starting() 282 if vm[i]['cmd'] and len(test_queue) > num_starting and \ 283 num_starting < max_start: 284 if i < status_line: 285 scr.move(i, 10) 286 scr.clrtoeol() 287 scr.addstr(i, 10, "starting VM") 288 start_vm(vm[i], sel) 289 return True, True 290 291 return running, False 292 293def vm_terminated(_vm, scr, sel, test_queue): 294 logger.debug("VM[%s] terminated" % _vm['idx']) 295 updated = False 296 for stream in [_vm['proc'].stdout, _vm['proc'].stderr]: 297 sel.unregister(stream) 298 _vm['proc'] = None 299 max_y, max_x = scr.getmaxyx() 300 status_line = num_servers 301 if status_line >= max_y: 302 status_line = max_y - 1 303 if _vm['idx'] < status_line: 304 scr.move(_vm['idx'], 10) 305 scr.clrtoeol() 306 log = '{}/{}.srv.{}/console'.format(dir, timestamp, _vm['idx'] + 1) 307 with open(log, 'r') as f: 308 if "Kernel panic" in f.read(): 309 if _vm['idx'] < status_line: 310 scr.addstr("kernel panic") 311 logger.info("VM[%d] kernel panic" % _vm['idx']) 312 updated = True 313 if test_queue: 314 num_vm = 0 315 for i in range(num_servers): 316 if vm[i]['proc']: 317 num_vm += 1 318 if len(test_queue) > num_vm: 319 if _vm['idx'] < status_line: 320 scr.addstr("unexpected exit") 321 logger.info("VM[%d] unexpected exit" % _vm['idx']) 322 updated = True 323 324 if _vm['current_name']: 325 global total_failed, all_failed, first_run_failures, rerun_failures 326 name = _vm['current_name'] 327 if _vm['idx'] < status_line: 328 if updated: 329 scr.addstr(" - ") 330 scr.addstr(name + " - did not complete") 331 logger.info("VM[%d] did not complete test %s" % (_vm['idx'], name)) 332 total_failed += 1 333 _vm['failed'].append(name) 334 all_failed.append(name) 335 336 count = _vm['current_count'] 337 if count == 0: 338 first_run_failures.append(name) 339 if rerun_failures and count < 1: 340 logger.debug("Requeue test case %s" % name) 341 test_queue.append((name, count + 1)) 342 updated = True 343 344 return updated 345 346def update_screen(scr, total_tests): 347 max_y, max_x = scr.getmaxyx() 348 status_line = num_servers 349 if status_line >= max_y: 350 status_line = max_y - 1 351 scr.move(status_line, 10) 352 scr.clrtoeol() 353 scr.addstr("{} %".format(int(100.0 * (total_passed + total_failed + total_skipped) / total_tests))) 354 scr.addstr(status_line, 20, 355 "TOTAL={} STARTED={} PASS={} FAIL={} SKIP={}".format(total_tests, total_started, total_passed, total_failed, total_skipped)) 356 global all_failed 357 max_y, max_x = scr.getmaxyx() 358 max_lines = max_y - num_servers - 3 359 if len(all_failed) > 0 and max_lines > 0 and num_servers + 1 < max_y - 1: 360 scr.move(num_servers + 1, 0) 361 scr.addstr("Last failed test cases:") 362 if max_lines >= len(all_failed): 363 max_lines = len(all_failed) 364 count = 0 365 for i in range(len(all_failed) - max_lines, len(all_failed)): 366 count += 1 367 if num_servers + 2 + count >= max_y: 368 break 369 scr.move(num_servers + 1 + count, 0) 370 scr.addstr(all_failed[i]) 371 scr.clrtoeol() 372 scr.refresh() 373 374def has_uml_mconsole(_vm): 375 if not shutil.which('uml_mconsole'): 376 return False 377 dir = os.path.join(os.path.expanduser('~/.uml'), 'hwsim-' + _vm['DATE']) 378 return os.path.exists(dir) 379 380def kill_uml_vm(_vm): 381 fname = os.path.join(os.path.expanduser('~/.uml'), 'hwsim-' + _vm['DATE'], 382 'pid') 383 with open(fname, 'r') as f: 384 pid = int(f.read()) 385 logger.info("Kill hung VM[%d] PID[%d]" % (_vm['idx'] + 1, pid)) 386 try: 387 subprocess.call(['uml_mconsole', 'hwsim-' + _vm['DATE'], 388 'halt'], stdout=open('/dev/null', 'w'), 389 timeout=5) 390 except subprocess.TimeoutExpired: 391 logger.info("uml_console timed out - kill UML process") 392 try: 393 os.kill(pid, signal.SIGTERM) 394 except Exception as e: 395 logger.info("os.kill() failed: " + str(e)) 396 397def show_progress(scr): 398 global num_servers 399 global vm 400 global dir 401 global timestamp 402 global tests 403 global first_run_failures 404 global total_started, total_passed, total_failed, total_skipped 405 global rerun_failures 406 407 sel = selectors.DefaultSelector() 408 total_tests = len(tests) 409 logger.info("Total tests: %d" % total_tests) 410 test_queue = [(t, 0) for t in tests] 411 start_vm(vm[0], sel) 412 413 scr.leaveok(1) 414 max_y, max_x = scr.getmaxyx() 415 status_line = num_servers 416 if status_line > max_y: 417 status_line = max_y 418 for i in range(0, num_servers): 419 if i < status_line: 420 scr.addstr(i, 0, "VM %d:" % (i + 1), curses.A_BOLD) 421 status = "starting VM" if vm[i]['proc'] else "not yet started" 422 scr.addstr(i, 10, status) 423 scr.addstr(status_line, 0, "Total:", curses.A_BOLD) 424 scr.addstr(status_line, 20, "TOTAL={} STARTED=0 PASS=0 FAIL=0 SKIP=0".format(total_tests)) 425 scr.refresh() 426 427 while True: 428 updated = False 429 events = sel.select(timeout=1) 430 for key, mask in events: 431 _vm = key.data 432 if not _vm['proc']: 433 continue 434 vm_read_stderr(_vm) 435 if vm_read_stdout(_vm, test_queue): 436 vm_next_step(_vm, scr, test_queue) 437 updated = True 438 vm_read_stderr(_vm) 439 if _vm['proc'].poll() is not None: 440 vm_terminated(_vm, scr, sel, test_queue) 441 updated = True 442 443 running, run_update = check_vm_start(scr, sel, test_queue) 444 if updated or run_update: 445 update_screen(scr, total_tests) 446 if not running: 447 break 448 449 status_line = num_servers 450 if status_line >= max_y: 451 status_line = max_y - 1 452 max_y, max_x = scr.getmaxyx() 453 updated = False 454 455 now = time.time() 456 for i in range(num_servers): 457 _vm = vm[i] 458 if not _vm['proc']: 459 continue 460 last = _vm['last_stdout'] 461 if last and now - last > 10: 462 if _vm['idx'] < status_line: 463 scr.move(_vm['idx'], max_x - 25) 464 scr.clrtoeol() 465 scr.addstr("(no update in %d s)" % (now - last)) 466 updated = True 467 if (not _vm['killed']) and has_uml_mconsole(_vm) and \ 468 last and now - last > 120: 469 if _vm['idx'] < status_line: 470 scr.move(_vm['idx'], 10) 471 scr.clrtoeol() 472 scr.addstr("terminating due to no updates received") 473 _vm['killed'] = True 474 kill_uml_vm(_vm) 475 if updated: 476 scr.refresh() 477 478 sel.close() 479 480 for i in range(num_servers): 481 if not vm[i]['proc']: 482 continue 483 vm[i]['proc'] = None 484 scr.move(i, 10) 485 scr.clrtoeol() 486 scr.addstr("still running") 487 logger.info("VM[%d] still running" % i) 488 489 scr.refresh() 490 time.sleep(0.3) 491 492def known_output(tests, line): 493 if not line: 494 return True 495 if line in tests: 496 return True 497 known = ["START ", "PASS ", "FAIL ", "SKIP ", "REASON ", "ALL-PASSED", 498 "READY", 499 " ", "Exception: ", "Traceback (most recent call last):", 500 "./run-all.sh: running", 501 "./run-all.sh: passing", 502 "Test run completed", "Logfiles are at", "Starting test run", 503 "passed all", "skipped ", "failed tests:"] 504 for k in known: 505 if line.startswith(k): 506 return True 507 return False 508 509def main(): 510 import argparse 511 import os 512 global num_servers 513 global vm 514 global all_failed 515 global dir 516 global timestamp 517 global tests 518 global first_run_failures 519 global total_started, total_passed, total_failed, total_skipped 520 global rerun_failures 521 522 total_started = 0 523 total_passed = 0 524 total_failed = 0 525 total_skipped = 0 526 527 debug_level = logging.INFO 528 rerun_failures = True 529 start_time = time.time() 530 timestamp = int(start_time) 531 532 scriptsdir = os.path.dirname(os.path.realpath(sys.argv[0])) 533 534 p = argparse.ArgumentParser(description='run multiple testing VMs in parallel') 535 p.add_argument('num_servers', metavar='number of VMs', type=int, choices=range(1, 100), 536 help="number of VMs to start") 537 p.add_argument('-f', dest='testmodules', metavar='<test module>', 538 help='execute only tests from these test modules', 539 type=str, nargs='+') 540 p.add_argument('-1', dest='no_retry', action='store_const', const=True, default=False, 541 help="don't retry failed tests automatically") 542 p.add_argument('--debug', dest='debug', action='store_const', const=True, default=False, 543 help="enable debug logging") 544 p.add_argument('--codecov', dest='codecov', action='store_const', const=True, default=False, 545 help="enable code coverage collection") 546 p.add_argument('--shuffle-tests', dest='shuffle', action='store_const', const=True, default=False, 547 help="shuffle test cases to randomize order") 548 p.add_argument('--short', dest='short', action='store_const', const=True, 549 default=False, 550 help="only run short-duration test cases") 551 p.add_argument('--long', dest='long', action='store_const', const=True, 552 default=False, 553 help="include long-duration test cases") 554 p.add_argument('--valgrind', dest='valgrind', action='store_const', 555 const=True, default=False, 556 help="run tests under valgrind") 557 p.add_argument('--telnet', dest='telnet', metavar='<baseport>', type=int, 558 help="enable telnet server inside VMs, specify the base port here") 559 p.add_argument('--nocurses', dest='nocurses', action='store_const', 560 const=True, default=False, help="Don't use curses for output") 561 p.add_argument('params', nargs='*') 562 args = p.parse_args() 563 564 dir = os.environ.get('HWSIM_TEST_LOG_DIR', '/tmp/hwsim-test-logs') 565 try: 566 os.makedirs(dir) 567 except OSError as e: 568 if e.errno != errno.EEXIST: 569 raise 570 571 num_servers = args.num_servers 572 rerun_failures = not args.no_retry 573 if args.debug: 574 debug_level = logging.DEBUG 575 extra_args = [] 576 if args.valgrind: 577 extra_args += ['--valgrind'] 578 if args.long: 579 extra_args += ['--long'] 580 if args.codecov: 581 print("Code coverage - build separate binaries") 582 logdir = os.path.join(dir, str(timestamp)) 583 os.makedirs(logdir) 584 subprocess.check_call([os.path.join(scriptsdir, 'build-codecov.sh'), 585 logdir]) 586 codecov_args = ['--codecov_dir', logdir] 587 codecov = True 588 else: 589 codecov_args = [] 590 codecov = False 591 592 first_run_failures = [] 593 if args.params: 594 tests = args.params 595 else: 596 tests = [] 597 cmd = [os.path.join(os.path.dirname(scriptsdir), 'run-tests.py'), '-L'] 598 if args.testmodules: 599 cmd += ["-f"] 600 cmd += args.testmodules 601 lst = subprocess.Popen(cmd, stdout=subprocess.PIPE) 602 for l in lst.stdout.readlines(): 603 name = l.decode().split(' ')[0] 604 tests.append(name) 605 if len(tests) == 0: 606 sys.exit("No test cases selected") 607 608 if args.shuffle: 609 from random import shuffle 610 shuffle(tests) 611 elif num_servers > 2 and len(tests) > 100: 612 # Move test cases with long duration to the beginning as an 613 # optimization to avoid last part of the test execution running a long 614 # duration test case on a single VM while all other VMs have already 615 # completed their work. 616 for l in long_tests: 617 if l in tests: 618 tests.remove(l) 619 tests.insert(0, l) 620 621 # Move test cases that have shown frequent, but random, issues UML 622 # to the beginning of the run to minimize risk of false failures. 623 for l in uml_issue_tests: 624 if l in tests: 625 tests.remove(l) 626 tests.insert(0, l) 627 628 # Test cases that read full wpa_supplicant or hostapd process memory 629 # can apparently cause resources issues at least with newer python3 630 # versions, so run them first before possible memory fragmentation has 631 # made this need more resources. 632 for l in memory_read_tests: 633 if l in tests: 634 tests.remove(l) 635 tests.insert(0, l) 636 if args.short: 637 tests = [t for t in tests if t not in long_tests] 638 639 logger.setLevel(debug_level) 640 if not args.nocurses: 641 log_handler = logging.FileHandler('parallel-vm.log') 642 else: 643 log_handler = logging.StreamHandler(sys.stdout) 644 log_handler.setLevel(debug_level) 645 fmt = "%(asctime)s %(levelname)s %(message)s" 646 log_formatter = logging.Formatter(fmt) 647 log_handler.setFormatter(log_formatter) 648 logger.addHandler(log_handler) 649 650 all_failed = [] 651 vm = {} 652 for i in range(0, num_servers): 653 cmd = [os.path.join(scriptsdir, 'vm-run.sh'), 654 '--timestamp', str(timestamp), 655 '--ext', 'srv.%d' % (i + 1), 656 '-i'] + codecov_args + extra_args 657 if args.telnet: 658 cmd += ['--telnet', str(args.telnet + i)] 659 vm[i] = {} 660 vm[i]['idx'] = i 661 vm[i]['DATE'] = str(timestamp) + '.srv.' + str(i + 1) 662 vm[i]['starting'] = False 663 vm[i]['started'] = False 664 vm[i]['cmd'] = cmd 665 vm[i]['proc'] = None 666 vm[i]['out'] = "" 667 vm[i]['pending'] = "" 668 vm[i]['err'] = "" 669 vm[i]['failed'] = [] 670 vm[i]['fail_seq'] = [] 671 vm[i]['skip_reason'] = [] 672 vm[i]['current_name'] = None 673 vm[i]['last_stdout'] = None 674 vm[i]['killed'] = False 675 print('') 676 677 if not args.nocurses: 678 curses.wrapper(show_progress) 679 else: 680 class FakeScreen: 681 def leaveok(self, n): 682 pass 683 def refresh(self): 684 pass 685 def addstr(self, *args, **kw): 686 pass 687 def move(self, x, y): 688 pass 689 def clrtoeol(self): 690 pass 691 def getmaxyx(self): 692 return (25, 80) 693 694 show_progress(FakeScreen()) 695 696 with open('{}/{}-parallel.log'.format(dir, timestamp), 'w') as f: 697 for i in range(0, num_servers): 698 f.write('VM {}\n{}\n{}\n'.format(i + 1, vm[i]['out'], vm[i]['err'])) 699 first = True 700 for i in range(0, num_servers): 701 for line in vm[i]['out'].splitlines(): 702 if line.startswith("FAIL "): 703 if first: 704 first = False 705 print("Logs for failed test cases:") 706 f.write("Logs for failed test cases:\n") 707 fname = "%s/%d.srv.%d/%s.log" % (dir, timestamp, i + 1, 708 line.split(' ')[1]) 709 print(fname) 710 f.write("%s\n" % fname) 711 712 failed = get_failed(vm) 713 714 if first_run_failures: 715 print("To re-run same failure sequence(s):") 716 for i in range(0, num_servers): 717 if len(vm[i]['failed']) == 0: 718 continue 719 print("./vm-run.sh", end=' ') 720 if args.long: 721 print("--long", end=' ') 722 skip = len(vm[i]['fail_seq']) 723 skip -= min(skip, 30) 724 for t in vm[i]['fail_seq']: 725 if skip > 0: 726 skip -= 1 727 continue 728 print(t, end=' ') 729 logger.info("Failure sequence: " + " ".join(vm[i]['fail_seq'])) 730 print('') 731 print("Failed test cases:") 732 for f in first_run_failures: 733 print(f, end=' ') 734 logger.info("Failed: " + f) 735 print('') 736 double_failed = [] 737 for name in failed: 738 double_failed.append(name) 739 for test in first_run_failures: 740 double_failed.remove(test) 741 if not rerun_failures: 742 pass 743 elif failed and not double_failed: 744 print("All failed cases passed on retry") 745 logger.info("All failed cases passed on retry") 746 elif double_failed: 747 print("Failed even on retry:") 748 for f in double_failed: 749 print(f, end=' ') 750 logger.info("Failed on retry: " + f) 751 print('') 752 res = "TOTAL={} PASS={} FAIL={} SKIP={}".format(total_started, 753 total_passed, 754 total_failed, 755 total_skipped) 756 print(res) 757 logger.info(res) 758 print("Logs: " + dir + '/' + str(timestamp)) 759 logger.info("Logs: " + dir + '/' + str(timestamp)) 760 761 skip_reason = [] 762 for i in range(num_servers): 763 if not vm[i]['started']: 764 continue 765 skip_reason += vm[i]['skip_reason'] 766 if len(vm[i]['pending']) > 0: 767 logger.info("Unprocessed stdout from VM[%d]: '%s'" % 768 (i, vm[i]['pending'])) 769 log = '{}/{}.srv.{}/console'.format(dir, timestamp, i + 1) 770 with open(log, 'r') as f: 771 if "Kernel panic" in f.read(): 772 print("Kernel panic in " + log) 773 logger.info("Kernel panic in " + log) 774 missing = {} 775 missing['OCV not supported'] = 'OCV' 776 missing['sigma_dut not available'] = 'sigma_dut' 777 missing['Skip test case with long duration due to --long not specified'] = 'long' 778 missing['TEST_ALLOC_FAIL not supported' ] = 'TEST_FAIL' 779 missing['TEST_ALLOC_FAIL not supported in the build'] = 'TEST_FAIL' 780 missing['TEST_FAIL not supported' ] = 'TEST_FAIL' 781 missing['veth not supported (kernel CONFIG_VETH)'] = 'KERNEL:CONFIG_VETH' 782 missing['WPA-EAP-SUITE-B-192 not supported'] = 'CONFIG_SUITEB192' 783 missing['WPA-EAP-SUITE-B not supported'] = 'CONFIG_SUITEB' 784 missing['wmediumd not available'] = 'wmediumd' 785 missing['DPP not supported'] = 'CONFIG_DPP' 786 missing['DPP version 2 not supported'] = 'CONFIG_DPP2' 787 missing['EAP method PWD not supported in the build'] = 'CONFIG_EAP_PWD' 788 missing['EAP method TEAP not supported in the build'] = 'CONFIG_EAP_TEAP' 789 missing['FILS not supported'] = 'CONFIG_FILS' 790 missing['FILS-SK-PFS not supported'] = 'CONFIG_FILS_SK_PFS' 791 missing['OWE not supported'] = 'CONFIG_OWE' 792 missing['SAE not supported'] = 'CONFIG_SAE' 793 missing['Not using OpenSSL'] = 'CONFIG_TLS=openssl' 794 missing['wpa_supplicant TLS library is not OpenSSL: internal'] = 'CONFIG_TLS=openssl' 795 missing_items = [] 796 other_reasons = [] 797 for reason in sorted(set(skip_reason)): 798 if reason in missing: 799 missing_items.append(missing[reason]) 800 elif reason.startswith('OCSP-multi not supported with this TLS library'): 801 missing_items.append('OCSP-MULTI') 802 else: 803 other_reasons.append(reason) 804 if missing_items: 805 print("Missing items (SKIP):", missing_items) 806 if other_reasons: 807 print("Other skip reasons:", other_reasons) 808 809 for i in range(num_servers): 810 unknown = "" 811 for line in vm[i]['out'].splitlines(): 812 if not known_output(tests, line): 813 unknown += line + "\n" 814 if unknown: 815 print("\nVM %d - unexpected stdout output:\n%s" % (i + 1, unknown)) 816 if vm[i]['err']: 817 print("\nVM %d - unexpected stderr output:\n%s\n" % (i + 1, vm[i]['err'])) 818 819 if codecov: 820 print("Code coverage - preparing report") 821 for i in range(num_servers): 822 subprocess.check_call([os.path.join(scriptsdir, 823 'process-codecov.sh'), 824 logdir + ".srv.%d" % (i + 1), 825 str(i)]) 826 subprocess.check_call([os.path.join(scriptsdir, 'combine-codecov.sh'), 827 logdir]) 828 print("file://%s/index.html" % logdir) 829 logger.info("Code coverage report: file://%s/index.html" % logdir) 830 831 end_time = time.time() 832 try: 833 cmd = subprocess.Popen(['git', 'describe'], stdout=subprocess.PIPE) 834 ver = cmd.stdout.read().decode().strip() 835 except: 836 ver = "unknown" 837 pass 838 logger.info("Tests run: {} Tests failed: {} Total time: {} Version: {}".format(total_started, total_failed, end_time - start_time, ver)) 839 840 if double_failed or (failed and not rerun_failures): 841 logger.info("Test run complete - failures found") 842 sys.exit(2) 843 if failed: 844 logger.info("Test run complete - failures found on first run; passed on retry") 845 sys.exit(1) 846 logger.info("Test run complete - no failures") 847 sys.exit(0) 848 849if __name__ == "__main__": 850 main() 851