misc: Fix python scripts shebang line
[vpp.git] / test / framework.py
index 59c451d..0138d24 100644 (file)
@@ -1,4 +1,4 @@
-#!/usr/bin/env python
+#!/usr/bin/env python3
 
 from __future__ import print_function
 import gc
@@ -159,7 +159,8 @@ def pump_output(testclass):
         if testclass.vpp.stdout.fileno() in readable:
             read = os.read(testclass.vpp.stdout.fileno(), 102400)
             if len(read) > 0:
-                split = read.splitlines(True)
+                split = read.decode('ascii',
+                                    errors='backslashreplace').splitlines(True)
                 if len(stdout_fragment) > 0:
                     split[0] = "%s%s" % (stdout_fragment, split[0])
                 if len(split) > 0 and split[-1].endswith("\n"):
@@ -175,14 +176,16 @@ def pump_output(testclass):
         if testclass.vpp.stderr.fileno() in readable:
             read = os.read(testclass.vpp.stderr.fileno(), 102400)
             if len(read) > 0:
-                split = read.splitlines(True)
+                split = read.decode('ascii',
+                                    errors='backslashreplace').splitlines(True)
                 if len(stderr_fragment) > 0:
                     split[0] = "%s%s" % (stderr_fragment, split[0])
-                if len(split) > 0 and split[-1].endswith(b"\n"):
+                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]:
@@ -218,7 +221,7 @@ def _running_on_centos():
     return True if "centos" in os_id.lower() else False
 
 
-running_on_centos = _running_on_centos
+running_on_centos = _running_on_centos()
 
 
 class KeepAliveReporter(object):
@@ -285,20 +288,24 @@ class VppTestCase(unittest.TestCase):
 
     @classmethod
     def set_debug_flags(cls, d):
+        cls.gdbserver_port = 7777
         cls.debug_core = False
         cls.debug_gdb = False
         cls.debug_gdbserver = False
+        cls.debug_all = False
         if d is None:
             return
         dl = d.lower()
         if dl == "core":
             cls.debug_core = True
-        elif dl == "gdb":
+        elif dl == "gdb" or dl == "gdb-all":
             cls.debug_gdb = True
-        elif dl == "gdbserver":
+        elif dl == "gdbserver" or dl == "gdbserver-all":
             cls.debug_gdbserver = True
         else:
             raise Exception("Unrecognized DEBUG option: '%s'" % d)
+        if dl == "gdb-all" or dl == "gdbserver-all":
+            cls.debug_all = True
 
     @staticmethod
     def get_least_used_cpu():
@@ -362,13 +369,16 @@ class VppTestCase(unittest.TestCase):
             coredump_size = "coredump-size unlimited"
 
         cpu_core_number = cls.get_least_used_cpu()
