3 from __future__ import print_function
18 from collections import deque
19 from threading import Thread, Event
20 from inspect import getdoc, isclass
21 from traceback import format_exception
22 from logging import FileHandler, DEBUG, Formatter
25 from scapy.packet import Raw
26 import hook as hookmodule
27 from vpp_pg_interface import VppPGInterface
28 from vpp_sub_interface import VppSubInterface
29 from vpp_lo_interface import VppLoInterface
30 from vpp_bvi_interface import VppBviInterface
31 from vpp_papi_provider import VppPapiProvider
33 from vpp_papi.vpp_stats import VPPStats
34 from vpp_papi.vpp_transport_shmem import VppTransportShmemIOError
35 from log import RED, GREEN, YELLOW, double_line_delim, single_line_delim, \
37 from vpp_object import VppObjectRegistry
38 from util import ppp, is_core_present
39 from scapy.layers.inet import IPerror, TCPerror, UDPerror, ICMPerror
40 from scapy.layers.inet6 import ICMPv6DestUnreach, ICMPv6EchoRequest
41 from scapy.layers.inet6 import ICMPv6EchoReply
43 if os.name == 'posix' and sys.version_info[0] < 3:
44 # using subprocess32 is recommended by python official documentation
45 # @ https://docs.python.org/2/library/subprocess.html
46 import subprocess32 as subprocess
50 # Python2/3 compatible
56 logger = logging.getLogger(__name__)
58 # Set up an empty logger for the testcase that can be overridden as necessary
59 null_logger = logging.getLogger('VppTestCase')
60 null_logger.addHandler(logging.NullHandler())
69 class BoolEnvironmentVariable(object):
71 def __init__(self, env_var_name, default='n', true_values=None):
72 self.name = env_var_name
73 self.default = default
74 self.true_values = true_values if true_values is not None else \
78 return os.getenv(self.name, self.default).lower() in self.true_values
80 if sys.version_info[0] == 2:
81 __nonzero__ = __bool__
84 return 'BoolEnvironmentVariable(%r, default=%r, true_values=%r)' % \
85 (self.name, self.default, self.true_values)
88 debug_framework = BoolEnvironmentVariable('TEST_DEBUG')
93 Test framework module.
95 The module provides a set of tools for constructing and running tests and
96 representing the results.
100 class VppDiedError(Exception):
101 """ exception for reporting that the subprocess has died."""
103 signals_by_value = {v: k for k, v in signal.__dict__.items() if
104 k.startswith('SIG') and not k.startswith('SIG_')}
106 def __init__(self, rv=None, testcase=None, method_name=None):
108 self.signal_name = None
109 self.testcase = testcase
110 self.method_name = method_name
113 self.signal_name = VppDiedError.signals_by_value[-rv]
114 except (KeyError, TypeError):
117 if testcase is None and method_name is None:
120 in_msg = 'running %s.%s ' % (testcase, method_name)
122 msg = "VPP subprocess died %sunexpectedly with return code: %d%s." % (
125 ' [%s]' % (self.signal_name if
126 self.signal_name is not None else ''))
127 super(VppDiedError, self).__init__(msg)
130 class _PacketInfo(object):
131 """Private class to create packet info object.
133 Help process information about the next packet.
134 Set variables to default values.
136 #: Store the index of the packet.
138 #: Store the index of the source packet generator interface of the packet.
140 #: Store the index of the destination packet generator interface
143 #: Store expected ip version
145 #: Store expected upper protocol
147 #: Store the copy of the former packet.
150 def __eq__(self, other):
151 index = self.index == other.index
152 src = self.src == other.src
153 dst = self.dst == other.dst
154 data = self.data == other.data
155 return index and src and dst and data
158 def pump_output(testclass):
159 """ pump output from vpp stdout/stderr to proper queues """
162 while not testclass.pump_thread_stop_flag.is_set():
163 readable = select.select([testclass.vpp.stdout.fileno(),
164 testclass.vpp.stderr.fileno(),
165 testclass.pump_thread_wakeup_pipe[0]],
167 if testclass.vpp.stdout.fileno() in readable:
168 read = os.read(testclass.vpp.stdout.fileno(), 102400)
170 split = read.decode('ascii',
171 errors='backslashreplace').splitlines(True)
172 if len(stdout_fragment) > 0:
173 split[0] = "%s%s" % (stdout_fragment, split[0])
174 if len(split) > 0 and split[-1].endswith("\n"):
178 stdout_fragment = split[-1]
179 testclass.vpp_stdout_deque.extend(split[:limit])
180 if not testclass.cache_vpp_output:
181 for line in split[:limit]:
182 testclass.logger.info(
183 "VPP STDOUT: %s" % line.rstrip("\n"))
184 if testclass.vpp.stderr.fileno() in readable:
185 read = os.read(testclass.vpp.stderr.fileno(), 102400)
187 split = read.decode('ascii',
188 errors='backslashreplace').splitlines(True)
189 if len(stderr_fragment) > 0:
190 split[0] = "%s%s" % (stderr_fragment, split[0])
191 if len(split) > 0 and split[-1].endswith("\n"):
195 stderr_fragment = split[-1]
197 testclass.vpp_stderr_deque.extend(split[:limit])
198 if not testclass.cache_vpp_output:
199 for line in split[:limit]:
200 testclass.logger.error(
201 "VPP STDERR: %s" % line.rstrip("\n"))
202 # ignoring the dummy pipe here intentionally - the
203 # flag will take care of properly terminating the loop
206 def _is_skip_aarch64_set():
207 return BoolEnvironmentVariable('SKIP_AARCH64')
210 is_skip_aarch64_set = _is_skip_aarch64_set()
213 def _is_platform_aarch64():
214 return platform.machine() == 'aarch64'
217 is_platform_aarch64 = _is_platform_aarch64()
220 def _running_extended_tests():
221 return BoolEnvironmentVariable("EXTENDED_TESTS")
224 running_extended_tests = _running_extended_tests()
227 def _running_gcov_tests():
228 return BoolEnvironmentVariable("GCOV_TESTS")
231 running_gcov_tests = _running_gcov_tests()
234 def _running_on_centos():
235 os_id = os.getenv("OS_ID", "")
236 return True if "centos" in os_id.lower() else False
239 running_on_centos = _running_on_centos()
242 class KeepAliveReporter(object):
244 Singleton object which reports test start to parent process
249 self.__dict__ = self._shared_state
257 def pipe(self, pipe):
258 if self._pipe is not None:
259 raise Exception("Internal error - pipe should only be set once.")
262 def send_keep_alive(self, test, desc=None):
264 Write current test tmpdir & desc to keep-alive pipe to signal liveness
266 if self.pipe is None:
267 # if not running forked..
271 desc = '%s (%s)' % (desc, unittest.util.strclass(test))
275 self.pipe.send((desc, test.vpp_bin, test.tempdir, test.vpp.pid))
278 class VppTestCase(unittest.TestCase):
279 """This subclass is a base class for VPP test cases that are implemented as
280 classes. It provides methods to create and run test case.
283 extra_vpp_punt_config = []
284 extra_vpp_plugin_config = []
286 vapi_response_timeout = 5
289 def packet_infos(self):
290 """List of packet infos"""
291 return self._packet_infos
294 def get_packet_count_for_if_idx(cls, dst_if_index):
295 """Get the number of packet info for specified destination if index"""
296 if dst_if_index in cls._packet_count_for_dst_if_idx:
297 return cls._packet_count_for_dst_if_idx[dst_if_index]
303 """ if the test case class is timing-sensitive - return true """
308 """Return the instance of this testcase"""
309 return cls.test_instance
312 def set_debug_flags(cls, d):
313 cls.gdbserver_port = 7777
314 cls.debug_core = False
315 cls.debug_gdb = False
316 cls.debug_gdbserver = False
317 cls.debug_all = False
322 cls.debug_core = True
323 elif dl == "gdb" or dl == "gdb-all":
325 elif dl == "gdbserver" or dl == "gdbserver-all":
326 cls.debug_gdbserver = True
328 raise Exception("Unrecognized DEBUG option: '%s'" % d)
329 if dl == "gdb-all" or dl == "gdbserver-all":
333 def get_least_used_cpu():
334 cpu_usage_list = [set(range(psutil.cpu_count()))]
335 vpp_processes = [p for p in psutil.process_iter(attrs=['pid', 'name'])
336 if 'vpp_main' == p.info['name']]
337 for vpp_process in vpp_processes:
338 for cpu_usage_set in cpu_usage_list:
340 cpu_num = vpp_process.cpu_num()
341 if cpu_num in cpu_usage_set:
342 cpu_usage_set_index = cpu_usage_list.index(
344 if cpu_usage_set_index == len(cpu_usage_list) - 1:
345 cpu_usage_list.append({cpu_num})
347 cpu_usage_list[cpu_usage_set_index + 1].add(
349 cpu_usage_set.remove(cpu_num)
351 except psutil.NoSuchProcess:
354 for cpu_usage_set in cpu_usage_list:
355 if len(cpu_usage_set) > 0:
356 min_usage_set = cpu_usage_set
359 return random.choice(tuple(min_usage_set))
362 def setUpConstants(cls):
363 """ Set-up the test case class based on environment variables """
364 cls.step = BoolEnvironmentVariable('STEP')
365 d = os.getenv("DEBUG", None)
366 # inverted case to handle '' == True
367 c = os.getenv("CACHE_OUTPUT", "1")
368 cls.cache_vpp_output = False if c.lower() in ("n", "no", "0") else True
369 cls.set_debug_flags(d)
370 cls.vpp_bin = os.getenv('VPP_BIN', "vpp")
371 cls.plugin_path = os.getenv('VPP_PLUGIN_PATH')
372 cls.test_plugin_path = os.getenv('VPP_TEST_PLUGIN_PATH')
373 cls.extern_plugin_path = os.getenv('EXTERN_PLUGINS')
375 if cls.plugin_path is not None:
376 if cls.extern_plugin_path is not None:
377 plugin_path = "%s:%s" % (
378 cls.plugin_path, cls.extern_plugin_path)
380 plugin_path = cls.plugin_path
381 elif cls.extern_plugin_path is not None:
382 plugin_path = cls.extern_plugin_path
384 if cls.step or cls.debug_gdb or cls.debug_gdbserver:
385 debug_cli = "cli-listen localhost:5002"
387 size = os.getenv("COREDUMP_SIZE")
389 coredump_size = "coredump-size %s" % size
390 if coredump_size is None:
391 coredump_size = "coredump-size unlimited"
393 cpu_core_number = cls.get_least_used_cpu()
394 if not hasattr(cls, "worker_config"):
395 cls.worker_config = ""
397 default_variant = os.getenv("VARIANT")
398 if default_variant is not None:
399 default_variant = "defaults { %s 100 }" % default_variant
403 api_fuzzing = os.getenv("API_FUZZ")
404 if api_fuzzing is None:
407 cls.vpp_cmdline = [cls.vpp_bin, "unix",
408 "{", "nodaemon", debug_cli, "full-coredump",
409 coredump_size, "runtime-dir", cls.tempdir, "}",
410 "api-trace", "{", "on", "}", "api-segment", "{",
411 "prefix", cls.shm_prefix, "}", "cpu", "{",
412 "main-core", str(cpu_core_number),
413 cls.worker_config, "}",
414 "physmem", "{", "max-size", "32m", "}",
415 "statseg", "{", "socket-name", cls.stats_sock, "}",
416 "socksvr", "{", "socket-name", cls.api_sock, "}",
417 "node { ", default_variant, "}",
418 "api-fuzz {", api_fuzzing, "}",
420 "{", "plugin", "dpdk_plugin.so", "{", "disable",
421 "}", "plugin", "rdma_plugin.so", "{", "disable",
422 "}", "plugin", "unittest_plugin.so", "{", "enable",
423 "}"] + cls.extra_vpp_plugin_config + ["}", ]
425 if cls.extra_vpp_punt_config is not None:
426 cls.vpp_cmdline.extend(cls.extra_vpp_punt_config)
427 if plugin_path is not None:
428 cls.vpp_cmdline.extend(["plugin_path", plugin_path])
429 if cls.test_plugin_path is not None:
430 cls.vpp_cmdline.extend(["test_plugin_path", cls.test_plugin_path])
432 cls.logger.info("vpp_cmdline args: %s" % cls.vpp_cmdline)
433 cls.logger.info("vpp_cmdline: %s" % " ".join(cls.vpp_cmdline))
436 def wait_for_enter(cls):
437 if cls.debug_gdbserver:
438 print(double_line_delim)
439 print("Spawned GDB server with PID: %d" % cls.vpp.pid)
441 print(double_line_delim)
442 print("Spawned VPP with PID: %d" % cls.vpp.pid)
444 cls.logger.debug("Spawned VPP with PID: %d" % cls.vpp.pid)
446 print(single_line_delim)
447 print("You can debug VPP using:")
448 if cls.debug_gdbserver:
449 print("sudo gdb " + cls.vpp_bin +
450 " -ex 'target remote localhost:{port}'"
451 .format(port=cls.gdbserver_port))
452 print("Now is the time to attach gdb by running the above "
453 "command, set up breakpoints etc., then resume VPP from "
454 "within gdb by issuing the 'continue' command")
455 cls.gdbserver_port += 1
457 print("sudo gdb " + cls.vpp_bin + " -ex 'attach %s'" % cls.vpp.pid)
458 print("Now is the time to attach gdb by running the above "
459 "command and set up breakpoints etc., then resume VPP from"
460 " within gdb by issuing the 'continue' command")
461 print(single_line_delim)
462 input("Press ENTER to continue running the testcase...")
466 cmdline = cls.vpp_cmdline
468 if cls.debug_gdbserver:
469 gdbserver = '/usr/bin/gdbserver'
470 if not os.path.isfile(gdbserver) or \
471 not os.access(gdbserver, os.X_OK):
472 raise Exception("gdbserver binary '%s' does not exist or is "
473 "not executable" % gdbserver)
475 cmdline = [gdbserver, 'localhost:{port}'
476 .format(port=cls.gdbserver_port)] + cls.vpp_cmdline
477 cls.logger.info("Gdbserver cmdline is %s", " ".join(cmdline))
480 cls.vpp = subprocess.Popen(cmdline,
481 stdout=subprocess.PIPE,
482 stderr=subprocess.PIPE)
483 except subprocess.CalledProcessError as e:
484 cls.logger.critical("Subprocess returned with non-0 return code: ("
488 cls.logger.critical("Subprocess returned with OS error: "
489 "(%s) %s", e.errno, e.strerror)
491 except Exception as e:
492 cls.logger.exception("Subprocess returned unexpected from "
499 def wait_for_coredump(cls):
500 corefile = cls.tempdir + "/core"
501 if os.path.isfile(corefile):
502 cls.logger.error("Waiting for coredump to complete: %s", corefile)
503 curr_size = os.path.getsize(corefile)
504 deadline = time.time() + 60
506 while time.time() < deadline:
509 curr_size = os.path.getsize(corefile)
510 if size == curr_size:
514 cls.logger.error("Timed out waiting for coredump to complete:"
517 cls.logger.error("Coredump complete: %s, size %d",
523 Perform class setup before running the testcase
524 Remove shared memory files, start vpp and connect the vpp-api
526 super(VppTestCase, cls).setUpClass()
527 gc.collect() # run garbage collection first
528 cls.logger = get_logger(cls.__name__)
529 seed = os.environ["RND_SEED"]
531 if hasattr(cls, 'parallel_handler'):
532 cls.logger.addHandler(cls.parallel_handler)
533 cls.logger.propagate = False
535 cls.tempdir = tempfile.mkdtemp(
536 prefix='vpp-unittest-%s-' % cls.__name__)
537 cls.stats_sock = "%s/stats.sock" % cls.tempdir
538 cls.api_sock = "%s/api.sock" % cls.tempdir
539 cls.file_handler = FileHandler("%s/log.txt" % cls.tempdir)
540 cls.file_handler.setFormatter(
541 Formatter(fmt='%(asctime)s,%(msecs)03d %(message)s',
543 cls.file_handler.setLevel(DEBUG)
544 cls.logger.addHandler(cls.file_handler)
545 cls.logger.debug("--- setUpClass() for %s called ---" %
547 cls.shm_prefix = os.path.basename(cls.tempdir)
548 os.chdir(cls.tempdir)
549 cls.logger.info("Temporary dir is %s, shm prefix is %s",
550 cls.tempdir, cls.shm_prefix)
551 cls.logger.debug("Random seed is %s" % seed)
553 cls.reset_packet_infos()
557 cls.registry = VppObjectRegistry()
558 cls.vpp_startup_failed = False
559 cls.reporter = KeepAliveReporter()
560 # need to catch exceptions here because if we raise, then the cleanup
561 # doesn't get called and we might end with a zombie vpp
564 cls.reporter.send_keep_alive(cls, 'setUpClass')
565 VppTestResult.current_test_case_info = TestCaseInfo(
566 cls.logger, cls.tempdir, cls.vpp.pid, cls.vpp_bin)
567 cls.vpp_stdout_deque = deque()
568 cls.vpp_stderr_deque = deque()
569 cls.pump_thread_stop_flag = Event()
570 cls.pump_thread_wakeup_pipe = os.pipe()
571 cls.pump_thread = Thread(target=pump_output, args=(cls,))
572 cls.pump_thread.daemon = True
573 cls.pump_thread.start()
574 if cls.debug_gdb or cls.debug_gdbserver:
575 cls.vapi_response_timeout = 0
576 cls.vapi = VppPapiProvider(cls.shm_prefix, cls.shm_prefix, cls,
577 cls.vapi_response_timeout)
579 hook = hookmodule.StepHook(cls)
581 hook = hookmodule.PollHook(cls)
582 cls.vapi.register_hook(hook)
583 cls.statistics = VPPStats(socketname=cls.stats_sock)
587 cls.vpp_startup_failed = True
589 "VPP died shortly after startup, check the"
590 " output to standard error for possible cause")
594 except vpp_papi.VPPIOError as e:
595 cls.logger.debug("Exception connecting to vapi: %s" % e)
596 cls.vapi.disconnect()
598 if cls.debug_gdbserver:
599 print(colorize("You're running VPP inside gdbserver but "
600 "VPP-API connection failed, did you forget "
601 "to 'continue' VPP from within gdb?", RED))
603 except vpp_papi.VPPRuntimeError as e:
604 cls.logger.debug("%s" % e)
607 except Exception as e:
608 cls.logger.debug("Exception connecting to VPP: %s" % e)
613 def _debug_quit(cls):
614 if (cls.debug_gdbserver or cls.debug_gdb):
618 if cls.vpp.returncode is None:
620 print(double_line_delim)
621 print("VPP or GDB server is still running")
622 print(single_line_delim)
623 input("When done debugging, press ENTER to kill the "
624 "process and finish running the testcase...")
625 except AttributeError:
631 Disconnect vpp-api, kill vpp and cleanup shared memory files
635 # first signal that we want to stop the pump thread, then wake it up
636 if hasattr(cls, 'pump_thread_stop_flag'):
637 cls.pump_thread_stop_flag.set()
638 if hasattr(cls, 'pump_thread_wakeup_pipe'):
639 os.write(cls.pump_thread_wakeup_pipe[1], b'ding dong wake up')
640 if hasattr(cls, 'pump_thread'):
641 cls.logger.debug("Waiting for pump thread to stop")
642 cls.pump_thread.join()
643 if hasattr(cls, 'vpp_stderr_reader_thread'):
644 cls.logger.debug("Waiting for stderr pump to stop")
645 cls.vpp_stderr_reader_thread.join()
647 if hasattr(cls, 'vpp'):
648 if hasattr(cls, 'vapi'):
649 cls.logger.debug(cls.vapi.vpp.get_stats())
650 cls.logger.debug("Disconnecting class vapi client on %s",
652 cls.vapi.disconnect()
653 cls.logger.debug("Deleting class vapi attribute on %s",
657 if cls.vpp.returncode is None:
658 cls.wait_for_coredump()
659 cls.logger.debug("Sending TERM to vpp")
661 cls.logger.debug("Waiting for vpp to die")
662 cls.vpp.communicate()
663 cls.logger.debug("Deleting class vpp attribute on %s",
667 if cls.vpp_startup_failed:
668 stdout_log = cls.logger.info
669 stderr_log = cls.logger.critical
671 stdout_log = cls.logger.info
672 stderr_log = cls.logger.info
674 if hasattr(cls, 'vpp_stdout_deque'):
675 stdout_log(single_line_delim)
676 stdout_log('VPP output to stdout while running %s:', cls.__name__)
677 stdout_log(single_line_delim)
678 vpp_output = "".join(cls.vpp_stdout_deque)
679 with open(cls.tempdir + '/vpp_stdout.txt', 'w') as f:
681 stdout_log('\n%s', vpp_output)
682 stdout_log(single_line_delim)
684 if hasattr(cls, 'vpp_stderr_deque'):
685 stderr_log(single_line_delim)
686 stderr_log('VPP output to stderr while running %s:', cls.__name__)
687 stderr_log(single_line_delim)
688 vpp_output = "".join(cls.vpp_stderr_deque)
689 with open(cls.tempdir + '/vpp_stderr.txt', 'w') as f:
691 stderr_log('\n%s', vpp_output)
692 stderr_log(single_line_delim)
695 def tearDownClass(cls):
696 """ Perform final cleanup after running all tests in this test-case """
697 cls.logger.debug("--- tearDownClass() for %s called ---" %
699 cls.reporter.send_keep_alive(cls, 'tearDownClass')
701 cls.file_handler.close()
702 cls.reset_packet_infos()
704 debug_internal.on_tear_down_class(cls)
706 def show_commands_at_teardown(self):
707 """ Allow subclass specific teardown logging additions."""
708 self.logger.info("--- No test specific show commands provided. ---")
711 """ Show various debug prints after each test """
712 self.logger.debug("--- tearDown() for %s.%s(%s) called ---" %
713 (self.__class__.__name__, self._testMethodName,
714 self._testMethodDoc))
717 if not self.vpp_dead:
718 self.logger.debug(self.vapi.cli("show trace max 1000"))
719 self.logger.info(self.vapi.ppcli("show interface"))
720 self.logger.info(self.vapi.ppcli("show hardware"))
721 self.logger.info(self.statistics.set_errors_str())
722 self.logger.info(self.vapi.ppcli("show run"))
723 self.logger.info(self.vapi.ppcli("show log"))
724 self.logger.info(self.vapi.ppcli("show bihash"))
725 self.logger.info("Logging testcase specific show commands.")
726 self.show_commands_at_teardown()
727 self.registry.remove_vpp_config(self.logger)
728 # Save/Dump VPP api trace log
729 m = self._testMethodName
730 api_trace = "vpp_api_trace.%s.%d.log" % (m, self.vpp.pid)
731 tmp_api_trace = "/tmp/%s" % api_trace
732 vpp_api_trace_log = "%s/%s" % (self.tempdir, api_trace)
733 self.logger.info(self.vapi.ppcli("api trace save %s" % api_trace))
734 self.logger.info("Moving %s to %s\n" % (tmp_api_trace,
736 os.rename(tmp_api_trace, vpp_api_trace_log)
737 self.logger.info(self.vapi.ppcli("api trace custom-dump %s" %
739 except VppTransportShmemIOError:
740 self.logger.debug("VppTransportShmemIOError: Vpp dead. "
741 "Cannot log show commands.")
744 self.registry.unregister_all(self.logger)
747 """ Clear trace before running each test"""
748 super(VppTestCase, self).setUp()
749 self.reporter.send_keep_alive(self)
752 raise VppDiedError(rv=None, testcase=self.__class__.__name__,
753 method_name=self._testMethodName)
754 self.sleep(.1, "during setUp")
755 self.vpp_stdout_deque.append(
756 "--- test setUp() for %s.%s(%s) starts here ---\n" %
757 (self.__class__.__name__, self._testMethodName,
758 self._testMethodDoc))
759 self.vpp_stderr_deque.append(
760 "--- test setUp() for %s.%s(%s) starts here ---\n" %
761 (self.__class__.__name__, self._testMethodName,
762 self._testMethodDoc))
763 self.vapi.cli("clear trace")
764 # store the test instance inside the test class - so that objects
765 # holding the class can access instance methods (like assertEqual)
766 type(self).test_instance = self
769 def pg_enable_capture(cls, interfaces=None):
771 Enable capture on packet-generator interfaces
773 :param interfaces: iterable interface indexes (if None,
774 use self.pg_interfaces)
777 if interfaces is None:
778 interfaces = cls.pg_interfaces
783 def register_capture(cls, cap_name):
784 """ Register a capture in the testclass """
785 # add to the list of captures with current timestamp
786 cls._captures.append((time.time(), cap_name))
789 def get_vpp_time(cls):
790 # processes e.g. "Time now 2.190522, Wed, 11 Mar 2020 17:29:54 GMT"
791 # returns float("2.190522")
792 timestr = cls.vapi.cli('show clock')
793 head, sep, tail = timestr.partition(',')
794 head, sep, tail = head.partition('Time now')
798 def sleep_on_vpp_time(cls, sec):
799 """ Sleep according to time in VPP world """
800 # On a busy system with many processes
801 # we might end up with VPP time being slower than real world
802 # So take that into account when waiting for VPP to do something
803 start_time = cls.get_vpp_time()
804 while cls.get_vpp_time() - start_time < sec:
809 """ Enable the PG, wait till it is done, then clean up """
810 cls.vapi.cli("trace add pg-input 1000")
811 cls.vapi.cli('packet-generator enable')
812 # PG, when starts, runs to completion -
813 # so let's avoid a race condition,
814 # and wait a little till it's done.
815 # Then clean it up - and then be gone.
816 deadline = time.time() + 300
817 while cls.vapi.cli('show packet-generator').find("Yes") != -1:
818 cls.sleep(0.01) # yield
819 if time.time() > deadline:
820 cls.logger.error("Timeout waiting for pg to stop")
822 for stamp, cap_name in cls._captures:
823 cls.vapi.cli('packet-generator delete %s' % cap_name)
827 def create_pg_interfaces(cls, interfaces, gso=0, gso_size=0):
829 Create packet-generator interfaces.
831 :param interfaces: iterable indexes of the interfaces.
832 :returns: List of created interfaces.
837 intf = VppPGInterface(cls, i, gso, gso_size)
838 setattr(cls, intf.name, intf)
840 cls.pg_interfaces = result
844 def create_loopback_interfaces(cls, count):
846 Create loopback interfaces.
848 :param count: number of interfaces created.
849 :returns: List of created interfaces.
851 result = [VppLoInterface(cls) for i in range(count)]
853 setattr(cls, intf.name, intf)
854 cls.lo_interfaces = result
858 def create_bvi_interfaces(cls, count):
860 Create BVI interfaces.
862 :param count: number of interfaces created.
863 :returns: List of created interfaces.
865 result = [VppBviInterface(cls) for i in range(count)]
867 setattr(cls, intf.name, intf)
868 cls.bvi_interfaces = result
872 def extend_packet(packet, size, padding=' '):
874 Extend packet to given size by padding with spaces or custom padding
875 NOTE: Currently works only when Raw layer is present.
877 :param packet: packet
878 :param size: target size
879 :param padding: padding used to extend the payload
882 packet_len = len(packet) + 4
883 extend = size - packet_len
885 num = (extend // len(padding)) + 1
886 packet[Raw].load += (padding * num)[:extend].encode("ascii")
889 def reset_packet_infos(cls):
890 """ Reset the list of packet info objects and packet counts to zero """
891 cls._packet_infos = {}
892 cls._packet_count_for_dst_if_idx = {}
895 def create_packet_info(cls, src_if, dst_if):
897 Create packet info object containing the source and destination indexes
898 and add it to the testcase's packet info list
900 :param VppInterface src_if: source interface
901 :param VppInterface dst_if: destination interface
903 :returns: _PacketInfo object
907 info.index = len(cls._packet_infos)
908 info.src = src_if.sw_if_index
909 info.dst = dst_if.sw_if_index
910 if isinstance(dst_if, VppSubInterface):
911 dst_idx = dst_if.parent.sw_if_index
913 dst_idx = dst_if.sw_if_index
914 if dst_idx in cls._packet_count_for_dst_if_idx:
915 cls._packet_count_for_dst_if_idx[dst_idx] += 1
917 cls._packet_count_for_dst_if_idx[dst_idx] = 1
918 cls._packet_infos[info.index] = info
922 def info_to_payload(info):
924 Convert _PacketInfo object to packet payload
926 :param info: _PacketInfo object
928 :returns: string containing serialized data from packet info
930 return "%d %d %d %d %d" % (info.index, info.src, info.dst,
934 def payload_to_info(payload, payload_field='load'):
936 Convert packet payload to _PacketInfo object
938 :param payload: packet payload
939 :type payload: <class 'scapy.packet.Raw'>
940 :param payload_field: packet fieldname of payload "load" for
941 <class 'scapy.packet.Raw'>
942 :type payload_field: str
943 :returns: _PacketInfo object containing de-serialized data from payload
946 numbers = getattr(payload, payload_field).split()
948 info.index = int(numbers[0])
949 info.src = int(numbers[1])
950 info.dst = int(numbers[2])
951 info.ip = int(numbers[3])
952 info.proto = int(numbers[4])
955 def get_next_packet_info(self, info):
957 Iterate over the packet info list stored in the testcase
958 Start iteration with first element if info is None
959 Continue based on index in info if info is specified
961 :param info: info or None
962 :returns: next info in list or None if no more infos
967 next_index = info.index + 1
968 if next_index == len(self._packet_infos):
971 return self._packet_infos[next_index]
973 def get_next_packet_info_for_interface(self, src_index, info):
975 Search the packet info list for the next packet info with same source
978 :param src_index: source interface index to search for
979 :param info: packet info - where to start the search
980 :returns: packet info or None
984 info = self.get_next_packet_info(info)
987 if info.src == src_index:
990 def get_next_packet_info_for_interface2(self, src_index, dst_index, info):
992 Search the packet info list for the next packet info with same source
993 and destination interface indexes
995 :param src_index: source interface index to search for
996 :param dst_index: destination interface index to search for
997 :param info: packet info - where to start the search
998 :returns: packet info or None
1002 info = self.get_next_packet_info_for_interface(src_index, info)
1005 if info.dst == dst_index:
1008 def assert_equal(self, real_value, expected_value, name_or_class=None):
1009 if name_or_class is None:
1010 self.assertEqual(real_value, expected_value)
1013 msg = "Invalid %s: %d('%s') does not match expected value %d('%s')"
1014 msg = msg % (getdoc(name_or_class).strip(),
1015 real_value, str(name_or_class(real_value)),
1016 expected_value, str(name_or_class(expected_value)))
1018 msg = "Invalid %s: %s does not match expected value %s" % (
1019 name_or_class, real_value, expected_value)
1021 self.assertEqual(real_value, expected_value, msg)
1023 def assert_in_range(self,
1031 msg = "Invalid %s: %s out of range <%s,%s>" % (
1032 name, real_value, expected_min, expected_max)
1033 self.assertTrue(expected_min <= real_value <= expected_max, msg)
1035 def assert_packet_checksums_valid(self, packet,
1036 ignore_zero_udp_checksums=True):
1037 received = packet.__class__(scapy.compat.raw(packet))
1038 udp_layers = ['UDP', 'UDPerror']
1039 checksum_fields = ['cksum', 'chksum']
1042 temp = received.__class__(scapy.compat.raw(received))
1044 layer = temp.getlayer(counter)
1046 layer = layer.copy()
1047 layer.remove_payload()
1048 for cf in checksum_fields:
1049 if hasattr(layer, cf):
1050 if ignore_zero_udp_checksums and \
1051 0 == getattr(layer, cf) and \
1052 layer.name in udp_layers:
1054 delattr(temp.getlayer(counter), cf)
1055 checksums.append((counter, cf))
1058 counter = counter + 1
1059 if 0 == len(checksums):
1061 temp = temp.__class__(scapy.compat.raw(temp))
1062 for layer, cf in checksums:
1063 calc_sum = getattr(temp[layer], cf)
1065 getattr(received[layer], cf), calc_sum,
1066 "packet checksum on layer #%d: %s" % (layer, temp[layer].name))
1068 "Checksum field `%s` on `%s` layer has correct value `%s`" %
1069 (cf, temp[layer].name, calc_sum))
1071 def assert_checksum_valid(self, received_packet, layer,
1072 field_name='chksum',
1073 ignore_zero_checksum=False):
1074 """ Check checksum of received packet on given layer """
1075 received_packet_checksum = getattr(received_packet[layer], field_name)
1076 if ignore_zero_checksum and 0 == received_packet_checksum:
1078 recalculated = received_packet.__class__(
1079 scapy.compat.raw(received_packet))
1080 delattr(recalculated[layer], field_name)
1081 recalculated = recalculated.__class__(scapy.compat.raw(recalculated))
1082 self.assert_equal(received_packet_checksum,
1083 getattr(recalculated[layer], field_name),
1084 "packet checksum on layer: %s" % layer)
1086 def assert_ip_checksum_valid(self, received_packet,
1087 ignore_zero_checksum=False):
1088 self.assert_checksum_valid(received_packet, 'IP',
1089 ignore_zero_checksum=ignore_zero_checksum)
1091 def assert_tcp_checksum_valid(self, received_packet,
1092 ignore_zero_checksum=False):
1093 self.assert_checksum_valid(received_packet, 'TCP',
1094 ignore_zero_checksum=ignore_zero_checksum)
1096 def assert_udp_checksum_valid(self, received_packet,
1097 ignore_zero_checksum=True):
1098 self.assert_checksum_valid(received_packet, 'UDP',
1099 ignore_zero_checksum=ignore_zero_checksum)
1101 def assert_embedded_icmp_checksum_valid(self, received_packet):
1102 if received_packet.haslayer(IPerror):
1103 self.assert_checksum_valid(received_packet, 'IPerror')
1104 if received_packet.haslayer(TCPerror):
1105 self.assert_checksum_valid(received_packet, 'TCPerror')
1106 if received_packet.haslayer(UDPerror):
1107 self.assert_checksum_valid(received_packet, 'UDPerror',
1108 ignore_zero_checksum=True)
1109 if received_packet.haslayer(ICMPerror):
1110 self.assert_checksum_valid(received_packet, 'ICMPerror')
1112 def assert_icmp_checksum_valid(self, received_packet):
1113 self.assert_checksum_valid(received_packet, 'ICMP')
1114 self.assert_embedded_icmp_checksum_valid(received_packet)
1116 def assert_icmpv6_checksum_valid(self, pkt):
1117 if pkt.haslayer(ICMPv6DestUnreach):
1118 self.assert_checksum_valid(pkt, 'ICMPv6DestUnreach', 'cksum')
1119 self.assert_embedded_icmp_checksum_valid(pkt)
1120 if pkt.haslayer(ICMPv6EchoRequest):
1121 self.assert_checksum_valid(pkt, 'ICMPv6EchoRequest', 'cksum')
1122 if pkt.haslayer(ICMPv6EchoReply):
1123 self.assert_checksum_valid(pkt, 'ICMPv6EchoReply', 'cksum')
1125 def get_packet_counter(self, counter):
1126 if counter.startswith("/"):
1127 counter_value = self.statistics.get_counter(counter)
1129 counters = self.vapi.cli("sh errors").split('\n')
1131 for i in range(1, len(counters) - 1):
1132 results = counters[i].split()
1133 if results[1] == counter:
1134 counter_value = int(results[0])
1136 return counter_value
1138 def assert_packet_counter_equal(self, counter, expected_value):
1139 counter_value = self.get_packet_counter(counter)
1140 self.assert_equal(counter_value, expected_value,
1141 "packet counter `%s'" % counter)
1143 def assert_error_counter_equal(self, counter, expected_value):
1144 counter_value = self.statistics.get_err_counter(counter)
1145 self.assert_equal(counter_value, expected_value,
1146 "error counter `%s'" % counter)
1149 def sleep(cls, timeout, remark=None):
1151 # /* Allow sleep(0) to maintain win32 semantics, and as decreed
1152 # * by Guido, only the main thread can be interrupted.
1154 # https://github.com/python/cpython/blob/6673decfa0fb078f60587f5cb5e98460eea137c2/Modules/timemodule.c#L1892 # noqa
1157 if hasattr(os, 'sched_yield'):
1163 cls.logger.debug("Starting sleep for %es (%s)", timeout, remark)
1164 before = time.time()
1167 if after - before > 2 * timeout:
1168 cls.logger.error("unexpected self.sleep() result - "
1169 "slept for %es instead of ~%es!",
1170 after - before, timeout)
1173 "Finished sleep (%s) - slept %es (wanted %es)",
1174 remark, after - before, timeout)
1176 def pg_send(self, intf, pkts, worker=None):
1177 self.vapi.cli("clear trace")
1178 intf.add_stream(pkts, worker=worker)
1179 self.pg_enable_capture(self.pg_interfaces)
1182 def send_and_assert_no_replies(self, intf, pkts, remark="", timeout=None):
1183 self.pg_send(intf, pkts)
1186 for i in self.pg_interfaces:
1187 i.get_capture(0, timeout=timeout)
1188 i.assert_nothing_captured(remark=remark)
1191 def send_and_expect(self, intf, pkts, output, n_rx=None, worker=None):
1194 self.pg_send(intf, pkts, worker=worker)
1195 rx = output.get_capture(n_rx)
1198 def send_and_expect_only(self, intf, pkts, output, timeout=None):
1199 self.pg_send(intf, pkts)
1200 rx = output.get_capture(len(pkts))
1204 for i in self.pg_interfaces:
1205 if i not in outputs:
1206 i.get_capture(0, timeout=timeout)
1207 i.assert_nothing_captured()
1213 def get_testcase_doc_name(test):
1214 return getdoc(test.__class__).splitlines()[0]
1217 def get_test_description(descriptions, test):
1218 short_description = test.shortDescription()
1219 if descriptions and short_description:
1220 return short_description
1225 class TestCaseInfo(object):
1226 def __init__(self, logger, tempdir, vpp_pid, vpp_bin_path):
1227 self.logger = logger
1228 self.tempdir = tempdir
1229 self.vpp_pid = vpp_pid
1230 self.vpp_bin_path = vpp_bin_path
1231 self.core_crash_test = None
1234 class VppTestResult(unittest.TestResult):
1236 @property result_string
1237 String variable to store the test case result string.
1239 List variable containing 2-tuples of TestCase instances and strings
1240 holding formatted tracebacks. Each tuple represents a test which
1241 raised an unexpected exception.
1243 List variable containing 2-tuples of TestCase instances and strings
1244 holding formatted tracebacks. Each tuple represents a test where
1245 a failure was explicitly signalled using the TestCase.assert*()
1249 failed_test_cases_info = set()
1250 core_crash_test_cases_info = set()
1251 current_test_case_info = None
1253 def __init__(self, stream=None, descriptions=None, verbosity=None,
1256 :param stream File descriptor to store where to report test results.
1257 Set to the standard error stream by default.
1258 :param descriptions Boolean variable to store information if to use
1259 test case descriptions.
1260 :param verbosity Integer variable to store required verbosity level.
1262 super(VppTestResult, self).__init__(stream, descriptions, verbosity)
1263 self.stream = stream
1264 self.descriptions = descriptions
1265 self.verbosity = verbosity
1266 self.result_string = None
1267 self.runner = runner
1269 def addSuccess(self, test):
1271 Record a test succeeded result
1276 if self.current_test_case_info:
1277 self.current_test_case_info.logger.debug(
1278 "--- addSuccess() %s.%s(%s) called" % (test.__class__.__name__,
1279 test._testMethodName,
1280 test._testMethodDoc))
1281 unittest.TestResult.addSuccess(self, test)
1282 self.result_string = colorize("OK", GREEN)
1284 self.send_result_through_pipe(test, PASS)
1286 def addSkip(self, test, reason):
1288 Record a test skipped.
1294 if self.current_test_case_info:
1295 self.current_test_case_info.logger.debug(
1296 "--- addSkip() %s.%s(%s) called, reason is %s" %
1297 (test.__class__.__name__, test._testMethodName,
1298 test._testMethodDoc, reason))
1299 unittest.TestResult.addSkip(self, test, reason)
1300 self.result_string = colorize("SKIP", YELLOW)
1302 self.send_result_through_pipe(test, SKIP)
1304 def symlink_failed(self):
1305 if self.current_test_case_info:
1307 failed_dir = os.getenv('FAILED_DIR')
1308 link_path = os.path.join(
1311 os.path.basename(self.current_test_case_info.tempdir))
1313 self.current_test_case_info.logger.debug(
1314 "creating a link to the failed test")
1315 self.current_test_case_info.logger.debug(
1316 "os.symlink(%s, %s)" %
1317 (self.current_test_case_info.tempdir, link_path))
1318 if os.path.exists(link_path):
1319 self.current_test_case_info.logger.debug(
1320 'symlink already exists')
1322 os.symlink(self.current_test_case_info.tempdir, link_path)
1324 except Exception as e:
1325 self.current_test_case_info.logger.error(e)
1327 def send_result_through_pipe(self, test, result):
1328 if hasattr(self, 'test_framework_result_pipe'):
1329 pipe = self.test_framework_result_pipe
1331 pipe.send((test.id(), result))
1333 def log_error(self, test, err, fn_name):
1334 if self.current_test_case_info:
1335 if isinstance(test, unittest.suite._ErrorHolder):
1336 test_name = test.description
1338 test_name = '%s.%s(%s)' % (test.__class__.__name__,
1339 test._testMethodName,
1340 test._testMethodDoc)
1341 self.current_test_case_info.logger.debug(
1342 "--- %s() %s called, err is %s" %
1343 (fn_name, test_name, err))
1344 self.current_test_case_info.logger.debug(
1345 "formatted exception is:\n%s" %
1346 "".join(format_exception(*err)))
1348 def add_error(self, test, err, unittest_fn, error_type):
1349 if error_type == FAIL:
1350 self.log_error(test, err, 'addFailure')
1351 error_type_str = colorize("FAIL", RED)
1352 elif error_type == ERROR:
1353 self.log_error(test, err, 'addError')
1354 error_type_str = colorize("ERROR", RED)
1356 raise Exception('Error type %s cannot be used to record an '
1357 'error or a failure' % error_type)
1359 unittest_fn(self, test, err)
1360 if self.current_test_case_info:
1361 self.result_string = "%s [ temp dir used by test case: %s ]" % \
1363 self.current_test_case_info.tempdir)
1364 self.symlink_failed()
1365 self.failed_test_cases_info.add(self.current_test_case_info)
1366 if is_core_present(self.current_test_case_info.tempdir):
1367 if not self.current_test_case_info.core_crash_test:
1368 if isinstance(test, unittest.suite._ErrorHolder):
1369 test_name = str(test)
1371 test_name = "'{!s}' ({!s})".format(
1372 get_testcase_doc_name(test), test.id())
1373 self.current_test_case_info.core_crash_test = test_name
1374 self.core_crash_test_cases_info.add(
1375 self.current_test_case_info)
1377 self.result_string = '%s [no temp dir]' % error_type_str
1379 self.send_result_through_pipe(test, error_type)
1381 def addFailure(self, test, err):
1383 Record a test failed result
1386 :param err: error message
1389 self.add_error(test, err, unittest.TestResult.addFailure, FAIL)
1391 def addError(self, test, err):
1393 Record a test error result
1396 :param err: error message
1399 self.add_error(test, err, unittest.TestResult.addError, ERROR)
1401 def getDescription(self, test):
1403 Get test description
1406 :returns: test description
1409 return get_test_description(self.descriptions, test)
1411 def startTest(self, test):
1419 def print_header(test):
1420 test_doc = getdoc(test)
1422 raise Exception("No doc string for test '%s'" % test.id())
1423 test_title = test_doc.splitlines()[0]
1424 test_title_colored = colorize(test_title, GREEN)
1425 if test.force_solo():
1426 # long live PEP-8 and 80 char width limitation...
1428 test_title_colored = colorize("SOLO RUN: " + test_title, c)
1430 if not hasattr(test.__class__, '_header_printed'):
1431 print(double_line_delim)
1432 print(test_title_colored)
1433 print(double_line_delim)
1434 test.__class__._header_printed = True
1437 self.start_test = time.time()
1438 unittest.TestResult.startTest(self, test)
1439 if self.verbosity > 0:
1440 self.stream.writeln(
1441 "Starting " + self.getDescription(test) + " ...")
1442 self.stream.writeln(single_line_delim)
1444 def stopTest(self, test):
1446 Called when the given test has been run
1451 unittest.TestResult.stopTest(self, test)
1453 if self.verbosity > 0:
1454 self.stream.writeln(single_line_delim)
1455 self.stream.writeln("%-73s%s" % (self.getDescription(test),
1456 self.result_string))
1457 self.stream.writeln(single_line_delim)
1459 self.stream.writeln("%-68s %4.2f %s" %
1460 (self.getDescription(test),
1461 time.time() - self.start_test,
1462 self.result_string))
1464 self.send_result_through_pipe(test, TEST_RUN)
1466 def printErrors(self):
1468 Print errors from running the test case
1470 if len(self.errors) > 0 or len(self.failures) > 0:
1471 self.stream.writeln()
1472 self.printErrorList('ERROR', self.errors)
1473 self.printErrorList('FAIL', self.failures)
1475 # ^^ that is the last output from unittest before summary
1476 if not self.runner.print_summary:
1477 devnull = unittest.runner._WritelnDecorator(open(os.devnull, 'w'))
1478 self.stream = devnull
1479 self.runner.stream = devnull
1481 def printErrorList(self, flavour, errors):
1483 Print error list to the output stream together with error type
1484 and test case description.
1486 :param flavour: error type
1487 :param errors: iterable errors
1490 for test, err in errors:
1491 self.stream.writeln(double_line_delim)
1492 self.stream.writeln("%s: %s" %
1493 (flavour, self.getDescription(test)))
1494 self.stream.writeln(single_line_delim)
1495 self.stream.writeln("%s" % err)
1498 class VppTestRunner(unittest.TextTestRunner):
1500 A basic test runner implementation which prints results to standard error.
1504 def resultclass(self):
1505 """Class maintaining the results of the tests"""
1506 return VppTestResult
1508 def __init__(self, keep_alive_pipe=None, descriptions=True, verbosity=1,
1509 result_pipe=None, failfast=False, buffer=False,
1510 resultclass=None, print_summary=True, **kwargs):
1511 # ignore stream setting here, use hard-coded stdout to be in sync
1512 # with prints from VppTestCase methods ...
1513 super(VppTestRunner, self).__init__(sys.stdout, descriptions,
1514 verbosity, failfast, buffer,
1515 resultclass, **kwargs)
1516 KeepAliveReporter.pipe = keep_alive_pipe
1518 self.orig_stream = self.stream
1519 self.resultclass.test_framework_result_pipe = result_pipe
1521 self.print_summary = print_summary
1523 def _makeResult(self):
1524 return self.resultclass(self.stream,
1529 def run(self, test):
1536 faulthandler.enable() # emit stack trace to stderr if killed by signal
1538 result = super(VppTestRunner, self).run(test)
1539 if not self.print_summary:
1540 self.stream = self.orig_stream
1541 result.stream = self.orig_stream
1545 class Worker(Thread):
1546 def __init__(self, executable_args, logger, env=None, *args, **kwargs):
1547 super(Worker, self).__init__(*args, **kwargs)
1548 self.logger = logger
1549 self.args = executable_args
1550 if hasattr(self, 'testcase') and self.testcase.debug_all:
1551 if self.testcase.debug_gdbserver:
1552 self.args = ['/usr/bin/gdbserver', 'localhost:{port}'
1553 .format(port=self.testcase.gdbserver_port)] + args
1554 elif self.testcase.debug_gdb and hasattr(self, 'wait_for_gdb'):
1555 self.args.append(self.wait_for_gdb)
1556 self.app_bin = executable_args[0]
1557 self.app_name = os.path.basename(self.app_bin)
1558 if hasattr(self, 'role'):
1559 self.app_name += ' {role}'.format(role=self.role)
1562 env = {} if env is None else env
1563 self.env = copy.deepcopy(env)
1565 def wait_for_enter(self):
1566 if not hasattr(self, 'testcase'):
1568 if self.testcase.debug_all and self.testcase.debug_gdbserver:
1570 print(double_line_delim)
1571 print("Spawned GDB Server for '{app}' with PID: {pid}"
1572 .format(app=self.app_name, pid=self.process.pid))
1573 elif self.testcase.debug_all and self.testcase.debug_gdb:
1575 print(double_line_delim)
1576 print("Spawned '{app}' with PID: {pid}"
1577 .format(app=self.app_name, pid=self.process.pid))
1580 print(single_line_delim)
1581 print("You can debug '{app}' using:".format(app=self.app_name))
1582 if self.testcase.debug_gdbserver:
1583 print("sudo gdb " + self.app_bin +
1584 " -ex 'target remote localhost:{port}'"
1585 .format(port=self.testcase.gdbserver_port))
1586 print("Now is the time to attach gdb by running the above "
1587 "command, set up breakpoints etc., then resume from "
1588 "within gdb by issuing the 'continue' command")
1589 self.testcase.gdbserver_port += 1
1590 elif self.testcase.debug_gdb:
1591 print("sudo gdb " + self.app_bin +
1592 " -ex 'attach {pid}'".format(pid=self.process.pid))
1593 print("Now is the time to attach gdb by running the above "
1594 "command and set up breakpoints etc., then resume from"
1595 " within gdb by issuing the 'continue' command")
1596 print(single_line_delim)
1597 input("Press ENTER to continue running the testcase...")
1600 executable = self.args[0]
1601 if not os.path.exists(executable) or not os.access(
1602 executable, os.F_OK | os.X_OK):
1603 # Exit code that means some system file did not exist,
1604 # could not be opened, or had some other kind of error.
1605 self.result = os.EX_OSFILE
1606 raise EnvironmentError(
1607 "executable '%s' is not found or executable." % executable)
1608 self.logger.debug("Running executable: '{app}'"
1609 .format(app=' '.join(self.args)))
1610 env = os.environ.copy()
1611 env.update(self.env)
1612 env["CK_LOG_FILE_NAME"] = "-"
1613 self.process = subprocess.Popen(
1614 self.args, shell=False, env=env, preexec_fn=os.setpgrp,
1615 stdout=subprocess.PIPE, stderr=subprocess.PIPE)
1616 self.wait_for_enter()
1617 out, err = self.process.communicate()
1618 self.logger.debug("Finished running `{app}'".format(app=self.app_name))
1619 self.logger.info("Return code is `%s'" % self.process.returncode)
1620 self.logger.info(single_line_delim)
1621 self.logger.info("Executable `{app}' wrote to stdout:"
1622 .format(app=self.app_name))
1623 self.logger.info(single_line_delim)
1624 self.logger.info(out.decode('utf-8'))
1625 self.logger.info(single_line_delim)
1626 self.logger.info("Executable `{app}' wrote to stderr:"
1627 .format(app=self.app_name))
1628 self.logger.info(single_line_delim)
1629 self.logger.info(err.decode('utf-8'))
1630 self.logger.info(single_line_delim)
1631 self.result = self.process.returncode
1634 if __name__ == '__main__':