reassembly: feature/concurrency
[vpp.git] / test / framework.py
index 67f8a05..2167399 100644 (file)
 #!/usr/bin/env python
-## @package framework
-#  Module to handle test case execution.
-#
-#  The module provides a set of tools for constructing and running tests and
-#  representing the results.
-
-import logging
-logging.getLogger("scapy.runtime").setLevel(logging.ERROR)
 
+from __future__ import print_function
+import gc
+import sys
 import os
-import subprocess
+import select
 import unittest
-from inspect import getdoc
-
-from scapy.utils import wrpcap, rdpcap
+import tempfile
+import time
+import faulthandler
+import random
+import copy
+from collections import deque
+from threading import Thread, Event
+from inspect import getdoc, isclass
+from traceback import format_exception
+from logging import FileHandler, DEBUG, Formatter
 from scapy.packet import Raw
+from hook import StepHook, PollHook
+from vpp_pg_interface import VppPGInterface
+from vpp_sub_interface import VppSubInterface
+from vpp_lo_interface import VppLoInterface
+from vpp_papi_provider import VppPapiProvider
+from log import RED, GREEN, YELLOW, double_line_delim, single_line_delim, \
+    getLogger, colorize
+from vpp_object import VppObjectRegistry
+if os.name == 'posix' and sys.version_info[0] < 3:
+    # using subprocess32 is recommended by python official documentation
+    # @ https://docs.python.org/2/library/subprocess.html
+    import subprocess32 as subprocess
+else:
+    import subprocess
+
+debug_framework = False
+if os.getenv('TEST_DEBUG', "0") == "1":
+    debug_framework = True
+    import debug_internal
+
+
+"""
+  Test framework module.
+
+  The module provides a set of tools for constructing and running tests and
+  representing the results.
+"""
+
 
-## Static variables to store color formatting strings.
-#
-#  These variables (RED, GREEN, YELLOW and LPURPLE) are used to configure
-#  the color of the text to be printed in the terminal. Variable END is used
-#  to revert the text color to the default one.
-RED = '\033[91m'
-GREEN = '\033[92m'
-YELLOW = '\033[93m'
-LPURPLE = '\033[94m'
-END = '\033[0m'
-
-## Private class to create packet info object.
-#
-#  Help process information about the next packet.
-#  Set variables to default values.
 class _PacketInfo(object):
+    """Private class to create packet info object.
+
+    Help process information about the next packet.
+    Set variables to default values.
+    """
+    #: Store the index of the packet.
     index = -1
+    #: Store the index of the source packet generator interface of the packet.
     src = -1
+    #: Store the index of the destination packet generator interface
+    #: of the packet.
     dst = -1
+    #: Store expected ip version
+    ip = -1
+    #: Store expected upper protocol
+    proto = -1
+    #: Store the copy of the former packet.
     data = None
-    ## @var index
-    #  Integer variable to store the index of the packet.
-    ## @var src
-    #  Integer variable to store the index of the source packet generator
-    #  interface of the packet.
-    ## @var dst
-    #  Integer variable to store the index of the destination packet generator
-    #  interface of the packet.
-    ## @var data
-    #  Object variable to store the copy of the former packet.
-
-## Subclass of the python unittest.TestCase class.
-#
-#  This subclass is a base class for test cases that are implemented as classes.
-#  It provides methods to create and run test case.
+
+    def __eq__(self, other):
+        index = self.index == other.index
+        src = self.src == other.src
+        dst = self.dst == other.dst
+        data = self.data == other.data
+        return index and src and dst and data
+
+
+def pump_output(testclass):
+    """ pump output from vpp stdout/stderr to proper queues """
+    stdout_fragment = ""
+    stderr_fragment = ""
+    while not testclass.pump_thread_stop_flag.wait(0):
+        readable = select.select([testclass.vpp.stdout.fileno(),
+                                  testclass.vpp.stderr.fileno(),
+                                  testclass.pump_thread_wakeup_pipe[0]],
+                                 [], [])[0]
+        if testclass.vpp.stdout.fileno() in readable:
+            read = os.read(testclass.vpp.stdout.fileno(), 102400)
+            if len(read) > 0:
+                split = read.splitlines(True)
+                if len(stdout_fragment) > 0:
+                    split[0] = "%s%s" % (stdout_fragment, split[0])
+                if len(split) > 0 and split[-1].endswith("\n"):
+                    limit = None
+                else:
+                    limit = -1
+                    stdout_fragment = split[-1]
+                testclass.vpp_stdout_deque.extend(split[:limit])
+                if not testclass.cache_vpp_output:
+                    for line in split[:limit]:
+                        testclass.logger.debug(
+                            "VPP STDOUT: %s" % line.rstrip("\n"))
+        if testclass.vpp.stderr.fileno() in readable:
+            read = os.read(testclass.vpp.stderr.fileno(), 102400)
+            if len(read) > 0:
+                split = read.splitlines(True)
+                if len(stderr_fragment) > 0:
+                    split[0] = "%s%s" % (stderr_fragment, split[0])
+                if len(split) > 0 and split[-1].endswith("\n"):
+                    limit = None
+                else:
+                    limit = -1
+                    stderr_fragment = split[-1]
+                testclass.vpp_stderr_deque.extend(split[:limit])
+                if not testclass.cache_vpp_output:
+                    for line in split[:limit]:
+                        testclass.logger.debug(
+                            "VPP STDERR: %s" % line.rstrip("\n"))
+        # ignoring the dummy pipe here intentionally - the flag will take care
+        # of properly terminating the loop
+
+
+def running_extended_tests():
+    try:
+        s = os.getenv("EXTENDED_TESTS")
+        return True if s.lower() in ("y", "yes", "1") else False
+    except:
+        return False
+    return False
+
+
+def running_on_centos():
+    try:
+        os_id = os.getenv("OS_ID")
+        return True if "centos" in os_id.lower() else False
+    except:
+        return False
+    return False
+
+
+class KeepAliveReporter(object):
+    """
+    Singleton object which reports test start to parent process
+    """
+    _shared_state = {}
+
+    def __init__(self):
+        self.__dict__ = self._shared_state
+
+    @property
+    def pipe(self):
+        return self._pipe
+
+    @pipe.setter
+    def pipe(self, pipe):
+        if hasattr(self, '_pipe'):
+            raise Exception("Internal error - pipe should only be set once.")
+        self._pipe = pipe
+
+    def send_keep_alive(self, test):
+        """
+        Write current test tmpdir & desc to keep-alive pipe to signal liveness
+        """
+        if self.pipe is None:
+            # if not running forked..
+            return
+
+        if isclass(test):
+            desc = test.__name__
+        else:
+            desc = test.shortDescription()
+            if not desc:
+                desc = str(test)
+
+        self.pipe.send((desc, test.vpp_bin, test.tempdir, test.vpp.pid))
+
+
 class VppTestCase(unittest.TestCase):
+    """This subclass is a base class for VPP test cases that are implemented as
+    classes. It provides methods to create and run test case.
+    """
+
+    @property
+    def packet_infos(self):
+        """List of packet infos"""
+        return self._packet_infos
+
+    @classmethod
+    def get_packet_count_for_if_idx(cls, dst_if_index):
+        """Get the number of packet info for specified destination if index"""
+        if dst_if_index in cls._packet_count_for_dst_if_idx:
+            return cls._packet_count_for_dst_if_idx[dst_if_index]
+        else:
+            return 0
+
+    @classmethod
+    def instance(cls):
+        """Return the instance of this testcase"""
+        return cls.test_instance
+
+    @classmethod
+    def set_debug_flags(cls, d):
+        cls.debug_core = False
+        cls.debug_gdb = False
+        cls.debug_gdbserver = False
+        if d is None:
+            return
+        dl = d.lower()
+        if dl == "core":
+            cls.debug_core = True
+        elif dl == "gdb":
+            cls.debug_gdb = True
+        elif dl == "gdbserver":
+            cls.debug_gdbserver = True
+        else:
+            raise Exception("Unrecognized DEBUG option: '%s'" % d)
 
