xref: /openbmc/qemu/scripts/device-crash-test (revision 1721fe75df1cbabf2665a2b76a6e7b5bc0fc036b)
1#!/usr/bin/env python3
2#
3#  Copyright (c) 2017 Red Hat Inc
4#
5# Author:
6#  Eduardo Habkost <ehabkost@redhat.com>
7#
8# This program is free software; you can redistribute it and/or modify
9# it under the terms of the GNU General Public License as published by
10# the Free Software Foundation; either version 2 of the License, or
11# (at your option) any later version.
12#
13# This program is distributed in the hope that it will be useful,
14# but WITHOUT ANY WARRANTY; without even the implied warranty of
15# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
16# GNU General Public License for more details.
17#
18# You should have received a copy of the GNU General Public License along
19# with this program; if not, see <https://www.gnu.org/licenses/>.
20
21"""
22Run QEMU with all combinations of -machine and -device types,
23check for crashes and unexpected errors.
24"""
25
26import os
27import sys
28import glob
29import logging
30import traceback
31import re
32import random
33import argparse
34from itertools import chain
35from pathlib import Path
36
37try:
38    from qemu.machine import QEMUMachine
39    from qemu.qmp import ConnectError
40except ModuleNotFoundError as exc:
41    path = Path(__file__).resolve()
42    print(f"Module '{exc.name}' not found.")
43    print("  Try 'make check-venv' from your build directory,")
44    print("  and then one way to run this script is like so:")
45    print(f'  > $builddir/pyvenv/bin/python3 "{path}"')
46    sys.exit(1)
47
48logger = logging.getLogger('device-crash-test')
49dbg = logger.debug
50
51
52# Purposes of the following rule list:
53# * Avoiding verbose log messages when we find known non-fatal
54#   (exitcode=1) errors
55# * Avoiding fatal errors when we find known crashes
56# * Skipping machines/devices that are known not to work out of
57#   the box, when running in --quick mode
58#
59# Keeping the rule list updated is desirable, but not required,
60# because unexpected cases where QEMU exits with exitcode=1 will
61# just trigger a INFO message.
62
63# Valid error rule keys:
64# * accel: regexp, full match only
65# * machine: regexp, full match only
66# * device: regexp, full match only
67# * log: regexp, partial match allowed
68# * exitcode: if not present, defaults to 1. If None, matches any exitcode
69# * warn: if True, matching failures will be logged as warnings
70# * expected: if True, QEMU is expected to always fail every time
71#   when testing the corresponding test case
72# * loglevel: log level of log output when there's a match.
73ERROR_RULE_LIST = [
74    # Machines that won't work out of the box:
75    #             MACHINE                         | ERROR MESSAGE
76    {'machine':'niagara', 'expected':True},       # Unable to load a firmware for -M niagara
77    {'machine':'boston', 'expected':True},        # Please provide either a -kernel or -bios argument
78    {'machine':'leon3_generic', 'expected':True}, # Can't read bios image (null)
79
80    # devices that don't work out of the box because they require extra options to "-device DEV":
81    #            DEVICE                                    | ERROR MESSAGE
82    {'device':'.*-(i386|x86_64)-cpu', 'expected':True},    # CPU socket-id is not set
83    {'device':'icp', 'expected':True},                     # icp_realize: required link 'xics' not found: Property '.xics' not found
84    {'device':'ics', 'expected':True},                     # ics_base_realize: required link 'xics' not found: Property '.xics' not found
85    # "-device ide-cd" does work on more recent QEMU versions, so it doesn't have expected=True
86    {'device':'ide-cd'},                                 # No drive specified
87    {'device':'ide-hd', 'expected':True},                  # No drive specified
88    {'device':'ipmi-bmc-extern', 'expected':True},         # IPMI external bmc requires chardev attribute
89    {'device':'isa-debugcon', 'expected':True},            # Can't create serial device, empty char device
90    {'device':'isa-ipmi-bt', 'expected':True},             # IPMI device requires a bmc attribute to be set
91    {'device':'isa-ipmi-kcs', 'expected':True},            # IPMI device requires a bmc attribute to be set
92    {'device':'isa-parallel', 'expected':True},            # Can't create serial device, empty char device
93    {'device':'ivshmem-doorbell', 'expected':True},        # You must specify a 'chardev'
94    {'device':'ivshmem-plain', 'expected':True},           # You must specify a 'memdev'
95    {'device':'loader', 'expected':True},                  # please include valid arguments
96    {'device':'nand', 'expected':True},                    # Unsupported NAND block size 0x1
97    {'device':'nvdimm', 'expected':True},                  # 'memdev' property is not set
98    {'device':'nvme', 'expected':True},                    # Device initialization failed
99    {'device':'pc-dimm', 'expected':True},                 # 'memdev' property is not set
100    {'device':'pci-bridge', 'expected':True},              # Bridge chassis not specified. Each bridge is required to be assigned a unique chassis id > 0.
101    {'device':'pci-bridge-seat', 'expected':True},         # Bridge chassis not specified. Each bridge is required to be assigned a unique chassis id > 0.
102    {'device':'pxb', 'expected':True},                     # Bridge chassis not specified. Each bridge is required to be assigned a unique chassis id > 0.
103    {'device':'pxb-cxl', 'expected':True},                 # pxb-cxl devices cannot reside on a PCI bus.
104    {'device':'scsi-block', 'expected':True},              # drive property not set
105    {'device':'scsi-generic', 'expected':True},            # drive property not set
106    {'device':'scsi-hd', 'expected':True},                 # drive property not set
107    {'device':'spapr-pci-host-bridge', 'expected':True},   # BUID not specified for PHB
108    {'device':'spapr-rng', 'expected':True},               # spapr-rng needs an RNG backend!
109    {'device':'spapr-vty', 'expected':True},               # chardev property not set
110    {'device':'tpm-tis', 'expected':True},                 # tpm_tis: backend driver with id (null) could not be found
111    {'device':'unimplemented-device', 'expected':True},    # property 'size' not specified or zero
112    {'device':'usb-braille', 'expected':True},             # Property chardev is required
113    {'device':'usb-mtp', 'expected':True},                 # rootdir property must be configured
114    {'device':'usb-redir', 'expected':True},               # Parameter 'chardev' is missing
115    {'device':'usb-serial', 'expected':True},              # Property chardev is required
116    {'device':'usb-storage', 'expected':True},             # drive property not set
117    {'device':'vfio-amd-xgbe', 'expected':True},           # -device vfio-amd-xgbe: vfio error: wrong host device name
118    {'device':'vfio-calxeda-xgmac', 'expected':True},      # -device vfio-calxeda-xgmac: vfio error: wrong host device name
119    {'device':'vfio-pci', 'expected':True},                # No provided host device
120    {'device':'vfio-pci-igd-lpc-bridge', 'expected':True}, # VFIO dummy ISA/LPC bridge must have address 1f.0
121    {'device':'vhost-scsi.*', 'expected':True},            # vhost-scsi: missing wwpn
122    {'device':'vhost-vsock-device', 'expected':True},      # guest-cid property must be greater than 2
123    {'device':'vhost-vsock-pci', 'expected':True},         # guest-cid property must be greater than 2
124    {'device':'virtio-9p-ccw', 'expected':True},           # 9pfs device couldn't find fsdev with the id = NULL
125    {'device':'virtio-9p-device', 'expected':True},        # 9pfs device couldn't find fsdev with the id = NULL
126    {'device':'virtio-9p-pci', 'expected':True},           # 9pfs device couldn't find fsdev with the id = NULL
127    {'device':'virtio-blk-ccw', 'expected':True},          # drive property not set
128    {'device':'virtio-blk-device', 'expected':True},       # drive property not set
129    {'device':'virtio-blk-device', 'expected':True},       # drive property not set
130    {'device':'virtio-blk-pci', 'expected':True},          # drive property not set
131    {'device':'virtio-crypto-ccw', 'expected':True},       # 'cryptodev' parameter expects a valid object
132    {'device':'virtio-crypto-device', 'expected':True},    # 'cryptodev' parameter expects a valid object
133    {'device':'virtio-crypto-pci', 'expected':True},       # 'cryptodev' parameter expects a valid object
134    {'device':'virtio-input-host-device', 'expected':True}, # evdev property is required
135    {'device':'virtio-input-host-pci', 'expected':True},   # evdev property is required
136    {'device':'xen-pvdevice', 'expected':True},            # Device ID invalid, it must always be supplied
137    {'device':'vhost-vsock-ccw', 'expected':True},         # guest-cid property must be greater than 2
138    {'device':'zpci', 'expected':True},                    # target must be defined
139    {'device':'pnv-(occ|icp|lpc)', 'expected':True},       # required link 'xics' not found: Property '.xics' not found
140    {'device':'powernv-cpu-.*', 'expected':True},          # pnv_core_realize: required link 'xics' not found: Property '.xics' not found
141
142    # ioapic devices are already created by pc and will fail:
143    {'machine':'q35|pc.*', 'device':'kvm-ioapic', 'expected':True}, # Only 1 ioapics allowed
144    {'machine':'q35|pc.*', 'device':'ioapic', 'expected':True},     # Only 1 ioapics allowed
145
146    # "spapr-cpu-core needs a pseries machine"
147    {'machine':'(?!pseries).*', 'device':'.*-spapr-cpu-core', 'expected':True},
148
149    # KVM-specific devices shouldn't be tried without accel=kvm:
150    {'accel':'(?!kvm).*', 'device':'kvmclock', 'expected':True},
151
152    # xen-specific machines and devices:
153    {'accel':'(?!xen).*', 'machine':'xen.*', 'expected':True},
154    {'accel':'(?!xen).*', 'device':'xen-.*', 'expected':True},
155
156    # this fails on some machine-types, but not all, so they don't have expected=True:
157    {'device':'vmgenid'}, # vmgenid requires DMA write support in fw_cfg, which this machine type does not provide
158
159    # Silence INFO messages for errors that are common on multiple
160    # devices/machines:
161    {'log':r"No '[\w-]+' bus found for device '[\w-]+'"},
162    {'log':r"images* must be given with the 'pflash' parameter"},
163    {'log':r"(Guest|ROM|Flash|Kernel) image must be specified"},
164    {'log':r"[cC]ould not load [\w ]+ (BIOS|bios) '[\w-]+\.bin'"},
165    {'log':r"Couldn't find rom image '[\w-]+\.bin'"},
166    {'log':r"speed mismatch trying to attach usb device"},
167    {'log':r"Can't create a second ISA bus"},
168    {'log':r"duplicate fw_cfg file name"},
169    # sysbus-related error messages: most machines reject most dynamic sysbus devices:
170    {'log':r"Option '-device [\w.,-]+' cannot be handled by this machine"},
171    {'log':r"Device [\w.,-]+ is not supported by this machine yet"},
172    {'log':r"Device [\w.,-]+ can not be dynamically instantiated"},
173    {'log':r"Platform Bus: Can not fit MMIO region of size "},
174    # other more specific errors we will ignore:
175    {'device':'.*-spapr-cpu-core', 'log':r"CPU core type should be"},
176    {'log':r"MSI(-X)? is not supported by interrupt controller"},
177    {'log':r"pxb-pcie? devices cannot reside on a PCIe? bus"},
178    {'log':r"Ignoring smp_cpus value"},
179    {'log':r"sd_init failed: Drive 'sd0' is already in use because it has been automatically connected to another device"},
180    {'log':r"This CPU requires a smaller page size than the system is using"},
181    {'log':r"MSI-X support is mandatory in the S390 architecture"},
182    {'log':r"rom check and register reset failed"},
183    {'log':r"Unable to initialize GIC, CPUState for CPU#0 not valid"},
184    {'log':r"Multiple VT220 operator consoles are not supported"},
185    {'log':r"core 0 already populated"},
186    {'log':r"could not find stage1 bootloader"},
187
188    # other exitcode=1 failures not listed above will just generate INFO messages:
189    {'exitcode':1, 'loglevel':logging.INFO},
190
191    # everything else (including SIGABRT and SIGSEGV) will be a fatal error:
192    {'exitcode':None, 'fatal':True, 'loglevel':logging.FATAL},
193]
194
195
196def errorRuleTestCaseMatch(rule, t):
197    """Check if a test case specification can match a error rule
198
199    This only checks if a error rule is a candidate match
200    for a given test case, it won't check if the test case
201    results/output match the rule.  See ruleListResultMatch().
202    """
203    return (('machine' not in rule or
204             'machine' not in t or
205             re.match(rule['machine'] + '$', t['machine'])) and
206            ('accel' not in rule or
207             'accel' not in t or
208             re.match(rule['accel'] + '$', t['accel'])) and
209            ('device' not in rule or
210             'device' not in t or
211             re.match(rule['device'] + '$', t['device'])))
212
213
214def ruleListCandidates(t):
215    """Generate the list of candidates that can match a test case"""
216    for i, rule in enumerate(ERROR_RULE_LIST):
217        if errorRuleTestCaseMatch(rule, t):
218            yield (i, rule)
219
220
221def findExpectedResult(t):
222    """Check if there's an expected=True error rule for a test case
223
224    Returns (i, rule) tuple, where i is the index in
225    ERROR_RULE_LIST and rule is the error rule itself.
226    """
227    for i, rule in ruleListCandidates(t):
228        if rule.get('expected'):
229            return (i, rule)
230
231
232def ruleListResultMatch(rule, r):
233    """Check if test case results/output match a error rule
234
235    It is valid to call this function only if
236    errorRuleTestCaseMatch() is True for the rule (e.g. on
237    rules returned by ruleListCandidates())
238    """
239    assert errorRuleTestCaseMatch(rule, r['testcase'])
240    return ((rule.get('exitcode', 1) is None or
241             r['exitcode'] == rule.get('exitcode', 1)) and
242            ('log' not in rule or
243             re.search(rule['log'], r['log'], re.MULTILINE)))
244
245
246def checkResultRuleList(r):
247    """Look up error rule for a given test case result
248
249    Returns (i, rule) tuple, where i is the index in
250    ERROR_RULE_LIST and rule is the error rule itself.
251    """
252    for i, rule in ruleListCandidates(r['testcase']):
253        if ruleListResultMatch(rule, r):
254            return i, rule
255
256    raise Exception("this should never happen")
257
258
259def qemuOptsEscape(s):
260    """Escape option value QemuOpts"""
261    return s.replace(",", ",,")
262
263
264def formatTestCase(t):
265    """Format test case info as "key=value key=value" for prettier logging output"""
266    return ' '.join('%s=%s' % (k, v) for k, v in t.items())
267
268
269def qomListTypeNames(vm, **kwargs):
270    """Run qom-list-types QMP command, return type names"""
271    types = vm.cmd('qom-list-types', **kwargs)
272    return [t['name'] for t in types]
273
274
275def infoQDM(vm):
276    """Parse 'info qdm' output"""
277    args = {'command-line': 'info qdm'}
278    devhelp = vm.cmd('human-monitor-command', **args)
279    for l in devhelp.split('\n'):
280        l = l.strip()
281        if l == '' or l.endswith(':'):
282            continue
283        d = {'name': re.search(r'name "([^"]+)"', l).group(1),
284             'no-user': (re.search(', no-user', l) is not None)}
285        yield d
286
287
288class QemuBinaryInfo(object):
289    def __init__(self, binary, devtype):
290        if devtype is None:
291            devtype = 'device'
292
293        self.binary = binary
294        self._machine_info = {}
295
296        dbg("devtype: %r", devtype)
297        args = ['-S', '-machine', 'none,accel=kvm:tcg']
298        dbg("querying info for QEMU binary: %s", binary)
299        vm = QEMUMachine(binary=binary, args=args)
300        vm.launch()
301        try:
302            self.alldevs = set(qomListTypeNames(vm, implements=devtype, abstract=False))
303            # there's no way to query DeviceClass::user_creatable using QMP,
304            # so use 'info qdm':
305            self.no_user_devs = set([d['name'] for d in infoQDM(vm, ) if d['no-user']])
306            self.machines = list(m['name'] for m in vm.cmd('query-machines'))
307            self.user_devs = self.alldevs.difference(self.no_user_devs)
308            self.kvm_available = vm.cmd('query-kvm')['enabled']
309        finally:
310            vm.shutdown()
311
312    def machineInfo(self, machine):
313        """Query for information on a specific machine-type
314
315        Results are cached internally, in case the same machine-
316        type is queried multiple times.
317        """
318        if machine in self._machine_info:
319            return self._machine_info[machine]
320
321        mi = {}
322        args = ['-S', '-machine', '%s' % (machine)]
323        dbg("querying machine info for binary=%s machine=%s", self.binary, machine)
324        vm = QEMUMachine(binary=self.binary, args=args)
325        try:
326            vm.launch()
327            mi['runnable'] = True
328        except Exception:
329            dbg("exception trying to run binary=%s machine=%s", self.binary, machine, exc_info=sys.exc_info())
330            dbg("log: %r", vm.get_log())
331            mi['runnable'] = False
332
333        vm.shutdown()
334        self._machine_info[machine] = mi
335        return mi
336
337
338BINARY_INFO = {}
339
340
341def getBinaryInfo(args, binary):
342    if binary not in BINARY_INFO:
343        BINARY_INFO[binary] = QemuBinaryInfo(binary, args.devtype)
344    return BINARY_INFO[binary]
345
346
347def checkOneCase(args, testcase):
348    """Check one specific case
349
350    Returns a dictionary containing failure information on error,
351    or None on success
352    """
353    binary = testcase['binary']
354    accel = testcase['accel']
355    machine = testcase['machine']
356    device = testcase['device']
357
358    dbg("will test: %r", testcase)
359
360    args = ['-S', '-machine', '%s,accel=%s' % (machine, accel),
361            '-device', qemuOptsEscape(device)]
362    cmdline = ' '.join([binary] + args)
363    dbg("will launch QEMU: %s", cmdline)
364    vm = QEMUMachine(binary=binary, args=args, qmp_timer=15)
365
366    exc = None
367    exc_traceback = None
368    try:
369        vm.launch()
370    except Exception as this_exc:
371        exc = this_exc
372        exc_traceback = traceback.format_exc()
373        dbg("Exception while running test case")
374    finally:
375        vm.shutdown()
376        ec = vm.exitcode()
377        log = vm.get_log()
378
379    if exc is not None or ec != 0:
380        return {'exc': exc,
381                'exc_traceback':exc_traceback,
382                'exitcode':ec,
383                'log':log,
384                'testcase':testcase,
385                'cmdline':cmdline}
386
387
388def binariesToTest(args, testcase):
389    if args.qemu:
390        r = args.qemu
391    else:
392        r = [f.path for f in os.scandir('.')
393             if f.name.startswith('qemu-system-') and
394                f.is_file() and os.access(f, os.X_OK)]
395    return r
396
397
398def accelsToTest(args, testcase):
399    if getBinaryInfo(args, testcase['binary']).kvm_available and not args.tcg_only:
400        yield 'kvm'
401    yield 'tcg'
402
403
404def machinesToTest(args, testcase):
405    return getBinaryInfo(args, testcase['binary']).machines
406
407
408def devicesToTest(args, testcase):
409    return getBinaryInfo(args, testcase['binary']).user_devs
410
411
412TESTCASE_VARIABLES = [
413    ('binary', binariesToTest),
414    ('accel', accelsToTest),
415    ('machine', machinesToTest),
416    ('device', devicesToTest),
417]
418
419
420def genCases1(args, testcases, var, fn):
421    """Generate new testcases for one variable
422
423    If an existing item already has a variable set, don't
424    generate new items and just return it directly. This
425    allows the "-t" command-line option to be used to choose
426    a specific test case.
427    """
428    for testcase in testcases:
429        if var in testcase:
430            yield testcase.copy()
431        else:
432            for i in fn(args, testcase):
433                t = testcase.copy()
434                t[var] = i
435                yield t
436
437
438def genCases(args, testcase):
439    """Generate test cases for all variables
440    """
441    cases = [testcase.copy()]
442    for var, fn in TESTCASE_VARIABLES:
443        dbg("var: %r, fn: %r", var, fn)
444        cases = genCases1(args, cases, var, fn)
445    return cases
446
447
448def casesToTest(args, testcase):
449    cases = genCases(args, testcase)
450    if args.random:
451        cases = list(cases)
452        cases = random.sample(cases, min(args.random, len(cases)))
453    if args.debug:
454        cases = list(cases)
455        dbg("%d test cases to test", len(cases))
456    if args.shuffle:
457        cases = list(cases)
458        random.shuffle(cases)
459    return cases
460
461
462def logFailure(f, level):
463    t = f['testcase']
464    logger.log(level, "failed: %s", formatTestCase(t))
465    logger.log(level, "cmdline: %s", f['cmdline'])
466    for l in f['log'].strip().split('\n'):
467        logger.log(level, "log: %s", l)
468    logger.log(level, "exit code: %r", f['exitcode'])
469
470    # If the Exception is merely a QMP connect error,
471    # reduce the logging level for its traceback to
472    # improve visual clarity.
473    if isinstance(f.get('exc'), ConnectError):
474        logger.log(level, "%s.%s: %s",
475                   type(f['exc']).__module__,
476                   type(f['exc']).__qualname__,
477                   str(f['exc']))
478        level = logging.DEBUG
479
480    if f['exc_traceback']:
481        logger.log(level, "exception:")
482        for l in f['exc_traceback'].split('\n'):
483            logger.log(level, "  %s", l.rstrip('\n'))
484
485
486def main():
487    parser = argparse.ArgumentParser(description="QEMU -device crash test")
488    parser.add_argument('-t', metavar='KEY=VALUE', nargs='*',
489                        help="Limit test cases to KEY=VALUE",
490                        action='append', dest='testcases', default=[])
491    parser.add_argument('-d', '--debug', action='store_true',
492                        help='debug output')
493    parser.add_argument('-v', '--verbose', action='store_true', default=True,
494                        help='verbose output')
495    parser.add_argument('-q', '--quiet', dest='verbose', action='store_false',
496                        help='non-verbose output')
497    parser.add_argument('-r', '--random', type=int, metavar='COUNT',
498                        help='run a random sample of COUNT test cases',
499                        default=0)
500    parser.add_argument('--shuffle', action='store_true',
501                        help='Run test cases in random order')
502    parser.add_argument('--dry-run', action='store_true',
503                        help="Don't run any tests, just generate list")
504    parser.add_argument('-D', '--devtype', metavar='TYPE',
505                        help="Test only device types that implement TYPE")
506    parser.add_argument('-Q', '--quick', action='store_true', default=True,
507                        help="Quick mode: skip test cases that are expected to fail")
508    parser.add_argument('-F', '--full', action='store_false', dest='quick',
509                        help="Full mode: test cases that are expected to fail")
510    parser.add_argument('--strict', action='store_true', dest='strict',
511                        help="Treat all warnings as fatal")
512    parser.add_argument('--tcg-only', action='store_true', dest='tcg_only',
513                        help="Only test with TCG accelerator")
514    parser.add_argument('qemu', nargs='*', metavar='QEMU',
515                        help='QEMU binary to run')
516    args = parser.parse_args()
517
518    if args.debug:
519        lvl = logging.DEBUG
520    elif args.verbose:
521        lvl = logging.INFO
522    else:
523        lvl = logging.WARN
524    logging.basicConfig(stream=sys.stdout, level=lvl, format='%(levelname)s: %(message)s')
525
526    if not args.debug:
527        # Async QMP, when in use, is chatty about connection failures.
528        # This script knowingly generates a ton of connection errors.
529        # Silence this logger.
530        logging.getLogger('qemu.qmp.qmp_client').setLevel(logging.CRITICAL)
531
532    fatal_failures = []
533    wl_stats = {}
534    skipped = 0
535    total = 0
536
537    tc = {}
538    dbg("testcases: %r", args.testcases)
539    if args.testcases:
540        for t in chain(*args.testcases):
541            for kv in t.split():
542                k, v = kv.split('=', 1)
543                tc[k] = v
544
545    if len(binariesToTest(args, tc)) == 0:
546        print("No QEMU binary found", file=sys.stderr)
547        parser.print_usage(sys.stderr)
548        return 1
549
550    for t in casesToTest(args, tc):
551        logger.info("running test case: %s", formatTestCase(t))
552        total += 1
553
554        expected_match = findExpectedResult(t)
555        if (args.quick and
556                (expected_match or
557                 not getBinaryInfo(args, t['binary']).machineInfo(t['machine'])['runnable'])):
558            dbg("skipped: %s", formatTestCase(t))
559            skipped += 1
560            continue
561
562        if args.dry_run:
563            continue
564
565        try:
566            f = checkOneCase(args, t)
567        except KeyboardInterrupt:
568            break
569
570        if f:
571            i, rule = checkResultRuleList(f)
572            dbg("testcase: %r, rule list match: %r", t, rule)
573            wl_stats.setdefault(i, []).append(f)
574            level = rule.get('loglevel', logging.DEBUG)
575            logFailure(f, level)
576            if rule.get('fatal') or (args.strict and level >= logging.WARN):
577                fatal_failures.append(f)
578        else:
579            dbg("success: %s", formatTestCase(t))
580            if expected_match:
581                logger.warn("Didn't fail as expected: %s", formatTestCase(t))
582
583    logger.info("Total: %d test cases", total)
584    if skipped:
585        logger.info("Skipped %d test cases", skipped)
586
587    if args.debug:
588        stats = sorted([(len(wl_stats.get(i, [])), rule) for i, rule in
589                         enumerate(ERROR_RULE_LIST)], key=lambda x: x[0])
590        for count, rule in stats:
591            dbg("error rule stats: %d: %r", count, rule)
592
593    if fatal_failures:
594        for f in fatal_failures:
595            t = f['testcase']
596            logger.error("Fatal failure: %s", formatTestCase(t))
597        logger.error("Fatal failures on some machine/device combinations")
598        return 1
599
600if __name__ == '__main__':
601    sys.exit(main())
602