2016-10-11 11:47:09 +02:00
|
|
|
import os
|
2018-03-21 12:35:51 +01:00
|
|
|
import sys
|
2016-10-28 13:20:27 +02:00
|
|
|
import traceback
|
test/hook.py. Add human-friendly annotations to log msgs.
* Add human-friendly annotations to packed data values in
the logs.
Examples:
vpp-unittest-TestNAT66-_JdbMS/log.txt:22:31:29,152 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=2, dst_address='\xfd\x01\x00\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02 (fd01:2::2)', mac_address='\x02\x02\x00\x00\xff\x02 (02:02:00:00:ff:02)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,130 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=5, dst_address='\xfd\x01\x00\x05\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xc9 (fd01:5::c9)', mac_address='\x02\x05\xc9\x00\xff\xc9 (02:05:c9:00:ff:c9)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,240 API: sw_interface_add_del_address (address_length=24, del_all=0, is_add=1, sw_if_index=6, address='\xac\x10\x06\x01 (172.16.6.1)', is_ipv6=0)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,314 API: sw_interface_add_del_address (address_length=64, del_all=0, is_add=1, sw_if_index=6, address='\xfd\x01\x00\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01 (fd01:6::1)', is_ipv6=1)
Change-Id: Id6991569ee0ff853f76fae8fac941e8a26468a19
Signed-off-by: Paul Vinciguerra <pvinci@vinciconsulting.com>
2018-12-12 01:04:20 -08:00
|
|
|
import ipaddress
|
2018-03-23 10:50:11 +01:00
|
|
|
from subprocess import check_output, CalledProcessError
|
2019-03-10 10:04:23 -07:00
|
|
|
|
|
|
|
import scapy.compat
|
2019-06-20 12:24:12 -04:00
|
|
|
import framework
|
2022-03-26 15:43:14 +00:00
|
|
|
from config import config
|
2019-06-20 12:24:12 -04:00
|
|
|
from log import RED, single_line_delim, double_line_delim
|
2018-09-21 13:55:16 +02:00
|
|
|
from util import check_core_path, get_core_path
|
2016-10-11 11:47:09 +02:00
|
|
|
|
|
|
|
|
2020-12-04 14:57:51 -05:00
|
|
|
class Hook:
|
2016-10-11 11:47:09 +02:00
|
|
|
"""
|
|
|
|
Generic hooks before/after API/CLI calls
|
|
|
|
"""
|
|
|
|
|
2019-01-08 20:37:40 -08:00
|
|
|
def __init__(self, test):
|
|
|
|
self.test = test
|
|
|
|
self.logger = test.logger
|
2016-10-28 13:20:27 +02:00
|
|
|
|
2016-10-11 11:47:09 +02:00
|
|
|
def before_api(self, api_name, api_args):
|
|
|
|
"""
|
|
|
|
Function called before API call
|
|
|
|
Emit a debug message describing the API name and arguments
|
|
|
|
|
|
|
|
@param api_name: name of the API
|
|
|
|
@param api_args: tuple containing the API arguments
|
|
|
|
"""
|
test/hook.py. Add human-friendly annotations to log msgs.
* Add human-friendly annotations to packed data values in
the logs.
Examples:
vpp-unittest-TestNAT66-_JdbMS/log.txt:22:31:29,152 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=2, dst_address='\xfd\x01\x00\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02 (fd01:2::2)', mac_address='\x02\x02\x00\x00\xff\x02 (02:02:00:00:ff:02)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,130 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=5, dst_address='\xfd\x01\x00\x05\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xc9 (fd01:5::c9)', mac_address='\x02\x05\xc9\x00\xff\xc9 (02:05:c9:00:ff:c9)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,240 API: sw_interface_add_del_address (address_length=24, del_all=0, is_add=1, sw_if_index=6, address='\xac\x10\x06\x01 (172.16.6.1)', is_ipv6=0)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,314 API: sw_interface_add_del_address (address_length=64, del_all=0, is_add=1, sw_if_index=6, address='\xfd\x01\x00\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01 (fd01:6::1)', is_ipv6=1)
Change-Id: Id6991569ee0ff853f76fae8fac941e8a26468a19
Signed-off-by: Paul Vinciguerra <pvinci@vinciconsulting.com>
2018-12-12 01:04:20 -08:00
|
|
|
|
|
|
|
def _friendly_format(val):
|
|
|
|
if not isinstance(val, str):
|
|
|
|
return val
|
|
|
|
if len(val) == 6:
|
2022-04-26 19:02:15 +02:00
|
|
|
return "{!s} ({!s})".format(
|
|
|
|
val, ":".join(["{:02x}".format(scapy.compat.orb(x)) for x in val])
|
|
|
|
)
|
test/hook.py. Add human-friendly annotations to log msgs.
* Add human-friendly annotations to packed data values in
the logs.
Examples:
vpp-unittest-TestNAT66-_JdbMS/log.txt:22:31:29,152 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=2, dst_address='\xfd\x01\x00\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02 (fd01:2::2)', mac_address='\x02\x02\x00\x00\xff\x02 (02:02:00:00:ff:02)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,130 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=5, dst_address='\xfd\x01\x00\x05\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xc9 (fd01:5::c9)', mac_address='\x02\x05\xc9\x00\xff\xc9 (02:05:c9:00:ff:c9)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,240 API: sw_interface_add_del_address (address_length=24, del_all=0, is_add=1, sw_if_index=6, address='\xac\x10\x06\x01 (172.16.6.1)', is_ipv6=0)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,314 API: sw_interface_add_del_address (address_length=64, del_all=0, is_add=1, sw_if_index=6, address='\xfd\x01\x00\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01 (fd01:6::1)', is_ipv6=1)
Change-Id: Id6991569ee0ff853f76fae8fac941e8a26468a19
Signed-off-by: Paul Vinciguerra <pvinci@vinciconsulting.com>
2018-12-12 01:04:20 -08:00
|
|
|
try:
|
2019-01-29 11:51:44 -08:00
|
|
|
# we don't call test_type(val) because it is a packed value.
|
2022-04-26 19:02:15 +02:00
|
|
|
return "{!s} ({!s})".format(val, str(ipaddress.ip_address(val)))
|
2019-03-27 14:28:50 -07:00
|
|
|
except ValueError:
|
test/hook.py. Add human-friendly annotations to log msgs.
* Add human-friendly annotations to packed data values in
the logs.
Examples:
vpp-unittest-TestNAT66-_JdbMS/log.txt:22:31:29,152 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=2, dst_address='\xfd\x01\x00\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02 (fd01:2::2)', mac_address='\x02\x02\x00\x00\xff\x02 (02:02:00:00:ff:02)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,130 API: ip_neighbor_add_del (is_static=0, is_no_adj_fib=0, is_add=1, sw_if_index=5, dst_address='\xfd\x01\x00\x05\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xc9 (fd01:5::c9)', mac_address='\x02\x05\xc9\x00\xff\xc9 (02:05:c9:00:ff:c9)', is_ipv6=1)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,240 API: sw_interface_add_del_address (address_length=24, del_all=0, is_add=1, sw_if_index=6, address='\xac\x10\x06\x01 (172.16.6.1)', is_ipv6=0)
vpp-unittest-TestACL_dot1ad_bridged-xEdhrj/log.txt:22:31:17,314 API: sw_interface_add_del_address (address_length=64, del_all=0, is_add=1, sw_if_index=6, address='\xfd\x01\x00\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01 (fd01:6::1)', is_ipv6=1)
Change-Id: Id6991569ee0ff853f76fae8fac941e8a26468a19
Signed-off-by: Paul Vinciguerra <pvinci@vinciconsulting.com>
2018-12-12 01:04:20 -08:00
|
|
|
return val
|
|
|
|
|
2022-04-26 19:02:15 +02:00
|
|
|
_args = ", ".join(
|
|
|
|
"{!s}={!r}".format(key, _friendly_format(val))
|
|
|
|
for (key, val) in api_args.items()
|
|
|
|
)
|
|
|
|
self.logger.debug("API: %s (%s)" % (api_name, _args), extra={"color": RED})
|
2016-10-11 11:47:09 +02:00
|
|
|
|
|
|
|
def after_api(self, api_name, api_args):
|
|
|
|
"""
|
|
|
|
Function called after API call
|
|
|
|
|
|
|
|
@param api_name: name of the API
|
|
|
|
@param api_args: tuple containing the API arguments
|
|
|
|
"""
|
|
|
|
pass
|
|
|
|
|
|
|
|
def before_cli(self, cli):
|
|
|
|
"""
|
|
|
|
Function called before CLI call
|
|
|
|
Emit a debug message describing the CLI
|
|
|
|
|
|
|
|
@param cli: CLI string
|
|
|
|
"""
|
2022-04-26 19:02:15 +02:00
|
|
|
self.logger.debug("CLI: %s" % (cli), extra={"color": RED})
|
2016-10-11 11:47:09 +02:00
|
|
|
|
|
|
|
def after_cli(self, cli):
|
|
|
|
"""
|
|
|
|
Function called after CLI call
|
|
|
|
"""
|
|
|
|
pass
|
|
|
|
|
|
|
|
|
|
|
|
class PollHook(Hook):
|
2022-04-26 19:02:15 +02:00
|
|
|
"""Hook which checks if the vpp subprocess is alive"""
|
2016-10-11 11:47:09 +02:00
|
|
|
|
2019-01-08 20:37:40 -08:00
|
|
|
def __init__(self, test):
|
|
|
|
super(PollHook, self).__init__(test)
|
2016-10-11 11:47:09 +02:00
|
|
|
|
|
|
|
def on_crash(self, core_path):
|
2022-04-26 19:02:15 +02:00
|
|
|
self.logger.error(
|
|
|
|
"Core file present, debug with: gdb %s %s", config.vpp, core_path
|
|
|
|
)
|
2018-09-21 13:55:16 +02:00
|
|
|
check_core_path(self.logger, core_path)
|
2018-11-28 11:34:21 -08:00
|
|
|
self.logger.error("Running `file %s':", core_path)
|
2018-09-21 13:55:16 +02:00
|
|
|
try:
|
|
|
|
info = check_output(["file", core_path])
|
|
|
|
self.logger.error(info)
|
|
|
|
except CalledProcessError as e:
|
|
|
|
self.logger.error(
|
2018-11-28 11:34:21 -08:00
|
|
|
"Subprocess returned with error running `file' utility on "
|
|
|
|
"core-file, "
|
2022-04-26 19:02:15 +02:00
|
|
|
"rc=%s",
|
|
|
|
e.returncode,
|
|
|
|
)
|
2018-11-28 11:34:21 -08:00
|
|
|
except OSError as e:
|
|
|
|
self.logger.error(
|
|
|
|
"Subprocess returned OS error running `file' utility on "
|
|
|
|
"core-file, "
|
2022-04-26 19:02:15 +02:00
|
|
|
"oserror=(%s) %s",
|
|
|
|
e.errno,
|
|
|
|
e.strerror,
|
|
|
|
)
|
2018-11-28 11:34:21 -08:00
|
|
|
except Exception as e:
|
|
|
|
self.logger.error(
|
|
|
|
"Subprocess returned unanticipated error running `file' "
|
|
|
|
"utility on core-file, "
|
2022-04-26 19:02:15 +02:00
|
|
|
"%s",
|
|
|
|
e,
|
|
|
|
)
|
2016-10-11 11:47:09 +02:00
|
|
|
|
|
|
|
def poll_vpp(self):
|
|
|
|
"""
|
|
|
|
Poll the vpp status and throw an exception if it's not running
|
|
|
|
:raises VppDiedError: exception if VPP is not running anymore
|
|
|
|
"""
|
2019-01-08 20:37:40 -08:00
|
|
|
if self.test.vpp_dead:
|
2016-10-11 11:47:09 +02:00
|
|
|
# already dead, nothing to do
|
|
|
|
return
|
|
|
|
|
2019-01-08 20:37:40 -08:00
|
|
|
self.test.vpp.poll()
|
|
|
|
if self.test.vpp.returncode is not None:
|
2019-06-20 12:24:12 -04:00
|
|
|
self.test.vpp_dead = True
|
|
|
|
raise framework.VppDiedError(rv=self.test.vpp.returncode)
|
2019-01-08 20:37:40 -08:00
|
|
|
core_path = get_core_path(self.test.tempdir)
|
2016-10-11 11:47:09 +02:00
|
|
|
if os.path.isfile(core_path):
|
|
|
|
self.on_crash(core_path)
|
|
|
|
|
2016-09-29 14:43:44 +02:00
|
|
|
def before_api(self, api_name, api_args):
|
2016-10-11 11:47:09 +02:00
|
|
|
"""
|
2016-09-29 14:43:44 +02:00
|
|
|
Check if VPP died before executing an API
|
2016-10-11 11:47:09 +02:00
|
|
|
|
|
|
|
:param api_name: name of the API
|
|
|
|
:param api_args: tuple containing the API arguments
|
|
|
|
:raises VppDiedError: exception if VPP is not running anymore
|
|
|
|
|
|
|
|
"""
|
2016-09-29 14:43:44 +02:00
|
|
|
super(PollHook, self).before_api(api_name, api_args)
|
2016-10-11 11:47:09 +02:00
|
|
|
self.poll_vpp()
|
|
|
|
|
2016-09-29 14:43:44 +02:00
|
|
|
def before_cli(self, cli):
|
2016-10-11 11:47:09 +02:00
|
|
|
"""
|
2016-09-29 14:43:44 +02:00
|
|
|
Check if VPP died before executing a CLI
|
2016-10-11 11:47:09 +02:00
|
|
|
|
|
|
|
:param cli: CLI string
|
|
|
|
:raises Exception: exception if VPP is not running anymore
|
|
|
|
|
|
|
|
"""
|
2016-09-29 14:43:44 +02:00
|
|
|
super(PollHook, self).before_cli(cli)
|
2016-10-11 11:47:09 +02:00
|
|
|
self.poll_vpp()
|
2016-10-28 13:20:27 +02:00
|
|
|
|
|
|
|
|
|
|
|
class StepHook(PollHook):
|
2022-04-26 19:02:15 +02:00
|
|
|
"""Hook which requires user to press ENTER before doing any API/CLI"""
|
2016-10-28 13:20:27 +02:00
|
|
|
|
2019-01-08 20:37:40 -08:00
|
|
|
def __init__(self, test):
|
2016-10-28 13:20:27 +02:00
|
|
|
self.skip_stack = None
|
|
|
|
self.skip_num = None
|
|
|
|
self.skip_count = 0
|
2022-01-28 11:31:01 +00:00
|
|
|
self.break_func = None
|
2019-01-08 20:37:40 -08:00
|
|
|
super(StepHook, self).__init__(test)
|
2016-10-28 13:20:27 +02:00
|
|
|
|
|
|
|
def skip(self):
|
2022-01-28 11:31:01 +00:00
|
|
|
if self.break_func is not None:
|
|
|
|
return self.should_skip_func_based()
|
|
|
|
if self.skip_stack is not None:
|
|
|
|
return self.should_skip_stack_based()
|
|
|
|
|
|
|
|
def should_skip_func_based(self):
|
|
|
|
stack = traceback.extract_stack()
|
|
|
|
for e in stack:
|
|
|
|
if e[2] == self.break_func:
|
|
|
|
self.break_func = None
|
|
|
|
return False
|
|
|
|
return True
|
|
|
|
|
|
|
|
def should_skip_stack_based(self):
|
2016-10-28 13:20:27 +02:00
|
|
|
stack = traceback.extract_stack()
|
|
|
|
counter = 0
|
|
|
|
skip = True
|
|
|
|
for e in stack:
|
|
|
|
if counter > self.skip_num:
|
|
|
|
break
|
|
|
|
if e[0] != self.skip_stack[counter][0]:
|
|
|
|
skip = False
|
|
|
|
if e[1] != self.skip_stack[counter][1]:
|
|
|
|
skip = False
|
|
|
|
counter += 1
|
|
|
|
if skip:
|
|
|
|
self.skip_count += 1
|
|
|
|
return True
|
|
|
|
else:
|
2022-04-26 19:02:15 +02:00
|
|
|
print("%d API/CLI calls skipped in specified stack frame" % self.skip_count)
|
2016-10-28 13:20:27 +02:00
|
|
|
self.skip_count = 0
|
|
|
|
self.skip_stack = None
|
|
|
|
self.skip_num = None
|
|
|
|
return False
|
|
|
|
|
|
|
|
def user_input(self):
|
2022-04-26 19:02:15 +02:00
|
|
|
print("number\tfunction\tfile\tcode")
|
2016-10-28 13:20:27 +02:00
|
|
|
counter = 0
|
|
|
|
stack = traceback.extract_stack()
|
|
|
|
for e in stack:
|
2022-04-26 19:02:15 +02:00
|
|
|
print("%02d.\t%s\t%s:%d\t[%s]" % (counter, e[2], e[0], e[1], e[3]))
|
2016-10-28 13:20:27 +02:00
|
|
|
counter += 1
|
|
|
|
print(single_line_delim)
|
2018-07-16 14:22:01 +02:00
|
|
|
print("You may enter a number of stack frame chosen from above")
|
2016-10-28 13:20:27 +02:00
|
|
|
print("Calls in/below that stack frame will be not be stepped anymore")
|
2022-01-28 11:31:01 +00:00
|
|
|
print("Alternatively, enter a test function name to stop at")
|
2016-10-28 13:20:27 +02:00
|
|
|
print(single_line_delim)
|
|
|
|
while True:
|
2022-04-26 19:02:15 +02:00
|
|
|
print(
|
|
|
|
"Enter your choice, if any, and press ENTER to continue "
|
|
|
|
"running the testcase..."
|
|
|
|
)
|
|
|
|
choice = sys.stdin.readline().rstrip("\r\n")
|
2016-10-28 13:20:27 +02:00
|
|
|
if choice == "":
|
|
|
|
choice = None
|
|
|
|
try:
|
|
|
|
if choice is not None:
|
|
|
|
num = int(choice)
|
2018-07-16 14:22:01 +02:00
|
|
|
except ValueError:
|
2022-01-28 11:31:01 +00:00
|
|
|
if choice.startswith("test_"):
|
|
|
|
break
|
2016-10-28 13:20:27 +02:00
|
|
|
print("Invalid input")
|
|
|
|
continue
|
|
|
|
if choice is not None and (num < 0 or num >= len(stack)):
|
|
|
|
print("Invalid choice")
|
|
|
|
continue
|
|
|
|
break
|
|
|
|
if choice is not None:
|
2022-01-28 11:31:01 +00:00
|
|
|
if choice.startswith("test_"):
|
|
|
|
self.break_func = choice
|
|
|
|
else:
|
|
|
|
self.break_func = None
|
|
|
|
self.skip_stack = stack
|
|
|
|
self.skip_num = num
|
2016-10-28 13:20:27 +02:00
|
|
|
|
|
|
|
def before_cli(self, cli):
|
2022-04-26 19:02:15 +02:00
|
|
|
"""Wait for ENTER before executing CLI"""
|
2016-10-28 13:20:27 +02:00
|
|
|
if self.skip():
|
|
|
|
print("Skip pause before executing CLI: %s" % cli)
|
|
|
|
else:
|
|
|
|
print(double_line_delim)
|
|
|
|
print("Test paused before executing CLI: %s" % cli)
|
|
|
|
print(single_line_delim)
|
|
|
|
self.user_input()
|
|
|
|
super(StepHook, self).before_cli(cli)
|
|
|
|
|
|
|
|
def before_api(self, api_name, api_args):
|
2022-04-26 19:02:15 +02:00
|
|
|
"""Wait for ENTER before executing API"""
|
2016-10-28 13:20:27 +02:00
|
|
|
if self.skip():
|
2022-04-26 19:02:15 +02:00
|
|
|
print("Skip pause before executing API: %s (%s)" % (api_name, api_args))
|
2016-10-28 13:20:27 +02:00
|
|
|
else:
|
|
|
|
print(double_line_delim)
|
2022-04-26 19:02:15 +02:00
|
|
|
print("Test paused before executing API: %s (%s)" % (api_name, api_args))
|
2016-10-28 13:20:27 +02:00
|
|
|
print(single_line_delim)
|
|
|
|
self.user_input()
|
|
|
|
super(StepHook, self).before_api(api_name, api_args)
|