-    ## Class method to set class constants necessary to run test case.
-    #  @param cls The class pointer.
     @classmethod
     def setUpConstants(cls):
+        """ Set-up the test case class based on environment variables """
+        try:
+            s = os.getenv("STEP")
+            cls.step = True if s.lower() in ("y", "yes", "1") else False
+        except:
+            cls.step = False
+        try:
+            d = os.getenv("DEBUG")
+        except:
+            d = None
+        try:
+            c = os.getenv("CACHE_OUTPUT", "1")
+            cls.cache_vpp_output = \
+                False if c.lower() in ("n", "no", "0") else True
+        except:
+            cls.cache_vpp_output = True
+        cls.set_debug_flags(d)
         cls.vpp_bin = os.getenv('VPP_TEST_BIN', "vpp")
-        cls.vpp_api_test_bin = os.getenv("VPP_TEST_API_TEST_BIN",
-                                         "vpp-api-test")
-        cls.vpp_cmdline = [cls.vpp_bin, "unix", "nodaemon", "api-segment", "{",
-                           "prefix", "unittest", "}"]
-        cls.vpp_api_test_cmdline = [cls.vpp_api_test_bin, "chroot", "prefix",
-                                    "unittest"]
+        cls.plugin_path = os.getenv('VPP_TEST_PLUGIN_PATH')
+        cls.extern_plugin_path = os.getenv('EXTERN_PLUGINS')
+        plugin_path = None
+        if cls.plugin_path is not None:
+            if cls.extern_plugin_path is not None:
+                plugin_path = "%s:%s" % (
+                    cls.plugin_path, cls.extern_plugin_path)
+            else:
+                plugin_path = cls.plugin_path
+        elif cls.extern_plugin_path is not None:
+            plugin_path = cls.extern_plugin_path
+        debug_cli = ""
+        if cls.step or cls.debug_gdb or cls.debug_gdbserver:
+            debug_cli = "cli-listen localhost:5002"
+        coredump_size = None
         try:
-            cls.verbose = int(os.getenv("V", 0))
+            size = os.getenv("COREDUMP_SIZE")
+            if size is not None:
+                coredump_size = "coredump-size %s" % size
         except:
-            cls.verbose = 0
-
-        ## @var vpp_bin
-        #  String variable to store the path to vpp (vector packet processor).
-        ## @var vpp_api_test_bin
-        #  String variable to store the path to vpp_api_test (vpp API test tool).
-        ## @var vpp_cmdline
-        #  List of command line attributes for vpp.
-        ## @var vpp_api_test_cmdline
-        #  List of command line attributes for vpp_api_test.
-        ## @var verbose
-        #  Integer variable to store required verbosity level.
-
-    ## Class method to start the test case.
-    #  1. Initiate test case constants and set test case variables to default
-    #  values.
-    #  2. Remove files from the shared memory.
-    #  3. Start vpp as a subprocess.
-    #  @param cls The class pointer.
+            pass
+        if coredump_size is None:
+            coredump_size = "coredump-size unlimited"
+        cls.vpp_cmdline = [cls.vpp_bin, "unix",
+                           "{", "nodaemon", debug_cli, "full-coredump",
+                           coredump_size, "}", "api-trace", "{", "on", "}",
+                           "api-segment", "{", "prefix", cls.shm_prefix, "}",
+                           "plugins", "{", "plugin", "dpdk_plugin.so", "{",
+                           "disable", "}", "}", ]
+        if plugin_path is not None:
+            cls.vpp_cmdline.extend(["plugin_path", plugin_path])
+        cls.logger.info("vpp_cmdline: %s" % cls.vpp_cmdline)
+
+    @classmethod
+    def wait_for_enter(cls):
+        if cls.debug_gdbserver:
+            print(double_line_delim)
+            print("Spawned GDB server with PID: %d" % cls.vpp.pid)
+        elif cls.debug_gdb:
+            print(double_line_delim)
+            print("Spawned VPP with PID: %d" % cls.vpp.pid)
+        else:
+            cls.logger.debug("Spawned VPP with PID: %d" % cls.vpp.pid)
+            return
+        print(single_line_delim)
+        print("You can debug the VPP using e.g.:")
+        if cls.debug_gdbserver:
+            print("gdb " + cls.vpp_bin + " -ex 'target remote localhost:7777'")
+            print("Now is the time to attach a gdb by running the above "
+                  "command, set up breakpoints etc. and then resume VPP from "
+                  "within gdb by issuing the 'continue' command")
+        elif cls.debug_gdb:
+            print("gdb " + cls.vpp_bin + " -ex 'attach %s'" % cls.vpp.pid)
+            print("Now is the time to attach a gdb by running the above "
+                  "command and set up breakpoints etc.")
+        print(single_line_delim)
+        raw_input("Press ENTER to continue running the testcase...")
+
+    @classmethod
+    def run_vpp(cls):
+        cmdline = cls.vpp_cmdline
+
+        if cls.debug_gdbserver:
+            gdbserver = '/usr/bin/gdbserver'
+            if not os.path.isfile(gdbserver) or \
+                    not os.access(gdbserver, os.X_OK):
+                raise Exception("gdbserver binary '%s' does not exist or is "
+                                "not executable" % gdbserver)
+
+            cmdline = [gdbserver, 'localhost:7777'] + cls.vpp_cmdline
+            cls.logger.info("Gdbserver cmdline is %s", " ".join(cmdline))
+
+        try:
+            cls.vpp = subprocess.Popen(cmdline,
+                                       stdout=subprocess.PIPE,
+                                       stderr=subprocess.PIPE,
+                                       bufsize=1)
+        except Exception as e:
+            cls.logger.critical("Couldn't start vpp: %s" % e)
+            raise
+
+        cls.wait_for_enter()
+
     @classmethod
     def setUpClass(cls):
+        """
+        Perform class setup before running the testcase
+        Remove shared memory files, start vpp and connect the vpp-api
+        """
+        gc.collect()  # run garbage collection first
+        random.seed()
+        cls.logger = getLogger(cls.__name__)
+        cls.tempdir = tempfile.mkdtemp(
+            prefix='vpp-unittest-%s-' % cls.__name__)
+        cls.file_handler = FileHandler("%s/log.txt" % cls.tempdir)
+        cls.file_handler.setFormatter(
+            Formatter(fmt='%(asctime)s,%(msecs)03d %(message)s',
+                      datefmt="%H:%M:%S"))
+        cls.file_handler.setLevel(DEBUG)
+        cls.logger.addHandler(cls.file_handler)
+        cls.shm_prefix = cls.tempdir.split("/")[-1]
+        os.chdir(cls.tempdir)
+        cls.logger.info("Temporary dir is %s, shm prefix is %s",
+                        cls.tempdir, cls.shm_prefix)
         cls.setUpConstants()
