test/framework.py

   1 #!/usr/bin/env python
   2
   3 from __future__ import print_function
   4 import gc
   5 import sys
   6 import os
   7 import select
   8 import unittest
   9 import tempfile
  10 import time
  11 import resource
  12 from collections import deque
  13 from threading import Thread, Event
  14 from inspect import getdoc
  15 from traceback import format_exception
  16 from logging import FileHandler, DEBUG, Formatter
  17 from scapy.packet import Raw
  18 from hook import StepHook, PollHook
  19 from vpp_pg_interface import VppPGInterface
  20 from vpp_sub_interface import VppSubInterface
  21 from vpp_lo_interface import VppLoInterface
  22 from vpp_papi_provider import VppPapiProvider
  23 from log import *
  24 from vpp_object import VppObjectRegistry
  25 if os.name == 'posix' and sys.version_info[0] < 3:
  26     # using subprocess32 is recommended by python official documentation
  27     # @ https://docs.python.org/2/library/subprocess.html
  28     import subprocess32 as subprocess
  29 else:
  30     import subprocess
  31
  32 """
  33   Test framework module.
  34
  35   The module provides a set of tools for constructing and running tests and
  36   representing the results.
  37 """
  38
  39
  40 class _PacketInfo(object):
  41     """Private class to create packet info object.
  42
  43     Help process information about the next packet.
  44     Set variables to default values.
  45     """
  46     #: Store the index of the packet.
  47     index = -1
  48     #: Store the index of the source packet generator interface of the packet.
  49     src = -1
  50     #: Store the index of the destination packet generator interface
  51     #: of the packet.
  52     dst = -1
  53     #: Store the copy of the former packet.
  54     data = None
  55
  56     def __eq__(self, other):
  57         index = self.index == other.index
  58         src = self.src == other.src
  59         dst = self.dst == other.dst
  60         data = self.data == other.data
  61         return index and src and dst and data
  62
  63
  64 def pump_output(testclass):
  65     """ pump output from vpp stdout/stderr to proper queues """
  66     while not testclass.pump_thread_stop_flag.wait(0):
  67         readable = select.select([testclass.vpp.stdout.fileno(),
  68                                   testclass.vpp.stderr.fileno(),
  69                                   testclass.pump_thread_wakeup_pipe[0]],
  70                                  [], [])[0]
  71         if testclass.vpp.stdout.fileno() in readable:
  72             read = os.read(testclass.vpp.stdout.fileno(), 1024)
  73             testclass.vpp_stdout_deque.append(read)
  74         if testclass.vpp.stderr.fileno() in readable:
  75             read = os.read(testclass.vpp.stderr.fileno(), 1024)
  76             testclass.vpp_stderr_deque.append(read)
  77         # ignoring the dummy pipe here intentionally - the flag will take care
  78         # of properly terminating the loop
  79
  80
  81 class VppTestCase(unittest.TestCase):
  82     """This subclass is a base class for VPP test cases that are implemented as
  83     classes. It provides methods to create and run test case.
  84     """
  85
  86     @property
  87     def packet_infos(self):
  88         """List of packet infos"""
  89         return self._packet_infos
  90
  91     @classmethod
  92     def get_packet_count_for_if_idx(cls, dst_if_index):
  93         """Get the number of packet info for specified destination if index"""
  94         if dst_if_index in cls._packet_count_for_dst_if_idx:
  95             return cls._packet_count_for_dst_if_idx[dst_if_index]
  96         else:
  97             return 0
  98
  99     @classmethod
 100     def instance(cls):
 101         """Return the instance of this testcase"""
 102         return cls.test_instance
 103
 104     @classmethod
 105     def set_debug_flags(cls, d):
 106         cls.debug_core = False
 107         cls.debug_gdb = False
 108         cls.debug_gdbserver = False
 109         if d is None:
 110             return
 111         dl = d.lower()
 112         if dl == "core":
 113             if resource.getrlimit(resource.RLIMIT_CORE)[0] <= 0:
 114                 # give a heads up if this is actually useless
 115                 print(colorize("WARNING: core size limit is set 0, core files "
 116                                "will NOT be created", RED))
 117             cls.debug_core = True
 118         elif dl == "gdb":
 119             cls.debug_gdb = True
 120         elif dl == "gdbserver":
 121             cls.debug_gdbserver = True
 122         else:
 123             raise Exception("Unrecognized DEBUG option: '%s'" % d)
 124
 125     @classmethod
 126     def setUpConstants(cls):
 127         """ Set-up the test case class based on environment variables """
 128         try:
 129             s = os.getenv("STEP")
 130             cls.step = True if s.lower() in ("y", "yes", "1") else False
 131         except:
 132             cls.step = False
 133         try:
 134             d = os.getenv("DEBUG")
 135         except:
 136             d = None
 137         cls.set_debug_flags(d)
 138         cls.vpp_bin = os.getenv('VPP_TEST_BIN', "vpp")
 139         cls.plugin_path = os.getenv('VPP_TEST_PLUGIN_PATH')
 140         debug_cli = ""
 141         if cls.step or cls.debug_gdb or cls.debug_gdbserver:
 142             debug_cli = "cli-listen localhost:5002"
 143         cls.vpp_cmdline = [cls.vpp_bin,
 144                            "unix", "{", "nodaemon", debug_cli, "}",
 145                            "api-segment", "{", "prefix", cls.shm_prefix, "}"]
 146         if cls.plugin_path is not None:
 147             cls.vpp_cmdline.extend(["plugin_path", cls.plugin_path])
 148         cls.logger.info("vpp_cmdline: %s" % cls.vpp_cmdline)
 149
 150     @classmethod
 151     def wait_for_enter(cls):
 152         if cls.debug_gdbserver:
 153             print(double_line_delim)
 154             print("Spawned GDB server with PID: %d" % cls.vpp.pid)
 155         elif cls.debug_gdb:
 156             print(double_line_delim)
 157             print("Spawned VPP with PID: %d" % cls.vpp.pid)
 158         else:
 159             cls.logger.debug("Spawned VPP with PID: %d" % cls.vpp.pid)
 160             return
 161         print(single_line_delim)
 162         print("You can debug the VPP using e.g.:")
 163         if cls.debug_gdbserver:
 164             print("gdb " + cls.vpp_bin + " -ex 'target remote localhost:7777'")
 165             print("Now is the time to attach a gdb by running the above "
 166                   "command, set up breakpoints etc. and then resume VPP from "
 167                   "within gdb by issuing the 'continue' command")
 168         elif cls.debug_gdb:
 169             print("gdb " + cls.vpp_bin + " -ex 'attach %s'" % cls.vpp.pid)
 170             print("Now is the time to attach a gdb by running the above "
 171                   "command and set up breakpoints etc.")
 172         print(single_line_delim)
 173         raw_input("Press ENTER to continue running the testcase...")
 174
 175     @classmethod
 176     def run_vpp(cls):
 177         cmdline = cls.vpp_cmdline
 178
 179         if cls.debug_gdbserver:
 180             gdbserver = '/usr/bin/gdbserver'
 181             if not os.path.isfile(gdbserver) or \
 182                     not os.access(gdbserver, os.X_OK):
 183                 raise Exception("gdbserver binary '%s' does not exist or is "
 184                                 "not executable" % gdbserver)
 185
 186             cmdline = [gdbserver, 'localhost:7777'] + cls.vpp_cmdline
 187             cls.logger.info("Gdbserver cmdline is %s", " ".join(cmdline))
 188
 189         try:
 190             cls.vpp = subprocess.Popen(cmdline,
 191                                        stdout=subprocess.PIPE,
 192                                        stderr=subprocess.PIPE,
 193                                        bufsize=1)
 194         except Exception as e:
 195             cls.logger.critical("Couldn't start vpp: %s" % e)
 196             raise
 197
 198         cls.wait_for_enter()
 199
 200     @classmethod
 201     def setUpClass(cls):
 202         """
 203         Perform class setup before running the testcase
 204         Remove shared memory files, start vpp and connect the vpp-api
 205         """
 206         gc.collect()  # run garbage collection first
 207         cls.logger = getLogger(cls.__name__)
 208         cls.tempdir = tempfile.mkdtemp(
 209             prefix='vpp-unittest-' + cls.__name__ + '-')
 210         file_handler = FileHandler("%s/log.txt" % cls.tempdir)
 211         file_handler.setFormatter(
 212             Formatter(fmt='%(asctime)s,%(msecs)03d %(message)s',
 213                       datefmt="%H:%M:%S"))
 214         file_handler.setLevel(DEBUG)
 215         cls.logger.addHandler(file_handler)
 216         cls.shm_prefix = cls.tempdir.split("/")[-1]
 217         os.chdir(cls.tempdir)
 218         cls.logger.info("Temporary dir is %s, shm prefix is %s",
 219                         cls.tempdir, cls.shm_prefix)
 220         cls.setUpConstants()
 221         cls.reset_packet_infos()
 222         cls._captures = []
 223         cls._zombie_captures = []
 224         cls.verbose = 0
 225         cls.vpp_dead = False
 226         cls.registry = VppObjectRegistry()
 227         print(double_line_delim)
 228         print(colorize(getdoc(cls).splitlines()[0], YELLOW))
 229         print(double_line_delim)
 230         # need to catch exceptions here because if we raise, then the cleanup
 231         # doesn't get called and we might end with a zombie vpp
 232         try:
 233             cls.run_vpp()
 234             cls.vpp_stdout_deque = deque()
 235             cls.vpp_stderr_deque = deque()
 236             cls.pump_thread_stop_flag = Event()
 237             cls.pump_thread_wakeup_pipe = os.pipe()
 238             cls.pump_thread = Thread(target=pump_output, args=(cls,))
 239             cls.pump_thread.daemon = True
 240             cls.pump_thread.start()
 241             cls.vapi = VppPapiProvider(cls.shm_prefix, cls.shm_prefix, cls)
 242             if cls.step:
 243                 hook = StepHook(cls)
 244             else:
 245                 hook = PollHook(cls)
 246             cls.vapi.register_hook(hook)
 247             cls.sleep(0.1, "after vpp startup, before initial poll")
 248             hook.poll_vpp()
 249             try:
 250                 cls.vapi.connect()
 251             except:
 252                 if cls.debug_gdbserver:
 253                     print(colorize("You're running VPP inside gdbserver but "
 254                                    "VPP-API connection failed, did you forget "
 255                                    "to 'continue' VPP from within gdb?", RED))
 256                 raise
 257         except:
 258             t, v, tb = sys.exc_info()
 259             try:
 260                 cls.quit()
 261             except:
 262                 pass
 263             raise t, v, tb
 264
 265     @classmethod
 266     def quit(cls):
 267         """
 268         Disconnect vpp-api, kill vpp and cleanup shared memory files
 269         """
 270         if (cls.debug_gdbserver or cls.debug_gdb) and hasattr(cls, 'vpp'):
 271             cls.vpp.poll()
 272             if cls.vpp.returncode is None:
 273                 print(double_line_delim)
 274                 print("VPP or GDB server is still running")
 275                 print(single_line_delim)
 276                 raw_input("When done debugging, press ENTER to kill the "
 277                           "process and finish running the testcase...")
 278
 279         os.write(cls.pump_thread_wakeup_pipe[1], 'ding dong wake up')
 280         cls.pump_thread_stop_flag.set()
 281         if hasattr(cls, 'pump_thread'):
 282             cls.logger.debug("Waiting for pump thread to stop")
 283             cls.pump_thread.join()
 284         if hasattr(cls, 'vpp_stderr_reader_thread'):
 285             cls.logger.debug("Waiting for stdderr pump to stop")
 286             cls.vpp_stderr_reader_thread.join()
 287
 288         if hasattr(cls, 'vpp'):
 289             if hasattr(cls, 'vapi'):
 290                 cls.vapi.disconnect()
 291                 del cls.vapi
 292             cls.vpp.poll()
 293             if cls.vpp.returncode is None:
 294                 cls.logger.debug("Sending TERM to vpp")
 295                 cls.vpp.terminate()
 296                 cls.logger.debug("Waiting for vpp to die")
 297                 cls.vpp.communicate()
 298             del cls.vpp
 299
 300         if hasattr(cls, 'vpp_stdout_deque'):
 301             cls.logger.info(single_line_delim)
 302             cls.logger.info('VPP output to stdout while running %s:',
 303                             cls.__name__)
 304             cls.logger.info(single_line_delim)
 305             f = open(cls.tempdir + '/vpp_stdout.txt', 'w')
 306             vpp_output = "".join(cls.vpp_stdout_deque)
 307             f.write(vpp_output)
 308             cls.logger.info('\n%s', vpp_output)
 309             cls.logger.info(single_line_delim)
 310
 311         if hasattr(cls, 'vpp_stderr_deque'):
 312             cls.logger.info(single_line_delim)
 313             cls.logger.info('VPP output to stderr while running %s:',
 314                             cls.__name__)
 315             cls.logger.info(single_line_delim)
 316             f = open(cls.tempdir + '/vpp_stderr.txt', 'w')
 317             vpp_output = "".join(cls.vpp_stderr_deque)
 318             f.write(vpp_output)
 319             cls.logger.info('\n%s', vpp_output)
 320             cls.logger.info(single_line_delim)
 321
 322     @classmethod
 323     def tearDownClass(cls):
 324         """ Perform final cleanup after running all tests in this test-case """
 325         cls.quit()
 326
 327     def tearDown(self):
 328         """ Show various debug prints after each test """
 329         self.logger.debug("--- tearDown() for %s.%s(%s) called ---" %
 330                           (self.__class__.__name__, self._testMethodName,
 331                            self._testMethodDoc))
 332         if not self.vpp_dead:
 333             self.logger.debug(self.vapi.cli("show trace"))
 334             self.logger.info(self.vapi.ppcli("show int"))
 335             self.logger.info(self.vapi.ppcli("show hardware"))
 336             self.logger.info(self.vapi.ppcli("show error"))
 337             self.logger.info(self.vapi.ppcli("show run"))
 338             self.registry.remove_vpp_config(self.logger)
 339
 340     def setUp(self):
 341         """ Clear trace before running each test"""
 342         self.logger.debug("--- setUp() for %s.%s(%s) called ---" %
 343                           (self.__class__.__name__, self._testMethodName,
 344                            self._testMethodDoc))
 345         if self.vpp_dead:
 346             raise Exception("VPP is dead when setting up the test")
 347         self.sleep(.1, "during setUp")
 348         self.vpp_stdout_deque.append(
 349             "--- test setUp() for %s.%s(%s) starts here ---\n" %
 350             (self.__class__.__name__, self._testMethodName,
 351              self._testMethodDoc))
 352         self.vpp_stderr_deque.append(
 353             "--- test setUp() for %s.%s(%s) starts here ---\n" %
 354             (self.__class__.__name__, self._testMethodName,
 355              self._testMethodDoc))
 356         self.vapi.cli("clear trace")
 357         # store the test instance inside the test class - so that objects
 358         # holding the class can access instance methods (like assertEqual)
 359         type(self).test_instance = self
 360
 361     @classmethod
 362     def pg_enable_capture(cls, interfaces):
 363         """
 364         Enable capture on packet-generator interfaces
 365
 366         :param interfaces: iterable interface indexes
 367
 368         """
 369         for i in interfaces:
 370             i.enable_capture()
 371
 372     @classmethod
 373     def register_capture(cls, cap_name):
 374         """ Register a capture in the testclass """
 375         # add to the list of captures with current timestamp
 376         cls._captures.append((time.time(), cap_name))
 377         # filter out from zombies
 378         cls._zombie_captures = [(stamp, name)
 379                                 for (stamp, name) in cls._zombie_captures
 380                                 if name != cap_name]
 381
 382     @classmethod
 383     def pg_start(cls):
 384         """ Remove any zombie captures and enable the packet generator """
 385         # how long before capture is allowed to be deleted - otherwise vpp
 386         # crashes - 100ms seems enough (this shouldn't be needed at all)
 387         capture_ttl = 0.1
 388         now = time.time()
 389         for stamp, cap_name in cls._zombie_captures:
 390             wait = stamp + capture_ttl - now
 391             if wait > 0:
 392                 cls.sleep(wait, "before deleting capture %s" % cap_name)
 393                 now = time.time()
 394             cls.logger.debug("Removing zombie capture %s" % cap_name)
 395             cls.vapi.cli('packet-generator delete %s' % cap_name)
 396
 397         cls.vapi.cli("trace add pg-input 50")  # 50 is maximum
 398         cls.vapi.cli('packet-generator enable')
 399         cls._zombie_captures = cls._captures
 400         cls._captures = []
 401
 402     @classmethod
 403     def create_pg_interfaces(cls, interfaces):
 404         """
 405         Create packet-generator interfaces.
 406
 407         :param interfaces: iterable indexes of the interfaces.
 408         :returns: List of created interfaces.
 409
 410         """
 411         result = []
 412         for i in interfaces:
 413             intf = VppPGInterface(cls, i)
 414             setattr(cls, intf.name, intf)
 415             result.append(intf)
 416         cls.pg_interfaces = result
 417         return result
 418
 419     @classmethod
 420     def create_loopback_interfaces(cls, interfaces):
 421         """
 422         Create loopback interfaces.
 423
 424         :param interfaces: iterable indexes of the interfaces.
 425         :returns: List of created interfaces.
 426         """
 427         result = []
 428         for i in interfaces:
 429             intf = VppLoInterface(cls, i)
 430             setattr(cls, intf.name, intf)
 431             result.append(intf)
 432         cls.lo_interfaces = result
 433         return result
 434
 435     @staticmethod
 436     def extend_packet(packet, size):
 437         """
 438         Extend packet to given size by padding with spaces
 439         NOTE: Currently works only when Raw layer is present.
 440
 441         :param packet: packet
 442         :param size: target size
 443
 444         """
 445         packet_len = len(packet) + 4
 446         extend = size - packet_len
 447         if extend > 0:
 448             packet[Raw].load += ' ' * extend
 449
 450     @classmethod
 451     def reset_packet_infos(cls):
 452         """ Reset the list of packet info objects and packet counts to zero """
 453         cls._packet_infos = {}
 454         cls._packet_count_for_dst_if_idx = {}
 455
 456     @classmethod
 457     def create_packet_info(cls, src_if, dst_if):
 458         """
 459         Create packet info object containing the source and destination indexes
 460         and add it to the testcase's packet info list
 461
 462         :param VppInterface src_if: source interface
 463         :param VppInterface dst_if: destination interface
 464
 465         :returns: _PacketInfo object
 466
 467         """
 468         info = _PacketInfo()
 469         info.index = len(cls._packet_infos)
 470         info.src = src_if.sw_if_index
 471         info.dst = dst_if.sw_if_index
 472         if isinstance(dst_if, VppSubInterface):
 473             dst_idx = dst_if.parent.sw_if_index
 474         else:
 475             dst_idx = dst_if.sw_if_index
 476         if dst_idx in cls._packet_count_for_dst_if_idx:
 477             cls._packet_count_for_dst_if_idx[dst_idx] += 1
 478         else:
 479             cls._packet_count_for_dst_if_idx[dst_idx] = 1
 480         cls._packet_infos[info.index] = info
 481         return info
 482
 483     @staticmethod
 484     def info_to_payload(info):
 485         """
 486         Convert _PacketInfo object to packet payload
 487
 488         :param info: _PacketInfo object
 489
 490         :returns: string containing serialized data from packet info
 491         """
 492         return "%d %d %d" % (info.index, info.src, info.dst)
 493
 494     @staticmethod
 495     def payload_to_info(payload):
 496         """
 497         Convert packet payload to _PacketInfo object
 498
 499         :param payload: packet payload
 500
 501         :returns: _PacketInfo object containing de-serialized data from payload
 502
 503         """
 504         numbers = payload.split()
 505         info = _PacketInfo()
 506         info.index = int(numbers[0])
 507         info.src = int(numbers[1])
 508         info.dst = int(numbers[2])
 509         return info
 510
 511     def get_next_packet_info(self, info):
 512         """
 513         Iterate over the packet info list stored in the testcase
 514         Start iteration with first element if info is None
 515         Continue based on index in info if info is specified
 516
 517         :param info: info or None
 518         :returns: next info in list or None if no more infos
 519         """
 520         if info is None:
 521             next_index = 0
 522         else:
 523             next_index = info.index + 1
 524         if next_index == len(self._packet_infos):
 525             return None
 526         else:
 527             return self._packet_infos[next_index]
 528
 529     def get_next_packet_info_for_interface(self, src_index, info):
 530         """
 531         Search the packet info list for the next packet info with same source
 532         interface index
 533
 534         :param src_index: source interface index to search for
 535         :param info: packet info - where to start the search
 536         :returns: packet info or None
 537
 538         """
 539         while True:
 540             info = self.get_next_packet_info(info)
 541             if info is None:
 542                 return None
 543             if info.src == src_index:
 544                 return info
 545
 546     def get_next_packet_info_for_interface2(self, src_index, dst_index, info):
 547         """
 548         Search the packet info list for the next packet info with same source
 549         and destination interface indexes
 550
 551         :param src_index: source interface index to search for
 552         :param dst_index: destination interface index to search for
 553         :param info: packet info - where to start the search
 554         :returns: packet info or None
 555
 556         """
 557         while True:
 558             info = self.get_next_packet_info_for_interface(src_index, info)
 559             if info is None:
 560                 return None
 561             if info.dst == dst_index:
 562                 return info
 563
 564     def assert_equal(self, real_value, expected_value, name_or_class=None):
 565         if name_or_class is None:
 566             self.assertEqual(real_value, expected_value, msg)
 567             return
 568         try:
 569             msg = "Invalid %s: %d('%s') does not match expected value %d('%s')"
 570             msg = msg % (getdoc(name_or_class).strip(),
 571                          real_value, str(name_or_class(real_value)),
 572                          expected_value, str(name_or_class(expected_value)))
 573         except:
 574             msg = "Invalid %s: %s does not match expected value %s" % (
 575                 name_or_class, real_value, expected_value)
 576
 577         self.assertEqual(real_value, expected_value, msg)
 578
 579     def assert_in_range(self,
 580                         real_value,
 581                         expected_min,
 582                         expected_max,
 583                         name=None):
 584         if name is None:
 585             msg = None
 586         else:
 587             msg = "Invalid %s: %s out of range <%s,%s>" % (
 588                 name, real_value, expected_min, expected_max)
 589         self.assertTrue(expected_min <= real_value <= expected_max, msg)
 590
 591     @classmethod
 592     def sleep(cls, timeout, remark=None):
 593         if hasattr(cls, 'logger'):
 594             cls.logger.debug("Sleeping for %ss (%s)" % (timeout, remark))
 595         time.sleep(timeout)
 596
 597
 598 class VppTestResult(unittest.TestResult):
 599     """
 600     @property result_string
 601      String variable to store the test case result string.
 602     @property errors
 603      List variable containing 2-tuples of TestCase instances and strings
 604      holding formatted tracebacks. Each tuple represents a test which
 605      raised an unexpected exception.
 606     @property failures
 607      List variable containing 2-tuples of TestCase instances and strings
 608      holding formatted tracebacks. Each tuple represents a test where
 609      a failure was explicitly signalled using the TestCase.assert*()
 610      methods.
 611     """
 612
 613     def __init__(self, stream, descriptions, verbosity):
 614         """
 615         :param stream File descriptor to store where to report test results.
 616             Set to the standard error stream by default.
 617         :param descriptions Boolean variable to store information if to use
 618             test case descriptions.
 619         :param verbosity Integer variable to store required verbosity level.
 620         """
 621         unittest.TestResult.__init__(self, stream, descriptions, verbosity)
 622         self.stream = stream
 623         self.descriptions = descriptions
 624         self.verbosity = verbosity
 625         self.result_string = None
 626
 627     def addSuccess(self, test):
 628         """
 629         Record a test succeeded result
 630
 631         :param test:
 632
 633         """
 634         if hasattr(test, 'logger'):
 635             test.logger.debug("--- addSuccess() %s.%s(%s) called"
 636                               % (test.__class__.__name__,
 637                                  test._testMethodName,
 638                                  test._testMethodDoc))
 639         unittest.TestResult.addSuccess(self, test)
 640         self.result_string = colorize("OK", GREEN)
 641
 642     def addSkip(self, test, reason):
 643         """
 644         Record a test skipped.
 645
 646         :param test:
 647         :param reason:
 648
 649         """
 650         if hasattr(test, 'logger'):
 651             test.logger.debug("--- addSkip() %s.%s(%s) called, reason is %s"
 652                               % (test.__class__.__name__,
 653                                  test._testMethodName,
 654                                  test._testMethodDoc,
 655                                  reason))
 656         unittest.TestResult.addSkip(self, test, reason)
 657         self.result_string = colorize("SKIP", YELLOW)
 658
 659     def addFailure(self, test, err):
 660         """
 661         Record a test failed result
 662
 663         :param test:
 664         :param err: error message
 665
 666         """
 667         if hasattr(test, 'logger'):
 668             test.logger.debug("--- addFailure() %s.%s(%s) called, err is %s"
 669                               % (test.__class__.__name__,
 670                                  test._testMethodName,
 671                                  test._testMethodDoc, err))
 672             test.logger.debug("formatted exception is:\n%s" %
 673                               "".join(format_exception(*err)))
 674         unittest.TestResult.addFailure(self, test, err)
 675         if hasattr(test, 'tempdir'):
 676             self.result_string = colorize("FAIL", RED) + \
 677                 ' [ temp dir used by test case: ' + test.tempdir + ' ]'
 678         else:
 679             self.result_string = colorize("FAIL", RED) + ' [no temp dir]'
 680
 681     def addError(self, test, err):
 682         """
 683         Record a test error result
 684
 685         :param test:
 686         :param err: error message
 687
 688         """
 689         if hasattr(test, 'logger'):
 690             test.logger.debug("--- addError() %s.%s(%s) called, err is %s"
 691                               % (test.__class__.__name__,
 692                                  test._testMethodName,
 693                                  test._testMethodDoc, err))
 694             test.logger.debug("formatted exception is:\n%s" %
 695                               "".join(format_exception(*err)))
 696         unittest.TestResult.addError(self, test, err)
 697         if hasattr(test, 'tempdir'):
 698             self.result_string = colorize("ERROR", RED) + \
 699                 ' [ temp dir used by test case: ' + test.tempdir + ' ]'
 700         else:
 701             self.result_string = colorize("ERROR", RED) + ' [no temp dir]'
 702
 703     def getDescription(self, test):
 704         """
 705         Get test description
 706
 707         :param test:
 708         :returns: test description
 709
 710         """
 711         # TODO: if none print warning not raise exception
 712         short_description = test.shortDescription()
 713         if self.descriptions and short_description:
 714             return short_description
 715         else:
 716             return str(test)
 717
 718     def startTest(self, test):
 719         """
 720         Start a test
 721
 722         :param test:
 723
 724         """
 725         unittest.TestResult.startTest(self, test)
 726         if self.verbosity > 0:
 727             self.stream.writeln(
 728                 "Starting " + self.getDescription(test) + " ...")
 729             self.stream.writeln(single_line_delim)
 730
 731     def stopTest(self, test):
 732         """
 733         Stop a test
 734
 735         :param test:
 736
 737         """
 738         unittest.TestResult.stopTest(self, test)
 739         if self.verbosity > 0:
 740             self.stream.writeln(single_line_delim)
 741             self.stream.writeln("%-73s%s" % (self.getDescription(test),
 742                                              self.result_string))
 743             self.stream.writeln(single_line_delim)
 744         else:
 745             self.stream.writeln("%-73s%s" % (self.getDescription(test),
 746                                              self.result_string))
 747
 748     def printErrors(self):
 749         """
 750         Print errors from running the test case
 751         """
 752         self.stream.writeln()
 753         self.printErrorList('ERROR', self.errors)
 754         self.printErrorList('FAIL', self.failures)
 755
 756     def printErrorList(self, flavour, errors):
 757         """
 758         Print error list to the output stream together with error type
 759         and test case description.
 760
 761         :param flavour: error type
 762         :param errors: iterable errors
 763
 764         """
 765         for test, err in errors:
 766             self.stream.writeln(double_line_delim)
 767             self.stream.writeln("%s: %s" %
 768                                 (flavour, self.getDescription(test)))
 769             self.stream.writeln(single_line_delim)
 770             self.stream.writeln("%s" % err)
 771
 772
 773 class VppTestRunner(unittest.TextTestRunner):
 774     """
 775     A basic test runner implementation which prints results to standard error.
 776     """
 777     @property
 778     def resultclass(self):
 779         """Class maintaining the results of the tests"""
 780         return VppTestResult
 781
 782     def __init__(self, stream=sys.stderr, descriptions=True, verbosity=1,
 783                  failfast=False, buffer=False, resultclass=None):
 784         # ignore stream setting here, use hard-coded stdout to be in sync
 785         # with prints from VppTestCase methods ...
 786         super(VppTestRunner, self).__init__(sys.stdout, descriptions,
 787                                             verbosity, failfast, buffer,
 788                                             resultclass)
 789
 790     test_option = "TEST"
 791
 792     def parse_test_option(self):
 793         try:
 794             f = os.getenv(self.test_option)
 795         except:
 796             f = None
 797         filter_file_name = None
 798         filter_class_name = None
 799         filter_func_name = None
 800         if f:
 801             if '.' in f:
 802                 parts = f.split('.')
 803                 if len(parts) > 3:
 804                     raise Exception("Unrecognized %s option: %s" %
 805                                     (self.test_option, f))
 806                 if len(parts) > 2:
 807                     if parts[2] not in ('*', ''):
 808                         filter_func_name = parts[2]
 809                 if parts[1] not in ('*', ''):
 810                     filter_class_name = parts[1]
 811                 if parts[0] not in ('*', ''):
 812                     if parts[0].startswith('test_'):
 813                         filter_file_name = parts[0]
 814                     else:
 815                         filter_file_name = 'test_%s' % parts[0]
 816             else:
 817                 if f.startswith('test_'):
 818                     filter_file_name = f
 819                 else:
 820                     filter_file_name = 'test_%s' % f
 821         return filter_file_name, filter_class_name, filter_func_name
 822
 823     def filter_tests(self, tests, filter_file, filter_class, filter_func):
 824         result = unittest.suite.TestSuite()
 825         for t in tests:
 826             if isinstance(t, unittest.suite.TestSuite):
 827                 # this is a bunch of tests, recursively filter...
 828                 x = self.filter_tests(t, filter_file, filter_class,
 829                                       filter_func)
 830                 if x.countTestCases() > 0:
 831                     result.addTest(x)
 832             elif isinstance(t, unittest.TestCase):
 833                 # this is a single test
 834                 parts = t.id().split('.')
 835                 # t.id() for common cases like this:
 836                 # test_classifier.TestClassifier.test_acl_ip
 837                 # apply filtering only if it is so
 838                 if len(parts) == 3:
 839                     if filter_file and filter_file != parts[0]:
 840                         continue
 841                     if filter_class and filter_class != parts[1]:
 842                         continue
 843                     if filter_func and filter_func != parts[2]:
 844                         continue
 845                 result.addTest(t)
 846             else:
 847                 # unexpected object, don't touch it
 848                 result.addTest(t)
 849         return result
 850
 851     def run(self, test):
 852         """
 853         Run the tests
 854
 855         :param test:
 856
 857         """
 858         gc.disable()  # disable garbage collection, we'll do that manually
 859         print("Running tests using custom test runner")  # debug message
 860         filter_file, filter_class, filter_func = self.parse_test_option()
 861         print("Active filters: file=%s, class=%s, function=%s" % (
 862             filter_file, filter_class, filter_func))
 863         filtered = self.filter_tests(test, filter_file, filter_class,
 864                                      filter_func)
 865         print("%s out of %s tests match specified filters" % (
 866             filtered.countTestCases(), test.countTestCases()))
 867         return super(VppTestRunner, self).run(filtered)