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