-        cls.pg_streams = []
-        cls.MY_MACS = {}
-        cls.MY_IP4S = {}
-        cls.MY_IP6S = {}
-        cls.VPP_MACS = {}
-        cls.VPP_IP4S = {}
-        cls.VPP_IP6S = {}
-        cls.packet_infos = {}
-        print "=================================================================="
-        print YELLOW + getdoc(cls) + END
-        print "=================================================================="
-        os.system("rm -f /dev/shm/unittest-global_vm")
-        os.system("rm -f /dev/shm/unittest-vpe-api")
-        os.system("rm -f /dev/shm/unittest-db")
-        cls.vpp = subprocess.Popen(cls.vpp_cmdline, stderr=subprocess.PIPE)
-        ## @var pg_streams
-        #  List variable to store packet-generator streams for interfaces.
-        ## @var MY_MACS
-        #  Dictionary variable to store host MAC addresses connected to packet
-        #  generator interfaces.
-        ## @var MY_IP4S
-        #  Dictionary variable to store host IPv4 addresses connected to packet
-        #  generator interfaces.
-        ## @var MY_IP6S
-        #  Dictionary variable to store host IPv6 addresses connected to packet
-        #  generator interfaces.
-        ## @var VPP_MACS
-        #  Dictionary variable to store VPP MAC addresses of the packet
-        #  generator interfaces.
-        ## @var VPP_IP4S
-        #  Dictionary variable to store VPP IPv4 addresses of the packet
-        #  generator interfaces.
-        ## @var VPP_IP6S
-        #  Dictionary variable to store VPP IPv6 addresses of the packet
-        #  generator interfaces.
-        ## @var vpp
-        #  Test case object variable to store file descriptor of running vpp
-        #  subprocess with open pipe to the standard error stream per
-        #  VppTestCase object.
-
-    ## Class method to do cleaning when all tests (test_) defined for
-    #  VppTestCase class are finished.
-    #  1. Terminate vpp and kill all vpp instances.
-    #  2. Remove files from the shared memory.
-    #  @param cls The class pointer.
+        cls.reset_packet_infos()
+        cls._captures = []
+        cls._zombie_captures = []
+        cls.verbose = 0
+        cls.vpp_dead = False
+        cls.registry = VppObjectRegistry()
+        cls.vpp_startup_failed = False
+        cls.reporter = KeepAliveReporter()
+        # need to catch exceptions here because if we raise, then the cleanup
+        # doesn't get called and we might end with a zombie vpp
+        try:
+            cls.run_vpp()
+            cls.reporter.send_keep_alive(cls)
+            cls.vpp_stdout_deque = deque()
+            cls.vpp_stderr_deque = deque()
+            cls.pump_thread_stop_flag = Event()
+            cls.pump_thread_wakeup_pipe = os.pipe()
+            cls.pump_thread = Thread(target=pump_output, args=(cls,))
+            cls.pump_thread.daemon = True
+            cls.pump_thread.start()
+            cls.vapi = VppPapiProvider(cls.shm_prefix, cls.shm_prefix, cls)
+            if cls.step:
+                hook = StepHook(cls)
+            else:
+                hook = PollHook(cls)
+            cls.vapi.register_hook(hook)
+            cls.sleep(0.1, "after vpp startup, before initial poll")
+            try:
+                hook.poll_vpp()
+            except:
+                cls.vpp_startup_failed = True
+                cls.logger.critical(
+                    "VPP died shortly after startup, check the"
+                    " output to standard error for possible cause")
+                raise
+            try:
+                cls.vapi.connect()
+            except:
+                try:
+                    cls.vapi.disconnect()
+                except:
+                    pass
+                if cls.debug_gdbserver:
+                    print(colorize("You're running VPP inside gdbserver but "
+                                   "VPP-API connection failed, did you forget "
+                                   "to 'continue' VPP from within gdb?", RED))
+                raise
+        except:
+            t, v, tb = sys.exc_info()
+            try:
+                cls.quit()
+            except:
+                pass
+            raise (t, v, tb)
+
     @classmethod
     def quit(cls):
-        cls.vpp.terminate()
-        cls.vpp = None
-        os.system("rm -f /dev/shm/unittest-global_vm")
-        os.system("rm -f /dev/shm/unittest-vpe-api")
-        os.system("rm -f /dev/shm/unittest-db")
-
-    ## Class method to define tear down action of the VppTestCase class.
-    #  @param cls The class pointer.
+        """
+        Disconnect vpp-api, kill vpp and cleanup shared memory files
+        """
+        if (cls.debug_gdbserver or cls.debug_gdb) and hasattr(cls, 'vpp'):
+            cls.vpp.poll()
+            if cls.vpp.returncode is None:
+                print(double_line_delim)
+                print("VPP or GDB server is still running")
+                print(single_line_delim)
+                raw_input("When done debugging, press ENTER to kill the "
+                          "process and finish running the testcase...")
+
+        os.write(cls.pump_thread_wakeup_pipe[1], 'ding dong wake up')
+        cls.pump_thread_stop_flag.set()
+        if hasattr(cls, 'pump_thread'):
+            cls.logger.debug("Waiting for pump thread to stop")
+            cls.pump_thread.join()
+        if hasattr(cls, 'vpp_stderr_reader_thread'):
+            cls.logger.debug("Waiting for stdderr pump to stop")
+            cls.vpp_stderr_reader_thread.join()
+
+        if hasattr(cls, 'vpp'):
+            if hasattr(cls, 'vapi'):
+                cls.vapi.disconnect()
+                del cls.vapi
+            cls.vpp.poll()
+            if cls.vpp.returncode is None:
+                cls.logger.debug("Sending TERM to vpp")
+                cls.vpp.terminate()
+                cls.logger.debug("Waiting for vpp to die")
+                cls.vpp.communicate()
+            del cls.vpp
+
+        if cls.vpp_startup_failed:
+            stdout_log = cls.logger.info
+            stderr_log = cls.logger.critical
+        else:
+            stdout_log = cls.logger.info
+            stderr_log = cls.logger.info
+
+        if hasattr(cls, 'vpp_stdout_deque'):
+            stdout_log(single_line_delim)
+            stdout_log('VPP output to stdout while running %s:', cls.__name__)
+            stdout_log(single_line_delim)
+            vpp_output = "".join(cls.vpp_stdout_deque)
+            with open(cls.tempdir + '/vpp_stdout.txt', 'w') as f:
+                f.write(vpp_output)
+            stdout_log('\n%s', vpp_output)
+            stdout_log(single_line_delim)
+
+        if hasattr(cls, 'vpp_stderr_deque'):
+            stderr_log(single_line_delim)
+            stderr_log('VPP output to stderr while running %s:', cls.__name__)
+            stderr_log(single_line_delim)
+            vpp_output = "".join(cls.vpp_stderr_deque)
+            with open(cls.tempdir + '/vpp_stderr.txt', 'w') as f:
+                f.write(vpp_output)
+            stderr_log('\n%s', vpp_output)
+            stderr_log(single_line_delim)
+
     @classmethod
     def tearDownClass(cls):
+        """ Perform final cleanup after running all tests in this test-case """
         cls.quit()
+        cls.file_handler.close()
+        cls.reset_packet_infos()
+        if debug_framework:
+            debug_internal.on_tear_down_class(cls)
 
-    ## Method to define tear down VPP actions of the test case.
-    #  @param self The object pointer.
     def tearDown(self):
-        self.cli(2, "show int")
-        self.cli(2, "show trace")
-        self.cli(2, "show hardware")
-        self.cli(2, "show ip arp")
-        self.cli(2, "show ip fib")
-        self.cli(2, "show error")
-        self.cli(2, "show run")
-
-    ## Method to define setup action of the test case.
-    #  @param self The object pointer.
+        """ Show various debug prints after each test """
+        self.logger.debug("--- tearDown() for %s.%s(%s) called ---" %
+                          (self.__class__.__name__, self._testMethodName,
+                           self._testMethodDoc))
+        if not self.vpp_dead:
+            self.logger.debug(self.vapi.cli("show trace"))
+            self.logger.info(self.vapi.ppcli("show interface"))
+            self.logger.info(self.vapi.ppcli("show hardware"))
+            self.logger.info(self.vapi.ppcli("show error"))
+            self.logger.info(self.vapi.ppcli("show run"))
+            self.registry.remove_vpp_config(self.logger)
+            # Save/Dump VPP api trace log
+            api_trace = "vpp_api_trace.%s.log" % self._testMethodName
+            tmp_api_trace = "/tmp/%s" % api_trace
+            vpp_api_trace_log = "%s/%s" % (self.tempdir, api_trace)
+            self.logger.info(self.vapi.ppcli("api trace save %s" % api_trace))
+            self.logger.info("Moving %s to %s\n" % (tmp_api_trace,
+                                                    vpp_api_trace_log))
+            os.rename(tmp_api_trace, vpp_api_trace_log)
+            self.logger.info(self.vapi.ppcli("api trace custom-dump %s" %
+                                             vpp_api_trace_log))
+        else:
+            self.registry.unregister_all(self.logger)
+
     def setUp(self):
