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