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