-        self.cli(2, "clear trace")
+        """ Clear trace before running each test"""
+        self.reporter.send_keep_alive(self)
+        self.logger.debug("--- setUp() for %s.%s(%s) called ---" %
+                          (self.__class__.__name__, self._testMethodName,
+                           self._testMethodDoc))
+        if self.vpp_dead:
+            raise Exception("VPP is dead when setting up the test")
+        self.sleep(.1, "during setUp")
+        self.vpp_stdout_deque.append(
+            "--- test setUp() for %s.%s(%s) starts here ---\n" %
+            (self.__class__.__name__, self._testMethodName,
+             self._testMethodDoc))
+        self.vpp_stderr_deque.append(
+            "--- test setUp() for %s.%s(%s) starts here ---\n" %
+            (self.__class__.__name__, self._testMethodName,
+             self._testMethodDoc))
+        self.vapi.cli("clear trace")
+        # store the test instance inside the test class - so that objects
+        # holding the class can access instance methods (like assertEqual)
+        type(self).test_instance = self
 
-    ## Class method to print logs.
-    #  Based on set level of verbosity print text in the terminal.
-    #  @param cls The class pointer.
-    #  @param s String variable to store text to be printed.
-    #  @param v Integer variable to store required level of verbosity.
     @classmethod
-    def log(cls, s, v=1):
-        if cls.verbose >= v:
-            print "LOG: " + LPURPLE + s + END
-
-    ## Class method to execute api commands.
-    #  Based on set level of verbosity print the output of the api command in
-    #  the terminal.
-    #  @param cls The class pointer.
-    #  @param s String variable to store api command string.
-    @classmethod
-    def api(cls, s):
-        p = subprocess.Popen(cls.vpp_api_test_cmdline,
-                             stdout=subprocess.PIPE,
-                             stdin=subprocess.PIPE,
-                             stderr=subprocess.PIPE)
-        if cls.verbose > 0:
-            print "API: " + RED + s + END
-        p.stdin.write(s)
-        out = p.communicate()[0]
-        out = out.replace("vat# ", "", 2)
-        if cls.verbose > 0:
-            if len(out) > 1:
-                print YELLOW + out + END
-        ## @var p
-        #  Object variable to store file descriptor of vpp_api_test subprocess
-        #  with open pipes to the standard output, inputs and error streams.
-        ## @var out
-        #  Tuple variable to store standard output of vpp_api_test subprocess
-        #  where the string "vat# " is replaced by empty string later.
-
-    ## Class method to execute cli commands.
-    #  Based on set level of verbosity of the log and verbosity defined by
-    #  environmental variable execute the cli command and print the output in
-    #  the terminal.
-    #  CLI command is executed via vpp API test tool (exec + cli_command)
-    #  @param cls The class pointer.
-    #  @param v Integer variable to store required level of verbosity.
-    #  @param s String variable to store cli command string.
-    @classmethod
-    def cli(cls, v, s):
-        if cls.verbose < v:
-            return
-        p = subprocess.Popen(cls.vpp_api_test_cmdline,
-                             stdout=subprocess.PIPE,
-                             stdin=subprocess.PIPE,
-                             stderr=subprocess.PIPE)
-        if cls.verbose > 0:
-            print "CLI: " + RED + s + END
-        p.stdin.write('exec ' + s)
-        out = p.communicate()[0]
-        out = out.replace("vat# ", "", 2)
-        if cls.verbose > 0:
-            if len(out) > 1:
-                print YELLOW + out + END
-        ## @var p
-        #  Object variable to store file descriptor of vpp_api_test subprocess
-        #  with open pipes to the standard output, inputs and error streams.
-        ## @var out
-        #  Tuple variable to store standard output of vpp_api_test subprocess
-        #  where the string "vat# " is replaced by empty string later.
-
-    ## Class method to create incoming packet stream for the packet-generator
-    #  interface.
-    #  Delete old /tmp/pgX_in.pcap file if exists and create the empty one and
-    #  fill it with provided packets and add it to pg_streams list.
-    #  @param cls The class pointer.
-    #  @param i Integer variable to store the index of the packet-generator
-    #  interface to create packet stream for.
-    #  @param pkts List variable to store packets to be added to the stream.
-    @classmethod
-    def pg_add_stream(cls, i, pkts):
-        os.system("sudo rm -f /tmp/pg%u_in.pcap" % i)
-        wrpcap("/tmp/pg%u_in.pcap" % i, pkts)
-        # no equivalent API command
-        cls.cli(0, "packet-generator new pcap /tmp/pg%u_in.pcap source pg%u"
-                   " name pcap%u" % (i, i, i))
-        cls.pg_streams.append('pcap%u' % i)
-
-    ## Class method to enable packet capturing for the packet-generator
-    #  interface.
-    #  Delete old /tmp/pgX_out.pcap file if exists and set the packet-generator
-    #  to capture outgoing packets to /tmp/pgX_out.pcap file.
-    #  @param cls The class pointer.
-    #  @param args List variable to store the indexes of the packet-generator
-    #  interfaces to start packet capturing for.
+    def pg_enable_capture(cls, interfaces=None):
+        """
+        Enable capture on packet-generator interfaces
+
+        :param interfaces: iterable interface indexes (if None,
+                           use self.pg_interfaces)
+
+        """
+        if interfaces is None:
+            interfaces = cls.pg_interfaces
+        for i in interfaces:
+            i.enable_capture()
+
     @classmethod
-    def pg_enable_capture(cls, args):
-        for i in args:
-            os.system("sudo rm -f /tmp/pg%u_out.pcap" % i)
-            cls.cli(0, "packet-generator capture pg%u pcap /tmp/pg%u_out.pcap"
-                    % (i, i))
-
-    ## Class method to start packet sending.
-    #  Start to send packets for all defined pg streams. Delete every stream
-    #  from the stream list when sent and clear the pg_streams list.
-    #  @param cls The class pointer.
+    def register_capture(cls, cap_name):
+        """ Register a capture in the testclass """
+        # add to the list of captures with current timestamp
+        cls._captures.append((time.time(), cap_name))
+        # filter out from zombies
+        cls._zombie_captures = [(stamp, name)
+                                for (stamp, name) in cls._zombie_captures
+                                if name != cap_name]
+
     @classmethod
     def pg_start(cls):
-        cls.cli(2, "trace add pg-input 50")  # 50 is maximum
-        cls.cli(0, 'packet-generator enable')
-        for stream in cls.pg_streams:
-            cls.cli(0, 'packet-generator delete %s' % stream)
-        cls.pg_streams = []
-
-    ## Class method to return captured packets.
-    #  Return packet captured for the defined packet-generator interface. Open
-    #  the corresponding pcap file (/tmp/pgX_out.pcap), read the content and
-    #  store captured packets to output variable.
-    #  @param cls The class pointer.
-    #  @param o Integer variable to store the index of the packet-generator
-    #  interface.
-    #  @return output List of packets captured on the defined packet-generator
-    #  interface. If the corresponding pcap file (/tmp/pgX_out.pcap) does not
-    #  exist return empty list.
+        """ Remove any zombie captures and enable the packet generator """
+        # how long before capture is allowed to be deleted - otherwise vpp
+        # crashes - 100ms seems enough (this shouldn't be needed at all)
+        capture_ttl = 0.1
+        now = time.time()
+        for stamp, cap_name in cls._zombie_captures:
+            wait = stamp + capture_ttl - now
+            if wait > 0:
+                cls.sleep(wait, "before deleting capture %s" % cap_name)
+                now = time.time()
+            cls.logger.debug("Removing zombie capture %s" % cap_name)
+            cls.vapi.cli('packet-generator delete %s' % cap_name)
+
+        cls.vapi.cli("trace add pg-input 50")  # 50 is maximum
+        cls.vapi.cli('packet-generator enable')
+        cls._zombie_captures = cls._captures
+        cls._captures = []
+
     @classmethod
