test/framework.py

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