+        if not hasattr(cls, "worker_config"):
+            cls.worker_config = ""
 
         cls.vpp_cmdline = [cls.vpp_bin, "unix",
                            "{", "nodaemon", debug_cli, "full-coredump",
                            coredump_size, "runtime-dir", cls.tempdir, "}",
                            "api-trace", "{", "on", "}", "api-segment", "{",
                            "prefix", cls.shm_prefix, "}", "cpu", "{",
-                           "main-core", str(cpu_core_number), "}",
+                           "main-core", str(cpu_core_number),
+                           cls.worker_config, "}",
                            "statseg", "{", "socket-name", cls.stats_sock, "}",
                            "socksvr", "{", "socket-name", cls.api_sock, "}",
                            "plugins",
@@ -398,17 +408,20 @@ class VppTestCase(unittest.TestCase):
             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.:")
+        print("You can debug VPP using:")
         if cls.debug_gdbserver:
             print("sudo 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 "
+                  " -ex 'target remote localhost:{port}'"
+                  .format(port=cls.gdbserver_port))
+            print("Now is the time to attach gdb by running the above "
+                  "command, set up breakpoints etc., then resume VPP from "
                   "within gdb by issuing the 'continue' command")
+            cls.gdbserver_port += 1
         elif cls.debug_gdb:
             print("sudo 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("Now is the time to attach gdb by running the above "
+                  "command and set up breakpoints etc., then resume VPP from"
+                  " within gdb by issuing the 'continue' command")
         print(single_line_delim)
         input("Press ENTER to continue running the testcase...")
 
@@ -423,7 +436,8 @@ class VppTestCase(unittest.TestCase):
                 raise Exception("gdbserver binary '%s' does not exist or is "
                                 "not executable" % gdbserver)
 
-            cmdline = [gdbserver, 'localhost:7777'] + cls.vpp_cmdline
+            cmdline = [gdbserver, 'localhost:{port}'
+                       .format(port=cls.gdbserver_port)] + cls.vpp_cmdline
             cls.logger.info("Gdbserver cmdline is %s", " ".join(cmdline))
 
         try:
@@ -448,7 +462,7 @@ class VppTestCase(unittest.TestCase):
 
     @classmethod
     def wait_for_stats_socket(cls):
-        deadline = time.time() + 3
+        deadline = time.time() + 300
         ok = False
         while time.time() < deadline or \
                 cls.debug_gdb or cls.debug_gdbserver:
@@ -489,8 +503,9 @@ class VppTestCase(unittest.TestCase):
         """
         super(VppTestCase, cls).setUpClass()
         gc.collect()  # run garbage collection first
-        random.seed()
         cls.logger = get_logger(cls.__name__)
+        seed = os.environ["RND_SEED"]
+        random.seed(seed)
         if hasattr(cls, 'parallel_handler'):
             cls.logger.addHandler(cls.parallel_handler)
             cls.logger.propagate = False
@@ -511,10 +526,10 @@ class VppTestCase(unittest.TestCase):
         os.chdir(cls.tempdir)
         cls.logger.info("Temporary dir is %s, shm prefix is %s",
                         cls.tempdir, cls.shm_prefix)
+        cls.logger.debug("Random seed is %s" % seed)
         cls.setUpConstants()
         cls.reset_packet_infos()
         cls._captures = []
-        cls._zombie_captures = []
         cls.verbose = 0
         cls.vpp_dead = False
         cls.registry = VppObjectRegistry()
@@ -567,7 +582,8 @@ class VppTestCase(unittest.TestCase):
                                    "VPP-API connection failed, did you forget "
                                    "to 'continue' VPP from within gdb?", RED))
                 raise
-        except Exception:
+        except Exception as e:
+            cls.logger.debug("Exception connecting to VPP: %s" % e)
 
             cls.quit()
             raise
@@ -580,6 +596,7 @@ class VppTestCase(unittest.TestCase):
         if (cls.debug_gdbserver or cls.debug_gdb) and hasattr(cls, 'vpp'):
             cls.vpp.poll()
             if cls.vpp.returncode is None:
+                print()
                 print(double_line_delim)
                 print("VPP or GDB server is still running")
                 print(single_line_delim)
@@ -679,7 +696,8 @@ class VppTestCase(unittest.TestCase):
                 self.show_commands_at_teardown()
                 self.registry.remove_vpp_config(self.logger)
             # Save/Dump VPP api trace log
-            api_trace = "vpp_api_trace.%s.log" % self._testMethodName
+            m = self._testMethodName
+            api_trace = "vpp_api_trace.%s.%d.log" % (m, self.vpp.pid)
             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))
@@ -736,33 +754,42 @@ class VppTestCase(unittest.TestCase):
         """ 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):
-        """ 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)
+    def get_vpp_time(cls):
+        return float(cls.vapi.cli('show clock').replace("Time now ", ""))
 
+    @classmethod
+    def sleep_on_vpp_time(cls, sec):
+        """ Sleep according to time in VPP world """
+        # On a busy system with many processes
+        # we might end up with VPP time being slower than real world
+        # So take that into account when waiting for VPP to do something
+        start_time = cls.get_vpp_time()
+        while cls.get_vpp_time() - start_time < sec:
+            cls.sleep(0.1)
+
+    @classmethod
+    def pg_start(cls):
+        """ Enable the PG, wait till it is done, then clean up """
         cls.vapi.cli("trace add pg-input 1000")
         cls.vapi.cli('packet-generator enable')
-        cls._zombie_captures = cls._captures
+        # PG, when starts, runs to completion -
+        # so let's avoid a race condition,
+        # and wait a little till it's done.
+        # Then clean it up  - and then be gone.
+        deadline = time.time() + 300
+        while cls.vapi.cli('show packet-generator').find("Yes") != -1:
+            cls.sleep(0.01)  # yield
+            if time.time() > deadline:
+                cls.logger.error("Timeout waiting for pg to stop")
+                break
+        for stamp, cap_name in cls._captures:
+            cls.vapi.cli('packet-generator delete %s' % cap_name)
         cls._captures = []
 
     @classmethod
-    def create_pg_interfaces(cls, interfaces):
+    def create_pg_interfaces(cls, interfaces, gso=0, gso_size=0):
         """
         Create packet-generator interfaces.
 