-    def pg_get_capture(cls, o):
-        pcap_filename = "/tmp/pg%u_out.pcap" % o
-        try:
-            output = rdpcap(pcap_filename)
-        except IOError:  # TODO
-            cls.log("WARNING: File %s does not exist, probably because no"
-                    " packets arrived" % pcap_filename)
-            return []
-        return output
-        ## @var pcap_filename
-        #  File descriptor to the corresponding pcap file.
-
-    ## Class method to create packet-generator interfaces.
-    #  Create packet-generator interfaces and add host MAC addresses connected
-    #  to these packet-generator interfaces to the MY_MACS dictionary.
-    #  @param cls The class pointer.
-    #  @param args List variable to store the indexes of the packet-generator
-    #  interfaces to be created.
+    def create_pg_interfaces(cls, interfaces):
+        """
+        Create packet-generator interfaces.
+
+        :param interfaces: iterable indexes of the interfaces.
+        :returns: List of created interfaces.
+
+        """
+        result = []
+        for i in interfaces:
+            intf = VppPGInterface(cls, i)
+            setattr(cls, intf.name, intf)
+            result.append(intf)
+        cls.pg_interfaces = result
+        return result
+
     @classmethod
-    def create_interfaces(cls, args):
-        for i in args:
-            cls.MY_MACS[i] = "02:00:00:00:ff:%02x" % i
-            cls.log("My MAC address is %s" % (cls.MY_MACS[i]))
-            cls.api("pg_create_interface if_id %u" % i)
-            cls.api("sw_interface_set_flags pg%u admin-up" % i)
-
-    ## Static method to extend packet to specified size
-    #  Extend provided packet to the specified size (including Ethernet FCS).
-    #  The packet is extended by adding corresponding number of spaces to the
-    #  packet payload.
-    #  NOTE: Currently works only when Raw layer is present.
-    #  @param packet Variable to store packet object.
-    #  @param size Integer variable to store the required size of the packet.
+    def create_loopback_interfaces(cls, interfaces):
+        """
+        Create loopback interfaces.
+
+        :param interfaces: iterable indexes of the interfaces.
+        :returns: List of created interfaces.
+        """
+        result = []
+        for i in interfaces:
+            intf = VppLoInterface(cls, i)
+            setattr(cls, intf.name, intf)
+            result.append(intf)
+        cls.lo_interfaces = result
+        return result
+
     @staticmethod
-    def extend_packet(packet, size):
+    def extend_packet(packet, size, padding=' '):
+        """
+        Extend packet to given size by padding with spaces or custom padding
+        NOTE: Currently works only when Raw layer is present.
+
+        :param packet: packet
+        :param size: target size
+        :param padding: padding used to extend the payload
+
+        """
         packet_len = len(packet) + 4
         extend = size - packet_len
         if extend > 0:
-            packet[Raw].load += ' ' * extend
-        ## @var packet_len
-        #  Integer variable to store the current packet length including
-        #  Ethernet FCS.
-        ## @var extend
-        #  Integer variable to store the size of the packet extension.
-
-    ## Method to add packet info object to the packet_infos list.
-    #  Extend the existing packet_infos list with the given information from
-    #  the packet.
-    #  @param self The object pointer.
-    #  @param info Object to store required information from the packet.
-    def add_packet_info_to_list(self, info):
-        info.index = len(self.packet_infos)
-        self.packet_infos[info.index] = info
-        ## @var info.index
-        # Info object attribute to store the packet order in the stream.
-        ## @var packet_infos
-        #  List variable to store required information from packets.
-
-    ## Method to create packet info object.
-    #  Create the existing packet_infos list with the given information from
-    #  the packet.
-    #  @param self The object pointer.
-    #  @param pg_id Integer variable to store the index of the packet-generator
-    #  interface.
-    def create_packet_info(self, pg_id, target_id):
+            num = (extend / len(padding)) + 1
+            packet[Raw].load += (padding * num)[:extend]
+
+    @classmethod
+    def reset_packet_infos(cls):
+        """ Reset the list of packet info objects and packet counts to zero """
+        cls._packet_infos = {}
+        cls._packet_count_for_dst_if_idx = {}
+
+    @classmethod
+    def create_packet_info(cls, src_if, dst_if):
+        """
+        Create packet info object containing the source and destination indexes
+        and add it to the testcase's packet info list
+
+        :param VppInterface src_if: source interface
+        :param VppInterface dst_if: destination interface
+
+        :returns: _PacketInfo object
+
+        """
         info = _PacketInfo()
-        self.add_packet_info_to_list(info)
-        info.src = pg_id
-        info.dst = target_id
+        info.index = len(cls._packet_infos)
+        info.src = src_if.sw_if_index
+        info.dst = dst_if.sw_if_index
+        if isinstance(dst_if, VppSubInterface):
+            dst_idx = dst_if.parent.sw_if_index
+        else:
+            dst_idx = dst_if.sw_if_index
+        if dst_idx in cls._packet_count_for_dst_if_idx:
+            cls._packet_count_for_dst_if_idx[dst_idx] += 1
+        else:
+            cls._packet_count_for_dst_if_idx[dst_idx] = 1
+        cls._packet_infos[info.index] = info
         return info
-        ## @var info
-        #  Object to store required information from packet.
-        ## @var info.src
-        #  Info object attribute to store the index of the source packet
-        #  generator interface of the packet.
-        ## @var info.dst
-        #  Info object attribute to store the index of the destination packet
-        #  generator interface of the packet.
-
-    ## Static method to return packet info string.
-    #  Create packet info string from the provided info object that will be put
-    #  to the packet payload.
-    #  @param info Object to store required information from the packet.
-    #  @return String of information about packet's order in the stream, source
-    #  and destination packet generator interface.
+
     @staticmethod
     def info_to_payload(info):
-        return "%d %d %d" % (info.index, info.src, info.dst)
+        """
+        Convert _PacketInfo object to packet payload
+
+        :param info: _PacketInfo object
+
+        :returns: string containing serialized data from packet info
+        """
+        return "%d %d %d %d %d" % (info.index, info.src, info.dst,
+                                   info.ip, info.proto)
 
-    ## Static method to create packet info object from the packet payload.
-    #  Create packet info object and set its attribute values based on data
-    #  gained from the packet payload.
-    #  @param payload String variable to store packet payload.
-    #  @return info Object to store required information about the packet.
     @staticmethod
     def payload_to_info(payload):
+        """
+        Convert packet payload to _PacketInfo object
+
+        :param payload: packet payload
+
+        :returns: _PacketInfo object containing de-serialized data from payload
+
+        """
         numbers = payload.split()
         info = _PacketInfo()
         info.index = int(numbers[0])
         info.src = int(numbers[1])
         info.dst = int(numbers[2])
+        info.ip = int(numbers[3])
+        info.proto = int(numbers[4])
         return info
