test/framework.py

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