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