tests/hwsim/run-tests.py

   1 #!/usr/bin/env python3
   2 #
   3 # Test case executor
   4 # Copyright (c) 2013-2019, 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
   9 import os
  10 import re
  11 import sys
  12 import time
  13 from datetime import datetime
  14 import argparse
  15 import subprocess
  16 import termios
  17
  18 import logging
  19 logger = logging.getLogger()
  20
  21 try:
  22     import sqlite3
  23     sqlite3_imported = True
  24 except ImportError:
  25     sqlite3_imported = False
  26
  27 scriptsdir = os.path.dirname(os.path.realpath(sys.modules[__name__].__file__))
  28 sys.path.append(os.path.join(scriptsdir, '..', '..', 'wpaspy'))
  29
  30 from wpasupplicant import WpaSupplicant
  31 from hostapd import HostapdGlobal
  32 from check_kernel import check_kernel
  33 from wlantest import Wlantest
  34 from utils import HwsimSkip
  35
  36 def set_term_echo(fd, enabled):
  37     [iflag, oflag, cflag, lflag, ispeed, ospeed, cc] = termios.tcgetattr(fd)
  38     if enabled:
  39         lflag |= termios.ECHO
  40     else:
  41         lflag &= ~termios.ECHO
  42     termios.tcsetattr(fd, termios.TCSANOW,
  43                       [iflag, oflag, cflag, lflag, ispeed, ospeed, cc])
  44
  45 def reset_devs(dev, apdev):
  46     ok = True
  47     for d in dev:
  48         try:
  49             d.reset()
  50         except Exception as e:
  51             logger.info("Failed to reset device " + d.ifname)
  52             print(str(e))
  53             ok = False
  54
  55     wpas = None
  56     try:
  57         wpas = WpaSupplicant(global_iface='/tmp/wpas-wlan5', monitor=False)
  58         ifaces = wpas.global_request("INTERFACES").splitlines()
  59         for iface in ifaces:
  60             if iface.startswith("wlan"):
  61                 wpas.interface_remove(iface)
  62     except Exception as e:
  63         pass
  64     if wpas:
  65         wpas.close_ctrl()
  66         del wpas
  67
  68     try:
  69         hapd = HostapdGlobal()
  70         hapd.flush()
  71         hapd.remove('wlan3-6')
  72         hapd.remove('wlan3-5')
  73         hapd.remove('wlan3-4')
  74         hapd.remove('wlan3-3')
  75         hapd.remove('wlan3-2')
  76         for ap in apdev:
  77             hapd.remove(ap['ifname'])
  78         hapd.remove('as-erp')
  79     except Exception as e:
  80         logger.info("Failed to remove hostapd interface")
  81         print(str(e))
  82         ok = False
  83     return ok
  84
  85 def add_log_file(conn, test, run, type, path):
  86     if not os.path.exists(path):
  87         return
  88     contents = None
  89     with open(path, 'rb') as f:
  90         contents = f.read()
  91     if contents is None:
  92         return
  93     sql = "INSERT INTO logs(test,run,type,contents) VALUES(?, ?, ?, ?)"
  94     params = (test, run, type, sqlite3.Binary(contents))
  95     try:
  96         conn.execute(sql, params)
  97         conn.commit()
  98     except Exception as e:
  99         print("sqlite: " + str(e))
 100         print("sql: %r" % (params, ))
 101
 102 def report(conn, prefill, build, commit, run, test, result, duration, logdir,
 103            sql_commit=True):
 104     if conn:
 105         if not build:
 106             build = ''
 107         if not commit:
 108             commit = ''
 109         if prefill:
 110             conn.execute('DELETE FROM results WHERE test=? AND run=? AND result=?', (test, run, 'NOTRUN'))
 111         sql = "INSERT INTO results(test,result,run,time,duration,build,commitid) VALUES(?, ?, ?, ?, ?, ?, ?)"
 112         params = (test, result, run, time.time(), duration, build, commit)
 113         try:
 114             conn.execute(sql, params)
 115             if sql_commit:
 116                 conn.commit()
 117         except Exception as e:
 118             print("sqlite: " + str(e))
 119             print("sql: %r" % (params, ))
 120
 121         if result == "FAIL":
 122             for log in ["log", "log0", "log1", "log2", "log3", "log5",
 123                         "hostapd", "dmesg", "hwsim0", "hwsim0.pcapng"]:
 124                 add_log_file(conn, test, run, log,
 125                              logdir + "/" + test + "." + log)
 126
 127 class DataCollector(object):
 128     def __init__(self, logdir, testname, args):
 129         self._logdir = logdir
 130         self._testname = testname
 131         self._tracing = args.tracing
 132         self._dmesg = args.dmesg
 133         self._dbus = args.dbus
 134     def __enter__(self):
 135         if self._tracing:
 136             output = os.path.abspath(os.path.join(self._logdir, '%s.dat' % (self._testname, )))
 137             self._trace_cmd = subprocess.Popen(['trace-cmd', 'record', '-o', output, '-e', 'mac80211', '-e', 'cfg80211', '-e', 'printk', 'sh', '-c', 'echo STARTED ; read l'],
 138                                                stdin=subprocess.PIPE,
 139                                                stdout=subprocess.PIPE,
 140                                                stderr=open('/dev/null', 'w'),
 141                                                cwd=self._logdir)
 142             l = self._trace_cmd.stdout.read(7)
 143             while self._trace_cmd.poll() is None and b'STARTED' not in l:
 144                 l += self._trace_cmd.stdout.read(1)
 145             res = self._trace_cmd.returncode
 146             if res:
 147                 print("Failed calling trace-cmd: returned exit status %d" % res)
 148                 sys.exit(1)
 149         if self._dbus:
 150             output = os.path.abspath(os.path.join(self._logdir, '%s.dbus' % (self._testname, )))
 151             self._dbus_cmd = subprocess.Popen(['dbus-monitor', '--system'],
 152                                               stdout=open(output, 'w'),
 153                                               stderr=open('/dev/null', 'w'),
 154                                               cwd=self._logdir)
 155             res = self._dbus_cmd.returncode
 156             if res:
 157                 print("Failed calling dbus-monitor: returned exit status %d" % res)
 158                 sys.exit(1)
 159     def __exit__(self, type, value, traceback):
 160         if self._tracing:
 161             self._trace_cmd.stdin.write(b'DONE\n')
 162             self._trace_cmd.stdin.flush()
 163             self._trace_cmd.wait()
 164         if self._dmesg:
 165             output = os.path.join(self._logdir, '%s.dmesg' % (self._testname, ))
 166             num = 0
 167             while os.path.exists(output):
 168                 output = os.path.join(self._logdir, '%s.dmesg-%d' % (self._testname, num))
 169                 num += 1
 170             subprocess.call(['dmesg', '-c'], stdout=open(output, 'w'))
 171
 172 def rename_log(logdir, basename, testname, dev):
 173     try:
 174         import getpass
 175         srcname = os.path.join(logdir, basename)
 176         dstname = os.path.join(logdir, testname + '.' + basename)
 177         num = 0
 178         while os.path.exists(dstname):
 179             dstname = os.path.join(logdir,
 180                                    testname + '.' + basename + '-' + str(num))
 181             num = num + 1
 182         os.rename(srcname, dstname)
 183         if dev:
 184             dev.relog()
 185             subprocess.call(['chown', '-f', getpass.getuser(), srcname])
 186     except Exception as e:
 187         logger.info("Failed to rename log files")
 188         logger.info(e)
 189
 190 def main():
 191     tests = []
 192     test_modules = []
 193     files = os.listdir(scriptsdir)
 194     for t in files:
 195         m = re.match(r'(test_.*)\.py$', t)
 196         if m:
 197             logger.debug("Import test cases from " + t)
 198             mod = __import__(m.group(1))
 199             test_modules.append(mod.__name__.replace('test_', '', 1))
 200             for key, val in mod.__dict__.items():
 201                 if key.startswith("test_"):
 202                     tests.append(val)
 203     test_names = list(set([t.__name__.replace('test_', '', 1) for t in tests]))
 204
 205     run = None
 206
 207     parser = argparse.ArgumentParser(description='hwsim test runner')
 208     parser.add_argument('--logdir', metavar='<directory>',
 209                         help='log output directory for all other options, ' +
 210                              'must be given if other log options are used')
 211     group = parser.add_mutually_exclusive_group()
 212     group.add_argument('-d', const=logging.DEBUG, action='store_const',
 213                        dest='loglevel', default=logging.INFO,
 214                        help="verbose debug output")
 215     group.add_argument('-q', const=logging.WARNING, action='store_const',
 216                        dest='loglevel', help="be quiet")
 217
 218     parser.add_argument('-S', metavar='<sqlite3 db>', dest='database',
 219                         help='database to write results to')
 220     parser.add_argument('--prefill-tests', action='store_true', dest='prefill',
 221                         help='prefill test database with NOTRUN before all tests')
 222     parser.add_argument('--commit', metavar='<commit id>',
 223                         help='commit ID, only for database')
 224     parser.add_argument('-b', metavar='<build>', dest='build', help='build ID')
 225     parser.add_argument('-L', action='store_true', dest='update_tests_db',
 226                         help='List tests (and update descriptions in DB)')
 227     parser.add_argument('-T', action='store_true', dest='tracing',
 228                         help='collect tracing per test case (in log directory)')
 229     parser.add_argument('-D', action='store_true', dest='dmesg',
 230                         help='collect dmesg per test case (in log directory)')
 231     parser.add_argument('--dbus', action='store_true', dest='dbus',
 232                         help='collect dbus per test case (in log directory)')
 233     parser.add_argument('--shuffle-tests', action='store_true',
 234                         dest='shuffle_tests',
 235                         help='Shuffle test cases to randomize order')
 236     parser.add_argument('--split', help='split tests for parallel execution (<server number>/<total servers>)')
 237     parser.add_argument('--no-reset', action='store_true', dest='no_reset',
 238                         help='Do not reset devices at the end of the test')
 239     parser.add_argument('--long', action='store_true',
 240                         help='Include test cases that take long time')
 241     parser.add_argument('-f', dest='testmodules', metavar='<test module>',
 242                         help='execute only tests from these test modules',
 243                         type=str, choices=[[]] + test_modules, nargs='+')
 244     parser.add_argument('-l', metavar='<modules file>', dest='mfile',
 245                         help='test modules file name')
 246     parser.add_argument('-i', action='store_true', dest='stdin_ctrl',
 247                         help='stdin-controlled test case execution')
 248     parser.add_argument('tests', metavar='<test>', nargs='*', type=str,
 249                         help='tests to run (only valid without -f)')
 250
 251     args = parser.parse_args()
 252
 253     if (args.tests and args.testmodules) or (args.tests and args.mfile) or (args.testmodules and args.mfile):
 254         print('Invalid arguments - only one of (test, test modules, modules file) can be given.')
 255         sys.exit(2)
 256
 257     if args.tests:
 258         fail = False
 259         for t in args.tests:
 260             if t.endswith('*'):
 261                 prefix = t.rstrip('*')
 262                 found = False
 263                 for tn in test_names:
 264                     if tn.startswith(prefix):
 265                         found = True
 266                         break
 267                 if not found:
 268                     print('Invalid arguments - test "%s" wildcard did not match' % t)
 269                     fail = True
 270             elif t not in test_names:
 271                 print('Invalid arguments - test "%s" not known' % t)
 272                 fail = True
 273         if fail:
 274             sys.exit(2)
 275
 276     if args.database:
 277         if not sqlite3_imported:
 278             print("No sqlite3 module found")
 279             sys.exit(2)
 280         conn = sqlite3.connect(args.database)
 281         conn.execute('CREATE TABLE IF NOT EXISTS results (test,result,run,time,duration,build,commitid)')
 282         conn.execute('CREATE TABLE IF NOT EXISTS tests (test,description)')
 283         conn.execute('CREATE TABLE IF NOT EXISTS logs (test,run,type,contents)')
 284     else:
 285         conn = None
 286
 287     if conn:
 288         run = int(time.time())
 289
 290     # read the modules from the modules file
 291     if args.mfile:
 292         args.testmodules = []
 293         with open(args.mfile) as f:
 294             for line in f.readlines():
 295                 line = line.strip()
 296                 if not line or line.startswith('#'):
 297                     continue
 298                 args.testmodules.append(line)
 299
 300     tests_to_run = []
 301     if args.tests:
 302         for selected in args.tests:
 303             for t in tests:
 304                 name = t.__name__.replace('test_', '', 1)
 305                 if selected.endswith('*'):
 306                     prefix = selected.rstrip('*')
 307                     if name.startswith(prefix):
 308                         tests_to_run.append(t)
 309                 elif name == selected:
 310                     tests_to_run.append(t)
 311     else:
 312         for t in tests:
 313             name = t.__name__.replace('test_', '', 1)
 314             if args.testmodules:
 315                 if t.__module__.replace('test_', '', 1) not in args.testmodules:
 316                     continue
 317             tests_to_run.append(t)
 318
 319     if args.update_tests_db:
 320         for t in tests_to_run:
 321             name = t.__name__.replace('test_', '', 1)
 322             if t.__doc__ is None:
 323                 print(name + " - MISSING DESCRIPTION")
 324             else:
 325                 print(name + " - " + t.__doc__)
 326             if conn:
 327                 sql = 'INSERT OR REPLACE INTO tests(test,description) VALUES (?, ?)'
 328                 params = (name, t.__doc__)
 329                 try:
 330                     conn.execute(sql, params)
 331                 except Exception as e:
 332                     print("sqlite: " + str(e))
 333                     print("sql: %r" % (params,))
 334         if conn:
 335             conn.commit()
 336             conn.close()
 337         sys.exit(0)
 338
 339     if not args.logdir:
 340         if os.path.exists('logs/current'):
 341             args.logdir = 'logs/current'
 342         else:
 343             args.logdir = 'logs'
 344
 345     # Write debug level log to a file and configurable verbosity to stdout
 346     logger.setLevel(logging.DEBUG)
 347
 348     stdout_handler = logging.StreamHandler()
 349     stdout_handler.setLevel(args.loglevel)
 350     logger.addHandler(stdout_handler)
 351
 352     file_name = os.path.join(args.logdir, 'run-tests.log')
 353     log_handler = logging.FileHandler(file_name, encoding='utf-8')
 354     log_handler.setLevel(logging.DEBUG)
 355     fmt = "%(asctime)s %(levelname)s %(message)s"
 356     log_formatter = logging.Formatter(fmt)
 357     log_handler.setFormatter(log_formatter)
 358     logger.addHandler(log_handler)
 359
 360     dev0 = WpaSupplicant('wlan0', '/tmp/wpas-wlan0')
 361     dev1 = WpaSupplicant('wlan1', '/tmp/wpas-wlan1')
 362     dev2 = WpaSupplicant('wlan2', '/tmp/wpas-wlan2')
 363     dev = [dev0, dev1, dev2]
 364     apdev = []
 365     apdev.append({"ifname": 'wlan3', "bssid": "02:00:00:00:03:00"})
 366     apdev.append({"ifname": 'wlan4', "bssid": "02:00:00:00:04:00"})
 367
 368     for d in dev:
 369         if not d.ping():
 370             logger.info(d.ifname + ": No response from wpa_supplicant")
 371             return
 372         logger.info("DEV: " + d.ifname + ": " + d.p2p_dev_addr())
 373     for ap in apdev:
 374         logger.info("APDEV: " + ap['ifname'])
 375
 376     passed = []
 377     skipped = []
 378     failed = []
 379
 380     # make sure nothing is left over from previous runs
 381     # (if there were any other manual runs or we crashed)
 382     if not reset_devs(dev, apdev):
 383         if conn:
 384             conn.close()
 385             conn = None
 386         sys.exit(1)
 387
 388     if args.dmesg:
 389         subprocess.call(['dmesg', '-c'], stdout=open('/dev/null', 'w'))
 390
 391     if conn and args.prefill:
 392         for t in tests_to_run:
 393             name = t.__name__.replace('test_', '', 1)
 394             report(conn, False, args.build, args.commit, run, name, 'NOTRUN', 0,
 395                    args.logdir, sql_commit=False)
 396         conn.commit()
 397
 398     if args.split:
 399         vals = args.split.split('/')
 400         split_server = int(vals[0])
 401         split_total = int(vals[1])
 402         logger.info("Parallel execution - %d/%d" % (split_server, split_total))
 403         split_server -= 1
 404         tests_to_run.sort(key=lambda t: t.__name__)
 405         tests_to_run = [x for i, x in enumerate(tests_to_run) if i % split_total == split_server]
 406
 407     if args.shuffle_tests:
 408         from random import shuffle
 409         shuffle(tests_to_run)
 410
 411     count = 0
 412     if args.stdin_ctrl:
 413         print("READY")
 414         sys.stdout.flush()
 415         num_tests = 0
 416     else:
 417         num_tests = len(tests_to_run)
 418     if args.stdin_ctrl:
 419         set_term_echo(sys.stdin.fileno(), False)
 420
 421     check_country_00 = True
 422     for d in dev:
 423         if d.get_driver_status_field("country") != "00":
 424             check_country_00 = False
 425
 426     while True:
 427         if args.stdin_ctrl:
 428             test = sys.stdin.readline()
 429             if not test:
 430                 break
 431             test = test.splitlines()[0]
 432             if test == '':
 433                 break
 434             t = None
 435             for tt in tests:
 436                 name = tt.__name__.replace('test_', '', 1)
 437                 if name == test:
 438                     t = tt
 439                     break
 440             if not t:
 441                 print("NOT-FOUND")
 442                 sys.stdout.flush()
 443                 continue
 444         else:
 445             if len(tests_to_run) == 0:
 446                 break
 447             t = tests_to_run.pop(0)
 448
 449         if dev[0].get_driver_status_field("country") == "98":
 450             # Work around cfg80211 regulatory issues in clearing intersected
 451             # country code 98. Need to make station disconnect without any
 452             # other wiphy being active in the system.
 453             logger.info("country=98 workaround - try to clear state")
 454             id = dev[1].add_network()
 455             dev[1].set_network(id, "mode", "2")
 456             dev[1].set_network_quoted(id, "ssid", "country98")
 457             dev[1].set_network(id, "key_mgmt", "NONE")
 458             dev[1].set_network(id, "frequency", "2412")
 459             dev[1].set_network(id, "scan_freq", "2412")
 460             dev[1].select_network(id)
 461             ev = dev[1].wait_event(["CTRL-EVENT-CONNECTED"])
 462             if ev:
 463                 dev[0].connect("country98", key_mgmt="NONE", scan_freq="2412")
 464                 dev[1].request("DISCONNECT")
 465                 dev[0].wait_disconnected()
 466                 dev[0].disconnect_and_stop_scan()
 467             dev[0].reset()
 468             dev[1].reset()
 469             dev[0].dump_monitor()
 470             dev[1].dump_monitor()
 471
 472         name = t.__name__.replace('test_', '', 1)
 473         open('/dev/kmsg', 'w').write('running hwsim test case %s\n' % name)
 474         if log_handler:
 475             log_handler.stream.close()
 476             logger.removeHandler(log_handler)
 477             file_name = os.path.join(args.logdir, name + '.log')
 478             log_handler = logging.FileHandler(file_name, encoding='utf-8')
 479             log_handler.setLevel(logging.DEBUG)
 480             log_handler.setFormatter(log_formatter)
 481             logger.addHandler(log_handler)
 482
 483         reset_ok = True
 484         with DataCollector(args.logdir, name, args):
 485             count = count + 1
 486             msg = "START {} {}/{}".format(name, count, num_tests)
 487             logger.info(msg)
 488             if args.loglevel == logging.WARNING:
 489                 print(msg)
 490                 sys.stdout.flush()
 491             if t.__doc__:
 492                 logger.info("Test: " + t.__doc__)
 493             start = datetime.now()
 494             open('/dev/kmsg', 'w').write('TEST-START %s @%.6f\n' % (name, time.time()))
 495             for d in dev:
 496                 try:
 497                     d.dump_monitor()
 498                     if not d.ping():
 499                         raise Exception("PING failed for {}".format(d.ifname))
 500                     if not d.global_ping():
 501                         raise Exception("Global PING failed for {}".format(d.ifname))
 502                     d.request("NOTE TEST-START " + name)
 503                 except Exception as e:
 504                     logger.info("Failed to issue TEST-START before " + name + " for " + d.ifname)
 505                     logger.info(e)
 506                     print("FAIL " + name + " - could not start test")
 507                     if conn:
 508                         conn.close()
 509                         conn = None
 510                     if args.stdin_ctrl:
 511                         set_term_echo(sys.stdin.fileno(), True)
 512                     sys.exit(1)
 513             try:
 514                 if t.__code__.co_argcount > 2:
 515                     params = {}
 516                     params['logdir'] = args.logdir
 517                     params['long'] = args.long
 518                     t(dev, apdev, params)
 519                 elif t.__code__.co_argcount > 1:
 520                     t(dev, apdev)
 521                 else:
 522                     t(dev)
 523                 result = "PASS"
 524                 if check_country_00:
 525                     for d in dev:
 526                         country = d.get_driver_status_field("country")
 527                         if country != "00":
 528                             d.dump_monitor()
 529                             logger.info(d.ifname + ": Country code not reset back to 00: is " + country)
 530                             print(d.ifname + ": Country code not reset back to 00: is " + country)
 531                             result = "FAIL"
 532
 533                             # Try to wait for cfg80211 regulatory state to
 534                             # clear.
 535                             d.cmd_execute(['iw', 'reg', 'set', '00'])
 536                             for i in range(5):
 537                                 time.sleep(1)
 538                                 country = d.get_driver_status_field("country")
 539                                 if country == "00":
 540                                     break
 541                             if country == "00":
 542                                 print(d.ifname + ": Country code cleared back to 00")
 543                                 logger.info(d.ifname + ": Country code cleared back to 00")
 544                             else:
 545                                 print("Country code remains set - expect following test cases to fail")
 546                                 logger.info("Country code remains set - expect following test cases to fail")
 547                             break
 548             except HwsimSkip as e:
 549                 logger.info("Skip test case: %s" % e)
 550                 result = "SKIP"
 551             except NameError as e:
 552                 import traceback
 553                 logger.info(e)
 554                 traceback.print_exc()
 555                 result = "FAIL"
 556             except Exception as e:
 557                 import traceback
 558                 logger.info(e)
 559                 traceback.print_exc()
 560                 if args.loglevel == logging.WARNING:
 561                     print("Exception: " + str(e))
 562                 result = "FAIL"
 563             open('/dev/kmsg', 'w').write('TEST-STOP %s @%.6f\n' % (name, time.time()))
 564             for d in dev:
 565                 try:
 566                     d.dump_monitor()
 567                     d.request("NOTE TEST-STOP " + name)
 568                 except Exception as e:
 569                     logger.info("Failed to issue TEST-STOP after {} for {}".format(name, d.ifname))
 570                     logger.info(e)
 571                     result = "FAIL"
 572             if args.no_reset:
 573                 print("Leaving devices in current state")
 574             else:
 575                 reset_ok = reset_devs(dev, apdev)
 576             wpas = None
 577             try:
 578                 wpas = WpaSupplicant(global_iface="/tmp/wpas-wlan5",
 579                                      monitor=False)
 580                 rename_log(args.logdir, 'log5', name, wpas)
 581                 if not args.no_reset:
 582                     wpas.remove_ifname()
 583             except Exception as e:
 584                 pass
 585             if wpas:
 586                 wpas.close_ctrl()
 587                 del wpas
 588
 589             for i in range(0, 3):
 590                 rename_log(args.logdir, 'log' + str(i), name, dev[i])
 591             try:
 592                 hapd = HostapdGlobal()
 593             except Exception as e:
 594                 print("Failed to connect to hostapd interface")
 595                 print(str(e))
 596                 reset_ok = False
 597                 result = "FAIL"
 598                 hapd = None
 599             rename_log(args.logdir, 'hostapd', name, hapd)
 600             if hapd:
 601                 del hapd
 602                 hapd = None
 603
 604             # Use None here since this instance of Wlantest() will never be
 605             # used for remote host hwsim tests on real hardware.
 606             Wlantest.setup(None)
 607             wt = Wlantest()
 608             rename_log(args.logdir, 'hwsim0.pcapng', name, wt)
 609             rename_log(args.logdir, 'hwsim0', name, wt)
 610             if os.path.exists(os.path.join(args.logdir, 'fst-wpa_supplicant')):
 611                 rename_log(args.logdir, 'fst-wpa_supplicant', name, None)
 612             if os.path.exists(os.path.join(args.logdir, 'fst-hostapd')):
 613                 rename_log(args.logdir, 'fst-hostapd', name, None)
 614             if os.path.exists(os.path.join(args.logdir, 'wmediumd.log')):
 615                 rename_log(args.logdir, 'wmediumd.log', name, None)
 616
 617         end = datetime.now()
 618         diff = end - start
 619
 620         if result == 'PASS' and args.dmesg:
 621             if not check_kernel(os.path.join(args.logdir, name + '.dmesg')):
 622                 logger.info("Kernel issue found in dmesg - mark test failed")
 623                 result = 'FAIL'
 624
 625         if result == 'PASS':
 626             passed.append(name)
 627         elif result == 'SKIP':
 628             skipped.append(name)
 629         else:
 630             failed.append(name)
 631
 632         report(conn, args.prefill, args.build, args.commit, run, name, result,
 633                diff.total_seconds(), args.logdir)
 634         result = "{} {} {} {}".format(result, name, diff.total_seconds(), end)
 635         logger.info(result)
 636         if args.loglevel == logging.WARNING:
 637             print(result)
 638             sys.stdout.flush()
 639
 640         if not reset_ok:
 641             print("Terminating early due to device reset failure")
 642             break
 643     if args.stdin_ctrl:
 644         set_term_echo(sys.stdin.fileno(), True)
 645
 646     if log_handler:
 647         log_handler.stream.close()
 648         logger.removeHandler(log_handler)
 649         file_name = os.path.join(args.logdir, 'run-tests.log')
 650         log_handler = logging.FileHandler(file_name, encoding='utf-8')
 651         log_handler.setLevel(logging.DEBUG)
 652         log_handler.setFormatter(log_formatter)
 653         logger.addHandler(log_handler)
 654
 655     if conn:
 656         conn.close()
 657
 658     if len(failed):
 659         logger.info("passed {} test case(s)".format(len(passed)))
 660         logger.info("skipped {} test case(s)".format(len(skipped)))
 661         logger.info("failed tests: " + ' '.join(failed))
 662         if args.loglevel == logging.WARNING:
 663             print("failed tests: " + ' '.join(failed))
 664         sys.exit(1)
 665     logger.info("passed all {} test case(s)".format(len(passed)))
 666     if len(skipped):
 667         logger.info("skipped {} test case(s)".format(len(skipped)))
 668     if args.loglevel == logging.WARNING:
 669         print("passed all {} test case(s)".format(len(passed)))
 670         if len(skipped):
 671             print("skipped {} test case(s)".format(len(skipped)))
 672
 673 if __name__ == "__main__":
 674     main()