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