blob: 9508297432e4776a7d4309d47acffcd2e8d69963 [file] [log] [blame]
Damjan Marionf56b77a2016-10-03 19:44:57 +02001#!/usr/bin/env python
Damjan Marionf56b77a2016-10-03 19:44:57 +02002
Klement Sekeraacb9b8e2017-02-14 02:55:31 +01003from __future__ import print_function
4import gc
Paul Vinciguerra72f00042018-11-25 11:05:13 -08005import sys
Ole Trøan162989e2018-11-26 10:27:50 +00006import os
7import select
Paul Vinciguerra496b0de2019-06-20 12:24:12 -04008import signal
Ole Trøan162989e2018-11-26 10:27:50 +00009import unittest
Klement Sekeraf62ae122016-10-11 11:47:09 +020010import tempfile
Klement Sekera277b89c2016-10-28 13:20:27 +020011import time
Paul Vinciguerra72f00042018-11-25 11:05:13 -080012import faulthandler
Ole Trøan162989e2018-11-26 10:27:50 +000013import random
14import copy
Paul Vinciguerra72f00042018-11-25 11:05:13 -080015import psutil
juraj.linkes68ebc832018-11-29 09:37:08 +010016import platform
Ole Trøan162989e2018-11-26 10:27:50 +000017from collections import deque
18from threading import Thread, Event
19from inspect import getdoc, isclass
20from traceback import format_exception
21from logging import FileHandler, DEBUG, Formatter
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -070022
23import scapy.compat
Ole Trøan162989e2018-11-26 10:27:50 +000024from scapy.packet import Raw
Paul Vinciguerra496b0de2019-06-20 12:24:12 -040025import hook as hookmodule
Paul Vinciguerra919efad2018-12-17 21:43:43 -080026from vpp_pg_interface import VppPGInterface
Ole Troana45dc072018-12-21 16:04:22 +010027from vpp_sub_interface import VppSubInterface
Ole Trøan162989e2018-11-26 10:27:50 +000028from vpp_lo_interface import VppLoInterface
Neale Ranns192b13f2019-03-15 02:16:20 -070029from vpp_bvi_interface import VppBviInterface
Ole Trøan162989e2018-11-26 10:27:50 +000030from vpp_papi_provider import VppPapiProvider
31from vpp_papi.vpp_stats import VPPStats
Paul Vinciguerra499ea642019-03-15 09:39:19 -070032from vpp_papi.vpp_transport_shmem import VppTransportShmemIOError
Ole Trøan162989e2018-11-26 10:27:50 +000033from log import RED, GREEN, YELLOW, double_line_delim, single_line_delim, \
34 get_logger, colorize
35from vpp_object import VppObjectRegistry
36from util import ppp, is_core_present
Klement Sekerad81ae412018-05-16 10:52:54 +020037from scapy.layers.inet import IPerror, TCPerror, UDPerror, ICMPerror
38from scapy.layers.inet6 import ICMPv6DestUnreach, ICMPv6EchoRequest
39from scapy.layers.inet6 import ICMPv6EchoReply
Paul Vinciguerra6919b0d2018-12-09 15:37:04 -080040
Klement Sekeraacb9b8e2017-02-14 02:55:31 +010041if os.name == 'posix' and sys.version_info[0] < 3:
42 # using subprocess32 is recommended by python official documentation
43 # @ https://docs.python.org/2/library/subprocess.html
44 import subprocess32 as subprocess
45else:
46 import subprocess
Klement Sekeraf62ae122016-10-11 11:47:09 +020047
Paul Vinciguerra852f5ef2018-12-15 10:16:35 -080048# Python2/3 compatible
49try:
50 input = raw_input
51except NameError:
52 pass
53
juraj.linkescae64f82018-09-19 15:01:47 +020054PASS = 0
55FAIL = 1
56ERROR = 2
57SKIP = 3
58TEST_RUN = 4
59
Paul Vinciguerra0cbc71d2019-07-03 08:38:38 -040060
61class BoolEnvironmentVariable(object):
62
63 def __init__(self, env_var_name, default='n', true_values=None):
64 self.name = env_var_name
65 self.default = default
66 self.true_values = true_values if true_values is not None else \
67 ("y", "yes", "1")
68
69 def __bool__(self):
70 return os.getenv(self.name, self.default).lower() in self.true_values
71
72 if sys.version_info[0] == 2:
73 __nonzero__ = __bool__
74
75 def __repr__(self):
76 return 'BoolEnvironmentVariable(%r, default=%r, true_values=%r)' % \
77 (self.name, self.default, self.true_values)
78
79
80debug_framework = BoolEnvironmentVariable('TEST_DEBUG')
81if debug_framework:
Klement Sekeraebbaf552018-02-17 13:41:33 +010082 import debug_internal
83
Klement Sekeraf62ae122016-10-11 11:47:09 +020084"""
85 Test framework module.
86
87 The module provides a set of tools for constructing and running tests and
88 representing the results.
89"""
90
Klement Sekeraf62ae122016-10-11 11:47:09 +020091
Paul Vinciguerra496b0de2019-06-20 12:24:12 -040092class VppDiedError(Exception):
93 """ exception for reporting that the subprocess has died."""
94
95 signals_by_value = {v: k for k, v in signal.__dict__.items() if
96 k.startswith('SIG') and not k.startswith('SIG_')}
97
Paul Vinciguerra5dd6a7b2019-06-19 10:29:24 -040098 def __init__(self, rv=None, testcase=None, method_name=None):
Paul Vinciguerra496b0de2019-06-20 12:24:12 -040099 self.rv = rv
100 self.signal_name = None
Paul Vinciguerra5dd6a7b2019-06-19 10:29:24 -0400101 self.testcase = testcase
102 self.method_name = method_name
103
Paul Vinciguerra496b0de2019-06-20 12:24:12 -0400104 try:
105 self.signal_name = VppDiedError.signals_by_value[-rv]
Paul Vinciguerrafea82602019-06-26 20:45:08 -0400106 except (KeyError, TypeError):
Paul Vinciguerra496b0de2019-06-20 12:24:12 -0400107 pass
108
Paul Vinciguerra5dd6a7b2019-06-19 10:29:24 -0400109 if testcase is None and method_name is None:
110 in_msg = ''
111 else:
112 in_msg = 'running %s.%s ' % (testcase, method_name)
113
114 msg = "VPP subprocess died %sunexpectedly with return code: %d%s." % (
115 in_msg,
Paul Vinciguerra496b0de2019-06-20 12:24:12 -0400116 self.rv,
Paul Vinciguerraf7457522019-07-13 09:35:38 -0400117 ' [%s]' % (self.signal_name if
118 self.signal_name is not None else ''))
Paul Vinciguerra496b0de2019-06-20 12:24:12 -0400119 super(VppDiedError, self).__init__(msg)
120
121
Damjan Marionf56b77a2016-10-03 19:44:57 +0200122class _PacketInfo(object):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200123 """Private class to create packet info object.
124
125 Help process information about the next packet.
126 Set variables to default values.
Klement Sekeraf62ae122016-10-11 11:47:09 +0200127 """
Matej Klotton86d87c42016-11-11 11:38:55 +0100128 #: Store the index of the packet.
Damjan Marionf56b77a2016-10-03 19:44:57 +0200129 index = -1
Matej Klotton86d87c42016-11-11 11:38:55 +0100130 #: Store the index of the source packet generator interface of the packet.
Damjan Marionf56b77a2016-10-03 19:44:57 +0200131 src = -1
Matej Klotton86d87c42016-11-11 11:38:55 +0100132 #: Store the index of the destination packet generator interface
133 #: of the packet.
Damjan Marionf56b77a2016-10-03 19:44:57 +0200134 dst = -1
Pavel Kotucek59dda062017-03-02 15:22:47 +0100135 #: Store expected ip version
136 ip = -1
137 #: Store expected upper protocol
138 proto = -1
Matej Klotton86d87c42016-11-11 11:38:55 +0100139 #: Store the copy of the former packet.
Damjan Marionf56b77a2016-10-03 19:44:57 +0200140 data = None
Damjan Marionf56b77a2016-10-03 19:44:57 +0200141
Matej Klotton16a14cd2016-12-07 15:09:13 +0100142 def __eq__(self, other):
143 index = self.index == other.index
144 src = self.src == other.src
145 dst = self.dst == other.dst
146 data = self.data == other.data
147 return index and src and dst and data
148
Klement Sekeraf62ae122016-10-11 11:47:09 +0200149
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100150def pump_output(testclass):
151 """ pump output from vpp stdout/stderr to proper queues """
Klement Sekera6a6f4f72017-11-09 09:16:39 +0100152 stdout_fragment = ""
153 stderr_fragment = ""
Neale Ranns16782362018-07-23 05:35:56 -0400154 while not testclass.pump_thread_stop_flag.is_set():
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100155 readable = select.select([testclass.vpp.stdout.fileno(),
156 testclass.vpp.stderr.fileno(),
157 testclass.pump_thread_wakeup_pipe[0]],
158 [], [])[0]
159 if testclass.vpp.stdout.fileno() in readable:
Klement Sekera6a6f4f72017-11-09 09:16:39 +0100160 read = os.read(testclass.vpp.stdout.fileno(), 102400)
161 if len(read) > 0:
Ole Troan45ec5702019-10-17 01:53:47 +0200162 split = read.decode('ascii',
163 errors='backslashreplace').splitlines(True)
Klement Sekera6a6f4f72017-11-09 09:16:39 +0100164 if len(stdout_fragment) > 0:
165 split[0] = "%s%s" % (stdout_fragment, split[0])
166 if len(split) > 0 and split[-1].endswith("\n"):
167 limit = None
168 else:
169 limit = -1
170 stdout_fragment = split[-1]
171 testclass.vpp_stdout_deque.extend(split[:limit])
172 if not testclass.cache_vpp_output:
173 for line in split[:limit]:
174 testclass.logger.debug(
175 "VPP STDOUT: %s" % line.rstrip("\n"))
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100176 if testclass.vpp.stderr.fileno() in readable:
Klement Sekera6a6f4f72017-11-09 09:16:39 +0100177 read = os.read(testclass.vpp.stderr.fileno(), 102400)
178 if len(read) > 0:
Ole Troan6ed154f2019-10-15 19:31:55 +0200179 split = read.decode('ascii',
180 errors='backslashreplace').splitlines(True)
Klement Sekera6a6f4f72017-11-09 09:16:39 +0100181 if len(stderr_fragment) > 0:
182 split[0] = "%s%s" % (stderr_fragment, split[0])
Ole Troan6ed154f2019-10-15 19:31:55 +0200183 if len(split) > 0 and split[-1].endswith("\n"):
Klement Sekera6a6f4f72017-11-09 09:16:39 +0100184 limit = None
185 else:
186 limit = -1
187 stderr_fragment = split[-1]
Ole Troan6ed154f2019-10-15 19:31:55 +0200188
Klement Sekera6a6f4f72017-11-09 09:16:39 +0100189 testclass.vpp_stderr_deque.extend(split[:limit])
190 if not testclass.cache_vpp_output:
191 for line in split[:limit]:
192 testclass.logger.debug(
193 "VPP STDERR: %s" % line.rstrip("\n"))
Paul Vinciguerra6919b0d2018-12-09 15:37:04 -0800194 # ignoring the dummy pipe here intentionally - the
195 # flag will take care of properly terminating the loop
Klement Sekera277b89c2016-10-28 13:20:27 +0200196
197
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800198def _is_skip_aarch64_set():
Paul Vinciguerra0cbc71d2019-07-03 08:38:38 -0400199 return BoolEnvironmentVariable('SKIP_AARCH64')
juraj.linkes68ebc832018-11-29 09:37:08 +0100200
Klement Sekera6aa58b72019-05-16 14:34:55 +0200201
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800202is_skip_aarch64_set = _is_skip_aarch64_set()
juraj.linkes68ebc832018-11-29 09:37:08 +0100203
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800204
205def _is_platform_aarch64():
juraj.linkes68ebc832018-11-29 09:37:08 +0100206 return platform.machine() == 'aarch64'
207
Klement Sekera6aa58b72019-05-16 14:34:55 +0200208
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800209is_platform_aarch64 = _is_platform_aarch64()
juraj.linkes68ebc832018-11-29 09:37:08 +0100210
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800211
212def _running_extended_tests():
Paul Vinciguerra0cbc71d2019-07-03 08:38:38 -0400213 return BoolEnvironmentVariable("EXTENDED_TESTS")
Klement Sekera87134932017-03-07 11:39:27 +0100214
Klement Sekera6aa58b72019-05-16 14:34:55 +0200215
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800216running_extended_tests = _running_extended_tests()
Klement Sekera87134932017-03-07 11:39:27 +0100217
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800218
219def _running_on_centos():
Klement Sekera13a83ef2018-03-21 12:35:51 +0100220 os_id = os.getenv("OS_ID", "")
221 return True if "centos" in os_id.lower() else False
Klement Sekerad3e671e2017-09-29 12:36:37 +0200222
Klement Sekera6aa58b72019-05-16 14:34:55 +0200223
Klement Sekera3a350702019-09-02 14:26:26 +0000224running_on_centos = _running_on_centos()
Paul Vinciguerradefde0f2018-12-06 07:46:13 -0800225
Klement Sekerad3e671e2017-09-29 12:36:37 +0200226
Klement Sekera909a6a12017-08-08 04:33:53 +0200227class KeepAliveReporter(object):
228 """
229 Singleton object which reports test start to parent process
230 """
231 _shared_state = {}
232
233 def __init__(self):
234 self.__dict__ = self._shared_state
Paul Vinciguerrac7b03fe2018-11-18 08:17:34 -0800235 self._pipe = None
Klement Sekera909a6a12017-08-08 04:33:53 +0200236
237 @property
238 def pipe(self):
239 return self._pipe
240
241 @pipe.setter
242 def pipe(self, pipe):
Paul Vinciguerrac7b03fe2018-11-18 08:17:34 -0800243 if self._pipe is not None:
Klement Sekera909a6a12017-08-08 04:33:53 +0200244 raise Exception("Internal error - pipe should only be set once.")
245 self._pipe = pipe
246
juraj.linkes40dd73b2018-09-21 13:55:16 +0200247 def send_keep_alive(self, test, desc=None):
Klement Sekera909a6a12017-08-08 04:33:53 +0200248 """
249 Write current test tmpdir & desc to keep-alive pipe to signal liveness
250 """
Klement Sekera3f6ff192017-08-11 06:56:05 +0200251 if self.pipe is None:
252 # if not running forked..
253 return
254
Klement Sekera909a6a12017-08-08 04:33:53 +0200255 if isclass(test):
juraj.linkes40dd73b2018-09-21 13:55:16 +0200256 desc = '%s (%s)' % (desc, unittest.util.strclass(test))
Klement Sekera909a6a12017-08-08 04:33:53 +0200257 else:
juraj.linkes40dd73b2018-09-21 13:55:16 +0200258 desc = test.id()
Klement Sekera909a6a12017-08-08 04:33:53 +0200259
Dave Wallacee2efd122017-09-30 22:04:21 -0400260 self.pipe.send((desc, test.vpp_bin, test.tempdir, test.vpp.pid))
Klement Sekera909a6a12017-08-08 04:33:53 +0200261
262
Damjan Marionf56b77a2016-10-03 19:44:57 +0200263class VppTestCase(unittest.TestCase):
Matej Klotton86d87c42016-11-11 11:38:55 +0100264 """This subclass is a base class for VPP test cases that are implemented as
265 classes. It provides methods to create and run test case.
Klement Sekeraf62ae122016-10-11 11:47:09 +0200266 """
267
Ole Troana45dc072018-12-21 16:04:22 +0100268 extra_vpp_punt_config = []
269 extra_vpp_plugin_config = []
Pavel Kotuceke88865d2018-11-28 07:42:11 +0100270
Klement Sekeraf62ae122016-10-11 11:47:09 +0200271 @property
272 def packet_infos(self):
273 """List of packet infos"""
274 return self._packet_infos
275
Klement Sekeradab231a2016-12-21 08:50:14 +0100276 @classmethod
277 def get_packet_count_for_if_idx(cls, dst_if_index):
278 """Get the number of packet info for specified destination if index"""
279 if dst_if_index in cls._packet_count_for_dst_if_idx:
280 return cls._packet_count_for_dst_if_idx[dst_if_index]
281 else:
282 return 0
Klement Sekeraf62ae122016-10-11 11:47:09 +0200283
284 @classmethod
285 def instance(cls):
286 """Return the instance of this testcase"""
287 return cls.test_instance
288
Damjan Marionf56b77a2016-10-03 19:44:57 +0200289 @classmethod
Klement Sekera277b89c2016-10-28 13:20:27 +0200290 def set_debug_flags(cls, d):
Dave Wallace24564332019-10-21 02:53:14 +0000291 cls.gdbserver_port = 7777
Klement Sekera277b89c2016-10-28 13:20:27 +0200292 cls.debug_core = False
293 cls.debug_gdb = False
294 cls.debug_gdbserver = False
Dave Wallace24564332019-10-21 02:53:14 +0000295 cls.debug_all = False
Klement Sekera277b89c2016-10-28 13:20:27 +0200296 if d is None:
297 return
298 dl = d.lower()
299 if dl == "core":
Klement Sekera277b89c2016-10-28 13:20:27 +0200300 cls.debug_core = True
Dave Wallace24564332019-10-21 02:53:14 +0000301 elif dl == "gdb" or dl == "gdb-all":
Klement Sekera277b89c2016-10-28 13:20:27 +0200302 cls.debug_gdb = True
Dave Wallace24564332019-10-21 02:53:14 +0000303 elif dl == "gdbserver" or dl == "gdbserver-all":
Klement Sekera277b89c2016-10-28 13:20:27 +0200304 cls.debug_gdbserver = True
305 else:
306 raise Exception("Unrecognized DEBUG option: '%s'" % d)
Dave Wallace24564332019-10-21 02:53:14 +0000307 if dl == "gdb-all" or dl == "gdbserver-all":
308 cls.debug_all = True
Klement Sekera277b89c2016-10-28 13:20:27 +0200309
Paul Vinciguerra86ebba62018-11-21 09:28:32 -0800310 @staticmethod
311 def get_least_used_cpu():
juraj.linkes184870a2018-07-16 14:22:01 +0200312 cpu_usage_list = [set(range(psutil.cpu_count()))]
313 vpp_processes = [p for p in psutil.process_iter(attrs=['pid', 'name'])
314 if 'vpp_main' == p.info['name']]
315 for vpp_process in vpp_processes:
316 for cpu_usage_set in cpu_usage_list:
317 try:
318 cpu_num = vpp_process.cpu_num()
319 if cpu_num in cpu_usage_set:
320 cpu_usage_set_index = cpu_usage_list.index(
321 cpu_usage_set)
322 if cpu_usage_set_index == len(cpu_usage_list) - 1:
323 cpu_usage_list.append({cpu_num})
324 else:
325 cpu_usage_list[cpu_usage_set_index + 1].add(
326 cpu_num)
327 cpu_usage_set.remove(cpu_num)
328 break
329 except psutil.NoSuchProcess:
330 pass
331
332 for cpu_usage_set in cpu_usage_list:
333 if len(cpu_usage_set) > 0:
334 min_usage_set = cpu_usage_set
335 break
336
337 return random.choice(tuple(min_usage_set))
338
Paul Vinciguerra86ebba62018-11-21 09:28:32 -0800339 @classmethod
Damjan Marionf56b77a2016-10-03 19:44:57 +0200340 def setUpConstants(cls):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200341 """ Set-up the test case class based on environment variables """
Paul Vinciguerra0cbc71d2019-07-03 08:38:38 -0400342 cls.step = BoolEnvironmentVariable('STEP')
Klement Sekera13a83ef2018-03-21 12:35:51 +0100343 d = os.getenv("DEBUG", None)
Paul Vinciguerra0cbc71d2019-07-03 08:38:38 -0400344 # inverted case to handle '' == True
Klement Sekera13a83ef2018-03-21 12:35:51 +0100345 c = os.getenv("CACHE_OUTPUT", "1")
346 cls.cache_vpp_output = False if c.lower() in ("n", "no", "0") else True
Klement Sekera277b89c2016-10-28 13:20:27 +0200347 cls.set_debug_flags(d)
Klement Sekerab8c72a42018-11-08 11:21:39 +0100348 cls.vpp_bin = os.getenv('VPP_BIN', "vpp")
349 cls.plugin_path = os.getenv('VPP_PLUGIN_PATH')
Dave Barach7d31ab22019-05-08 19:18:18 -0400350 cls.test_plugin_path = os.getenv('VPP_TEST_PLUGIN_PATH')
Klement Sekera47e275b2017-03-21 08:21:25 +0100351 cls.extern_plugin_path = os.getenv('EXTERN_PLUGINS')
352 plugin_path = None
353 if cls.plugin_path is not None:
354 if cls.extern_plugin_path is not None:
355 plugin_path = "%s:%s" % (
356 cls.plugin_path, cls.extern_plugin_path)
Klement Sekera6abbc282017-03-24 05:47:15 +0100357 else:
358 plugin_path = cls.plugin_path
Klement Sekera47e275b2017-03-21 08:21:25 +0100359 elif cls.extern_plugin_path is not None:
360 plugin_path = cls.extern_plugin_path
Ole Troana45dc072018-12-21 16:04:22 +0100361 debug_cli = ""
Klement Sekera01bbbe92016-11-02 09:25:05 +0100362 if cls.step or cls.debug_gdb or cls.debug_gdbserver:
Ole Troana45dc072018-12-21 16:04:22 +0100363 debug_cli = "cli-listen localhost:5002"
Klement Sekera80a7f0a2017-03-02 11:27:11 +0100364 coredump_size = None
Klement Sekera13a83ef2018-03-21 12:35:51 +0100365 size = os.getenv("COREDUMP_SIZE")
Ole Troana45dc072018-12-21 16:04:22 +0100366 if size is not None:
367 coredump_size = "coredump-size %s" % size
368 if coredump_size is None:
369 coredump_size = "coredump-size unlimited"
juraj.linkes184870a2018-07-16 14:22:01 +0200370
Ole Troana45dc072018-12-21 16:04:22 +0100371 cpu_core_number = cls.get_least_used_cpu()
Klement Sekera630ab582019-07-19 09:14:19 +0000372 if not hasattr(cls, "worker_config"):
373 cls.worker_config = ""
juraj.linkes184870a2018-07-16 14:22:01 +0200374
Ole Troana45dc072018-12-21 16:04:22 +0100375 cls.vpp_cmdline = [cls.vpp_bin, "unix",
376 "{", "nodaemon", debug_cli, "full-coredump",
377 coredump_size, "runtime-dir", cls.tempdir, "}",
378 "api-trace", "{", "on", "}", "api-segment", "{",
379 "prefix", cls.shm_prefix, "}", "cpu", "{",
Klement Sekera630ab582019-07-19 09:14:19 +0000380 "main-core", str(cpu_core_number),
381 cls.worker_config, "}",
Ole Troan4ff09ae2019-04-15 11:27:22 +0200382 "statseg", "{", "socket-name", cls.stats_sock, "}",
383 "socksvr", "{", "socket-name", cls.api_sock, "}",
384 "plugins",
Ole Troana45dc072018-12-21 16:04:22 +0100385 "{", "plugin", "dpdk_plugin.so", "{", "disable",
Ole Troan2e1c8962019-04-10 09:44:23 +0200386 "}", "plugin", "rdma_plugin.so", "{", "disable",
Ole Troana45dc072018-12-21 16:04:22 +0100387 "}", "plugin", "unittest_plugin.so", "{", "enable",
388 "}"] + cls.extra_vpp_plugin_config + ["}", ]
389 if cls.extra_vpp_punt_config is not None:
390 cls.vpp_cmdline.extend(cls.extra_vpp_punt_config)
Klement Sekera47e275b2017-03-21 08:21:25 +0100391 if plugin_path is not None:
Ole Troana45dc072018-12-21 16:04:22 +0100392 cls.vpp_cmdline.extend(["plugin_path", plugin_path])
Dave Barach7d31ab22019-05-08 19:18:18 -0400393 if cls.test_plugin_path is not None:
394 cls.vpp_cmdline.extend(["test_plugin_path", cls.test_plugin_path])
395
Klement Sekeraf37c3ba2018-11-08 11:24:34 +0100396 cls.logger.info("vpp_cmdline args: %s" % cls.vpp_cmdline)
397 cls.logger.info("vpp_cmdline: %s" % " ".join(cls.vpp_cmdline))
Klement Sekera277b89c2016-10-28 13:20:27 +0200398
399 @classmethod
400 def wait_for_enter(cls):
401 if cls.debug_gdbserver:
402 print(double_line_delim)
403 print("Spawned GDB server with PID: %d" % cls.vpp.pid)
404 elif cls.debug_gdb:
405 print(double_line_delim)
406 print("Spawned VPP with PID: %d" % cls.vpp.pid)
407 else:
408 cls.logger.debug("Spawned VPP with PID: %d" % cls.vpp.pid)
409 return
410 print(single_line_delim)
Dave Wallace24564332019-10-21 02:53:14 +0000411 print("You can debug VPP using:")
Klement Sekera277b89c2016-10-28 13:20:27 +0200412 if cls.debug_gdbserver:
Paul Vinciguerra3a9f11e2019-06-18 22:59:55 -0400413 print("sudo gdb " + cls.vpp_bin +
Dave Wallace24564332019-10-21 02:53:14 +0000414 " -ex 'target remote localhost:{port}'"
415 .format(port=cls.gdbserver_port))
416 print("Now is the time to attach gdb by running the above "
417 "command, set up breakpoints etc., then resume VPP from "
Klement Sekera277b89c2016-10-28 13:20:27 +0200418 "within gdb by issuing the 'continue' command")
Dave Wallace24564332019-10-21 02:53:14 +0000419 cls.gdbserver_port += 1
Klement Sekera277b89c2016-10-28 13:20:27 +0200420 elif cls.debug_gdb:
Paul Vinciguerra3a9f11e2019-06-18 22:59:55 -0400421 print("sudo gdb " + cls.vpp_bin + " -ex 'attach %s'" % cls.vpp.pid)
Dave Wallace24564332019-10-21 02:53:14 +0000422 print("Now is the time to attach gdb by running the above "
423 "command and set up breakpoints etc., then resume VPP from"
424 " within gdb by issuing the 'continue' command")
Klement Sekera277b89c2016-10-28 13:20:27 +0200425 print(single_line_delim)
Paul Vinciguerra852f5ef2018-12-15 10:16:35 -0800426 input("Press ENTER to continue running the testcase...")
Klement Sekera277b89c2016-10-28 13:20:27 +0200427
428 @classmethod
429 def run_vpp(cls):
430 cmdline = cls.vpp_cmdline
431
432 if cls.debug_gdbserver:
Klement Sekera931be3a2016-11-03 05:36:01 +0100433 gdbserver = '/usr/bin/gdbserver'
434 if not os.path.isfile(gdbserver) or \
435 not os.access(gdbserver, os.X_OK):
436 raise Exception("gdbserver binary '%s' does not exist or is "
437 "not executable" % gdbserver)
438
Dave Wallace24564332019-10-21 02:53:14 +0000439 cmdline = [gdbserver, 'localhost:{port}'
440 .format(port=cls.gdbserver_port)] + cls.vpp_cmdline
Klement Sekera277b89c2016-10-28 13:20:27 +0200441 cls.logger.info("Gdbserver cmdline is %s", " ".join(cmdline))
442
Klement Sekera931be3a2016-11-03 05:36:01 +0100443 try:
444 cls.vpp = subprocess.Popen(cmdline,
445 stdout=subprocess.PIPE,
446 stderr=subprocess.PIPE,
447 bufsize=1)
Paul Vinciguerra61e63bf2018-11-24 21:19:38 -0800448 except subprocess.CalledProcessError as e:
Paul Vinciguerra38a4ec72018-11-28 11:34:21 -0800449 cls.logger.critical("Subprocess returned with non-0 return code: ("
450 "%s)", e.returncode)
451 raise
452 except OSError as e:
453 cls.logger.critical("Subprocess returned with OS error: "
454 "(%s) %s", e.errno, e.strerror)
455 raise
456 except Exception as e:
457 cls.logger.exception("Subprocess returned unexpected from "
458 "%s:", cmdline)
Klement Sekera931be3a2016-11-03 05:36:01 +0100459 raise
460
Klement Sekera277b89c2016-10-28 13:20:27 +0200461 cls.wait_for_enter()
Pierre Pfistercd8e3182016-10-07 16:30:03 +0100462
Damjan Marionf56b77a2016-10-03 19:44:57 +0200463 @classmethod
Klement Sekera611864f2018-09-26 11:19:00 +0200464 def wait_for_stats_socket(cls):
Andrew Yourtchenko4f05a8e2019-10-13 10:06:46 +0000465 deadline = time.time() + 300
Paul Vinciguerradd4b2bb2018-11-15 08:13:03 -0800466 ok = False
467 while time.time() < deadline or \
468 cls.debug_gdb or cls.debug_gdbserver:
Klement Sekera611864f2018-09-26 11:19:00 +0200469 if os.path.exists(cls.stats_sock):
Paul Vinciguerradd4b2bb2018-11-15 08:13:03 -0800470 ok = True
Klement Sekera611864f2018-09-26 11:19:00 +0200471 break
Paul Vinciguerra0f6602c2019-03-10 09:10:54 -0700472 cls.sleep(0.8)
Paul Vinciguerradd4b2bb2018-11-15 08:13:03 -0800473 if not ok:
474 cls.logger.critical("Couldn't stat : {}".format(cls.stats_sock))
Klement Sekera611864f2018-09-26 11:19:00 +0200475
476 @classmethod
Andrew Yourtchenkob31d3932019-10-31 08:34:22 +0000477 def wait_for_coredump(cls):
478 corefile = cls.tempdir + "/core"
Dave Wallace3e9b7a22019-04-09 20:19:51 -0400479 if os.path.isfile(corefile):
Andrew Yourtchenkob31d3932019-10-31 08:34:22 +0000480 cls.logger.error("Waiting for coredump to complete: %s", corefile)
Dave Wallace3e9b7a22019-04-09 20:19:51 -0400481 curr_size = os.path.getsize(corefile)
Andrew Yourtchenkob31d3932019-10-31 08:34:22 +0000482 deadline = time.time() + 60
Dave Wallace3e9b7a22019-04-09 20:19:51 -0400483 ok = False
484 while time.time() < deadline:
485 cls.sleep(1)
486 size = curr_size
487 curr_size = os.path.getsize(corefile)
488 if size == curr_size:
489 ok = True
490 break
491 if not ok:
492 cls.logger.error("Timed out waiting for coredump to complete:"
493 " %s", corefile)
494 else:
495 cls.logger.error("Coredump complete: %s, size %d",
496 corefile, curr_size)
497
498 @classmethod
Damjan Marionf56b77a2016-10-03 19:44:57 +0200499 def setUpClass(cls):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200500 """
501 Perform class setup before running the testcase
502 Remove shared memory files, start vpp and connect the vpp-api
503 """
Paul Vinciguerra8d991d92019-01-25 14:05:48 -0800504 super(VppTestCase, cls).setUpClass()
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100505 gc.collect() # run garbage collection first
juraj.linkesdfb5f2a2018-11-09 11:58:54 +0100506 cls.logger = get_logger(cls.__name__)
Klement Sekera45a95dd2019-11-05 11:18:25 +0000507 seed = os.environ["RND_SEED"]
508 random.seed(seed)
juraj.linkesdfb5f2a2018-11-09 11:58:54 +0100509 if hasattr(cls, 'parallel_handler'):
510 cls.logger.addHandler(cls.parallel_handler)
juraj.linkes3d9b92a2018-11-21 13:13:39 +0100511 cls.logger.propagate = False
Paul Vinciguerra90cf21b2019-03-13 09:23:05 -0700512
Klement Sekeraf62ae122016-10-11 11:47:09 +0200513 cls.tempdir = tempfile.mkdtemp(
Klement Sekeraf413bef2017-08-15 07:09:02 +0200514 prefix='vpp-unittest-%s-' % cls.__name__)
Klement Sekera611864f2018-09-26 11:19:00 +0200515 cls.stats_sock = "%s/stats.sock" % cls.tempdir
Ole Troan4ff09ae2019-04-15 11:27:22 +0200516 cls.api_sock = "%s/api.sock" % cls.tempdir
Klement Sekera027dbd52017-04-11 06:01:53 +0200517 cls.file_handler = FileHandler("%s/log.txt" % cls.tempdir)
518 cls.file_handler.setFormatter(
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100519 Formatter(fmt='%(asctime)s,%(msecs)03d %(message)s',
520 datefmt="%H:%M:%S"))
Klement Sekera027dbd52017-04-11 06:01:53 +0200521 cls.file_handler.setLevel(DEBUG)
522 cls.logger.addHandler(cls.file_handler)
Paul Vinciguerra90cf21b2019-03-13 09:23:05 -0700523 cls.logger.debug("--- setUpClass() for %s called ---" %
524 cls.__name__)
juraj.linkes184870a2018-07-16 14:22:01 +0200525 cls.shm_prefix = os.path.basename(cls.tempdir)
Klement Sekeraf62ae122016-10-11 11:47:09 +0200526 os.chdir(cls.tempdir)
Klement Sekera277b89c2016-10-28 13:20:27 +0200527 cls.logger.info("Temporary dir is %s, shm prefix is %s",
528 cls.tempdir, cls.shm_prefix)
Klement Sekera45a95dd2019-11-05 11:18:25 +0000529 cls.logger.debug("Random seed is %s" % seed)
Damjan Marionf56b77a2016-10-03 19:44:57 +0200530 cls.setUpConstants()
Klement Sekeradab231a2016-12-21 08:50:14 +0100531 cls.reset_packet_infos()
Klement Sekera9225dee2016-12-12 08:36:58 +0100532 cls._captures = []
Klement Sekeraf62ae122016-10-11 11:47:09 +0200533 cls.verbose = 0
Klement Sekera085f5c02016-11-24 01:59:16 +0100534 cls.vpp_dead = False
Klement Sekera10db26f2017-01-11 08:16:53 +0100535 cls.registry = VppObjectRegistry()
Klement Sekera3747c752017-04-10 06:30:17 +0200536 cls.vpp_startup_failed = False
Klement Sekera909a6a12017-08-08 04:33:53 +0200537 cls.reporter = KeepAliveReporter()
Klement Sekeraf62ae122016-10-11 11:47:09 +0200538 # need to catch exceptions here because if we raise, then the cleanup
539 # doesn't get called and we might end with a zombie vpp
540 try:
Klement Sekera277b89c2016-10-28 13:20:27 +0200541 cls.run_vpp()
juraj.linkes40dd73b2018-09-21 13:55:16 +0200542 cls.reporter.send_keep_alive(cls, 'setUpClass')
543 VppTestResult.current_test_case_info = TestCaseInfo(
544 cls.logger, cls.tempdir, cls.vpp.pid, cls.vpp_bin)
Klement Sekerae4504c62016-12-08 10:16:41 +0100545 cls.vpp_stdout_deque = deque()
Klement Sekerae4504c62016-12-08 10:16:41 +0100546 cls.vpp_stderr_deque = deque()
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100547 cls.pump_thread_stop_flag = Event()
548 cls.pump_thread_wakeup_pipe = os.pipe()
549 cls.pump_thread = Thread(target=pump_output, args=(cls,))
Klement Sekeraaeeac3b2017-02-14 07:11:52 +0100550 cls.pump_thread.daemon = True
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100551 cls.pump_thread.start()
Klement Sekera611864f2018-09-26 11:19:00 +0200552 if cls.debug_gdb or cls.debug_gdbserver:
553 read_timeout = 0
554 else:
555 read_timeout = 5
556 cls.vapi = VppPapiProvider(cls.shm_prefix, cls.shm_prefix, cls,
557 read_timeout)
Klement Sekera085f5c02016-11-24 01:59:16 +0100558 if cls.step:
Paul Vinciguerra496b0de2019-06-20 12:24:12 -0400559 hook = hookmodule.StepHook(cls)
Klement Sekera085f5c02016-11-24 01:59:16 +0100560 else:
Paul Vinciguerra496b0de2019-06-20 12:24:12 -0400561 hook = hookmodule.PollHook(cls)
Klement Sekera085f5c02016-11-24 01:59:16 +0100562 cls.vapi.register_hook(hook)
Klement Sekera611864f2018-09-26 11:19:00 +0200563 cls.wait_for_stats_socket()
564 cls.statistics = VPPStats(socketname=cls.stats_sock)
Klement Sekera3747c752017-04-10 06:30:17 +0200565 try:
566 hook.poll_vpp()
Klement Sekera13a83ef2018-03-21 12:35:51 +0100567 except VppDiedError:
Klement Sekera3747c752017-04-10 06:30:17 +0200568 cls.vpp_startup_failed = True
569 cls.logger.critical(
570 "VPP died shortly after startup, check the"
571 " output to standard error for possible cause")
572 raise
Klement Sekera085f5c02016-11-24 01:59:16 +0100573 try:
574 cls.vapi.connect()
Klement Sekera13a83ef2018-03-21 12:35:51 +0100575 except Exception:
Klement Sekera4c533132018-02-22 11:41:12 +0100576 try:
577 cls.vapi.disconnect()
Klement Sekera13a83ef2018-03-21 12:35:51 +0100578 except Exception:
Klement Sekera4c533132018-02-22 11:41:12 +0100579 pass
Klement Sekera085f5c02016-11-24 01:59:16 +0100580 if cls.debug_gdbserver:
581 print(colorize("You're running VPP inside gdbserver but "
582 "VPP-API connection failed, did you forget "
583 "to 'continue' VPP from within gdb?", RED))
584 raise
Andrew Yourtchenko4f05a8e2019-10-13 10:06:46 +0000585 except Exception as e:
586 cls.logger.debug("Exception connecting to VPP: %s" % e)
Paul Vinciguerra496b0de2019-06-20 12:24:12 -0400587
588 cls.quit()
Klement Sekera13a83ef2018-03-21 12:35:51 +0100589 raise
Damjan Marionf56b77a2016-10-03 19:44:57 +0200590
Damjan Marionf56b77a2016-10-03 19:44:57 +0200591 @classmethod
592 def quit(cls):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200593 """
594 Disconnect vpp-api, kill vpp and cleanup shared memory files
595 """
Klement Sekera277b89c2016-10-28 13:20:27 +0200596 if (cls.debug_gdbserver or cls.debug_gdb) and hasattr(cls, 'vpp'):
597 cls.vpp.poll()
598 if cls.vpp.returncode is None:
Dave Wallace24564332019-10-21 02:53:14 +0000599 print()
Klement Sekera277b89c2016-10-28 13:20:27 +0200600 print(double_line_delim)
601 print("VPP or GDB server is still running")
602 print(single_line_delim)
Paul Vinciguerra852f5ef2018-12-15 10:16:35 -0800603 input("When done debugging, press ENTER to kill the "
604 "process and finish running the testcase...")
Klement Sekera277b89c2016-10-28 13:20:27 +0200605
juraj.linkes184870a2018-07-16 14:22:01 +0200606 # first signal that we want to stop the pump thread, then wake it up
607 if hasattr(cls, 'pump_thread_stop_flag'):
608 cls.pump_thread_stop_flag.set()
609 if hasattr(cls, 'pump_thread_wakeup_pipe'):
Ole Troan7f991832018-12-06 17:35:12 +0100610 os.write(cls.pump_thread_wakeup_pipe[1], b'ding dong wake up')
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100611 if hasattr(cls, 'pump_thread'):
612 cls.logger.debug("Waiting for pump thread to stop")
613 cls.pump_thread.join()
614 if hasattr(cls, 'vpp_stderr_reader_thread'):
Andrew Yourtchenkob31d3932019-10-31 08:34:22 +0000615 cls.logger.debug("Waiting for stdderr pump to stop")
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100616 cls.vpp_stderr_reader_thread.join()
617
Klement Sekeraf62ae122016-10-11 11:47:09 +0200618 if hasattr(cls, 'vpp'):
Klement Sekera0529a742016-12-02 07:05:24 +0100619 if hasattr(cls, 'vapi'):
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -0700620 cls.logger.debug("Disconnecting class vapi client on %s",
621 cls.__name__)
Klement Sekera0529a742016-12-02 07:05:24 +0100622 cls.vapi.disconnect()
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -0700623 cls.logger.debug("Deleting class vapi attribute on %s",
624 cls.__name__)
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100625 del cls.vapi
Klement Sekeraf62ae122016-10-11 11:47:09 +0200626 cls.vpp.poll()
627 if cls.vpp.returncode is None:
Andrew Yourtchenkob31d3932019-10-31 08:34:22 +0000628 cls.wait_for_coredump()
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100629 cls.logger.debug("Sending TERM to vpp")
Dave Barachad646872019-05-06 10:49:41 -0400630 cls.vpp.terminate()
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100631 cls.logger.debug("Waiting for vpp to die")
632 cls.vpp.communicate()
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -0700633 cls.logger.debug("Deleting class vpp attribute on %s",
634 cls.__name__)
Klement Sekeraf62ae122016-10-11 11:47:09 +0200635 del cls.vpp
Damjan Marionf56b77a2016-10-03 19:44:57 +0200636
Klement Sekera3747c752017-04-10 06:30:17 +0200637 if cls.vpp_startup_failed:
638 stdout_log = cls.logger.info
639 stderr_log = cls.logger.critical
640 else:
641 stdout_log = cls.logger.info
642 stderr_log = cls.logger.info
643
Klement Sekerae4504c62016-12-08 10:16:41 +0100644 if hasattr(cls, 'vpp_stdout_deque'):
Klement Sekera3747c752017-04-10 06:30:17 +0200645 stdout_log(single_line_delim)
646 stdout_log('VPP output to stdout while running %s:', cls.__name__)
647 stdout_log(single_line_delim)
Klement Sekerae4504c62016-12-08 10:16:41 +0100648 vpp_output = "".join(cls.vpp_stdout_deque)
Klement Sekera027dbd52017-04-11 06:01:53 +0200649 with open(cls.tempdir + '/vpp_stdout.txt', 'w') as f:
650 f.write(vpp_output)
Klement Sekera3747c752017-04-10 06:30:17 +0200651 stdout_log('\n%s', vpp_output)
652 stdout_log(single_line_delim)
Klement Sekera277b89c2016-10-28 13:20:27 +0200653
Klement Sekerae4504c62016-12-08 10:16:41 +0100654 if hasattr(cls, 'vpp_stderr_deque'):
Klement Sekera3747c752017-04-10 06:30:17 +0200655 stderr_log(single_line_delim)
656 stderr_log('VPP output to stderr while running %s:', cls.__name__)
657 stderr_log(single_line_delim)
Klement Sekera0ede47a2019-01-29 11:49:09 +0100658 vpp_output = "".join(cls.vpp_stderr_deque)
Klement Sekera027dbd52017-04-11 06:01:53 +0200659 with open(cls.tempdir + '/vpp_stderr.txt', 'w') as f:
660 f.write(vpp_output)
Klement Sekera3747c752017-04-10 06:30:17 +0200661 stderr_log('\n%s', vpp_output)
662 stderr_log(single_line_delim)
Klement Sekera277b89c2016-10-28 13:20:27 +0200663
Damjan Marionf56b77a2016-10-03 19:44:57 +0200664 @classmethod
665 def tearDownClass(cls):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200666 """ Perform final cleanup after running all tests in this test-case """
Paul Vinciguerra90cf21b2019-03-13 09:23:05 -0700667 cls.logger.debug("--- tearDownClass() for %s called ---" %
668 cls.__name__)
juraj.linkes40dd73b2018-09-21 13:55:16 +0200669 cls.reporter.send_keep_alive(cls, 'tearDownClass')
Damjan Marionf56b77a2016-10-03 19:44:57 +0200670 cls.quit()
Klement Sekera027dbd52017-04-11 06:01:53 +0200671 cls.file_handler.close()
Klement Sekeraebbaf552018-02-17 13:41:33 +0100672 cls.reset_packet_infos()
673 if debug_framework:
674 debug_internal.on_tear_down_class(cls)
Damjan Marionf56b77a2016-10-03 19:44:57 +0200675
Paul Vinciguerra90cf21b2019-03-13 09:23:05 -0700676 def show_commands_at_teardown(self):
677 """ Allow subclass specific teardown logging additions."""
678 self.logger.info("--- No test specific show commands provided. ---")
679
Damjan Marionf56b77a2016-10-03 19:44:57 +0200680 def tearDown(self):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200681 """ Show various debug prints after each test """
Klement Sekerab91017a2017-02-09 06:04:36 +0100682 self.logger.debug("--- tearDown() for %s.%s(%s) called ---" %
683 (self.__class__.__name__, self._testMethodName,
684 self._testMethodDoc))
Paul Vinciguerra499ea642019-03-15 09:39:19 -0700685
686 try:
687 if not self.vpp_dead:
688 self.logger.debug(self.vapi.cli("show trace max 1000"))
689 self.logger.info(self.vapi.ppcli("show interface"))
690 self.logger.info(self.vapi.ppcli("show hardware"))
691 self.logger.info(self.statistics.set_errors_str())
692 self.logger.info(self.vapi.ppcli("show run"))
693 self.logger.info(self.vapi.ppcli("show log"))
Dave Barach32dcd3b2019-07-08 12:25:38 -0400694 self.logger.info(self.vapi.ppcli("show bihash"))
Paul Vinciguerra499ea642019-03-15 09:39:19 -0700695 self.logger.info("Logging testcase specific show commands.")
696 self.show_commands_at_teardown()
697 self.registry.remove_vpp_config(self.logger)
Dave Wallace90c55722017-02-16 11:25:26 -0500698 # Save/Dump VPP api trace log
Andrew Yourtchenko586d3ed2019-10-21 12:55:48 +0000699 m = self._testMethodName
700 api_trace = "vpp_api_trace.%s.%d.log" % (m, self.vpp.pid)
Dave Wallace90c55722017-02-16 11:25:26 -0500701 tmp_api_trace = "/tmp/%s" % api_trace
702 vpp_api_trace_log = "%s/%s" % (self.tempdir, api_trace)
703 self.logger.info(self.vapi.ppcli("api trace save %s" % api_trace))
704 self.logger.info("Moving %s to %s\n" % (tmp_api_trace,
705 vpp_api_trace_log))
706 os.rename(tmp_api_trace, vpp_api_trace_log)
Dave Wallace5ba58372018-02-13 16:14:06 -0500707 self.logger.info(self.vapi.ppcli("api trace custom-dump %s" %
Dave Wallace90c55722017-02-16 11:25:26 -0500708 vpp_api_trace_log))
Paul Vinciguerra499ea642019-03-15 09:39:19 -0700709 except VppTransportShmemIOError:
710 self.logger.debug("VppTransportShmemIOError: Vpp dead. "
711 "Cannot log show commands.")
712 self.vpp_dead = True
Klement Sekera1b686402017-03-02 11:29:19 +0100713 else:
714 self.registry.unregister_all(self.logger)
Damjan Marionf56b77a2016-10-03 19:44:57 +0200715
Damjan Marionf56b77a2016-10-03 19:44:57 +0200716 def setUp(self):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200717 """ Clear trace before running each test"""
Paul Vinciguerra8d991d92019-01-25 14:05:48 -0800718 super(VppTestCase, self).setUp()
Klement Sekera909a6a12017-08-08 04:33:53 +0200719 self.reporter.send_keep_alive(self)
Klement Sekera0c1519b2016-12-08 05:03:32 +0100720 if self.vpp_dead:
Paul Vinciguerrafea82602019-06-26 20:45:08 -0400721
722 raise VppDiedError(rv=None, testcase=self.__class__.__name__,
723 method_name=self._testMethodName)
Klement Sekeraacb9b8e2017-02-14 02:55:31 +0100724 self.sleep(.1, "during setUp")
Klement Sekerae4504c62016-12-08 10:16:41 +0100725 self.vpp_stdout_deque.append(
726 "--- test setUp() for %s.%s(%s) starts here ---\n" %
727 (self.__class__.__name__, self._testMethodName,
728 self._testMethodDoc))
729 self.vpp_stderr_deque.append(
730 "--- test setUp() for %s.%s(%s) starts here ---\n" %
731 (self.__class__.__name__, self._testMethodName,
732 self._testMethodDoc))
Klement Sekeraf62ae122016-10-11 11:47:09 +0200733 self.vapi.cli("clear trace")
734 # store the test instance inside the test class - so that objects
735 # holding the class can access instance methods (like assertEqual)
736 type(self).test_instance = self
Damjan Marionf56b77a2016-10-03 19:44:57 +0200737
Damjan Marionf56b77a2016-10-03 19:44:57 +0200738 @classmethod
Klement Sekera75e7d132017-09-20 08:26:30 +0200739 def pg_enable_capture(cls, interfaces=None):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200740 """
741 Enable capture on packet-generator interfaces
Damjan Marionf56b77a2016-10-03 19:44:57 +0200742
Klement Sekera75e7d132017-09-20 08:26:30 +0200743 :param interfaces: iterable interface indexes (if None,
744 use self.pg_interfaces)
Damjan Marionf56b77a2016-10-03 19:44:57 +0200745
Klement Sekeraf62ae122016-10-11 11:47:09 +0200746 """
Klement Sekera75e7d132017-09-20 08:26:30 +0200747 if interfaces is None:
748 interfaces = cls.pg_interfaces
Klement Sekeraf62ae122016-10-11 11:47:09 +0200749 for i in interfaces:
750 i.enable_capture()
Damjan Marionf56b77a2016-10-03 19:44:57 +0200751
Damjan Marionf56b77a2016-10-03 19:44:57 +0200752 @classmethod
Klement Sekera9225dee2016-12-12 08:36:58 +0100753 def register_capture(cls, cap_name):
754 """ Register a capture in the testclass """
755 # add to the list of captures with current timestamp
756 cls._captures.append((time.time(), cap_name))
Klement Sekera9225dee2016-12-12 08:36:58 +0100757
758 @classmethod
Andrew Yourtchenko63cb8822019-10-13 18:56:03 +0000759 def get_vpp_time(cls):
760 return float(cls.vapi.cli('show clock').replace("Time now ", ""))
761
762 @classmethod
763 def sleep_on_vpp_time(cls, sec):
764 """ Sleep according to time in VPP world """
765 # On a busy system with many processes
766 # we might end up with VPP time being slower than real world
767 # So take that into account when waiting for VPP to do something
768 start_time = cls.get_vpp_time()
769 while cls.get_vpp_time() - start_time < sec:
770 cls.sleep(0.1)
771
772 @classmethod
Klement Sekera9225dee2016-12-12 08:36:58 +0100773 def pg_start(cls):
Andrew Yourtchenko8d829f62019-10-13 10:09:50 +0000774 """ Enable the PG, wait till it is done, then clean up """
Klement Sekerad91fa612019-01-15 13:25:09 +0100775 cls.vapi.cli("trace add pg-input 1000")
Klement Sekeraf62ae122016-10-11 11:47:09 +0200776 cls.vapi.cli('packet-generator enable')
Andrew Yourtchenko8d829f62019-10-13 10:09:50 +0000777 # PG, when starts, runs to completion -
778 # so let's avoid a race condition,
779 # and wait a little till it's done.
780 # Then clean it up - and then be gone.
781 deadline = time.time() + 300
782 while cls.vapi.cli('show packet-generator').find("Yes") != -1:
783 cls.sleep(0.01) # yield
784 if time.time() > deadline:
785 cls.logger.error("Timeout waiting for pg to stop")
786 break
787 for stamp, cap_name in cls._captures:
788 cls.vapi.cli('packet-generator delete %s' % cap_name)
Klement Sekera9225dee2016-12-12 08:36:58 +0100789 cls._captures = []
Damjan Marionf56b77a2016-10-03 19:44:57 +0200790
Damjan Marionf56b77a2016-10-03 19:44:57 +0200791 @classmethod
Mohsin Kazmi22e9cfd2019-07-23 11:54:48 +0200792 def create_pg_interfaces(cls, interfaces, gso=0, gso_size=0):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200793 """
Matej Klotton8d8a1da2016-12-22 11:06:56 +0100794 Create packet-generator interfaces.
Damjan Marionf56b77a2016-10-03 19:44:57 +0200795
Matej Klotton8d8a1da2016-12-22 11:06:56 +0100796 :param interfaces: iterable indexes of the interfaces.
797 :returns: List of created interfaces.
Damjan Marionf56b77a2016-10-03 19:44:57 +0200798
Klement Sekeraf62ae122016-10-11 11:47:09 +0200799 """
800 result = []
801 for i in interfaces:
Mohsin Kazmi22e9cfd2019-07-23 11:54:48 +0200802 intf = VppPGInterface(cls, i, gso, gso_size)
Klement Sekeraf62ae122016-10-11 11:47:09 +0200803 setattr(cls, intf.name, intf)
804 result.append(intf)
805 cls.pg_interfaces = result
806 return result
807
Matej Klotton0178d522016-11-04 11:11:44 +0100808 @classmethod
Klement Sekerab9ef2732018-06-24 22:49:33 +0200809 def create_loopback_interfaces(cls, count):
Matej Klotton0178d522016-11-04 11:11:44 +0100810 """
Matej Klotton8d8a1da2016-12-22 11:06:56 +0100811 Create loopback interfaces.
Matej Klotton0178d522016-11-04 11:11:44 +0100812
Klement Sekerab9ef2732018-06-24 22:49:33 +0200813 :param count: number of interfaces created.
Matej Klotton8d8a1da2016-12-22 11:06:56 +0100814 :returns: List of created interfaces.
Matej Klotton0178d522016-11-04 11:11:44 +0100815 """
Klement Sekerab9ef2732018-06-24 22:49:33 +0200816 result = [VppLoInterface(cls) for i in range(count)]
817 for intf in result:
Matej Klotton0178d522016-11-04 11:11:44 +0100818 setattr(cls, intf.name, intf)
Matej Klotton0178d522016-11-04 11:11:44 +0100819 cls.lo_interfaces = result
820 return result
821
Neale Ranns192b13f2019-03-15 02:16:20 -0700822 @classmethod
823 def create_bvi_interfaces(cls, count):
824 """
825 Create BVI interfaces.
826
827 :param count: number of interfaces created.
828 :returns: List of created interfaces.
829 """
830 result = [VppBviInterface(cls) for i in range(count)]
831 for intf in result:
832 setattr(cls, intf.name, intf)
833 cls.bvi_interfaces = result
834 return result
835
Damjan Marionf56b77a2016-10-03 19:44:57 +0200836 @staticmethod
Klement Sekera75e7d132017-09-20 08:26:30 +0200837 def extend_packet(packet, size, padding=' '):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200838 """
Klement Sekera75e7d132017-09-20 08:26:30 +0200839 Extend packet to given size by padding with spaces or custom padding
Klement Sekeraf62ae122016-10-11 11:47:09 +0200840 NOTE: Currently works only when Raw layer is present.
841
842 :param packet: packet
843 :param size: target size
Klement Sekera75e7d132017-09-20 08:26:30 +0200844 :param padding: padding used to extend the payload
Klement Sekeraf62ae122016-10-11 11:47:09 +0200845
846 """
Damjan Marionf56b77a2016-10-03 19:44:57 +0200847 packet_len = len(packet) + 4
848 extend = size - packet_len
849 if extend > 0:
Alexandre Poirriercc991492019-05-07 10:39:57 +0200850 num = (extend // len(padding)) + 1
851 packet[Raw].load += (padding * num)[:extend].encode("ascii")
Damjan Marionf56b77a2016-10-03 19:44:57 +0200852
Klement Sekeradab231a2016-12-21 08:50:14 +0100853 @classmethod
854 def reset_packet_infos(cls):
855 """ Reset the list of packet info objects and packet counts to zero """
856 cls._packet_infos = {}
857 cls._packet_count_for_dst_if_idx = {}
Klement Sekeraf62ae122016-10-11 11:47:09 +0200858
Klement Sekeradab231a2016-12-21 08:50:14 +0100859 @classmethod
860 def create_packet_info(cls, src_if, dst_if):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200861 """
862 Create packet info object containing the source and destination indexes
863 and add it to the testcase's packet info list
864
Klement Sekeradab231a2016-12-21 08:50:14 +0100865 :param VppInterface src_if: source interface
866 :param VppInterface dst_if: destination interface
Klement Sekeraf62ae122016-10-11 11:47:09 +0200867
868 :returns: _PacketInfo object
869
870 """
Damjan Marionf56b77a2016-10-03 19:44:57 +0200871 info = _PacketInfo()
Klement Sekeradab231a2016-12-21 08:50:14 +0100872 info.index = len(cls._packet_infos)
873 info.src = src_if.sw_if_index
874 info.dst = dst_if.sw_if_index
875 if isinstance(dst_if, VppSubInterface):
876 dst_idx = dst_if.parent.sw_if_index
877 else:
878 dst_idx = dst_if.sw_if_index
879 if dst_idx in cls._packet_count_for_dst_if_idx:
880 cls._packet_count_for_dst_if_idx[dst_idx] += 1
881 else:
882 cls._packet_count_for_dst_if_idx[dst_idx] = 1
883 cls._packet_infos[info.index] = info
Damjan Marionf56b77a2016-10-03 19:44:57 +0200884 return info
Damjan Marionf56b77a2016-10-03 19:44:57 +0200885
Damjan Marionf56b77a2016-10-03 19:44:57 +0200886 @staticmethod
887 def info_to_payload(info):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200888 """
889 Convert _PacketInfo object to packet payload
890
891 :param info: _PacketInfo object
892
893 :returns: string containing serialized data from packet info
894 """
Pavel Kotucek59dda062017-03-02 15:22:47 +0100895 return "%d %d %d %d %d" % (info.index, info.src, info.dst,
896 info.ip, info.proto)
Damjan Marionf56b77a2016-10-03 19:44:57 +0200897
Damjan Marionf56b77a2016-10-03 19:44:57 +0200898 @staticmethod
Paul Vinciguerraeaea4212019-03-06 11:58:06 -0800899 def payload_to_info(payload, payload_field='load'):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200900 """
901 Convert packet payload to _PacketInfo object
902
903 :param payload: packet payload
Paul Vinciguerra22364e42019-03-12 20:04:56 -0700904 :type payload: <class 'scapy.packet.Raw'>
905 :param payload_field: packet fieldname of payload "load" for
Paul Vinciguerraeaea4212019-03-06 11:58:06 -0800906 <class 'scapy.packet.Raw'>
Paul Vinciguerra22364e42019-03-12 20:04:56 -0700907 :type payload_field: str
Klement Sekeraf62ae122016-10-11 11:47:09 +0200908 :returns: _PacketInfo object containing de-serialized data from payload
909
910 """
Paul Vinciguerraeaea4212019-03-06 11:58:06 -0800911 numbers = getattr(payload, payload_field).split()
Damjan Marionf56b77a2016-10-03 19:44:57 +0200912 info = _PacketInfo()
913 info.index = int(numbers[0])
914 info.src = int(numbers[1])
915 info.dst = int(numbers[2])
Pavel Kotucek59dda062017-03-02 15:22:47 +0100916 info.ip = int(numbers[3])
917 info.proto = int(numbers[4])
Damjan Marionf56b77a2016-10-03 19:44:57 +0200918 return info
Damjan Marionf56b77a2016-10-03 19:44:57 +0200919
Damjan Marionf56b77a2016-10-03 19:44:57 +0200920 def get_next_packet_info(self, info):
Klement Sekeraf62ae122016-10-11 11:47:09 +0200921 """
922 Iterate over the packet info list stored in the testcase
923 Start iteration with first element if info is None
924 Continue based on index in info if info is specified
925
926 :param info: info or None
927 :returns: next info in list or None if no more infos
928 """
Damjan Marionf56b77a2016-10-03 19:44:57 +0200929 if info is None:
930 next_index = 0
931 else:
932 next_index = info.index + 1
Klement Sekeradab231a2016-12-21 08:50:14 +0100933 if next_index == len(self._packet_infos):
Damjan Marionf56b77a2016-10-03 19:44:57 +0200934 return None
935 else:
Klement Sekeradab231a2016-12-21 08:50:14 +0100936 return self._packet_infos[next_index]
Damjan Marionf56b77a2016-10-03 19:44:57 +0200937
Klement Sekeraf62ae122016-10-11 11:47:09 +0200938 def get_next_packet_info_for_interface(self, src_index, info):
939 """
940 Search the packet info list for the next packet info with same source
941 interface index
942
943 :param src_index: source interface index to search for
944 :param info: packet info - where to start the search
945 :returns: packet info or None
946
947 """
Damjan Marionf56b77a2016-10-03 19:44:57 +0200948 while True:
949 info = self.get_next_packet_info(info)
950 if info is None:
951 return None
Klement Sekeraf62ae122016-10-11 11:47:09 +0200952 if info.src == src_index:
Damjan Marionf56b77a2016-10-03 19:44:57 +0200953 return info
Damjan Marionf56b77a2016-10-03 19:44:57 +0200954
Klement Sekeraf62ae122016-10-11 11:47:09 +0200955 def get_next_packet_info_for_interface2(self, src_index, dst_index, info):
956 """
957 Search the packet info list for the next packet info with same source
958 and destination interface indexes
959
960 :param src_index: source interface index to search for
961 :param dst_index: destination interface index to search for
962 :param info: packet info - where to start the search
963 :returns: packet info or None
964
965 """
Damjan Marionf56b77a2016-10-03 19:44:57 +0200966 while True:
Klement Sekeraf62ae122016-10-11 11:47:09 +0200967 info = self.get_next_packet_info_for_interface(src_index, info)
Damjan Marionf56b77a2016-10-03 19:44:57 +0200968 if info is None:
969 return None
Klement Sekeraf62ae122016-10-11 11:47:09 +0200970 if info.dst == dst_index:
Damjan Marionf56b77a2016-10-03 19:44:57 +0200971 return info
Damjan Marionf56b77a2016-10-03 19:44:57 +0200972
Klement Sekera0e3c0de2016-09-29 14:43:44 +0200973 def assert_equal(self, real_value, expected_value, name_or_class=None):
974 if name_or_class is None:
Klement Sekera239790f2017-02-16 10:53:53 +0100975 self.assertEqual(real_value, expected_value)
Klement Sekera0e3c0de2016-09-29 14:43:44 +0200976 return
977 try:
978 msg = "Invalid %s: %d('%s') does not match expected value %d('%s')"
979 msg = msg % (getdoc(name_or_class).strip(),
980 real_value, str(name_or_class(real_value)),
981 expected_value, str(name_or_class(expected_value)))
Klement Sekera13a83ef2018-03-21 12:35:51 +0100982 except Exception:
Klement Sekera0e3c0de2016-09-29 14:43:44 +0200983 msg = "Invalid %s: %s does not match expected value %s" % (
984 name_or_class, real_value, expected_value)
985
986 self.assertEqual(real_value, expected_value, msg)
987
Klement Sekerab17dd962017-01-09 07:43:48 +0100988 def assert_in_range(self,
989 real_value,
990 expected_min,
991 expected_max,
992 name=None):
Klement Sekera0e3c0de2016-09-29 14:43:44 +0200993 if name is None:
994 msg = None
995 else:
996 msg = "Invalid %s: %s out of range <%s,%s>" % (
997 name, real_value, expected_min, expected_max)
998 self.assertTrue(expected_min <= real_value <= expected_max, msg)
999
Klement Sekerad81ae412018-05-16 10:52:54 +02001000 def assert_packet_checksums_valid(self, packet,
1001 ignore_zero_udp_checksums=True):
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -07001002 received = packet.__class__(scapy.compat.raw(packet))
Klement Sekerad81ae412018-05-16 10:52:54 +02001003 udp_layers = ['UDP', 'UDPerror']
1004 checksum_fields = ['cksum', 'chksum']
1005 checksums = []
1006 counter = 0
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -07001007 temp = received.__class__(scapy.compat.raw(received))
Klement Sekerad81ae412018-05-16 10:52:54 +02001008 while True:
1009 layer = temp.getlayer(counter)
1010 if layer:
1011 for cf in checksum_fields:
1012 if hasattr(layer, cf):
1013 if ignore_zero_udp_checksums and \
Klement Sekera6aa58b72019-05-16 14:34:55 +02001014 0 == getattr(layer, cf) and \
1015 layer.name in udp_layers:
Klement Sekerad81ae412018-05-16 10:52:54 +02001016 continue
1017 delattr(layer, cf)
1018 checksums.append((counter, cf))
1019 else:
1020 break
1021 counter = counter + 1
Klement Sekera31da2e32018-06-24 22:49:55 +02001022 if 0 == len(checksums):
1023 return
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -07001024 temp = temp.__class__(scapy.compat.raw(temp))
Klement Sekerad81ae412018-05-16 10:52:54 +02001025 for layer, cf in checksums:
Klement Sekera31da2e32018-06-24 22:49:55 +02001026 calc_sum = getattr(temp[layer], cf)
1027 self.assert_equal(
1028 getattr(received[layer], cf), calc_sum,
1029 "packet checksum on layer #%d: %s" % (layer, temp[layer].name))
1030 self.logger.debug(
1031 "Checksum field `%s` on `%s` layer has correct value `%s`" %
1032 (cf, temp[layer].name, calc_sum))
Klement Sekerad81ae412018-05-16 10:52:54 +02001033
1034 def assert_checksum_valid(self, received_packet, layer,
1035 field_name='chksum',
1036 ignore_zero_checksum=False):
1037 """ Check checksum of received packet on given layer """
1038 received_packet_checksum = getattr(received_packet[layer], field_name)
1039 if ignore_zero_checksum and 0 == received_packet_checksum:
1040 return
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -07001041 recalculated = received_packet.__class__(
1042 scapy.compat.raw(received_packet))
Klement Sekerad81ae412018-05-16 10:52:54 +02001043 delattr(recalculated[layer], field_name)
Paul Vinciguerraa7427ec2019-03-10 10:04:23 -07001044 recalculated = recalculated.__class__(scapy.compat.raw(recalculated))
Klement Sekerad81ae412018-05-16 10:52:54 +02001045 self.assert_equal(received_packet_checksum,
1046 getattr(recalculated[layer], field_name),
1047 "packet checksum on layer: %s" % layer)
1048
1049 def assert_ip_checksum_valid(self, received_packet,
1050 ignore_zero_checksum=False):
1051 self.assert_checksum_valid(received_packet, 'IP',
1052 ignore_zero_checksum=ignore_zero_checksum)
1053
1054 def assert_tcp_checksum_valid(self, received_packet,
1055 ignore_zero_checksum=False):
1056 self.assert_checksum_valid(received_packet, 'TCP',
1057 ignore_zero_checksum=ignore_zero_checksum)
1058
1059 def assert_udp_checksum_valid(self, received_packet,
1060 ignore_zero_checksum=True):
1061 self.assert_checksum_valid(received_packet, 'UDP',
1062 ignore_zero_checksum=ignore_zero_checksum)
1063
1064 def assert_embedded_icmp_checksum_valid(self, received_packet):
1065 if received_packet.haslayer(IPerror):
1066 self.assert_checksum_valid(received_packet, 'IPerror')
1067 if received_packet.haslayer(TCPerror):
1068 self.assert_checksum_valid(received_packet, 'TCPerror')
1069 if received_packet.haslayer(UDPerror):
1070 self.assert_checksum_valid(received_packet, 'UDPerror',
1071 ignore_zero_checksum=True)
1072 if received_packet.haslayer(ICMPerror):
1073 self.assert_checksum_valid(received_packet, 'ICMPerror')
1074
1075 def assert_icmp_checksum_valid(self, received_packet):
1076 self.assert_checksum_valid(received_packet, 'ICMP')
1077 self.assert_embedded_icmp_checksum_valid(received_packet)
1078
1079 def assert_icmpv6_checksum_valid(self, pkt):
1080 if pkt.haslayer(ICMPv6DestUnreach):
1081 self.assert_checksum_valid(pkt, 'ICMPv6DestUnreach', 'cksum')
1082 self.assert_embedded_icmp_checksum_valid(pkt)
1083 if pkt.haslayer(ICMPv6EchoRequest):
1084 self.assert_checksum_valid(pkt, 'ICMPv6EchoRequest', 'cksum')
1085 if pkt.haslayer(ICMPv6EchoReply):
1086 self.assert_checksum_valid(pkt, 'ICMPv6EchoReply', 'cksum')
1087
Klement Sekera3a343d42019-05-16 14:35:46 +02001088 def get_packet_counter(self, counter):
1089 if counter.startswith("/"):
1090 counter_value = self.statistics.get_counter(counter)
1091 else:
1092 counters = self.vapi.cli("sh errors").split('\n')
Klement Sekera6aa58b72019-05-16 14:34:55 +02001093 counter_value = 0
Klement Sekera3a343d42019-05-16 14:35:46 +02001094 for i in range(1, len(counters) - 1):
1095 results = counters[i].split()
1096 if results[1] == counter:
1097 counter_value = int(results[0])
1098 break
1099 return counter_value
1100
Klement Sekeraf37c3ba2018-11-08 11:24:34 +01001101 def assert_packet_counter_equal(self, counter, expected_value):
Klement Sekera6aa58b72019-05-16 14:34:55 +02001102 counter_value = self.get_packet_counter(counter)
1103 self.assert_equal(counter_value, expected_value,
1104 "packet counter `%s'" % counter)
Klement Sekeraf37c3ba2018-11-08 11:24:34 +01001105
Ole Troan233e4682019-05-16 15:01:34 +02001106 def assert_error_counter_equal(self, counter, expected_value):
1107 counter_value = self.statistics.get_err_counter(counter)
1108 self.assert_equal(counter_value, expected_value,
1109 "error counter `%s'" % counter)
1110
Klement Sekeraacb9b8e2017-02-14 02:55:31 +01001111 @classmethod
1112 def sleep(cls, timeout, remark=None):
Paul Vinciguerra0f6602c2019-03-10 09:10:54 -07001113
1114 # /* Allow sleep(0) to maintain win32 semantics, and as decreed
1115 # * by Guido, only the main thread can be interrupted.
1116 # */
1117 # https://github.com/python/cpython/blob/6673decfa0fb078f60587f5cb5e98460eea137c2/Modules/timemodule.c#L1892 # noqa
1118 if timeout == 0:
1119 # yield quantum
1120 if hasattr(os, 'sched_yield'):
1121 os.sched_yield()
1122 else:
1123 time.sleep(0)
1124 return
1125
Klement Sekeraacb9b8e2017-02-14 02:55:31 +01001126 if hasattr(cls, 'logger'):
Paul Vinciguerra6919b0d2018-12-09 15:37:04 -08001127 cls.logger.debug("Starting sleep for %es (%s)", timeout, remark)
Klement Sekera3cfa5582017-04-19 07:10:58 +00001128 before = time.time()
Klement Sekeraa57a9702017-02-02 06:58:07 +01001129 time.sleep(timeout)
Klement Sekera3cfa5582017-04-19 07:10:58 +00001130 after = time.time()
Paul Vinciguerra6919b0d2018-12-09 15:37:04 -08001131 if hasattr(cls, 'logger') and after - before > 2 * timeout:
Paul Vinciguerra0f6602c2019-03-10 09:10:54 -07001132 cls.logger.error("unexpected self.sleep() result - "
Paul Vinciguerra6919b0d2018-12-09 15:37:04 -08001133 "slept for %es instead of ~%es!",
1134 after - before, timeout)
Klement Sekera3cfa5582017-04-19 07:10:58 +00001135 if hasattr(cls, 'logger'):
1136 cls.logger.debug(
Paul Vinciguerra6919b0d2018-12-09 15:37:04 -08001137 "Finished sleep (%s) - slept %es (wanted %es)",
1138 remark, after - before, timeout)
Klement Sekeraa57a9702017-02-02 06:58:07 +01001139
Paul Vinciguerraeb414432019-02-20 09:01:14 -08001140 def pg_send(self, intf, pkts):
Neale Ranns52fae862018-01-08 04:41:42 -08001141 self.vapi.cli("clear trace")
1142 intf.add_stream(pkts)
1143 self.pg_enable_capture(self.pg_interfaces)
1144 self.pg_start()
Paul Vinciguerraeb414432019-02-20 09:01:14 -08001145
1146 def send_and_assert_no_replies(self, intf, pkts, remark="", timeout=None):
1147 self.pg_send(intf, pkts)
Neale Ranns947ea622018-06-07 23:48:20 -07001148 if not timeout:
1149 timeout = 1
Neale Ranns52fae862018-01-08 04:41:42 -08001150 for i in self.pg_interfaces:
1151 i.get_capture(0, timeout=timeout)
1152 i.assert_nothing_captured(remark=remark)
1153 timeout = 0.1
1154
Neale Rannsd7603d92019-03-28 08:56:10 +00001155 def send_and_expect(self, intf, pkts, output, n_rx=None):
1156 if not n_rx:
1157 n_rx = len(pkts)
Paul Vinciguerraeb414432019-02-20 09:01:14 -08001158 self.pg_send(intf, pkts)
Neale Rannsd7603d92019-03-28 08:56:10 +00001159 rx = output.get_capture(n_rx)
Neale Ranns93cc3ee2018-10-10 07:22:51 -07001160 return rx
1161
Paul Vinciguerraeb414432019-02-20 09:01:14 -08001162 def send_and_expect_only(self, intf, pkts, output, timeout=None):
1163 self.pg_send(intf, pkts)
Paul Vinciguerra8aeb2202019-01-07 16:29:26 -08001164 rx = output.get_capture(len(pkts))
1165 outputs = [output]
Neale Ranns93cc3ee2018-10-10 07:22:51 -07001166 if not timeout:
1167 timeout = 1
1168 for i in self.pg_interfaces:
1169 if i not in outputs:
1170 i.get_capture(0, timeout=timeout)
1171 i.assert_nothing_captured()
1172 timeout = 0.1
1173
Neale Ranns52fae862018-01-08 04:41:42 -08001174 return rx
1175
Paul Vinciguerra087c8112018-12-15 08:03:09 -08001176 def runTest(self):
1177 """ unittest calls runTest when TestCase is instantiated without a
1178 test case. Use case: Writing unittests against VppTestCase"""
1179 pass
1180
Damjan Marionf56b77a2016-10-03 19:44:57 +02001181
juraj.linkes184870a2018-07-16 14:22:01 +02001182def get_testcase_doc_name(test):
1183 return getdoc(test.__class__).splitlines()[0]
1184
1185
Ole Trøan5ba91592018-11-22 10:01:09 +00001186def get_test_description(descriptions, test):
1187 short_description = test.shortDescription()
1188 if descriptions and short_description:
1189 return short_description
1190 else:
1191 return str(test)
1192
1193
juraj.linkes40dd73b2018-09-21 13:55:16 +02001194class TestCaseInfo(object):
1195 def __init__(self, logger, tempdir, vpp_pid, vpp_bin_path):
1196 self.logger = logger
1197 self.tempdir = tempdir
1198 self.vpp_pid = vpp_pid
1199 self.vpp_bin_path = vpp_bin_path
1200 self.core_crash_test = None
Klement Sekera87134932017-03-07 11:39:27 +01001201
1202
Damjan Marionf56b77a2016-10-03 19:44:57 +02001203class VppTestResult(unittest.TestResult):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001204 """
1205 @property result_string
1206 String variable to store the test case result string.
1207 @property errors
1208 List variable containing 2-tuples of TestCase instances and strings
1209 holding formatted tracebacks. Each tuple represents a test which
1210 raised an unexpected exception.
1211 @property failures
1212 List variable containing 2-tuples of TestCase instances and strings
1213 holding formatted tracebacks. Each tuple represents a test where
1214 a failure was explicitly signalled using the TestCase.assert*()
1215 methods.
1216 """
1217
juraj.linkes40dd73b2018-09-21 13:55:16 +02001218 failed_test_cases_info = set()
1219 core_crash_test_cases_info = set()
1220 current_test_case_info = None
1221
Paul Vinciguerra1ec06ff2019-01-16 11:12:50 -08001222 def __init__(self, stream=None, descriptions=None, verbosity=None,
1223 runner=None):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001224 """
Klement Sekerada505f62017-01-04 12:58:53 +01001225 :param stream File descriptor to store where to report test results.
1226 Set to the standard error stream by default.
1227 :param descriptions Boolean variable to store information if to use
1228 test case descriptions.
Klement Sekeraf62ae122016-10-11 11:47:09 +02001229 :param verbosity Integer variable to store required verbosity level.
1230 """
Paul Vinciguerradd3c5d22019-01-13 16:09:10 -08001231 super(VppTestResult, self).__init__(stream, descriptions, verbosity)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001232 self.stream = stream
1233 self.descriptions = descriptions
1234 self.verbosity = verbosity
1235 self.result_string = None
juraj.linkesabec0122018-11-16 17:28:56 +01001236 self.runner = runner
Damjan Marionf56b77a2016-10-03 19:44:57 +02001237
Damjan Marionf56b77a2016-10-03 19:44:57 +02001238 def addSuccess(self, test):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001239 """
1240 Record a test succeeded result
1241
1242 :param test:
1243
1244 """
juraj.linkes40dd73b2018-09-21 13:55:16 +02001245 if self.current_test_case_info:
1246 self.current_test_case_info.logger.debug(
1247 "--- addSuccess() %s.%s(%s) called" % (test.__class__.__name__,
1248 test._testMethodName,
1249 test._testMethodDoc))
Damjan Marionf56b77a2016-10-03 19:44:57 +02001250 unittest.TestResult.addSuccess(self, test)
Klement Sekera277b89c2016-10-28 13:20:27 +02001251 self.result_string = colorize("OK", GREEN)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001252
juraj.linkescae64f82018-09-19 15:01:47 +02001253 self.send_result_through_pipe(test, PASS)
1254
Klement Sekeraf62ae122016-10-11 11:47:09 +02001255 def addSkip(self, test, reason):
1256 """
1257 Record a test skipped.
1258
1259 :param test:
1260 :param reason:
1261
1262 """
juraj.linkes40dd73b2018-09-21 13:55:16 +02001263 if self.current_test_case_info:
1264 self.current_test_case_info.logger.debug(
1265 "--- addSkip() %s.%s(%s) called, reason is %s" %
1266 (test.__class__.__name__, test._testMethodName,
1267 test._testMethodDoc, reason))
Klement Sekeraf62ae122016-10-11 11:47:09 +02001268 unittest.TestResult.addSkip(self, test, reason)
Klement Sekera277b89c2016-10-28 13:20:27 +02001269 self.result_string = colorize("SKIP", YELLOW)
Klement Sekeraf62ae122016-10-11 11:47:09 +02001270
juraj.linkescae64f82018-09-19 15:01:47 +02001271 self.send_result_through_pipe(test, SKIP)
1272
juraj.linkes40dd73b2018-09-21 13:55:16 +02001273 def symlink_failed(self):
1274 if self.current_test_case_info:
Klement Sekeraf413bef2017-08-15 07:09:02 +02001275 try:
Klement Sekerab8c72a42018-11-08 11:21:39 +01001276 failed_dir = os.getenv('FAILED_DIR')
juraj.linkes40dd73b2018-09-21 13:55:16 +02001277 link_path = os.path.join(
1278 failed_dir,
1279 '%s-FAILED' %
1280 os.path.basename(self.current_test_case_info.tempdir))
1281 if self.current_test_case_info.logger:
1282 self.current_test_case_info.logger.debug(
1283 "creating a link to the failed test")
1284 self.current_test_case_info.logger.debug(
1285 "os.symlink(%s, %s)" %
1286 (self.current_test_case_info.tempdir, link_path))
juraj.linkes184870a2018-07-16 14:22:01 +02001287 if os.path.exists(link_path):
juraj.linkes40dd73b2018-09-21 13:55:16 +02001288 if self.current_test_case_info.logger:
1289 self.current_test_case_info.logger.debug(
1290 'symlink already exists')
juraj.linkes184870a2018-07-16 14:22:01 +02001291 else:
juraj.linkes40dd73b2018-09-21 13:55:16 +02001292 os.symlink(self.current_test_case_info.tempdir, link_path)
juraj.linkes184870a2018-07-16 14:22:01 +02001293
Klement Sekeraf413bef2017-08-15 07:09:02 +02001294 except Exception as e:
juraj.linkes40dd73b2018-09-21 13:55:16 +02001295 if self.current_test_case_info.logger:
1296 self.current_test_case_info.logger.error(e)
Klement Sekeraf413bef2017-08-15 07:09:02 +02001297
juraj.linkescae64f82018-09-19 15:01:47 +02001298 def send_result_through_pipe(self, test, result):
1299 if hasattr(self, 'test_framework_result_pipe'):
1300 pipe = self.test_framework_result_pipe
juraj.linkes5e2c54d2018-08-30 10:51:45 +02001301 if pipe:
juraj.linkescae64f82018-09-19 15:01:47 +02001302 pipe.send((test.id(), result))
juraj.linkes5e2c54d2018-08-30 10:51:45 +02001303
juraj.linkes40dd73b2018-09-21 13:55:16 +02001304 def log_error(self, test, err, fn_name):
1305 if self.current_test_case_info:
1306 if isinstance(test, unittest.suite._ErrorHolder):
1307 test_name = test.description
1308 else:
1309 test_name = '%s.%s(%s)' % (test.__class__.__name__,
1310 test._testMethodName,
1311 test._testMethodDoc)
1312 self.current_test_case_info.logger.debug(
1313 "--- %s() %s called, err is %s" %
1314 (fn_name, test_name, err))
1315 self.current_test_case_info.logger.debug(
1316 "formatted exception is:\n%s" %
1317 "".join(format_exception(*err)))
1318
1319 def add_error(self, test, err, unittest_fn, error_type):
1320 if error_type == FAIL:
1321 self.log_error(test, err, 'addFailure')
1322 error_type_str = colorize("FAIL", RED)
1323 elif error_type == ERROR:
1324 self.log_error(test, err, 'addError')
1325 error_type_str = colorize("ERROR", RED)
1326 else:
1327 raise Exception('Error type %s cannot be used to record an '
1328 'error or a failure' % error_type)
1329
1330 unittest_fn(self, test, err)
1331 if self.current_test_case_info:
1332 self.result_string = "%s [ temp dir used by test case: %s ]" % \
1333 (error_type_str,
1334 self.current_test_case_info.tempdir)
1335 self.symlink_failed()
1336 self.failed_test_cases_info.add(self.current_test_case_info)
1337 if is_core_present(self.current_test_case_info.tempdir):
1338 if not self.current_test_case_info.core_crash_test:
1339 if isinstance(test, unittest.suite._ErrorHolder):
1340 test_name = str(test)
1341 else:
Paul Vinciguerraea2450f2019-03-06 08:23:58 -08001342 test_name = "'{!s}' ({!s})".format(
juraj.linkes40dd73b2018-09-21 13:55:16 +02001343 get_testcase_doc_name(test), test.id())
1344 self.current_test_case_info.core_crash_test = test_name
1345 self.core_crash_test_cases_info.add(
1346 self.current_test_case_info)
1347 else:
1348 self.result_string = '%s [no temp dir]' % error_type_str
1349
1350 self.send_result_through_pipe(test, error_type)
1351
Damjan Marionf56b77a2016-10-03 19:44:57 +02001352 def addFailure(self, test, err):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001353 """
1354 Record a test failed result
1355
1356 :param test:
1357 :param err: error message
1358
1359 """
juraj.linkes40dd73b2018-09-21 13:55:16 +02001360 self.add_error(test, err, unittest.TestResult.addFailure, FAIL)
juraj.linkescae64f82018-09-19 15:01:47 +02001361
Damjan Marionf56b77a2016-10-03 19:44:57 +02001362 def addError(self, test, err):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001363 """
1364 Record a test error result
Damjan Marionf56b77a2016-10-03 19:44:57 +02001365
Klement Sekeraf62ae122016-10-11 11:47:09 +02001366 :param test:
1367 :param err: error message
1368
1369 """
juraj.linkes40dd73b2018-09-21 13:55:16 +02001370 self.add_error(test, err, unittest.TestResult.addError, ERROR)
juraj.linkescae64f82018-09-19 15:01:47 +02001371
Damjan Marionf56b77a2016-10-03 19:44:57 +02001372 def getDescription(self, test):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001373 """
1374 Get test description
1375
1376 :param test:
1377 :returns: test description
1378
1379 """
Ole Trøan5ba91592018-11-22 10:01:09 +00001380 return get_test_description(self.descriptions, test)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001381
Damjan Marionf56b77a2016-10-03 19:44:57 +02001382 def startTest(self, test):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001383 """
1384 Start a test
1385
1386 :param test:
1387
1388 """
Paul Vinciguerradd3c5d22019-01-13 16:09:10 -08001389
1390 def print_header(test):
1391 if not hasattr(test.__class__, '_header_printed'):
1392 print(double_line_delim)
1393 print(colorize(getdoc(test).splitlines()[0], GREEN))
1394 print(double_line_delim)
1395 test.__class__._header_printed = True
1396
1397 print_header(test)
juraj.linkes40dd73b2018-09-21 13:55:16 +02001398
Damjan Marionf56b77a2016-10-03 19:44:57 +02001399 unittest.TestResult.startTest(self, test)
1400 if self.verbosity > 0:
Klement Sekeraf62ae122016-10-11 11:47:09 +02001401 self.stream.writeln(
1402 "Starting " + self.getDescription(test) + " ...")
1403 self.stream.writeln(single_line_delim)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001404
Damjan Marionf56b77a2016-10-03 19:44:57 +02001405 def stopTest(self, test):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001406 """
juraj.linkes5e2c54d2018-08-30 10:51:45 +02001407 Called when the given test has been run
Klement Sekeraf62ae122016-10-11 11:47:09 +02001408
1409 :param test:
1410
1411 """
Damjan Marionf56b77a2016-10-03 19:44:57 +02001412 unittest.TestResult.stopTest(self, test)
1413 if self.verbosity > 0:
Klement Sekeraf62ae122016-10-11 11:47:09 +02001414 self.stream.writeln(single_line_delim)
Klement Sekera52e84f32017-01-13 07:25:25 +01001415 self.stream.writeln("%-73s%s" % (self.getDescription(test),
Klement Sekerada505f62017-01-04 12:58:53 +01001416 self.result_string))
Klement Sekeraf62ae122016-10-11 11:47:09 +02001417 self.stream.writeln(single_line_delim)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001418 else:
Klement Sekera52e84f32017-01-13 07:25:25 +01001419 self.stream.writeln("%-73s%s" % (self.getDescription(test),
Klement Sekerada505f62017-01-04 12:58:53 +01001420 self.result_string))
juraj.linkescae64f82018-09-19 15:01:47 +02001421
1422 self.send_result_through_pipe(test, TEST_RUN)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001423
Damjan Marionf56b77a2016-10-03 19:44:57 +02001424 def printErrors(self):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001425 """
1426 Print errors from running the test case
1427 """
juraj.linkesabec0122018-11-16 17:28:56 +01001428 if len(self.errors) > 0 or len(self.failures) > 0:
1429 self.stream.writeln()
1430 self.printErrorList('ERROR', self.errors)
1431 self.printErrorList('FAIL', self.failures)
1432
1433 # ^^ that is the last output from unittest before summary
1434 if not self.runner.print_summary:
1435 devnull = unittest.runner._WritelnDecorator(open(os.devnull, 'w'))
1436 self.stream = devnull
1437 self.runner.stream = devnull
Damjan Marionf56b77a2016-10-03 19:44:57 +02001438
Damjan Marionf56b77a2016-10-03 19:44:57 +02001439 def printErrorList(self, flavour, errors):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001440 """
1441 Print error list to the output stream together with error type
1442 and test case description.
1443
1444 :param flavour: error type
1445 :param errors: iterable errors
1446
1447 """
Damjan Marionf56b77a2016-10-03 19:44:57 +02001448 for test, err in errors:
Klement Sekeraf62ae122016-10-11 11:47:09 +02001449 self.stream.writeln(double_line_delim)
1450 self.stream.writeln("%s: %s" %
1451 (flavour, self.getDescription(test)))
1452 self.stream.writeln(single_line_delim)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001453 self.stream.writeln("%s" % err)
Damjan Marionf56b77a2016-10-03 19:44:57 +02001454
1455
Damjan Marionf56b77a2016-10-03 19:44:57 +02001456class VppTestRunner(unittest.TextTestRunner):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001457 """
Klement Sekera104543f2017-02-03 07:29:43 +01001458 A basic test runner implementation which prints results to standard error.
Klement Sekeraf62ae122016-10-11 11:47:09 +02001459 """
Paul Vinciguerra6919b0d2018-12-09 15:37:04 -08001460
Klement Sekeraf62ae122016-10-11 11:47:09 +02001461 @property
1462 def resultclass(self):
1463 """Class maintaining the results of the tests"""
1464 return VppTestResult
Damjan Marionf56b77a2016-10-03 19:44:57 +02001465
juraj.linkes184870a2018-07-16 14:22:01 +02001466 def __init__(self, keep_alive_pipe=None, descriptions=True, verbosity=1,
juraj.linkescae64f82018-09-19 15:01:47 +02001467 result_pipe=None, failfast=False, buffer=False,
Paul Vinciguerra98894022019-01-13 21:32:37 -08001468 resultclass=None, print_summary=True, **kwargs):
Klement Sekera7a161da2017-01-17 13:42:48 +01001469 # ignore stream setting here, use hard-coded stdout to be in sync
1470 # with prints from VppTestCase methods ...
1471 super(VppTestRunner, self).__init__(sys.stdout, descriptions,
1472 verbosity, failfast, buffer,
Paul Vinciguerra98894022019-01-13 21:32:37 -08001473 resultclass, **kwargs)
juraj.linkesccfead62018-11-21 13:20:43 +01001474 KeepAliveReporter.pipe = keep_alive_pipe
Klement Sekera104543f2017-02-03 07:29:43 +01001475
juraj.linkesabec0122018-11-16 17:28:56 +01001476 self.orig_stream = self.stream
1477 self.resultclass.test_framework_result_pipe = result_pipe
1478
1479 self.print_summary = print_summary
1480
1481 def _makeResult(self):
1482 return self.resultclass(self.stream,
1483 self.descriptions,
1484 self.verbosity,
1485 self)
juraj.linkes5e2c54d2018-08-30 10:51:45 +02001486
Damjan Marionf56b77a2016-10-03 19:44:57 +02001487 def run(self, test):
Klement Sekeraf62ae122016-10-11 11:47:09 +02001488 """
1489 Run the tests
1490
1491 :param test:
1492
1493 """
Klement Sekera3658adc2017-06-07 08:19:47 +02001494 faulthandler.enable() # emit stack trace to stderr if killed by signal
juraj.linkes184870a2018-07-16 14:22:01 +02001495
1496 result = super(VppTestRunner, self).run(test)
juraj.linkesabec0122018-11-16 17:28:56 +01001497 if not self.print_summary:
1498 self.stream = self.orig_stream
1499 result.stream = self.orig_stream
juraj.linkes184870a2018-07-16 14:22:01 +02001500 return result
Neale Ranns812ed392017-10-16 04:20:13 -07001501
1502
1503class Worker(Thread):
Paul Vinciguerra063366e2019-06-30 15:38:55 -04001504 def __init__(self, args, logger, env=None):
Neale Ranns812ed392017-10-16 04:20:13 -07001505 self.logger = logger
1506 self.args = args
Dave Wallace24564332019-10-21 02:53:14 +00001507 if hasattr(self, 'testcase') and self.testcase.debug_all:
1508 if self.testcase.debug_gdbserver:
1509 self.args = ['/usr/bin/gdbserver', 'localhost:{port}'
1510 .format(port=self.testcase.gdbserver_port)] + args
1511 elif self.testcase.debug_gdb and hasattr(self, 'wait_for_gdb'):
1512 self.args.append(self.wait_for_gdb)
1513 self.app_bin = args[0]
1514 self.app_name = os.path.basename(self.app_bin)
1515 if hasattr(self, 'role'):
1516 self.app_name += ' {role}'.format(role=self.role)
Paul Vinciguerra063366e2019-06-30 15:38:55 -04001517 self.process = None
Neale Ranns812ed392017-10-16 04:20:13 -07001518 self.result = None
Paul Vinciguerra063366e2019-06-30 15:38:55 -04001519 env = {} if env is None else env
Dave Wallace42996c02018-02-26 14:40:13 -05001520 self.env = copy.deepcopy(env)
Neale Ranns812ed392017-10-16 04:20:13 -07001521 super(Worker, self).__init__()
1522
Dave Wallace24564332019-10-21 02:53:14 +00001523 def wait_for_enter(self):
1524 if not hasattr(self, 'testcase'):
1525 return
1526 if self.testcase.debug_all and self.testcase.debug_gdbserver:
1527 print()
1528 print(double_line_delim)
1529 print("Spawned GDB Server for '{app}' with PID: {pid}"
1530 .format(app=self.app_name, pid=self.process.pid))
1531 elif self.testcase.debug_all and self.testcase.debug_gdb:
1532 print()
1533 print(double_line_delim)
1534 print("Spawned '{app}' with PID: {pid}"
1535 .format(app=self.app_name, pid=self.process.pid))
1536 else:
1537 return
1538 print(single_line_delim)
1539 print("You can debug '{app}' using:".format(app=self.app_name))
1540 if self.testcase.debug_gdbserver:
1541 print("sudo gdb " + self.app_bin +
1542 " -ex 'target remote localhost:{port}'"
1543 .format(port=self.testcase.gdbserver_port))
1544 print("Now is the time to attach gdb by running the above "
1545 "command, set up breakpoints etc., then resume from "
1546 "within gdb by issuing the 'continue' command")
1547 self.testcase.gdbserver_port += 1
1548 elif self.testcase.debug_gdb:
1549 print("sudo gdb " + self.app_bin +
1550 " -ex 'attach {pid}'".format(pid=self.process.pid))
1551 print("Now is the time to attach gdb by running the above "
1552 "command and set up breakpoints etc., then resume from"
1553 " within gdb by issuing the 'continue' command")
1554 print(single_line_delim)
1555 input("Press ENTER to continue running the testcase...")
1556
Neale Ranns812ed392017-10-16 04:20:13 -07001557 def run(self):
1558 executable = self.args[0]
Paul Vinciguerra063366e2019-06-30 15:38:55 -04001559 if not os.path.exists(executable) or not os.access(
1560 executable, os.F_OK | os.X_OK):
1561 # Exit code that means some system file did not exist,
1562 # could not be opened, or had some other kind of error.
1563 self.result = os.EX_OSFILE
1564 raise EnvironmentError(
1565 "executable '%s' is not found or executable." % executable)
Dave Wallace24564332019-10-21 02:53:14 +00001566 self.logger.debug("Running executable: '{app}'"
1567 .format(app=' '.join(self.args)))
Neale Ranns812ed392017-10-16 04:20:13 -07001568 env = os.environ.copy()
Dave Wallacecfcf2f42018-02-16 18:31:56 -05001569 env.update(self.env)
Neale Ranns812ed392017-10-16 04:20:13 -07001570 env["CK_LOG_FILE_NAME"] = "-"
1571 self.process = subprocess.Popen(
1572 self.args, shell=False, env=env, preexec_fn=os.setpgrp,
1573 stdout=subprocess.PIPE, stderr=subprocess.PIPE)
Dave Wallace24564332019-10-21 02:53:14 +00001574 self.wait_for_enter()
Neale Ranns812ed392017-10-16 04:20:13 -07001575 out, err = self.process.communicate()
Dave Wallace24564332019-10-21 02:53:14 +00001576 self.logger.debug("Finished running `{app}'".format(app=self.app_name))
Neale Ranns812ed392017-10-16 04:20:13 -07001577 self.logger.info("Return code is `%s'" % self.process.returncode)
1578 self.logger.info(single_line_delim)
Dave Wallace24564332019-10-21 02:53:14 +00001579 self.logger.info("Executable `{app}' wrote to stdout:"
1580 .format(app=self.app_name))
Neale Ranns812ed392017-10-16 04:20:13 -07001581 self.logger.info(single_line_delim)
Dave Wallace97ea2f42019-10-29 19:12:03 -04001582 self.logger.info(out.decode('utf-8'))
Neale Ranns812ed392017-10-16 04:20:13 -07001583 self.logger.info(single_line_delim)
Dave Wallace24564332019-10-21 02:53:14 +00001584 self.logger.info("Executable `{app}' wrote to stderr:"
1585 .format(app=self.app_name))
Neale Ranns812ed392017-10-16 04:20:13 -07001586 self.logger.info(single_line_delim)
Dave Wallace97ea2f42019-10-29 19:12:03 -04001587 self.logger.info(err.decode('utf-8'))
Neale Ranns812ed392017-10-16 04:20:13 -07001588 self.logger.info(single_line_delim)
1589 self.result = self.process.returncode
Paul Vinciguerradd3c5d22019-01-13 16:09:10 -08001590
Klement Sekera6aa58b72019-05-16 14:34:55 +02001591
Paul Vinciguerradd3c5d22019-01-13 16:09:10 -08001592if __name__ == '__main__':
1593 pass