-        ## @var info.index
-        #  Info object attribute to store the packet order in the stream.
-        ## @var info.src
-        #  Info object attribute to store the index of the source packet
-        #  generator interface of the packet.
-        ## @var info.dst
-        #  Info object attribute to store the index of the destination packet
-        #  generator interface of the packet.
-
-    ## Method to return packet info object of the next packet in
-    #  the packet_infos list.
-    #  Get the next packet info object from the packet_infos list by increasing
-    #  the packet_infos list index by one.
-    #  @param self The object pointer.
-    #  @param info Object to store required information about the packet.
-    #  @return packet_infos[next_index] Next info object from the packet_infos
-    #  list with stored information about packets. Return None if the end of
-    #  the list is reached.
+
     def get_next_packet_info(self, info):
+        """
+        Iterate over the packet info list stored in the testcase
+        Start iteration with first element if info is None
+        Continue based on index in info if info is specified
+
+        :param info: info or None
+        :returns: next info in list or None if no more infos
+        """
         if info is None:
             next_index = 0
         else:
             next_index = info.index + 1
-        if next_index == len(self.packet_infos):
+        if next_index == len(self._packet_infos):
             return None
         else:
-            return self.packet_infos[next_index]
-        ## @var next_index
-        #  Integer variable to store the index of the next info object.
-
-    ## Method to return packet info object of the next packet with the required
-    #  source packet generator interface.
-    #  Iterate over the packet_infos list and search for the next packet info
-    #  object with the required source packet generator interface.
-    #  @param self The object pointer.
-    #  @param src_pg Integer variable to store index of requested source packet
-    #  generator interface.
-    #  @param info Object to store required information about the packet.
-    #  @return packet_infos[next_index] Next info object from the packet_infos
-    #  list with stored information about packets. Return None if the end of
-    #  the list is reached.
-    def get_next_packet_info_for_interface(self, src_pg, info):
+            return self._packet_infos[next_index]
+
+    def get_next_packet_info_for_interface(self, src_index, info):
+        """
+        Search the packet info list for the next packet info with same source
+        interface index
+
+        :param src_index: source interface index to search for
+        :param info: packet info - where to start the search
+        :returns: packet info or None
+
+        """
         while True:
             info = self.get_next_packet_info(info)
             if info is None:
                 return None
-            if info.src == src_pg:
+            if info.src == src_index:
                 return info
-        ## @var info.src
-        #  Info object attribute to store the index of the source packet
-        #  generator interface of the packet.
-
-    ## Method to return packet info object of the next packet with required
-    #  source and destination packet generator interfaces.
-    #  Search for the next packet info object with the required source and
-    #  destination packet generator interfaces.
-    #  @param self The object pointer.
-    #  @param src_pg Integer variable to store the index of the requested source
-    #  packet generator interface.
-    #  @param dst_pg Integer variable to store the index of the requested source
-    #  packet generator interface.
-    #  @param info Object to store required information about the packet.
-    #  @return info Object with the info about the next packet with with
-    #  required source and destination packet generator interfaces. Return None
-    #  if there is no other packet with required data.
-    def get_next_packet_info_for_interface2(self, src_pg, dst_pg, info):
+
+    def get_next_packet_info_for_interface2(self, src_index, dst_index, info):
+        """
+        Search the packet info list for the next packet info with same source
+        and destination interface indexes
+
+        :param src_index: source interface index to search for
+        :param dst_index: destination interface index to search for
+        :param info: packet info - where to start the search
+        :returns: packet info or None
+
+        """
         while True:
-            info = self.get_next_packet_info_for_interface(src_pg, info)
+            info = self.get_next_packet_info_for_interface(src_index, info)
             if info is None:
                 return None
-            if info.dst == dst_pg:
+            if info.dst == dst_index:
                 return info
-        ## @var info.dst
-        #  Info object attribute to store the index of the destination packet
-        #  generator interface of the packet.
+
+    def assert_equal(self, real_value, expected_value, name_or_class=None):
+        if name_or_class is None:
+            self.assertEqual(real_value, expected_value)
+            return
+        try:
+            msg = "Invalid %s: %d('%s') does not match expected value %d('%s')"
+            msg = msg % (getdoc(name_or_class).strip(),
+                         real_value, str(name_or_class(real_value)),
+                         expected_value, str(name_or_class(expected_value)))
+        except:
+            msg = "Invalid %s: %s does not match expected value %s" % (
+                name_or_class, real_value, expected_value)
+
+        self.assertEqual(real_value, expected_value, msg)
+
+    def assert_in_range(self,
+                        real_value,
+                        expected_min,
+                        expected_max,
+                        name=None):
+        if name is None:
+            msg = None
+        else:
+            msg = "Invalid %s: %s out of range <%s,%s>" % (
+                name, real_value, expected_min, expected_max)
+        self.assertTrue(expected_min <= real_value <= expected_max, msg)
+
+    @classmethod
+    def sleep(cls, timeout, remark=None):
+        if hasattr(cls, 'logger'):
+            cls.logger.debug("Starting sleep for %ss (%s)" % (timeout, remark))
+        before = time.time()
+        time.sleep(timeout)
+        after = time.time()
+        if after - before > 2 * timeout:
+            cls.logger.error("unexpected time.sleep() result - "
+                             "slept for %ss instead of ~%ss!" % (
+                                 after - before, timeout))
+        if hasattr(cls, 'logger'):
+            cls.logger.debug(
+                "Finished sleep (%s) - slept %ss (wanted %ss)" % (
+                    remark, after - before, timeout))
+
+    def send_and_assert_no_replies(self, intf, pkts, remark=""):
+        self.vapi.cli("clear trace")
+        intf.add_stream(pkts)
+        self.pg_enable_capture(self.pg_interfaces)
+        self.pg_start()
+        timeout = 1
+        for i in self.pg_interfaces:
+            i.get_capture(0, timeout=timeout)
+            i.assert_nothing_captured(remark=remark)
+            timeout = 0.1
+
+    def send_and_expect(self, input, pkts, output):
+        self.vapi.cli("clear trace")
+        input.add_stream(pkts)
+        self.pg_enable_capture(self.pg_interfaces)
+        self.pg_start()
+        rx = output.get_capture(len(pkts))
+        return rx
+
+
+class TestCasePrinter(object):
+    _shared_state = {}
+
+    def __init__(self):
+        self.__dict__ = self._shared_state
+        if not hasattr(self, "_test_case_set"):
+            self._test_case_set = set()
+
+    def print_test_case_heading_if_first_time(self, case):
+        if case.__class__ not in self._test_case_set:
+            print(double_line_delim)
+            print(colorize(getdoc(case.__class__).splitlines()[0], YELLOW))
+            print(double_line_delim)
+            self._test_case_set.add(case.__class__)
 
 
-## Subclass of the python unittest.TestResult class.
-#
-#  This subclass provides methods to compile information about which tests have
-#  succeeded and which have failed.
 class VppTestResult(unittest.TestResult):
-    ## The constructor.
-    #  @param stream File descriptor to store where to report test results. Set
-    #  to the standard error stream by default.
-    #  @param descriptions Boolean variable to store information if to use test
-    #  case descriptions.
-    #  @param verbosity Integer variable to store required verbosity level.
+    """
+    @property result_string
+     String variable to store the test case result string.
+    @property errors
+     List variable containing 2-tuples of TestCase instances and strings
+     holding formatted tracebacks. Each tuple represents a test which
+     raised an unexpected exception.
+    @property failures
+     List variable containing 2-tuples of TestCase instances and strings
+     holding formatted tracebacks. Each tuple represents a test where
+     a failure was explicitly signalled using the TestCase.assert*()
+     methods.
+    """
+
     def __init__(self, stream, descriptions, verbosity):
+        """
+        :param stream File descriptor to store where to report test results.
+            Set to the standard error stream by default.
+        :param descriptions Boolean variable to store information if to use
+            test case descriptions.
+        :param verbosity Integer variable to store required verbosity level.
+        """
         unittest.TestResult.__init__(self, stream, descriptions, verbosity)
         self.stream = stream
         self.descriptions = descriptions
         self.verbosity = verbosity
         self.result_string = None
