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