3 from __future__ import print_function
19 from collections import deque
20 from threading import Thread, Event
21 from inspect import getdoc, isclass
22 from traceback import format_exception
23 from logging import FileHandler, DEBUG, Formatter
25 from abc import ABC, abstractmethod
26 from struct import pack, unpack
29 from scapy.packet import Raw, Packet
30 import hook as hookmodule
31 from vpp_pg_interface import VppPGInterface
32 from vpp_sub_interface import VppSubInterface
33 from vpp_lo_interface import VppLoInterface
34 from vpp_bvi_interface import VppBviInterface
35 from vpp_papi_provider import VppPapiProvider
36 from vpp_papi import VppEnum
38 from vpp_papi.vpp_stats import VPPStats
39 from vpp_papi.vpp_transport_socket import VppTransportSocketIOError
40 from log import RED, GREEN, YELLOW, double_line_delim, single_line_delim, \
42 from vpp_object import VppObjectRegistry
43 from util import ppp, is_core_present
44 from scapy.layers.inet import IPerror, TCPerror, UDPerror, ICMPerror
45 from scapy.layers.inet6 import ICMPv6DestUnreach, ICMPv6EchoRequest
46 from scapy.layers.inet6 import ICMPv6EchoReply
48 from cpu_config import available_cpus, num_cpus, max_vpp_cpus
50 logger = logging.getLogger(__name__)
52 # Set up an empty logger for the testcase that can be overridden as necessary
53 null_logger = logging.getLogger('VppTestCase')
54 null_logger.addHandler(logging.NullHandler())
64 class BoolEnvironmentVariable(object):
66 def __init__(self, env_var_name, default='n', true_values=None):
67 self.name = env_var_name
68 self.default = default
69 self.true_values = true_values if true_values is not None else \
73 return os.getenv(self.name, self.default).lower() in self.true_values
75 if sys.version_info[0] == 2:
76 __nonzero__ = __bool__
79 return 'BoolEnvironmentVariable(%r, default=%r, true_values=%r)' % \
80 (self.name, self.default, self.true_values)
83 debug_framework = BoolEnvironmentVariable('TEST_DEBUG')
88 Test framework module.
90 The module provides a set of tools for constructing and running tests and
91 representing the results.
95 class VppDiedError(Exception):
96 """ exception for reporting that the subprocess has died."""
98 signals_by_value = {v: k for k, v in signal.__dict__.items() if
99 k.startswith('SIG') and not k.startswith('SIG_')}
101 def __init__(self, rv=None, testcase=None, method_name=None):
103 self.signal_name = None
104 self.testcase = testcase
105 self.method_name = method_name
108 self.signal_name = VppDiedError.signals_by_value[-rv]
109 except (KeyError, TypeError):
112 if testcase is None and method_name is None:
115 in_msg = ' while running %s.%s' % (testcase, method_name)
118 msg = "VPP subprocess died unexpectedly%s with return code: %d%s."\
119 % (in_msg, self.rv, ' [%s]' %
121 self.signal_name is not None else ''))
123 msg = "VPP subprocess died unexpectedly%s." % in_msg
125 super(VppDiedError, self).__init__(msg)
128 class _PacketInfo(object):
129 """Private class to create packet info object.
131 Help process information about the next packet.
132 Set variables to default values.
134 #: Store the index of the packet.
136 #: Store the index of the source packet generator interface of the packet.
138 #: Store the index of the destination packet generator interface
141 #: Store expected ip version
143 #: Store expected upper protocol
145 #: Store the copy of the former packet.
148 def __eq__(self, other):
149 index = self.index == other.index
150 src = self.src == other.src
151 dst = self.dst == other.dst
152 data = self.data == other.data
153 return index and src and dst and data
156 def pump_output(testclass):
157 """ pump output from vpp stdout/stderr to proper queues """
160 while not testclass.pump_thread_stop_flag.is_set():
161 readable = select.select([testclass.vpp.stdout.fileno(),
162 testclass.vpp.stderr.fileno(),
163 testclass.pump_thread_wakeup_pipe[0]],
165 if testclass.vpp.stdout.fileno() in readable:
166 read = os.read(testclass.vpp.stdout.fileno(), 102400)
168 split = read.decode('ascii',
169 errors='backslashreplace').splitlines(True)
170 if len(stdout_fragment) > 0:
171 split[0] = "%s%s" % (stdout_fragment, split[0])
172 if len(split) > 0 and split[-1].endswith("\n"):
176 stdout_fragment = split[-1]
177 testclass.vpp_stdout_deque.extend(split[:limit])
178 if not testclass.cache_vpp_output:
179 for line in split[:limit]:
180 testclass.logger.info(
181 "VPP STDOUT: %s" % line.rstrip("\n"))
182 if testclass.vpp.stderr.fileno() in readable:
183 read = os.read(testclass.vpp.stderr.fileno(), 102400)
185 split = read.decode('ascii',
186 errors='backslashreplace').splitlines(True)
187 if len(stderr_fragment) > 0:
188 split[0] = "%s%s" % (stderr_fragment, split[0])
189 if len(split) > 0 and split[-1].endswith("\n"):
193 stderr_fragment = split[-1]
195 testclass.vpp_stderr_deque.extend(split[:limit])
196 if not testclass.cache_vpp_output:
197 for line in split[:limit]:
198 testclass.logger.error(
199 "VPP STDERR: %s" % line.rstrip("\n"))
200 # ignoring the dummy pipe here intentionally - the
201 # flag will take care of properly terminating the loop
204 def _is_skip_aarch64_set():
205 return BoolEnvironmentVariable('SKIP_AARCH64')
208 is_skip_aarch64_set = _is_skip_aarch64_set()
211 def _is_platform_aarch64():
212 return platform.machine() == 'aarch64'
215 is_platform_aarch64 = _is_platform_aarch64()
218 def _running_extended_tests():
219 return BoolEnvironmentVariable("EXTENDED_TESTS")
222 running_extended_tests = _running_extended_tests()
225 def _running_gcov_tests():
226 return BoolEnvironmentVariable("GCOV_TESTS")
229 running_gcov_tests = _running_gcov_tests()
232 def get_environ_vpp_worker_count():
233 worker_config = os.getenv("VPP_WORKER_CONFIG", None)
235 elems = worker_config.split(" ")
236 if elems[0] != "workers" or len(elems) != 2:
237 raise ValueError("Wrong VPP_WORKER_CONFIG == '%s' value." %
244 environ_vpp_worker_count = get_environ_vpp_worker_count()
247 class KeepAliveReporter(object):
249 Singleton object which reports test start to parent process
254 self.__dict__ = self._shared_state
262 def pipe(self, pipe):
263 if self._pipe is not None:
264 raise Exception("Internal error - pipe should only be set once.")
267 def send_keep_alive(self, test, desc=None):
269 Write current test tmpdir & desc to keep-alive pipe to signal liveness
271 if self.pipe is None:
272 # if not running forked..
276 desc = '%s (%s)' % (desc, unittest.util.strclass(test))
280 self.pipe.send((desc, test.vpp_bin, test.tempdir, test.vpp.pid))
283 class TestCaseTag(Enum):
284 # marks the suites that must run at the end
285 # using only a single test runner
287 # marks the suites broken on VPP multi-worker
288 FIXME_VPP_WORKERS = 2
289 # marks the suites broken when ASan is enabled
293 def create_tag_decorator(e):
296 cls.test_tags.append(e)
297 except AttributeError:
303 tag_run_solo = create_tag_decorator(TestCaseTag.RUN_SOLO)
304 tag_fixme_vpp_workers = create_tag_decorator(TestCaseTag.FIXME_VPP_WORKERS)
305 tag_fixme_asan = create_tag_decorator(TestCaseTag.FIXME_ASAN)
319 class CPUInterface(ABC):
321 skipped_due_to_cpu_lack = False
325 def get_cpus_required(cls):
329 def assign_cpus(cls, cpus):
333 class VppTestCase(CPUInterface, unittest.TestCase):
334 """This subclass is a base class for VPP test cases that are implemented as
335 classes. It provides methods to create and run test case.
338 extra_vpp_statseg_config = ""
339 extra_vpp_punt_config = []
340 extra_vpp_plugin_config = []
342 vapi_response_timeout = 5
345 def packet_infos(self):
346 """List of packet infos"""
347 return self._packet_infos
350 def get_packet_count_for_if_idx(cls, dst_if_index):
351 """Get the number of packet info for specified destination if index"""
352 if dst_if_index in cls._packet_count_for_dst_if_idx:
353 return cls._packet_count_for_dst_if_idx[dst_if_index]
358 def has_tag(cls, tag):
359 """ if the test case has a given tag - return true """
361 return tag in cls.test_tags
362 except AttributeError:
367 def is_tagged_run_solo(cls):
368 """ if the test case class is timing-sensitive - return true """
369 return cls.has_tag(TestCaseTag.RUN_SOLO)
372 def skip_fixme_asan(cls):
373 """ if @tag_fixme_asan & ASan is enabled - mark for skip """
374 if cls.has_tag(TestCaseTag.FIXME_ASAN):
375 vpp_extra_cmake_args = os.environ.get('VPP_EXTRA_CMAKE_ARGS', '')
376 if 'DVPP_ENABLE_SANITIZE_ADDR=ON' in vpp_extra_cmake_args:
377 cls = unittest.skip("Skipping @tag_fixme_asan tests")(cls)
381 """Return the instance of this testcase"""
382 return cls.test_instance
385 def set_debug_flags(cls, d):
386 cls.gdbserver_port = 7777
387 cls.debug_core = False
388 cls.debug_gdb = False
389 cls.debug_gdbserver = False
390 cls.debug_all = False
391 cls.debug_attach = False
396 cls.debug_core = True
397 elif dl == "gdb" or dl == "gdb-all":
399 elif dl == "gdbserver" or dl == "gdbserver-all":
400 cls.debug_gdbserver = True
402 cls.debug_attach = True
404 raise Exception("Unrecognized DEBUG option: '%s'" % d)
405 if dl == "gdb-all" or dl == "gdbserver-all":
409 def get_vpp_worker_count(cls):
410 if not hasattr(cls, "vpp_worker_count"):
411 if cls.has_tag(TestCaseTag.FIXME_VPP_WORKERS):
412 cls.vpp_worker_count = 0
414 cls.vpp_worker_count = environ_vpp_worker_count
415 return cls.vpp_worker_count
418 def get_cpus_required(cls):
419 return 1 + cls.get_vpp_worker_count()
422 def setUpConstants(cls):
423 """ Set-up the test case class based on environment variables """
424 cls.step = BoolEnvironmentVariable('STEP')
425 # inverted case to handle '' == True
426 c = os.getenv("CACHE_OUTPUT", "1")
427 cls.cache_vpp_output = False if c.lower() in ("n", "no", "0") else True
428 cls.vpp_bin = os.getenv('VPP_BIN', "vpp")
429 extern_plugin_path = os.getenv('EXTERN_PLUGINS')
431 if cls.step or cls.debug_gdb or cls.debug_gdbserver:
432 debug_cli = "cli-listen localhost:5002"
434 size = os.getenv("COREDUMP_SIZE")
436 coredump_size = "coredump-size %s" % size
437 if coredump_size is None:
438 coredump_size = "coredump-size unlimited"
440 default_variant = os.getenv("VARIANT")
441 if default_variant is not None:
442 default_variant = "defaults { %s 100 }" % default_variant
446 api_fuzzing = os.getenv("API_FUZZ")
447 if api_fuzzing is None:
452 "unix", "{", "nodaemon", debug_cli, "full-coredump",
453 coredump_size, "runtime-dir", cls.tempdir, "}",
454 "api-trace", "{", "on", "}",
455 "api-segment", "{", "prefix", cls.get_api_segment_prefix(), "}",
456 "cpu", "{", "main-core", str(cls.cpus[0]), ]
457 if extern_plugin_path is not None:
458 cls.extra_vpp_plugin_config.append(
459 "add-path %s" % extern_plugin_path)
460 if cls.get_vpp_worker_count():
461 cls.vpp_cmdline.extend([
462 "corelist-workers", ",".join([str(x) for x in cls.cpus[1:]])])
463 cls.vpp_cmdline.extend([
465 "physmem", "{", "max-size", "32m", "}",
466 "statseg", "{", "socket-name", cls.get_stats_sock_path(),
467 cls.extra_vpp_statseg_config, "}",
468 "socksvr", "{", "socket-name", cls.get_api_sock_path(), "}",
469 "node { ", default_variant, "}",
470 "api-fuzz {", api_fuzzing, "}",
471 "plugins", "{", "plugin", "dpdk_plugin.so", "{", "disable", "}",
472 "plugin", "rdma_plugin.so", "{", "disable", "}",
473 "plugin", "lisp_unittest_plugin.so", "{", "enable", "}",
474 "plugin", "unittest_plugin.so", "{", "enable", "}"
475 ] + cls.extra_vpp_plugin_config + ["}", ])
477 if cls.extra_vpp_punt_config is not None:
478 cls.vpp_cmdline.extend(cls.extra_vpp_punt_config)
480 if not cls.debug_attach:
481 cls.logger.info("vpp_cmdline args: %s" % cls.vpp_cmdline)
482 cls.logger.info("vpp_cmdline: %s" % " ".join(cls.vpp_cmdline))
485 def wait_for_enter(cls):
486 if cls.debug_gdbserver:
487 print(double_line_delim)
488 print("Spawned GDB server with PID: %d" % cls.vpp.pid)
490 print(double_line_delim)
491 print("Spawned VPP with PID: %d" % cls.vpp.pid)
493 cls.logger.debug("Spawned VPP with PID: %d" % cls.vpp.pid)
495 print(single_line_delim)
496 print("You can debug VPP using:")
497 if cls.debug_gdbserver:
498 print("sudo gdb " + cls.vpp_bin +
499 " -ex 'target remote localhost:{port}'"
500 .format(port=cls.gdbserver_port))
501 print("Now is the time to attach gdb by running the above "
502 "command, set up breakpoints etc., then resume VPP from "
503 "within gdb by issuing the 'continue' command")
504 cls.gdbserver_port += 1
506 print("sudo gdb " + cls.vpp_bin + " -ex 'attach %s'" % cls.vpp.pid)
507 print("Now is the time to attach gdb by running the above "
508 "command and set up breakpoints etc., then resume VPP from"
509 " within gdb by issuing the 'continue' command")
510 print(single_line_delim)
511 input("Press ENTER to continue running the testcase...")
519 cls.logger.debug(f"Assigned cpus: {cls.cpus}")
520 cmdline = cls.vpp_cmdline
522 if cls.debug_gdbserver:
523 gdbserver = '/usr/bin/gdbserver'
524 if not os.path.isfile(gdbserver) or\
525 not os.access(gdbserver, os.X_OK):
526 raise Exception("gdbserver binary '%s' does not exist or is "
527 "not executable" % gdbserver)
529 cmdline = [gdbserver, 'localhost:{port}'
530 .format(port=cls.gdbserver_port)] + cls.vpp_cmdline
531 cls.logger.info("Gdbserver cmdline is %s", " ".join(cmdline))
534 cls.vpp = subprocess.Popen(cmdline,
535 stdout=subprocess.PIPE,
536 stderr=subprocess.PIPE)
537 except subprocess.CalledProcessError as e:
538 cls.logger.critical("Subprocess returned with non-0 return code: ("
542 cls.logger.critical("Subprocess returned with OS error: "
543 "(%s) %s", e.errno, e.strerror)
545 except Exception as e:
546 cls.logger.exception("Subprocess returned unexpected from "
553 def wait_for_coredump(cls):
554 corefile = cls.tempdir + "/core"
555 if os.path.isfile(corefile):
556 cls.logger.error("Waiting for coredump to complete: %s", corefile)
557 curr_size = os.path.getsize(corefile)
558 deadline = time.time() + 60
560 while time.time() < deadline:
563 curr_size = os.path.getsize(corefile)
564 if size == curr_size:
568 cls.logger.error("Timed out waiting for coredump to complete:"
571 cls.logger.error("Coredump complete: %s, size %d",
575 def get_stats_sock_path(cls):
576 return "%s/stats.sock" % cls.tempdir
579 def get_api_sock_path(cls):
580 return "%s/api.sock" % cls.tempdir
583 def get_api_segment_prefix(cls):
584 return os.path.basename(cls.tempdir) # Only used for VAPI
587 def get_tempdir(cls):
589 return os.getenv("VPP_IN_GDB_TMP_DIR",
590 "/tmp/unittest-attach-gdb")
592 return tempfile.mkdtemp(prefix='vpp-unittest-%s-' % cls.__name__)
597 Perform class setup before running the testcase
598 Remove shared memory files, start vpp and connect the vpp-api
600 super(VppTestCase, cls).setUpClass()
601 cls.logger = get_logger(cls.__name__)
602 seed = os.environ["RND_SEED"]
604 if hasattr(cls, 'parallel_handler'):
605 cls.logger.addHandler(cls.parallel_handler)
606 cls.logger.propagate = False
607 d = os.getenv("DEBUG", None)
608 cls.set_debug_flags(d)
609 cls.tempdir = cls.get_tempdir()
610 cls.file_handler = FileHandler("%s/log.txt" % cls.tempdir)
611 cls.file_handler.setFormatter(
612 Formatter(fmt='%(asctime)s,%(msecs)03d %(message)s',
614 cls.file_handler.setLevel(DEBUG)
615 cls.logger.addHandler(cls.file_handler)
616 cls.logger.debug("--- setUpClass() for %s called ---" % cls.__name__)
617 os.chdir(cls.tempdir)
618 cls.logger.info("Temporary dir is %s, api socket is %s",
619 cls.tempdir, cls.get_api_sock_path())
620 cls.logger.debug("Random seed is %s", seed)
622 cls.reset_packet_infos()
627 cls.registry = VppObjectRegistry()
628 cls.vpp_startup_failed = False
629 cls.reporter = KeepAliveReporter()
630 # need to catch exceptions here because if we raise, then the cleanup
631 # doesn't get called and we might end with a zombie vpp
637 cls.reporter.send_keep_alive(cls, 'setUpClass')
638 VppTestResult.current_test_case_info = TestCaseInfo(
639 cls.logger, cls.tempdir, cls.vpp.pid, cls.vpp_bin)
640 cls.vpp_stdout_deque = deque()
641 cls.vpp_stderr_deque = deque()
642 if not cls.debug_attach:
643 cls.pump_thread_stop_flag = Event()
644 cls.pump_thread_wakeup_pipe = os.pipe()
645 cls.pump_thread = Thread(target=pump_output, args=(cls,))
646 cls.pump_thread.daemon = True
647 cls.pump_thread.start()
648 if cls.debug_gdb or cls.debug_gdbserver or cls.debug_attach:
649 cls.vapi_response_timeout = 0
650 cls.vapi = VppPapiProvider(cls.__name__, cls,
651 cls.vapi_response_timeout)
653 hook = hookmodule.StepHook(cls)
655 hook = hookmodule.PollHook(cls)
656 cls.vapi.register_hook(hook)
657 cls.statistics = VPPStats(socketname=cls.get_stats_sock_path())
661 cls.vpp_startup_failed = True
663 "VPP died shortly after startup, check the"
664 " output to standard error for possible cause")
668 except (vpp_papi.VPPIOError, Exception) as e:
669 cls.logger.debug("Exception connecting to vapi: %s" % e)
670 cls.vapi.disconnect()
672 if cls.debug_gdbserver:
673 print(colorize("You're running VPP inside gdbserver but "
674 "VPP-API connection failed, did you forget "
675 "to 'continue' VPP from within gdb?", RED))
678 last_line = cls.vapi.cli("show thread").split("\n")[-2]
679 cls.vpp_worker_count = int(last_line.split(" ")[0])
680 print("Detected VPP with %s workers." % cls.vpp_worker_count)
681 except vpp_papi.VPPRuntimeError as e:
682 cls.logger.debug("%s" % e)
685 except Exception as e:
686 cls.logger.debug("Exception connecting to VPP: %s" % e)
691 def _debug_quit(cls):
692 if (cls.debug_gdbserver or cls.debug_gdb):
696 if cls.vpp.returncode is None:
698 print(double_line_delim)
699 print("VPP or GDB server is still running")
700 print(single_line_delim)
701 input("When done debugging, press ENTER to kill the "
702 "process and finish running the testcase...")
703 except AttributeError:
709 Disconnect vpp-api, kill vpp and cleanup shared memory files
713 # first signal that we want to stop the pump thread, then wake it up
714 if hasattr(cls, 'pump_thread_stop_flag'):
715 cls.pump_thread_stop_flag.set()
716 if hasattr(cls, 'pump_thread_wakeup_pipe'):
717 os.write(cls.pump_thread_wakeup_pipe[1], b'ding dong wake up')
718 if hasattr(cls, 'pump_thread'):
719 cls.logger.debug("Waiting for pump thread to stop")
720 cls.pump_thread.join()
721 if hasattr(cls, 'vpp_stderr_reader_thread'):
722 cls.logger.debug("Waiting for stderr pump to stop")
723 cls.vpp_stderr_reader_thread.join()
725 if hasattr(cls, 'vpp'):
726 if hasattr(cls, 'vapi'):
727 cls.logger.debug(cls.vapi.vpp.get_stats())
728 cls.logger.debug("Disconnecting class vapi client on %s",
730 cls.vapi.disconnect()
731 cls.logger.debug("Deleting class vapi attribute on %s",
735 if not cls.debug_attach and cls.vpp.returncode is None:
736 cls.wait_for_coredump()
737 cls.logger.debug("Sending TERM to vpp")
739 cls.logger.debug("Waiting for vpp to die")
741 outs, errs = cls.vpp.communicate(timeout=5)
742 except subprocess.TimeoutExpired:
744 outs, errs = cls.vpp.communicate()
745 cls.logger.debug("Deleting class vpp attribute on %s",
747 if not cls.debug_attach:
748 cls.vpp.stdout.close()
749 cls.vpp.stderr.close()
752 if cls.vpp_startup_failed:
753 stdout_log = cls.logger.info
754 stderr_log = cls.logger.critical
756 stdout_log = cls.logger.info
757 stderr_log = cls.logger.info
759 if hasattr(cls, 'vpp_stdout_deque'):
760 stdout_log(single_line_delim)
761 stdout_log('VPP output to stdout while running %s:', cls.__name__)
762 stdout_log(single_line_delim)
763 vpp_output = "".join(cls.vpp_stdout_deque)
764 with open(cls.tempdir + '/vpp_stdout.txt', 'w') as f:
766 stdout_log('\n%s', vpp_output)
767 stdout_log(single_line_delim)
769 if hasattr(cls, 'vpp_stderr_deque'):
770 stderr_log(single_line_delim)
771 stderr_log('VPP output to stderr while running %s:', cls.__name__)
772 stderr_log(single_line_delim)
773 vpp_output = "".join(cls.vpp_stderr_deque)
774 with open(cls.tempdir + '/vpp_stderr.txt', 'w') as f:
776 stderr_log('\n%s', vpp_output)
777 stderr_log(single_line_delim)
780 def tearDownClass(cls):
781 """ Perform final cleanup after running all tests in this test-case """
782 cls.logger.debug("--- tearDownClass() for %s called ---" %
784 cls.reporter.send_keep_alive(cls, 'tearDownClass')
786 cls.file_handler.close()
787 cls.reset_packet_infos()
789 debug_internal.on_tear_down_class(cls)
791 def show_commands_at_teardown(self):
792 """ Allow subclass specific teardown logging additions."""
793 self.logger.info("--- No test specific show commands provided. ---")
796 """ Show various debug prints after each test """
797 self.logger.debug("--- tearDown() for %s.%s(%s) called ---" %
798 (self.__class__.__name__, self._testMethodName,
799 self._testMethodDoc))
802 if not self.vpp_dead:
803 self.logger.debug(self.vapi.cli("show trace max 1000"))
804 self.logger.info(self.vapi.ppcli("show interface"))
805 self.logger.info(self.vapi.ppcli("show hardware"))
806 self.logger.info(self.statistics.set_errors_str())
807 self.logger.info(self.vapi.ppcli("show run"))
808 self.logger.info(self.vapi.ppcli("show log"))
809 self.logger.info(self.vapi.ppcli("show bihash"))
810 self.logger.info("Logging testcase specific show commands.")
811 self.show_commands_at_teardown()
812 self.registry.remove_vpp_config(self.logger)
813 # Save/Dump VPP api trace log
814 m = self._testMethodName
815 api_trace = "vpp_api_trace.%s.%d.log" % (m, self.vpp.pid)
816 tmp_api_trace = "/tmp/%s" % api_trace
817 vpp_api_trace_log = "%s/%s" % (self.tempdir, api_trace)
818 self.logger.info(self.vapi.ppcli("api trace save %s" % api_trace))
819 self.logger.info("Moving %s to %s\n" % (tmp_api_trace,
821 os.rename(tmp_api_trace, vpp_api_trace_log)
822 except VppTransportSocketIOError:
823 self.logger.debug("VppTransportSocketIOError: Vpp dead. "
824 "Cannot log show commands.")
827 self.registry.unregister_all(self.logger)
830 """ Clear trace before running each test"""
831 super(VppTestCase, self).setUp()
832 self.reporter.send_keep_alive(self)
834 raise VppDiedError(rv=None, testcase=self.__class__.__name__,
835 method_name=self._testMethodName)
836 self.sleep(.1, "during setUp")
837 self.vpp_stdout_deque.append(
838 "--- test setUp() for %s.%s(%s) starts here ---\n" %
839 (self.__class__.__name__, self._testMethodName,
840 self._testMethodDoc))
841 self.vpp_stderr_deque.append(
842 "--- test setUp() for %s.%s(%s) starts here ---\n" %
843 (self.__class__.__name__, self._testMethodName,
844 self._testMethodDoc))
845 self.vapi.cli("clear trace")
846 # store the test instance inside the test class - so that objects
847 # holding the class can access instance methods (like assertEqual)
848 type(self).test_instance = self
851 def pg_enable_capture(cls, interfaces=None):
853 Enable capture on packet-generator interfaces
855 :param interfaces: iterable interface indexes (if None,
856 use self.pg_interfaces)
859 if interfaces is None:
860 interfaces = cls.pg_interfaces
865 def register_pcap(cls, intf, worker):
866 """ Register a pcap in the testclass """
867 # add to the list of captures with current timestamp
868 cls._pcaps.append((intf, worker))
871 def get_vpp_time(cls):
872 # processes e.g. "Time now 2.190522, Wed, 11 Mar 2020 17:29:54 GMT"
873 # returns float("2.190522")
874 timestr = cls.vapi.cli('show clock')
875 head, sep, tail = timestr.partition(',')
876 head, sep, tail = head.partition('Time now')
880 def sleep_on_vpp_time(cls, sec):
881 """ Sleep according to time in VPP world """
882 # On a busy system with many processes
883 # we might end up with VPP time being slower than real world
884 # So take that into account when waiting for VPP to do something
885 start_time = cls.get_vpp_time()
886 while cls.get_vpp_time() - start_time < sec:
890 def pg_start(cls, trace=True):
891 """ Enable the PG, wait till it is done, then clean up """
892 for (intf, worker) in cls._old_pcaps:
893 intf.rename_old_pcap_file(intf.get_in_path(worker),
894 intf.in_history_counter)
897 cls.vapi.cli("clear trace")
898 cls.vapi.cli("trace add pg-input 1000")
899 cls.vapi.cli('packet-generator enable')
900 # PG, when starts, runs to completion -
901 # so let's avoid a race condition,
902 # and wait a little till it's done.
903 # Then clean it up - and then be gone.
904 deadline = time.time() + 300
905 while cls.vapi.cli('show packet-generator').find("Yes") != -1:
906 cls.sleep(0.01) # yield
907 if time.time() > deadline:
908 cls.logger.error("Timeout waiting for pg to stop")
910 for intf, worker in cls._pcaps:
911 cls.vapi.cli('packet-generator delete %s' %
912 intf.get_cap_name(worker))
913 cls._old_pcaps = cls._pcaps
917 def create_pg_interfaces_internal(cls, interfaces, gso=0, gso_size=0,
920 Create packet-generator interfaces.
922 :param interfaces: iterable indexes of the interfaces.
923 :returns: List of created interfaces.
928 intf = VppPGInterface(cls, i, gso, gso_size, mode)
929 setattr(cls, intf.name, intf)
931 cls.pg_interfaces = result
935 def create_pg_ip4_interfaces(cls, interfaces, gso=0, gso_size=0):
936 pgmode = VppEnum.vl_api_pg_interface_mode_t
937 return cls.create_pg_interfaces_internal(interfaces, gso, gso_size,
938 pgmode.PG_API_MODE_IP4)
941 def create_pg_ip6_interfaces(cls, interfaces, gso=0, gso_size=0):
942 pgmode = VppEnum.vl_api_pg_interface_mode_t
943 return cls.create_pg_interfaces_internal(interfaces, gso, gso_size,
944 pgmode.PG_API_MODE_IP6)
947 def create_pg_interfaces(cls, interfaces, gso=0, gso_size=0):
948 pgmode = VppEnum.vl_api_pg_interface_mode_t
949 return cls.create_pg_interfaces_internal(interfaces, gso, gso_size,
950 pgmode.PG_API_MODE_ETHERNET)
953 def create_pg_ethernet_interfaces(cls, interfaces, gso=0, gso_size=0):
954 pgmode = VppEnum.vl_api_pg_interface_mode_t
955 return cls.create_pg_interfaces_internal(interfaces, gso, gso_size,
956 pgmode.PG_API_MODE_ETHERNET)
959 def create_loopback_interfaces(cls, count):
961 Create loopback interfaces.
963 :param count: number of interfaces created.
964 :returns: List of created interfaces.
966 result = [VppLoInterface(cls) for i in range(count)]
968 setattr(cls, intf.name, intf)
969 cls.lo_interfaces = result
973 def create_bvi_interfaces(cls, count):
975 Create BVI interfaces.
977 :param count: number of interfaces created.
978 :returns: List of created interfaces.
980 result = [VppBviInterface(cls) for i in range(count)]
982 setattr(cls, intf.name, intf)
983 cls.bvi_interfaces = result
987 def extend_packet(packet, size, padding=' '):
989 Extend packet to given size by padding with spaces or custom padding
990 NOTE: Currently works only when Raw layer is present.
992 :param packet: packet
993 :param size: target size
994 :param padding: padding used to extend the payload
997 packet_len = len(packet) + 4
998 extend = size - packet_len
1000 num = (extend // len(padding)) + 1
1001 packet[Raw].load += (padding * num)[:extend].encode("ascii")
1004 def reset_packet_infos(cls):
1005 """ Reset the list of packet info objects and packet counts to zero """
1006 cls._packet_infos = {}
1007 cls._packet_count_for_dst_if_idx = {}
1010 def create_packet_info(cls, src_if, dst_if):
1012 Create packet info object containing the source and destination indexes
1013 and add it to the testcase's packet info list
1015 :param VppInterface src_if: source interface
1016 :param VppInterface dst_if: destination interface
1018 :returns: _PacketInfo object
1021 info = _PacketInfo()
1022 info.index = len(cls._packet_infos)
1023 info.src = src_if.sw_if_index
1024 info.dst = dst_if.sw_if_index
1025 if isinstance(dst_if, VppSubInterface):
1026 dst_idx = dst_if.parent.sw_if_index
1028 dst_idx = dst_if.sw_if_index
1029 if dst_idx in cls._packet_count_for_dst_if_idx:
1030 cls._packet_count_for_dst_if_idx[dst_idx] += 1
1032 cls._packet_count_for_dst_if_idx[dst_idx] = 1
1033 cls._packet_infos[info.index] = info
1037 def info_to_payload(info):
1039 Convert _PacketInfo object to packet payload
1041 :param info: _PacketInfo object
1043 :returns: string containing serialized data from packet info
1046 # retrieve payload, currently 18 bytes (4 x ints + 1 short)
1047 return pack('iiiih', info.index, info.src,
1048 info.dst, info.ip, info.proto)
1051 def payload_to_info(payload, payload_field='load'):
1053 Convert packet payload to _PacketInfo object
1055 :param payload: packet payload
1056 :type payload: <class 'scapy.packet.Raw'>
1057 :param payload_field: packet fieldname of payload "load" for
1058 <class 'scapy.packet.Raw'>
1059 :type payload_field: str
1060 :returns: _PacketInfo object containing de-serialized data from payload
1064 # retrieve payload, currently 18 bytes (4 x ints + 1 short)
1065 payload_b = getattr(payload, payload_field)[:18]
1067 info = _PacketInfo()
1068 info.index, info.src, info.dst, info.ip, info.proto \
1069 = unpack('iiiih', payload_b)
1071 # some SRv6 TCs depend on get an exception if bad values are detected
1072 if info.index > 0x4000:
1073 raise ValueError('Index value is invalid')
1077 def get_next_packet_info(self, info):
1079 Iterate over the packet info list stored in the testcase
1080 Start iteration with first element if info is None
1081 Continue based on index in info if info is specified
1083 :param info: info or None
1084 :returns: next info in list or None if no more infos
1089 next_index = info.index + 1
1090 if next_index == len(self._packet_infos):
1093 return self._packet_infos[next_index]
1095 def get_next_packet_info_for_interface(self, src_index, info):
1097 Search the packet info list for the next packet info with same source
1100 :param src_index: source interface index to search for
1101 :param info: packet info - where to start the search
1102 :returns: packet info or None
1106 info = self.get_next_packet_info(info)
1109 if info.src == src_index:
1112 def get_next_packet_info_for_interface2(self, src_index, dst_index, info):
1114 Search the packet info list for the next packet info with same source
1115 and destination interface indexes
1117 :param src_index: source interface index to search for
1118 :param dst_index: destination interface index to search for
1119 :param info: packet info - where to start the search
1120 :returns: packet info or None
1124 info = self.get_next_packet_info_for_interface(src_index, info)
1127 if info.dst == dst_index:
1130 def assert_equal(self, real_value, expected_value, name_or_class=None):
1131 if name_or_class is None:
1132 self.assertEqual(real_value, expected_value)
1135 msg = "Invalid %s: %d('%s') does not match expected value %d('%s')"
1136 msg = msg % (getdoc(name_or_class).strip(),
1137 real_value, str(name_or_class(real_value)),
1138 expected_value, str(name_or_class(expected_value)))
1140 msg = "Invalid %s: %s does not match expected value %s" % (
1141 name_or_class, real_value, expected_value)
1143 self.assertEqual(real_value, expected_value, msg)
1145 def assert_in_range(self,
1153 msg = "Invalid %s: %s out of range <%s,%s>" % (
1154 name, real_value, expected_min, expected_max)
1155 self.assertTrue(expected_min <= real_value <= expected_max, msg)
1157 def assert_packet_checksums_valid(self, packet,
1158 ignore_zero_udp_checksums=True):
1159 received = packet.__class__(scapy.compat.raw(packet))
1160 udp_layers = ['UDP', 'UDPerror']
1161 checksum_fields = ['cksum', 'chksum']
1164 temp = received.__class__(scapy.compat.raw(received))
1166 layer = temp.getlayer(counter)
1168 layer = layer.copy()
1169 layer.remove_payload()
1170 for cf in checksum_fields:
1171 if hasattr(layer, cf):
1172 if ignore_zero_udp_checksums and \
1173 0 == getattr(layer, cf) and \
1174 layer.name in udp_layers:
1176 delattr(temp.getlayer(counter), cf)
1177 checksums.append((counter, cf))
1180 counter = counter + 1
1181 if 0 == len(checksums):
1183 temp = temp.__class__(scapy.compat.raw(temp))
1184 for layer, cf in checksums:
1185 calc_sum = getattr(temp[layer], cf)
1187 getattr(received[layer], cf), calc_sum,
1188 "packet checksum on layer #%d: %s" % (layer, temp[layer].name))
1190 "Checksum field `%s` on `%s` layer has correct value `%s`" %
1191 (cf, temp[layer].name, calc_sum))
1193 def assert_checksum_valid(self, received_packet, layer,
1194 field_name='chksum',
1195 ignore_zero_checksum=False):
1196 """ Check checksum of received packet on given layer """
1197 received_packet_checksum = getattr(received_packet[layer], field_name)
1198 if ignore_zero_checksum and 0 == received_packet_checksum:
1200 recalculated = received_packet.__class__(
1201 scapy.compat.raw(received_packet))
1202 delattr(recalculated[layer], field_name)
1203 recalculated = recalculated.__class__(scapy.compat.raw(recalculated))
1204 self.assert_equal(received_packet_checksum,
1205 getattr(recalculated[layer], field_name),
1206 "packet checksum on layer: %s" % layer)
1208 def assert_ip_checksum_valid(self, received_packet,
1209 ignore_zero_checksum=False):
1210 self.assert_checksum_valid(received_packet, 'IP',
1211 ignore_zero_checksum=ignore_zero_checksum)
1213 def assert_tcp_checksum_valid(self, received_packet,
1214 ignore_zero_checksum=False):
1215 self.assert_checksum_valid(received_packet, 'TCP',
1216 ignore_zero_checksum=ignore_zero_checksum)
1218 def assert_udp_checksum_valid(self, received_packet,
1219 ignore_zero_checksum=True):
1220 self.assert_checksum_valid(received_packet, 'UDP',
1221 ignore_zero_checksum=ignore_zero_checksum)
1223 def assert_embedded_icmp_checksum_valid(self, received_packet):
1224 if received_packet.haslayer(IPerror):
1225 self.assert_checksum_valid(received_packet, 'IPerror')
1226 if received_packet.haslayer(TCPerror):
1227 self.assert_checksum_valid(received_packet, 'TCPerror')
1228 if received_packet.haslayer(UDPerror):
1229 self.assert_checksum_valid(received_packet, 'UDPerror',
1230 ignore_zero_checksum=True)
1231 if received_packet.haslayer(ICMPerror):
1232 self.assert_checksum_valid(received_packet, 'ICMPerror')
1234 def assert_icmp_checksum_valid(self, received_packet):
1235 self.assert_checksum_valid(received_packet, 'ICMP')
1236 self.assert_embedded_icmp_checksum_valid(received_packet)
1238 def assert_icmpv6_checksum_valid(self, pkt):
1239 if pkt.haslayer(ICMPv6DestUnreach):
1240 self.assert_checksum_valid(pkt, 'ICMPv6DestUnreach', 'cksum')
1241 self.assert_embedded_icmp_checksum_valid(pkt)
1242 if pkt.haslayer(ICMPv6EchoRequest):
1243 self.assert_checksum_valid(pkt, 'ICMPv6EchoRequest', 'cksum')
1244 if pkt.haslayer(ICMPv6EchoReply):
1245 self.assert_checksum_valid(pkt, 'ICMPv6EchoReply', 'cksum')
1247 def get_packet_counter(self, counter):
1248 if counter.startswith("/"):
1249 counter_value = self.statistics.get_counter(counter)
1251 counters = self.vapi.cli("sh errors").split('\n')
1253 for i in range(1, len(counters) - 1):
1254 results = counters[i].split()
1255 if results[1] == counter:
1256 counter_value = int(results[0])
1258 return counter_value
1260 def assert_packet_counter_equal(self, counter, expected_value):
1261 counter_value = self.get_packet_counter(counter)
1262 self.assert_equal(counter_value, expected_value,
1263 "packet counter `%s'" % counter)
1265 def assert_error_counter_equal(self, counter, expected_value):
1266 counter_value = self.statistics[counter].sum()
1267 self.assert_equal(counter_value, expected_value,
1268 "error counter `%s'" % counter)
1271 def sleep(cls, timeout, remark=None):
1273 # /* Allow sleep(0) to maintain win32 semantics, and as decreed
1274 # * by Guido, only the main thread can be interrupted.
1276 # https://github.com/python/cpython/blob/6673decfa0fb078f60587f5cb5e98460eea137c2/Modules/timemodule.c#L1892 # noqa
1279 if hasattr(os, 'sched_yield'):
1285 cls.logger.debug("Starting sleep for %es (%s)", timeout, remark)
1286 before = time.time()
1289 if after - before > 2 * timeout:
1290 cls.logger.error("unexpected self.sleep() result - "
1291 "slept for %es instead of ~%es!",
1292 after - before, timeout)
1295 "Finished sleep (%s) - slept %es (wanted %es)",
1296 remark, after - before, timeout)
1298 def virtual_sleep(self, timeout, remark=None):
1299 self.logger.debug("Moving VPP time by %s (%s)", timeout, remark)
1300 self.vapi.cli("set clock adjust %s" % timeout)
1302 def pg_send(self, intf, pkts, worker=None, trace=True):
1303 intf.add_stream(pkts, worker=worker)
1304 self.pg_enable_capture(self.pg_interfaces)
1305 self.pg_start(trace=trace)
1307 def send_and_assert_no_replies(self, intf, pkts, remark="", timeout=None,
1309 self.pg_send(intf, pkts)
1312 for i in self.pg_interfaces:
1313 i.get_capture(0, timeout=timeout)
1314 i.assert_nothing_captured(remark=remark)
1317 self.logger.debug(self.vapi.cli("show trace"))
1319 def send_and_expect(self, intf, pkts, output, n_rx=None, worker=None,
1322 n_rx = 1 if isinstance(pkts, Packet) else len(pkts)
1323 self.pg_send(intf, pkts, worker=worker, trace=trace)
1324 rx = output.get_capture(n_rx)
1326 self.logger.debug(self.vapi.cli("show trace"))
1329 def send_and_expect_only(self, intf, pkts, output, timeout=None):
1330 self.pg_send(intf, pkts)
1331 rx = output.get_capture(len(pkts))
1335 for i in self.pg_interfaces:
1336 if i not in outputs:
1337 i.get_capture(0, timeout=timeout)
1338 i.assert_nothing_captured()
1344 def get_testcase_doc_name(test):
1345 return getdoc(test.__class__).splitlines()[0]
1348 def get_test_description(descriptions, test):
1349 short_description = test.shortDescription()
1350 if descriptions and short_description:
1351 return short_description
1356 class TestCaseInfo(object):
1357 def __init__(self, logger, tempdir, vpp_pid, vpp_bin_path):
1358 self.logger = logger
1359 self.tempdir = tempdir
1360 self.vpp_pid = vpp_pid
1361 self.vpp_bin_path = vpp_bin_path
1362 self.core_crash_test = None
1365 class VppTestResult(unittest.TestResult):
1367 @property result_string
1368 String variable to store the test case result string.
1370 List variable containing 2-tuples of TestCase instances and strings
1371 holding formatted tracebacks. Each tuple represents a test which
1372 raised an unexpected exception.
1374 List variable containing 2-tuples of TestCase instances and strings
1375 holding formatted tracebacks. Each tuple represents a test where
1376 a failure was explicitly signalled using the TestCase.assert*()
1380 failed_test_cases_info = set()
1381 core_crash_test_cases_info = set()
1382 current_test_case_info = None
1384 def __init__(self, stream=None, descriptions=None, verbosity=None,
1387 :param stream File descriptor to store where to report test results.
1388 Set to the standard error stream by default.
1389 :param descriptions Boolean variable to store information if to use
1390 test case descriptions.
1391 :param verbosity Integer variable to store required verbosity level.
1393 super(VppTestResult, self).__init__(stream, descriptions, verbosity)
1394 self.stream = stream
1395 self.descriptions = descriptions
1396 self.verbosity = verbosity
1397 self.result_string = None
1398 self.runner = runner
1401 def addSuccess(self, test):
1403 Record a test succeeded result
1408 if self.current_test_case_info:
1409 self.current_test_case_info.logger.debug(
1410 "--- addSuccess() %s.%s(%s) called" % (test.__class__.__name__,
1411 test._testMethodName,
1412 test._testMethodDoc))
1413 unittest.TestResult.addSuccess(self, test)
1414 self.result_string = colorize("OK", GREEN)
1416 self.send_result_through_pipe(test, PASS)
1418 def addSkip(self, test, reason):
1420 Record a test skipped.
1426 if self.current_test_case_info:
1427 self.current_test_case_info.logger.debug(
1428 "--- addSkip() %s.%s(%s) called, reason is %s" %
1429 (test.__class__.__name__, test._testMethodName,
1430 test._testMethodDoc, reason))
1431 unittest.TestResult.addSkip(self, test, reason)
1432 self.result_string = colorize("SKIP", YELLOW)
1434 if reason == "not enough cpus":
1435 self.send_result_through_pipe(test, SKIP_CPU_SHORTAGE)
1437 self.send_result_through_pipe(test, SKIP)
1439 def symlink_failed(self):
1440 if self.current_test_case_info:
1442 failed_dir = os.getenv('FAILED_DIR')
1443 link_path = os.path.join(
1446 os.path.basename(self.current_test_case_info.tempdir))
1448 self.current_test_case_info.logger.debug(
1449 "creating a link to the failed test")
1450 self.current_test_case_info.logger.debug(
1451 "os.symlink(%s, %s)" %
1452 (self.current_test_case_info.tempdir, link_path))
1453 if os.path.exists(link_path):
1454 self.current_test_case_info.logger.debug(
1455 'symlink already exists')
1457 os.symlink(self.current_test_case_info.tempdir, link_path)
1459 except Exception as e:
1460 self.current_test_case_info.logger.error(e)
1462 def send_result_through_pipe(self, test, result):
1463 if hasattr(self, 'test_framework_result_pipe'):
1464 pipe = self.test_framework_result_pipe
1466 pipe.send((test.id(), result))
1468 def log_error(self, test, err, fn_name):
1469 if self.current_test_case_info:
1470 if isinstance(test, unittest.suite._ErrorHolder):
1471 test_name = test.description
1473 test_name = '%s.%s(%s)' % (test.__class__.__name__,
1474 test._testMethodName,
1475 test._testMethodDoc)
1476 self.current_test_case_info.logger.debug(
1477 "--- %s() %s called, err is %s" %
1478 (fn_name, test_name, err))
1479 self.current_test_case_info.logger.debug(
1480 "formatted exception is:\n%s" %
1481 "".join(format_exception(*err)))
1483 def add_error(self, test, err, unittest_fn, error_type):
1484 if error_type == FAIL:
1485 self.log_error(test, err, 'addFailure')
1486 error_type_str = colorize("FAIL", RED)
1487 elif error_type == ERROR:
1488 self.log_error(test, err, 'addError')
1489 error_type_str = colorize("ERROR", RED)
1491 raise Exception('Error type %s cannot be used to record an '
1492 'error or a failure' % error_type)
1494 unittest_fn(self, test, err)
1495 if self.current_test_case_info:
1496 self.result_string = "%s [ temp dir used by test case: %s ]" % \
1498 self.current_test_case_info.tempdir)
1499 self.symlink_failed()
1500 self.failed_test_cases_info.add(self.current_test_case_info)
1501 if is_core_present(self.current_test_case_info.tempdir):
1502 if not self.current_test_case_info.core_crash_test:
1503 if isinstance(test, unittest.suite._ErrorHolder):
1504 test_name = str(test)
1506 test_name = "'{!s}' ({!s})".format(
1507 get_testcase_doc_name(test), test.id())
1508 self.current_test_case_info.core_crash_test = test_name
1509 self.core_crash_test_cases_info.add(
1510 self.current_test_case_info)
1512 self.result_string = '%s [no temp dir]' % error_type_str
1514 self.send_result_through_pipe(test, error_type)
1516 def addFailure(self, test, err):
1518 Record a test failed result
1521 :param err: error message
1524 self.add_error(test, err, unittest.TestResult.addFailure, FAIL)
1526 def addError(self, test, err):
1528 Record a test error result
1531 :param err: error message
1534 self.add_error(test, err, unittest.TestResult.addError, ERROR)
1536 def getDescription(self, test):
1538 Get test description
1541 :returns: test description
1544 return get_test_description(self.descriptions, test)
1546 def startTest(self, test):
1554 def print_header(test):
1555 if test.__class__ in self.printed:
1558 test_doc = getdoc(test)
1560 raise Exception("No doc string for test '%s'" % test.id())
1562 test_title = test_doc.splitlines()[0].rstrip()
1563 test_title = colorize(test_title, GREEN)
1564 if test.is_tagged_run_solo():
1565 test_title = colorize(f"SOLO RUN: {test_title}", YELLOW)
1567 # This block may overwrite the colorized title above,
1568 # but we want this to stand out and be fixed
1569 if test.has_tag(TestCaseTag.FIXME_VPP_WORKERS):
1570 test_title = colorize(
1571 f"FIXME with VPP workers: {test_title}", RED)
1573 if test.has_tag(TestCaseTag.FIXME_ASAN):
1574 test_title = colorize(
1575 f"FIXME with ASAN: {test_title}", RED)
1576 test.skip_fixme_asan()
1578 if hasattr(test, 'vpp_worker_count'):
1579 if test.vpp_worker_count == 0:
1580 test_title += " [main thread only]"
1581 elif test.vpp_worker_count == 1:
1582 test_title += " [1 worker thread]"
1584 test_title += f" [{test.vpp_worker_count} worker threads]"
1586 if test.__class__.skipped_due_to_cpu_lack:
1587 test_title = colorize(
1588 f"{test_title} [skipped - not enough cpus, "
1589 f"required={test.__class__.get_cpus_required()}, "
1590 f"available={max_vpp_cpus}]", YELLOW)
1592 print(double_line_delim)
1594 print(double_line_delim)
1595 self.printed.append(test.__class__)
1598 self.start_test = time.time()
1599 unittest.TestResult.startTest(self, test)
1600 if self.verbosity > 0:
1601 self.stream.writeln(
1602 "Starting " + self.getDescription(test) + " ...")
1603 self.stream.writeln(single_line_delim)
1605 def stopTest(self, test):
1607 Called when the given test has been run
1612 unittest.TestResult.stopTest(self, test)
1614 if self.verbosity > 0:
1615 self.stream.writeln(single_line_delim)
1616 self.stream.writeln("%-73s%s" % (self.getDescription(test),
1617 self.result_string))
1618 self.stream.writeln(single_line_delim)
1620 self.stream.writeln("%-68s %4.2f %s" %
1621 (self.getDescription(test),
1622 time.time() - self.start_test,
1623 self.result_string))
1625 self.send_result_through_pipe(test, TEST_RUN)
1627 def printErrors(self):
1629 Print errors from running the test case
1631 if len(self.errors) > 0 or len(self.failures) > 0:
1632 self.stream.writeln()
1633 self.printErrorList('ERROR', self.errors)
1634 self.printErrorList('FAIL', self.failures)
1636 # ^^ that is the last output from unittest before summary
1637 if not self.runner.print_summary:
1638 devnull = unittest.runner._WritelnDecorator(open(os.devnull, 'w'))
1639 self.stream = devnull
1640 self.runner.stream = devnull
1642 def printErrorList(self, flavour, errors):
1644 Print error list to the output stream together with error type
1645 and test case description.
1647 :param flavour: error type
1648 :param errors: iterable errors
1651 for test, err in errors:
1652 self.stream.writeln(double_line_delim)
1653 self.stream.writeln("%s: %s" %
1654 (flavour, self.getDescription(test)))
1655 self.stream.writeln(single_line_delim)
1656 self.stream.writeln("%s" % err)
1659 class VppTestRunner(unittest.TextTestRunner):
1661 A basic test runner implementation which prints results to standard error.
1665 def resultclass(self):
1666 """Class maintaining the results of the tests"""
1667 return VppTestResult
1669 def __init__(self, keep_alive_pipe=None, descriptions=True, verbosity=1,
1670 result_pipe=None, failfast=False, buffer=False,
1671 resultclass=None, print_summary=True, **kwargs):
1672 # ignore stream setting here, use hard-coded stdout to be in sync
1673 # with prints from VppTestCase methods ...
1674 super(VppTestRunner, self).__init__(sys.stdout, descriptions,
1675 verbosity, failfast, buffer,
1676 resultclass, **kwargs)
1677 KeepAliveReporter.pipe = keep_alive_pipe
1679 self.orig_stream = self.stream
1680 self.resultclass.test_framework_result_pipe = result_pipe
1682 self.print_summary = print_summary
1684 def _makeResult(self):
1685 return self.resultclass(self.stream,
1690 def run(self, test):
1697 faulthandler.enable() # emit stack trace to stderr if killed by signal
1699 result = super(VppTestRunner, self).run(test)
1700 if not self.print_summary:
1701 self.stream = self.orig_stream
1702 result.stream = self.orig_stream
1706 class Worker(Thread):
1707 def __init__(self, executable_args, logger, env=None, *args, **kwargs):
1708 super(Worker, self).__init__(*args, **kwargs)
1709 self.logger = logger
1710 self.args = executable_args
1711 if hasattr(self, 'testcase') and self.testcase.debug_all:
1712 if self.testcase.debug_gdbserver:
1713 self.args = ['/usr/bin/gdbserver', 'localhost:{port}'
1714 .format(port=self.testcase.gdbserver_port)] + args
1715 elif self.testcase.debug_gdb and hasattr(self, 'wait_for_gdb'):
1716 self.args.append(self.wait_for_gdb)
1717 self.app_bin = executable_args[0]
1718 self.app_name = os.path.basename(self.app_bin)
1719 if hasattr(self, 'role'):
1720 self.app_name += ' {role}'.format(role=self.role)
1723 env = {} if env is None else env
1724 self.env = copy.deepcopy(env)
1726 def wait_for_enter(self):
1727 if not hasattr(self, 'testcase'):
1729 if self.testcase.debug_all and self.testcase.debug_gdbserver:
1731 print(double_line_delim)
1732 print("Spawned GDB Server for '{app}' with PID: {pid}"
1733 .format(app=self.app_name, pid=self.process.pid))
1734 elif self.testcase.debug_all and self.testcase.debug_gdb:
1736 print(double_line_delim)
1737 print("Spawned '{app}' with PID: {pid}"
1738 .format(app=self.app_name, pid=self.process.pid))
1741 print(single_line_delim)
1742 print("You can debug '{app}' using:".format(app=self.app_name))
1743 if self.testcase.debug_gdbserver:
1744 print("sudo gdb " + self.app_bin +
1745 " -ex 'target remote localhost:{port}'"
1746 .format(port=self.testcase.gdbserver_port))
1747 print("Now is the time to attach gdb by running the above "
1748 "command, set up breakpoints etc., then resume from "
1749 "within gdb by issuing the 'continue' command")
1750 self.testcase.gdbserver_port += 1
1751 elif self.testcase.debug_gdb:
1752 print("sudo gdb " + self.app_bin +
1753 " -ex 'attach {pid}'".format(pid=self.process.pid))
1754 print("Now is the time to attach gdb by running the above "
1755 "command and set up breakpoints etc., then resume from"
1756 " within gdb by issuing the 'continue' command")
1757 print(single_line_delim)
1758 input("Press ENTER to continue running the testcase...")
1761 executable = self.args[0]
1762 if not os.path.exists(executable) or not os.access(
1763 executable, os.F_OK | os.X_OK):
1764 # Exit code that means some system file did not exist,
1765 # could not be opened, or had some other kind of error.
1766 self.result = os.EX_OSFILE
1767 raise EnvironmentError(
1768 "executable '%s' is not found or executable." % executable)
1769 self.logger.debug("Running executable '{app}': '{cmd}'"
1770 .format(app=self.app_name,
1771 cmd=' '.join(self.args)))
1772 env = os.environ.copy()
1773 env.update(self.env)
1774 env["CK_LOG_FILE_NAME"] = "-"
1775 self.process = subprocess.Popen(
1776 ['stdbuf', '-o0', '-e0'] + self.args, shell=False, env=env,
1777 preexec_fn=os.setpgrp, stdout=subprocess.PIPE,
1778 stderr=subprocess.PIPE)
1779 self.wait_for_enter()
1780 out, err = self.process.communicate()
1781 self.logger.debug("Finished running `{app}'".format(app=self.app_name))
1782 self.logger.info("Return code is `%s'" % self.process.returncode)
1783 self.logger.info(single_line_delim)
1784 self.logger.info("Executable `{app}' wrote to stdout:"
1785 .format(app=self.app_name))
1786 self.logger.info(single_line_delim)
1787 self.logger.info(out.decode('utf-8'))
1788 self.logger.info(single_line_delim)
1789 self.logger.info("Executable `{app}' wrote to stderr:"
1790 .format(app=self.app_name))
1791 self.logger.info(single_line_delim)
1792 self.logger.info(err.decode('utf-8'))
1793 self.logger.info(single_line_delim)
1794 self.result = self.process.returncode
1797 if __name__ == '__main__':