-        ## @var result_string
-        #  String variable to store the test case result string.
-
+        self.printer = TestCasePrinter()
 
-    ## Method called when the test case succeeds.
-    #  Run the default implementation (that does nothing) and set the result
-    #  string in case of test case success.
-    #  @param self The object pointer.
-    #  @param test Object variable to store the test case instance.
     def addSuccess(self, test):
+        """
+        Record a test succeeded result
+
+        :param test:
+
+        """
+        if hasattr(test, 'logger'):
+            test.logger.debug("--- addSuccess() %s.%s(%s) called"
+                              % (test.__class__.__name__,
+                                 test._testMethodName,
+                                 test._testMethodDoc))
         unittest.TestResult.addSuccess(self, test)
-        self.result_string = GREEN + "OK" + END
-        ## @var result_string
-        #  String variable to store the test case result string.
-
-    ## Method called when the test case signals a failure.
-    #  Run the default implementation that appends a tuple (test, formatted_err)
-    #  to the instance's failures attribute, where formatted_err is a formatted
-    #  traceback derived from err and set the result string in case of test case
-    #  success.
-    #  @param self The object pointer.
-    #  @param test Object variable to store the test case instance.
-    #  @param err Tuple variable to store the error data:
-    #  (type, value, traceback).
+        self.result_string = colorize("OK", GREEN)
+
+    def addSkip(self, test, reason):
+        """
+        Record a test skipped.
+
+        :param test:
+        :param reason:
+
+        """
+        if hasattr(test, 'logger'):
+            test.logger.debug("--- addSkip() %s.%s(%s) called, reason is %s"
+                              % (test.__class__.__name__,
+                                 test._testMethodName,
+                                 test._testMethodDoc,
+                                 reason))
+        unittest.TestResult.addSkip(self, test, reason)
+        self.result_string = colorize("SKIP", YELLOW)
+
+    def symlink_failed(self, test):
+        logger = None
+        if hasattr(test, 'logger'):
+            logger = test.logger
+        if hasattr(test, 'tempdir'):
+            try:
+                failed_dir = os.getenv('VPP_TEST_FAILED_DIR')
+                link_path = '%s/%s-FAILED' % (failed_dir,
+                                              test.tempdir.split("/")[-1])
+                if logger:
+                    logger.debug("creating a link to the failed test")
+                    logger.debug("os.symlink(%s, %s)" %
+                                 (test.tempdir, link_path))
+                os.symlink(test.tempdir, link_path)
+            except Exception as e:
+                if logger:
+                    logger.error(e)
+
+    def send_failure_through_pipe(self, test):
+        if hasattr(self, 'test_framework_failed_pipe'):
+            pipe = self.test_framework_failed_pipe
+            if pipe:
+                pipe.send(test.__class__)
+
     def addFailure(self, test, err):
+        """
+        Record a test failed result
+
+        :param test:
+        :param err: error message
+
+        """
+        if hasattr(test, 'logger'):
+            test.logger.debug("--- addFailure() %s.%s(%s) called, err is %s"
+                              % (test.__class__.__name__,
+                                 test._testMethodName,
+                                 test._testMethodDoc, err))
+            test.logger.debug("formatted exception is:\n%s" %
+                              "".join(format_exception(*err)))
         unittest.TestResult.addFailure(self, test, err)
-        self.result_string = RED + "FAIL" + END
-        ## @var result_string
-        #  String variable to store the test case result string.
-
-    ## Method called when the test case raises an unexpected exception.
-    #  Run the default implementation that appends a tuple (test, formatted_err)
-    #  to the instance's error attribute, where formatted_err is a formatted
-    #  traceback derived from err and set the result string in case of test case
-    #  unexpected failure.
-    #  @param self The object pointer.
-    #  @param test Object variable to store the test case instance.
-    #  @param err Tuple variable to store the error data:
-    #  (type, value, traceback).
+        if hasattr(test, 'tempdir'):
+            self.result_string = colorize("FAIL", RED) + \
+                ' [ temp dir used by test case: ' + test.tempdir + ' ]'
+            self.symlink_failed(test)
+        else:
+            self.result_string = colorize("FAIL", RED) + ' [no temp dir]'
+
+        self.send_failure_through_pipe(test)
+
     def addError(self, test, err):
+        """
+        Record a test error result
+
+        :param test:
+        :param err: error message
+
+        """
+        if hasattr(test, 'logger'):
+            test.logger.debug("--- addError() %s.%s(%s) called, err is %s"
+                              % (test.__class__.__name__,
+                                 test._testMethodName,
+                                 test._testMethodDoc, err))
+            test.logger.debug("formatted exception is:\n%s" %
+                              "".join(format_exception(*err)))
         unittest.TestResult.addError(self, test, err)
-        self.result_string = RED + "ERROR" + END
-        ## @var result_string
-        #  String variable to store the test case result string.
-
-    ## Method to get the description of the test case.
-    #  Used to get the description string from the test case object.
-    #  @param self The object pointer.
-    #  @param test Object variable to store the test case instance.
-    #  @return String of the short description if exist otherwise return test
-    #  case name string.
+        if hasattr(test, 'tempdir'):
+            self.result_string = colorize("ERROR", RED) + \
+                ' [ temp dir used by test case: ' + test.tempdir + ' ]'
+            self.symlink_failed(test)
+        else:
+            self.result_string = colorize("ERROR", RED) + ' [no temp dir]'
+
+        self.send_failure_through_pipe(test)
+
     def getDescription(self, test):
+        """
+        Get test description
+
+        :param test:
+        :returns: test description
+
+        """
         # TODO: if none print warning not raise exception
         short_description = test.shortDescription()
         if self.descriptions and short_description:
             return short_description
         else:
             return str(test)
-        ## @var short_description
-        #  String variable to store the short description of the test case.
-
-    ## Method called when the test case is about to be run.
-    #  Run the default implementation and based on the set verbosity level write
-    #  the starting string to the output stream.
-    #  @param self The object pointer.
-    #  @param test Object variable to store the test case instance.
+
     def startTest(self, test):
+        """
+        Start a test
+
+        :param test:
+
+        """
+        self.printer.print_test_case_heading_if_first_time(test)
         unittest.TestResult.startTest(self, test)
         if self.verbosity > 0:
-            self.stream.writeln("Starting " + self.getDescription(test) + " ...")
-            self.stream.writeln("------------------------------------------------------------------")
-
-    ## Method called after the test case has been executed.
-    #  Run the default implementation and based on the set verbosity level write
-    #  the result string to the output stream.
-    #  @param self The object pointer.
-    #  @param test Object variable to store the test case instance.
+            self.stream.writeln(
+                "Starting " + self.getDescription(test) + " ...")
+            self.stream.writeln(single_line_delim)
+
     def stopTest(self, test):
+        """
+        Stop a test
+
+        :param test:
+
+        """
         unittest.TestResult.stopTest(self, test)
         if self.verbosity > 0:
-            self.stream.writeln("------------------------------------------------------------------")
-            self.stream.writeln("%-60s%s" % (self.getDescription(test), self.result_string))
-            self.stream.writeln("------------------------------------------------------------------")
+            self.stream.writeln(single_line_delim)
+            self.stream.writeln("%-73s%s" % (self.getDescription(test),
+                                             self.result_string))
+            self.stream.writeln(single_line_delim)
         else:
-            self.stream.writeln("%-60s%s" % (self.getDescription(test), self.result_string))
+            self.stream.writeln("%-73s%s" % (self.getDescription(test),
+                                             self.result_string))
 
-    ## Method to write errors and failures information to the output stream.
-    #  Write content of errors and failures lists to the output stream.
-    #  @param self The object pointer.
     def printErrors(self):