@@ -772,7 +799,7 @@ class VppTestCase(unittest.TestCase):
         """
         result = []
         for i in interfaces:
-            intf = VppPGInterface(cls, i)
+            intf = VppPGInterface(cls, i, gso, gso_size)
             setattr(cls, intf.name, intf)
             result.append(intf)
         cls.pg_interfaces = result
@@ -973,8 +1000,6 @@ class VppTestCase(unittest.TestCase):
     def assert_packet_checksums_valid(self, packet,
                                       ignore_zero_udp_checksums=True):
         received = packet.__class__(scapy.compat.raw(packet))
-        self.logger.debug(
-            ppp("Verifying packet checksums for packet:", received))
         udp_layers = ['UDP', 'UDPerror']
         checksum_fields = ['cksum', 'chksum']
         checksums = []
@@ -1479,12 +1504,56 @@ class Worker(Thread):
     def __init__(self, args, logger, env=None):
         self.logger = logger
         self.args = args
+        if hasattr(self, 'testcase') and self.testcase.debug_all:
+            if self.testcase.debug_gdbserver:
+                self.args = ['/usr/bin/gdbserver', 'localhost:{port}'
+                             .format(port=self.testcase.gdbserver_port)] + args
+            elif self.testcase.debug_gdb and hasattr(self, 'wait_for_gdb'):
+                self.args.append(self.wait_for_gdb)
+        self.app_bin = args[0]
+        self.app_name = os.path.basename(self.app_bin)
+        if hasattr(self, 'role'):
+            self.app_name += ' {role}'.format(role=self.role)
         self.process = None
         self.result = None
         env = {} if env is None else env
         self.env = copy.deepcopy(env)
         super(Worker, self).__init__()
 
+    def wait_for_enter(self):
+        if not hasattr(self, 'testcase'):
+            return
+        if self.testcase.debug_all and self.testcase.debug_gdbserver:
+            print()
+            print(double_line_delim)
+            print("Spawned GDB Server for '{app}' with PID: {pid}"
+                  .format(app=self.app_name, pid=self.process.pid))
+        elif self.testcase.debug_all and self.testcase.debug_gdb:
+            print()
+            print(double_line_delim)
+            print("Spawned '{app}' with PID: {pid}"
+                  .format(app=self.app_name, pid=self.process.pid))
+        else:
+            return
+        print(single_line_delim)
+        print("You can debug '{app}' using:".format(app=self.app_name))
+        if self.testcase.debug_gdbserver:
+            print("sudo gdb " + self.app_bin +
+                  " -ex 'target remote localhost:{port}'"
+                  .format(port=self.testcase.gdbserver_port))
+            print("Now is the time to attach gdb by running the above "
+                  "command, set up breakpoints etc., then resume from "
+                  "within gdb by issuing the 'continue' command")
+            self.testcase.gdbserver_port += 1
+        elif self.testcase.debug_gdb:
+            print("sudo gdb " + self.app_bin +
+                  " -ex 'attach {pid}'".format(pid=self.process.pid))
+            print("Now is the time to attach gdb by running the above "
+                  "command and set up breakpoints etc., then resume from"
+                  " within gdb by issuing the 'continue' command")
+        print(single_line_delim)
+        input("Press ENTER to continue running the testcase...")
+
     def run(self):
         executable = self.args[0]
         if not os.path.exists(executable) or not os.access(
@@ -1494,24 +1563,28 @@ class Worker(Thread):
             self.result = os.EX_OSFILE
             raise EnvironmentError(
                 "executable '%s' is not found or executable." % executable)
-        self.logger.debug("Running executable w/args `%s'" % self.args)
+        self.logger.debug("Running executable: '{app}'"
+                          .format(app=' '.join(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)
+        self.wait_for_enter()
         out, err = self.process.communicate()
-        self.logger.debug("Finished running `%s'" % executable)
+        self.logger.debug("Finished running `{app}'".format(app=self.app_name))
         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("Executable `{app}' wrote to stdout:"
+                         .format(app=self.app_name))
         self.logger.info(single_line_delim)
-        self.logger.info(out)
+        self.logger.info(out.decode('utf-8'))
         self.logger.info(single_line_delim)
-        self.logger.info("Executable `%s' wrote to stderr:" % executable)
+        self.logger.info("Executable `{app}' wrote to stderr:"
+                         .format(app=self.app_name))
         self.logger.info(single_line_delim)
-        self.logger.info(err)
+        self.logger.info(err.decode('utf-8'))
         self.logger.info(single_line_delim)
         self.result = self.process.returncode