test/framework.py

   1 #!/usr/bin/env python
   2
   3 import subprocess
   4 import unittest
   5 import tempfile
   6 import time
   7 import resource
   8 from collections import deque
   9 from threading import Thread
  10 from inspect import getdoc
  11 from hook import StepHook, PollHook
  12 from vpp_pg_interface import VppPGInterface
  13 from vpp_sub_interface import VppSubInterface
  14 from vpp_lo_interface import VppLoInterface
  15 from vpp_papi_provider import VppPapiProvider
  16 from scapy.packet import Raw
  17 from logging import FileHandler, DEBUG
  18 from log import *
  19
  20 """
  21   Test framework module.
  22
  23   The module provides a set of tools for constructing and running tests and
  24   representing the results.
  25 """
  26
  27
  28 class _PacketInfo(object):
  29     """Private class to create packet info object.
  30
  31     Help process information about the next packet.
  32     Set variables to default values.
  33     """
  34     #: Store the index of the packet.
  35     index = -1
  36     #: Store the index of the source packet generator interface of the packet.
  37     src = -1
  38     #: Store the index of the destination packet generator interface
  39     #: of the packet.
  40     dst = -1
  41     #: Store the copy of the former packet.
  42     data = None
  43
  44     def __eq__(self, other):
  45         index = self.index == other.index
  46         src = self.src == other.src
  47         dst = self.dst == other.dst
  48         data = self.data == other.data
  49         return index and src and dst and data
  50
  51
  52 def pump_output(out, deque):
  53     for line in iter(out.readline, b''):
  54         deque.append(line)
  55
  56
  57 class VppTestCase(unittest.TestCase):
  58     """This subclass is a base class for VPP test cases that are implemented as
  59     classes. It provides methods to create and run test case.
  60     """
  61
  62     @property
  63     def packet_infos(self):
  64         """List of packet infos"""
  65         return self._packet_infos
  66
  67     @classmethod
  68     def get_packet_count_for_if_idx(cls, dst_if_index):
  69         """Get the number of packet info for specified destination if index"""
  70         if dst_if_index in cls._packet_count_for_dst_if_idx:
  71             return cls._packet_count_for_dst_if_idx[dst_if_index]
  72         else:
  73             return 0
  74
  75     @classmethod
  76     def instance(cls):
  77         """Return the instance of this testcase"""
  78         return cls.test_instance
  79
  80     @classmethod
  81     def set_debug_flags(cls, d):
  82         cls.debug_core = False
  83         cls.debug_gdb = False
  84         cls.debug_gdbserver = False
  85         if d is None:
  86             return
  87         dl = d.lower()
  88         if dl == "core":
  89             if resource.getrlimit(resource.RLIMIT_CORE)[0] <= 0:
  90                 # give a heads up if this is actually useless
  91                 cls.logger.critical("WARNING: core size limit is set 0, core "
  92                                     "files will NOT be created")
  93             cls.debug_core = True
  94         elif dl == "gdb":
  95             cls.debug_gdb = True
  96         elif dl == "gdbserver":
  97             cls.debug_gdbserver = True
  98         else:
  99             raise Exception("Unrecognized DEBUG option: '%s'" % d)
 100
 101     @classmethod
 102     def setUpConstants(cls):
 103         """ Set-up the test case class based on environment variables """
 104         try:
 105             s = os.getenv("STEP")
 106             cls.step = True if s.lower() in ("y", "yes", "1") else False
 107         except:
 108             cls.step = False
 109         try:
 110             d = os.getenv("DEBUG")
 111         except:
 112             d = None
 113         cls.set_debug_flags(d)
 114         cls.vpp_bin = os.getenv('VPP_TEST_BIN', "vpp")
 115         cls.plugin_path = os.getenv('VPP_TEST_PLUGIN_PATH')
 116         debug_cli = ""
 117         if cls.step or cls.debug_gdb or cls.debug_gdbserver:
 118             debug_cli = "cli-listen localhost:5002"
 119         cls.vpp_cmdline = [cls.vpp_bin, "unix", "{", "nodaemon", debug_cli, "}",
 120                            "api-segment", "{", "prefix", cls.shm_prefix, "}"]
 121         if cls.plugin_path is not None:
 122             cls.vpp_cmdline.extend(["plugin_path", cls.plugin_path])
 123         cls.logger.info("vpp_cmdline: %s" % cls.vpp_cmdline)
 124
 125     @classmethod
 126     def wait_for_enter(cls):
 127         if cls.debug_gdbserver:
 128             print(double_line_delim)
 129             print("Spawned GDB server with PID: %d" % cls.vpp.pid)
 130         elif cls.debug_gdb:
 131             print(double_line_delim)
 132             print("Spawned VPP with PID: %d" % cls.vpp.pid)
 133         else:
 134             cls.logger.debug("Spawned VPP with PID: %d" % cls.vpp.pid)
 135             return
 136         print(single_line_delim)
 137         print("You can debug the VPP using e.g.:")
 138         if cls.debug_gdbserver:
 139             print("gdb " + cls.vpp_bin + " -ex 'target remote localhost:7777'")
 140             print("Now is the time to attach a gdb by running the above "
 141                   "command, set up breakpoints etc. and then resume VPP from "
 142                   "within gdb by issuing the 'continue' command")
 143         elif cls.debug_gdb:
 144             print("gdb " + cls.vpp_bin + " -ex 'attach %s'" % cls.vpp.pid)
 145             print("Now is the time to attach a gdb by running the above "
 146                   "command and set up breakpoints etc.")
 147         print(single_line_delim)
 148         raw_input("Press ENTER to continue running the testcase...")
 149
 150     @classmethod
 151     def run_vpp(cls):
 152         cmdline = cls.vpp_cmdline
 153
 154         if cls.debug_gdbserver:
 155             gdbserver = '/usr/bin/gdbserver'
 156             if not os.path.isfile(gdbserver) or \
 157                     not os.access(gdbserver, os.X_OK):
 158                 raise Exception("gdbserver binary '%s' does not exist or is "
 159                                 "not executable" % gdbserver)
 160
 161             cmdline = [gdbserver, 'localhost:7777'] + cls.vpp_cmdline
 162             cls.logger.info("Gdbserver cmdline is %s", " ".join(cmdline))
 163
 164         try:
 165             cls.vpp = subprocess.Popen(cmdline,
 166                                        stdout=subprocess.PIPE,
 167                                        stderr=subprocess.PIPE,
 168                                        bufsize=1)
 169         except Exception as e:
 170             cls.logger.critical("Couldn't start vpp: %s" % e)
 171             raise
 172
 173         cls.wait_for_enter()
 174
 175     @classmethod
 176     def setUpClass(cls):
 177         """
 178         Perform class setup before running the testcase
 179         Remove shared memory files, start vpp and connect the vpp-api
 180         """
 181         cls.logger = getLogger(cls.__name__)
 182         cls.tempdir = tempfile.mkdtemp(
 183             prefix='vpp-unittest-' + cls.__name__ + '-')
 184         file_handler = FileHandler("%s/log.txt" % cls.tempdir)
 185         file_handler.setLevel(DEBUG)
 186         cls.logger.addHandler(file_handler)
 187         cls.shm_prefix = cls.tempdir.split("/")[-1]
 188         os.chdir(cls.tempdir)
 189         cls.logger.info("Temporary dir is %s, shm prefix is %s",
 190                         cls.tempdir, cls.shm_prefix)
 191         cls.setUpConstants()
 192         cls.reset_packet_infos()
 193         cls._captures = []
 194         cls._zombie_captures = []
 195         cls.verbose = 0
 196         cls.vpp_dead = False
 197         print(double_line_delim)
 198         print(colorize(getdoc(cls).splitlines()[0], YELLOW))
 199         print(double_line_delim)
 200         # need to catch exceptions here because if we raise, then the cleanup
 201         # doesn't get called and we might end with a zombie vpp
 202         try:
 203             cls.run_vpp()
 204             cls.vpp_stdout_deque = deque()
 205             cls.vpp_stdout_reader_thread = Thread(target=pump_output, args=(
 206                 cls.vpp.stdout, cls.vpp_stdout_deque))
 207             cls.vpp_stdout_reader_thread.start()
 208             cls.vpp_stderr_deque = deque()
 209             cls.vpp_stderr_reader_thread = Thread(target=pump_output, args=(
 210                 cls.vpp.stderr, cls.vpp_stderr_deque))
 211             cls.vpp_stderr_reader_thread.start()
 212             cls.vapi = VppPapiProvider(cls.shm_prefix, cls.shm_prefix, cls)
 213             if cls.step:
 214                 hook = StepHook(cls)
 215             else:
 216                 hook = PollHook(cls)
 217             cls.vapi.register_hook(hook)
 218             time.sleep(0.1)
 219             hook.poll_vpp()
 220             try:
 221                 cls.vapi.connect()
 222             except:
 223                 if cls.debug_gdbserver:
 224                     print(colorize("You're running VPP inside gdbserver but "
 225                                    "VPP-API connection failed, did you forget "
 226                                    "to 'continue' VPP from within gdb?", RED))
 227                 raise
 228         except:
 229             t, v, tb = sys.exc_info()
 230             try:
 231                 cls.quit()
 232             except:
 233                 pass
 234             raise t, v, tb
 235
 236     @classmethod
 237     def quit(cls):
 238         """
 239         Disconnect vpp-api, kill vpp and cleanup shared memory files
 240         """
 241         if (cls.debug_gdbserver or cls.debug_gdb) and hasattr(cls, 'vpp'):
 242             cls.vpp.poll()
 243             if cls.vpp.returncode is None:
 244                 print(double_line_delim)
 245                 print("VPP or GDB server is still running")
 246                 print(single_line_delim)
 247                 raw_input("When done debugging, press ENTER to kill the process"
 248                           " and finish running the testcase...")
 249
 250         if hasattr(cls, 'vpp'):
 251             if hasattr(cls, 'vapi'):
 252                 cls.vapi.disconnect()
 253             cls.vpp.poll()
 254             if cls.vpp.returncode is None:
 255                 cls.vpp.terminate()
 256             del cls.vpp
 257
 258         if hasattr(cls, 'vpp_stdout_deque'):
 259             cls.logger.info(single_line_delim)
 260             cls.logger.info('VPP output to stdout while running %s:',
 261                             cls.__name__)
 262             cls.logger.info(single_line_delim)
 263             f = open(cls.tempdir + '/vpp_stdout.txt', 'w')
 264             vpp_output = "".join(cls.vpp_stdout_deque)
 265             f.write(vpp_output)
 266             cls.logger.info('\n%s', vpp_output)
 267             cls.logger.info(single_line_delim)
 268
 269         if hasattr(cls, 'vpp_stderr_deque'):
 270             cls.logger.info(single_line_delim)
 271             cls.logger.info('VPP output to stderr while running %s:',
 272                             cls.__name__)
 273             cls.logger.info(single_line_delim)
 274             f = open(cls.tempdir + '/vpp_stderr.txt', 'w')
 275             vpp_output = "".join(cls.vpp_stderr_deque)
 276             f.write(vpp_output)
 277             cls.logger.info('\n%s', vpp_output)
 278             cls.logger.info(single_line_delim)
 279
 280     @classmethod
 281     def tearDownClass(cls):
 282         """ Perform final cleanup after running all tests in this test-case """
 283         cls.quit()
 284
 285     def tearDown(self):
 286         """ Show various debug prints after each test """
 287         if not self.vpp_dead:
 288             self.logger.debug(self.vapi.cli("show trace"))
 289             self.logger.info(self.vapi.ppcli("show int"))
 290             self.logger.info(self.vapi.ppcli("show hardware"))
 291             self.logger.info(self.vapi.ppcli("show error"))
 292             self.logger.info(self.vapi.ppcli("show run"))
 293
 294     def setUp(self):
 295         """ Clear trace before running each test"""
 296         if self.vpp_dead:
 297             raise Exception("VPP is dead when setting up the test")
 298         time.sleep(.1)
 299         self.vpp_stdout_deque.append(
 300             "--- test setUp() for %s.%s(%s) starts here ---\n" %
 301             (self.__class__.__name__, self._testMethodName,
 302              self._testMethodDoc))
 303         self.vpp_stderr_deque.append(
 304             "--- test setUp() for %s.%s(%s) starts here ---\n" %
 305             (self.__class__.__name__, self._testMethodName,
 306              self._testMethodDoc))
 307         self.vapi.cli("clear trace")
 308         # store the test instance inside the test class - so that objects
 309         # holding the class can access instance methods (like assertEqual)
 310         type(self).test_instance = self
 311
 312     @classmethod
 313     def pg_enable_capture(cls, interfaces):
 314         """
 315         Enable capture on packet-generator interfaces
 316
 317         :param interfaces: iterable interface indexes
 318
 319         """
 320         for i in interfaces:
 321             i.enable_capture()
 322
 323     @classmethod
 324     def register_capture(cls, cap_name):
 325         """ Register a capture in the testclass """
 326         # add to the list of captures with current timestamp
 327         cls._captures.append((time.time(), cap_name))
 328         # filter out from zombies
 329         cls._zombie_captures = [(stamp, name)
 330                                 for (stamp, name) in cls._zombie_captures
 331                                 if name != cap_name]
 332
 333     @classmethod
 334     def pg_start(cls):
 335         """ Remove any zombie captures and enable the packet generator """
 336         # how long before capture is allowed to be deleted - otherwise vpp
 337         # crashes - 100ms seems enough (this shouldn't be needed at all)
 338         capture_ttl = 0.1
 339         now = time.time()
 340         for stamp, cap_name in cls._zombie_captures:
 341             wait = stamp + capture_ttl - now
 342             if wait > 0:
 343                 cls.logger.debug("Waiting for %ss before deleting capture %s",
 344                                  wait, cap_name)
 345                 time.sleep(wait)
 346                 now = time.time()
 347             cls.logger.debug("Removing zombie capture %s" % cap_name)
 348             cls.vapi.cli('packet-generator delete %s' % cap_name)
 349
 350         cls.vapi.cli("trace add pg-input 50")  # 50 is maximum
 351         cls.vapi.cli('packet-generator enable')
 352         cls._zombie_captures = cls._captures
 353         cls._captures = []
 354
 355     @classmethod
 356     def create_pg_interfaces(cls, interfaces):
 357         """
 358         Create packet-generator interfaces
 359
 360         :param interfaces: iterable indexes of the interfaces
 361
 362         """
 363         result = []
 364         for i in interfaces:
 365             intf = VppPGInterface(cls, i)
 366             setattr(cls, intf.name, intf)
 367             result.append(intf)
 368         cls.pg_interfaces = result
 369         return result
 370
 371     @classmethod
 372     def create_loopback_interfaces(cls, interfaces):
 373         """
 374         Create loopback interfaces
 375
 376         :param interfaces: iterable indexes of the interfaces
 377
 378         """
 379         result = []
 380         for i in interfaces:
 381             intf = VppLoInterface(cls, i)
 382             setattr(cls, intf.name, intf)
 383             result.append(intf)
 384         cls.lo_interfaces = result
 385         return result
 386
 387     @staticmethod
 388     def extend_packet(packet, size):
 389         """
 390         Extend packet to given size by padding with spaces
 391         NOTE: Currently works only when Raw layer is present.
 392
 393         :param packet: packet
 394         :param size: target size
 395
 396         """
 397         packet_len = len(packet) + 4
 398         extend = size - packet_len
 399         if extend > 0:
 400             packet[Raw].load += ' ' * extend
 401
 402     @classmethod
 403     def reset_packet_infos(cls):
 404         """ Reset the list of packet info objects and packet counts to zero """
 405         cls._packet_infos = {}
 406         cls._packet_count_for_dst_if_idx = {}
 407
 408     @classmethod
 409     def create_packet_info(cls, src_if, dst_if):
 410         """
 411         Create packet info object containing the source and destination indexes
 412         and add it to the testcase's packet info list
 413
 414         :param VppInterface src_if: source interface
 415         :param VppInterface dst_if: destination interface
 416
 417         :returns: _PacketInfo object
 418
 419         """
 420         info = _PacketInfo()
 421         info.index = len(cls._packet_infos)
 422         info.src = src_if.sw_if_index
 423         info.dst = dst_if.sw_if_index
 424         if isinstance(dst_if, VppSubInterface):
 425             dst_idx = dst_if.parent.sw_if_index
 426         else:
 427             dst_idx = dst_if.sw_if_index
 428         if dst_idx in cls._packet_count_for_dst_if_idx:
 429             cls._packet_count_for_dst_if_idx[dst_idx] += 1
 430         else:
 431             cls._packet_count_for_dst_if_idx[dst_idx] = 1
 432         cls._packet_infos[info.index] = info
 433         return info
 434
 435     @staticmethod
 436     def info_to_payload(info):
 437         """
 438         Convert _PacketInfo object to packet payload
 439
 440         :param info: _PacketInfo object
 441
 442         :returns: string containing serialized data from packet info
 443         """
 444         return "%d %d %d" % (info.index, info.src, info.dst)
 445
 446     @staticmethod
 447     def payload_to_info(payload):
 448         """
 449         Convert packet payload to _PacketInfo object
 450
 451         :param payload: packet payload
 452
 453         :returns: _PacketInfo object containing de-serialized data from payload
 454
 455         """
 456         numbers = payload.split()
 457         info = _PacketInfo()
 458         info.index = int(numbers[0])
 459         info.src = int(numbers[1])
 460         info.dst = int(numbers[2])
 461         return info
 462
 463     def get_next_packet_info(self, info):
 464         """
 465         Iterate over the packet info list stored in the testcase
 466         Start iteration with first element if info is None
 467         Continue based on index in info if info is specified
 468
 469         :param info: info or None
 470         :returns: next info in list or None if no more infos
 471         """
 472         if info is None:
 473             next_index = 0
 474         else:
 475             next_index = info.index + 1
 476         if next_index == len(self._packet_infos):
 477             return None
 478         else:
 479             return self._packet_infos[next_index]
 480
 481     def get_next_packet_info_for_interface(self, src_index, info):
 482         """
 483         Search the packet info list for the next packet info with same source
 484         interface index
 485
 486         :param src_index: source interface index to search for
 487         :param info: packet info - where to start the search
 488         :returns: packet info or None
 489
 490         """
 491         while True:
 492             info = self.get_next_packet_info(info)
 493             if info is None:
 494                 return None
 495             if info.src == src_index:
 496                 return info
 497
 498     def get_next_packet_info_for_interface2(self, src_index, dst_index, info):
 499         """
 500         Search the packet info list for the next packet info with same source
 501         and destination interface indexes
 502
 503         :param src_index: source interface index to search for
 504         :param dst_index: destination interface index to search for
 505         :param info: packet info - where to start the search
 506         :returns: packet info or None
 507
 508         """
 509         while True:
 510             info = self.get_next_packet_info_for_interface(src_index, info)
 511             if info is None:
 512                 return None
 513             if info.dst == dst_index:
 514                 return info
 515
 516     def assert_equal(self, real_value, expected_value, name_or_class=None):
 517         if name_or_class is None:
 518             self.assertEqual(real_value, expected_value, msg)
 519             return
 520         try:
 521             msg = "Invalid %s: %d('%s') does not match expected value %d('%s')"
 522             msg = msg % (getdoc(name_or_class).strip(),
 523                          real_value, str(name_or_class(real_value)),
 524                          expected_value, str(name_or_class(expected_value)))
 525         except:
 526             msg = "Invalid %s: %s does not match expected value %s" % (
 527                 name_or_class, real_value, expected_value)
 528
 529         self.assertEqual(real_value, expected_value, msg)
 530
 531     def assert_in_range(
 532             self,
 533             real_value,
 534             expected_min,
 535             expected_max,
 536             name=None):
 537         if name is None:
 538             msg = None
 539         else:
 540             msg = "Invalid %s: %s out of range <%s,%s>" % (
 541                 name, real_value, expected_min, expected_max)
 542         self.assertTrue(expected_min <= real_value <= expected_max, msg)
 543
 544
 545 class VppTestResult(unittest.TestResult):
 546     """
 547     @property result_string
 548      String variable to store the test case result string.
 549     @property errors
 550      List variable containing 2-tuples of TestCase instances and strings
 551      holding formatted tracebacks. Each tuple represents a test which
 552      raised an unexpected exception.
 553     @property failures
 554      List variable containing 2-tuples of TestCase instances and strings
 555      holding formatted tracebacks. Each tuple represents a test where
 556      a failure was explicitly signalled using the TestCase.assert*()
 557      methods.
 558     """
 559
 560     def __init__(self, stream, descriptions, verbosity):
 561         """
 562         :param stream File descriptor to store where to report test results. Set
 563             to the standard error stream by default.
 564         :param descriptions Boolean variable to store information if to use test
 565             case descriptions.
 566         :param verbosity Integer variable to store required verbosity level.
 567         """
 568         unittest.TestResult.__init__(self, stream, descriptions, verbosity)
 569         self.stream = stream
 570         self.descriptions = descriptions
 571         self.verbosity = verbosity
 572         self.result_string = None
 573
 574     def addSuccess(self, test):
 575         """
 576         Record a test succeeded result
 577
 578         :param test:
 579
 580         """
 581         unittest.TestResult.addSuccess(self, test)
 582         self.result_string = colorize("OK", GREEN)
 583
 584     def addSkip(self, test, reason):
 585         """
 586         Record a test skipped.
 587
 588         :param test:
 589         :param reason:
 590
 591         """
 592         unittest.TestResult.addSkip(self, test, reason)
 593         self.result_string = colorize("SKIP", YELLOW)
 594
 595     def addFailure(self, test, err):
 596         """
 597         Record a test failed result
 598
 599         :param test:
 600         :param err: error message
 601
 602         """
 603         unittest.TestResult.addFailure(self, test, err)
 604         if hasattr(test, 'tempdir'):
 605             self.result_string = colorize("FAIL", RED) + \
 606                 ' [ temp dir used by test case: ' + test.tempdir + ' ]'
 607         else:
 608             self.result_string = colorize("FAIL", RED) + ' [no temp dir]'
 609
 610     def addError(self, test, err):
 611         """
 612         Record a test error result
 613
 614         :param test:
 615         :param err: error message
 616
 617         """
 618         unittest.TestResult.addError(self, test, err)
 619         if hasattr(test, 'tempdir'):
 620             self.result_string = colorize("ERROR", RED) + \
 621                 ' [ temp dir used by test case: ' + test.tempdir + ' ]'
 622         else:
 623             self.result_string = colorize("ERROR", RED) + ' [no temp dir]'
 624
 625     def getDescription(self, test):
 626         """
 627         Get test description
 628
 629         :param test:
 630         :returns: test description
 631
 632         """
 633         # TODO: if none print warning not raise exception
 634         short_description = test.shortDescription()
 635         if self.descriptions and short_description:
 636             return short_description
 637         else:
 638             return str(test)
 639
 640     def startTest(self, test):
 641         """
 642         Start a test
 643
 644         :param test:
 645
 646         """
 647         unittest.TestResult.startTest(self, test)
 648         if self.verbosity > 0:
 649             self.stream.writeln(
 650                 "Starting " + self.getDescription(test) + " ...")
 651             self.stream.writeln(single_line_delim)
 652
 653     def stopTest(self, test):
 654         """
 655         Stop a test
 656
 657         :param test:
 658
 659         """
 660         unittest.TestResult.stopTest(self, test)
 661         if self.verbosity > 0:
 662             self.stream.writeln(single_line_delim)
 663             self.stream.writeln("%-60s%s" %
 664                                 (self.getDescription(test), self.result_string))
 665             self.stream.writeln(single_line_delim)
 666         else:
 667             self.stream.writeln("%-60s%s" %
 668                                 (self.getDescription(test), self.result_string))
 669
 670     def printErrors(self):
 671         """
 672         Print errors from running the test case
 673         """
 674         self.stream.writeln()
 675         self.printErrorList('ERROR', self.errors)
 676         self.printErrorList('FAIL', self.failures)
 677
 678     def printErrorList(self, flavour, errors):
 679         """
 680         Print error list to the output stream together with error type
 681         and test case description.
 682
 683         :param flavour: error type
 684         :param errors: iterable errors
 685
 686         """
 687         for test, err in errors:
 688             self.stream.writeln(double_line_delim)
 689             self.stream.writeln("%s: %s" %
 690                                 (flavour, self.getDescription(test)))
 691             self.stream.writeln(single_line_delim)
 692             self.stream.writeln("%s" % err)
 693
 694
 695 class VppTestRunner(unittest.TextTestRunner):
 696     """
 697     A basic test runner implementation which prints results on standard error.
 698     """
 699     @property
 700     def resultclass(self):
 701         """Class maintaining the results of the tests"""
 702         return VppTestResult
 703
 704     def run(self, test):
 705         """
 706         Run the tests
 707
 708         :param test:
 709
 710         """
 711         print("Running tests using custom test runner")  # debug message
 712         return super(VppTestRunner, self).run(test)