+        """
+        Print errors from running the test case
+        """
         self.stream.writeln()
         self.printErrorList('ERROR', self.errors)
         self.printErrorList('FAIL', self.failures)
-        ## @var errors
-        #  List variable containing 2-tuples of TestCase instances and strings
-        #  holding formatted tracebacks. Each tuple represents a test which
-        #  raised an unexpected exception.
-        ## @var failures
-        #  List variable containing 2-tuples of TestCase instances and strings
-        #  holding formatted tracebacks. Each tuple represents a test where
-        #  a failure was explicitly signalled using the TestCase.assert*()
-        #  methods.
-
-    ## Method to write the error information to the output stream.
-    #  Write content of error lists to the output stream together with error
-    #  type and test case description.
-    #  @param self The object pointer.
-    #  @param flavour String variable to store error type.
-    #  @param errors List variable to store 2-tuples of TestCase instances and
-    #  strings holding formatted tracebacks.
+
     def printErrorList(self, flavour, errors):
+        """
+        Print error list to the output stream together with error type
+        and test case description.
+
+        :param flavour: error type
+        :param errors: iterable errors
+
+        """
         for test, err in errors:
-            self.stream.writeln('=' * 70)
-            self.stream.writeln("%s: %s" % (flavour, self.getDescription(test)))
-            self.stream.writeln('-' * 70)
+            self.stream.writeln(double_line_delim)
+            self.stream.writeln("%s: %s" %
+                                (flavour, self.getDescription(test)))
+            self.stream.writeln(single_line_delim)
             self.stream.writeln("%s" % err)
-        ## @var test
-        #  Object variable to store the test case instance.
-        ## @var err
-        #  String variable to store formatted tracebacks.
 
 
-## Subclass of the python unittest.TextTestRunner class.
-#
-#  A basic test runner implementation which prints results on standard error.
+class Filter_by_test_option:
+    def __init__(self, filter_file_name, filter_class_name, filter_func_name):
+        self.filter_file_name = filter_file_name
+        self.filter_class_name = filter_class_name
+        self.filter_func_name = filter_func_name
+
+    def __call__(self, file_name, class_name, func_name):
+        if self.filter_file_name and file_name != self.filter_file_name:
+            return False
+        if self.filter_class_name and class_name != self.filter_class_name:
+            return False
+        if self.filter_func_name and func_name != self.filter_func_name:
+            return False
+        return True
+
+
 class VppTestRunner(unittest.TextTestRunner):
-    ##  Class object variable to store the results of a set of tests.
-    resultclass = VppTestResult
-
-    ## Method to run the test.
-    #  Print debug message in the terminal and run the standard run() method
-    #  of the test runner collecting the result into the test result object.
-    #  @param self The object pointer.
-    #  @param test Object variable to store the test case instance.
-    #  @return Test result object of the VppTestRunner.
+    """
+    A basic test runner implementation which prints results to standard error.
+    """
+    @property
+    def resultclass(self):
+        """Class maintaining the results of the tests"""
+        return VppTestResult
+
+    def __init__(self, keep_alive_pipe=None, failed_pipe=None,
+                 stream=sys.stderr, descriptions=True,
+                 verbosity=1, failfast=False, buffer=False, resultclass=None):
+        # ignore stream setting here, use hard-coded stdout to be in sync
+        # with prints from VppTestCase methods ...
+        super(VppTestRunner, self).__init__(sys.stdout, descriptions,
+                                            verbosity, failfast, buffer,
+                                            resultclass)
+        reporter = KeepAliveReporter()
+        reporter.pipe = keep_alive_pipe
+        # this is super-ugly, but very simple to implement and works as long
+        # as we run only one test at the same time
+        VppTestResult.test_framework_failed_pipe = failed_pipe
+
+    test_option = "TEST"
+
+    def parse_test_option(self):
+        try:
+            f = os.getenv(self.test_option)
+        except:
+            f = None
+        filter_file_name = None
+        filter_class_name = None
+        filter_func_name = None
+        if f:
+            if '.' in f:
+                parts = f.split('.')
+                if len(parts) > 3:
+                    raise Exception("Unrecognized %s option: %s" %
+                                    (self.test_option, f))
+                if len(parts) > 2:
+                    if parts[2] not in ('*', ''):
+                        filter_func_name = parts[2]
+                if parts[1] not in ('*', ''):
+                    filter_class_name = parts[1]
+                if parts[0] not in ('*', ''):
+                    if parts[0].startswith('test_'):
+                        filter_file_name = parts[0]
+                    else:
+                        filter_file_name = 'test_%s' % parts[0]
+            else:
+                if f.startswith('test_'):
+                    filter_file_name = f
+                else:
+                    filter_file_name = 'test_%s' % f
+        return filter_file_name, filter_class_name, filter_func_name
+
+    @staticmethod
+    def filter_tests(tests, filter_cb):
+        result = unittest.suite.TestSuite()
+        for t in tests:
+            if isinstance(t, unittest.suite.TestSuite):
+                # this is a bunch of tests, recursively filter...
+                x = VppTestRunner.filter_tests(t, filter_cb)
+                if x.countTestCases() > 0:
+                    result.addTest(x)
+            elif isinstance(t, unittest.TestCase):
+                # this is a single test
+                parts = t.id().split('.')
+                # t.id() for common cases like this:
+                # test_classifier.TestClassifier.test_acl_ip
+                # apply filtering only if it is so
+                if len(parts) == 3:
+                    if not filter_cb(parts[0], parts[1], parts[2]):
+                        continue
+                result.addTest(t)
+            else:
+                # unexpected object, don't touch it
+                result.addTest(t)
+        return result
+
     def run(self, test):
-        print "Running tests using custom test runner"  # debug message
-        return super(VppTestRunner, self).run(test)
+        """
+        Run the tests
+
+        :param test:
+
+        """
+        faulthandler.enable()  # emit stack trace to stderr if killed by signal
+        print("Running tests using custom test runner")  # debug message
+        filter_file, filter_class, filter_func = self.parse_test_option()
+        print("Active filters: file=%s, class=%s, function=%s" % (
+            filter_file, filter_class, filter_func))
+        filter_cb = Filter_by_test_option(
+            filter_file, filter_class, filter_func)
+        filtered = self.filter_tests(test, filter_cb)
+        print("%s out of %s tests match specified filters" % (
+            filtered.countTestCases(), test.countTestCases()))
+        if not running_extended_tests():
+            print("Not running extended tests (some tests will be skipped)")
+        return super(VppTestRunner, self).run(filtered)
+
+
+class Worker(Thread):
+    def __init__(self, args, logger, env={}):
+        self.logger = logger
+        self.args = args
+        self.result = None
+        self.env = copy.deepcopy(env)
+        super(Worker, self).__init__()
+
+    def run(self):
+        executable = self.args[0]
+        self.logger.debug("Running executable w/args `%s'" % self.args)
+        env = os.environ.copy()
+        env.update(self.env)
+        env["CK_LOG_FILE_NAME"] = "-"
+        self.process = subprocess.Popen(
+            self.args, shell=False, env=env, preexec_fn=os.setpgrp,
+            stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+        out, err = self.process.communicate()
+        self.logger.debug("Finished running `%s'" % executable)
+        self.logger.info("Return code is `%s'" % self.process.returncode)
+        self.logger.info(single_line_delim)
+        self.logger.info("Executable `%s' wrote to stdout:" % executable)
+        self.logger.info(single_line_delim)
+        self.logger.info(out)
+        self.logger.info(single_line_delim)
+        self.logger.info("Executable `%s' wrote to stderr:" % executable)
+        self.logger.info(single_line_delim)
+        self.logger.info(err)
+        self.logger.info(single_line_delim)
+        self.result = self.process.returncode