def test_ft_ntp_disable_enable_with_message_log():
"""
Author: Anil Kumar Kacharla <*****@*****.**>
Referrence Topology : Test bed ID:4 D1--Mgmt network
Verify that Ntp synchronization is successful after doing NTP server on and off and the message log display the correct time based upon the system up time.
"""
st.log("Ensuring minimum topology")
vars = st.ensure_min_topology("D1")
data.string_generate = 'Iam Testing NTP'
data.lines = 1
data.time_date = time.strftime('%a %B %d %H:%M:%S %Z %Y')
ntp_obj.config_date(vars.D1, data.time_date)
st.log("checking time in message log without ntp ")
log_message_1 = syslog_obj.show_logging(vars.D1,
severity=None,
filter_list=[],
lines=data.lines)
if not log_message_1:
st.log("log message_1 not created")
st.report_fail("operation_failed")
clock = common_obj.log_parser(log_message_1[0])
config_ntp_server_on_config_db_file(vars.D1, data.servers)
st.log("Generating log messages")
syslog_obj.clear_logging(vars.D1)
syslog_obj.write_logging(vars.D1, data.string_generate)
log_message = syslog_obj.show_logging(vars.D1,
severity=None,
filter_list=[data.string_generate])
if not log_message:
st.log("log message not created")
st.report_fail("operation_failed")
st.log("printing system clock")
ntp_obj.show_clock(vars.D1)
out = common_obj.log_parser(log_message[0])
if not (clock[0]['month'] == out[0]['month'] and clock[0]['hours']
== out[0]['hours'] and clock[0]['date'] == out[0]['date']
and clock[0]['minutes'] <= out[0]['minutes']
or clock[0]['seconds'] >= out[0]['seconds']):
st.log("time not updated")
st.report_fail("operation_failed")
st.log("message log displaying correct timed based on system up time")
st.log("disabling ntp")
basic_obj.service_operations(vars.D1, data.ntp_service, action="stop")
if not ntp_obj.verify_ntp_service_status(vars.D1, 'inactive (dead)'):
st.log("ntp disabled failed")
st.report_fail("operation_failed")
st.log("Enabling NTP")
basic_obj.service_operations(vars.D1, data.ntp_service, action="restart")
if not ntp_obj.verify_ntp_service_status(
vars.D1, 'active (running)', iteration=65, delay=2):
st.log("ntp is exited after enable and disable ntp")
st.report_fail("operation_failed")
if not ntp_obj.verify_ntp_status(
vars.D1, iteration=65, delay=2, server=data.servers):
st.log("ntp syncronization failed after enable and disable ntp")
st.report_fail("operation_failed")
st.report_pass("test_case_passed")
def get_crm_logging_details(dut, severity=None, filter_list=None, lines=None):
"""
To get the CRM log parameters
Author : Prudvi Mangadu ([email protected])
:param dut:
:param severity:
:param filter_list:
:param lines:
:return:
"""
temp = {}
crm_log = r"checkCrmThresholds:\s+(\S+)\s+(\S+)\s+for\s+(\S+)\s+(\d+)\%\s+Used\s+count\s+(\d+)\s+" \
r"free\s+count\s+(\d+)"
all_logs = lapi.show_logging(dut, severity, filter_list, lines)
if not all_logs:
st.error("No logs found.")
return temp
log_data = uapi.log_parser(all_logs[-1])
if not log_data:
st.error("Unable to parse the log message - {}".format(log_data))
return temp
log_data = log_data[0]['message']
out = re.findall(crm_log, log_data)
if not out:
st.error("Not match with CRM log pattern - {}".format(log_data))
return temp
temp['family'] = out[0][0]
temp['action'] = out[0][1]
temp['type'] = out[0][2]
temp['percentage'] = ast.literal_eval(out[0][3])
temp['used'] = ast.literal_eval(out[0][4])
temp['free'] = ast.literal_eval(out[0][5])
return temp
def check_test_status(family):
global crm_test_result
if family != "all":
if family not in crm_test_result:
st.log("Test [{}] NOT Executed".format(family))
return family
elif crm_test_result[family] == 6:
st.log("Test [{}] PASSED".format(family))
st.log("Successfully generated threshold logs for [{}]".format(
family))
return None
else:
slog_obj.show_logging(vars.D1, lines=100)
st.log("Test [{}] FAILED [{}]".format(family,
crm_test_result[family]))
st.log("Failed to generate threshold logs for [{}]".format(family))
return family
else:
return None
def threshold_feature_debug(dut, mode, platform=None, test=''):
"""
Debug calls for Threshold feature.
Author: Prudvi Mangadu ([email protected])
:param dut:
:param mode:
:param platform:
:param test:
:return:
"""
mode_li = list(mode) if isinstance(mode, list) else [mode]
for each_mode in mode_li:
if each_mode == 'clear_counters':
intapi.clear_interface_counters(dut)
# intapi.clear_watermark_counters(dut,'all')
if each_mode == 'show_counters':
intapi.show_interface_counters_all(dut)
# intapi.show_watermark_counters(dut,'all')
asicapi.clear_counters(dut)
st.wait(1)
asicapi.dump_counters(dut)
if each_mode == 'asic_info':
asicapi.dump_threshold_info(dut, test, platform, 'asic_info')
if each_mode == 'debug_log_enable':
st.config(dut, 'swssloglevel -l DEBUG -c thresholdmgr', skip_error_check=True)
st.config(dut, 'swssloglevel -l SAI_LOG_LEVEL_DEBUG -s -c TAM', skip_error_check=True)
if each_mode == 'debug_log_disable':
st.config(dut, 'swssloglevel -l INFO -c thresholdmgr', skip_error_check=True)
st.config(dut, 'swssloglevel -l SAI_LOG_LEVEL_INFO -s -c TAM', skip_error_check=True)
if each_mode == 'show_logging':
logapi.show_logging(dut, lines=100)
if each_mode == 'port_map':
asicapi.dump_threshold_info(dut, test, platform, 'asic_portmap')
def crm_verify_syslog(dut, resource_name, threshold_msg, threshold_type,
threshold, resource_count_max):
res = resource_str[resource_name]
syslog_used_counter_offset = 7
syslog_free_counter_offset = 10
msglist = slog_obj.show_logging(dut,
severity='WARNING',
filter_list=threshold_msg)
if len(msglist) <= 0:
st.error('No {} {} {} detected in syslog'.format(
resource_name, threshold_type, threshold_msg))
return False
found = 0
for msg in msglist:
if 'repeated' in msg:
msg = msg.replace(']', ' ')
words = msg.split()
if res in words and words.index(res):
found = 1
used = int(words[words.index(res) + syslog_used_counter_offset])
free = int(words[words.index(res) + syslog_free_counter_offset])
st.log('crminfo: Msg: {} Used:{} Free:{} Type:{} val:{}'.format(
threshold_msg, used, free, threshold_type, threshold))
if threshold_type == 'used':
value = used
elif threshold_type == 'free':
value = free
else:
value = int(used * 100 / resource_count_max)
if threshold_msg == 'THRESHOLD_EXCEEDED' and value < threshold:
st.error(
'For {} val:{} should be less than Threshold:{}'.format(
threshold_msg, value, threshold))
return False
if threshold_msg == 'THRESHOLD_CLEAR' and value > threshold:
st.error(
'For {} val:{} should be more than Threshold:{}'.format(
threshold_msg, value, threshold))
return False
if found == 0:
st.error('{} for {} not detected in syslog'.format(
threshold_msg, resource_name))
return False
return True
def test_system_up_performance():
timer_dict = {}
test_port = vars.D1D2P1
max_port_up_time = 20
if not intapi.verify_interface_status(vars.D1, test_port, 'oper', 'up'):
st.error('{} interface is down on dut'.format(test_port))
st.report_fail('test_case_failed')
st.banner("START - REBOOT TEST ")
tstart = datetime.now()
st.reboot(vars.D1)
bcapi.get_system_status(vars.D1)
tdiff = datetime.now() - tstart
timer_dict['REBOOT_TEST'] = "{} {}".format(tdiff, 'H:M:S:msec')
st.banner("END - REBOOT TEST -- {}".format(timer_dict['REBOOT_TEST']))
st.banner("START - CONFIG REBOOT TEST ")
tstart = datetime.now()
config_reload(vars.D1)
bcapi.get_system_status(vars.D1)
tdiff = datetime.now() - tstart
timer_dict['CONFIG_REBOOT_TEST'] = "{} {}".format(tdiff, 'H:M:S:msec')
st.banner("END - CONFIG REBOOT TEST -- {}".format(
timer_dict['CONFIG_REBOOT_TEST']))
st.banner("START - PORT UP TEST ")
logapi.clear_logging(vars.D1)
intapi.interface_shutdown(vars.D1, test_port)
intapi.verify_interface_status(vars.D1, test_port, 'oper', 'down')
st.wait(5)
intapi.interface_noshutdown(vars.D1, test_port)
if not intapi.poll_for_interface_status(
vars.D1, test_port, 'oper', 'up', iteration=max_port_up_time,
delay=1):
st.error('{} interface is down on dut for MAX time = {}'.format(
test_port, max_port_up_time))
log_down = logapi.show_logging(
vars.D1,
filter_list=['sudo config interface startup {}'.format(test_port)])
log_up = logapi.show_logging(
vars.D1,
filter_list=[
'Set operation status UP to host interface {}'.format(test_port)
])
logapi.show_logging(vars.D1)
log_down_time = utils.log_parser(log_down[0])[0]
log_up_time = utils.log_parser(log_up[0])[0]
f_down_time = utils.convert_time_to_milli_seconds(
days=0,
hours=log_down_time['hours'],
minutes=log_down_time['minutes'],
seconds=log_down_time['seconds'],
milli_second=log_down_time['micro_second'])
f_up_time = utils.convert_time_to_milli_seconds(
days=0,
hours=log_up_time['hours'],
minutes=log_up_time['minutes'],
seconds=log_up_time['seconds'],
milli_second=log_up_time['micro_second'])
st.log("f_down_time : {} , f_up_time : {}".format(f_down_time, f_up_time))
timer_dict['PORT_UP_TEST'] = "{} {}".format(
(f_up_time - f_down_time) / 1000, 'mili sec')
st.banner("END - PORT UP TEST -- {}".format(timer_dict['PORT_UP_TEST']))
st.log("\n" + pprint.pformat(timer_dict, width=2) + '\n')
st.log('\n' +
cutils.sprint_vtable(['Test Name', 'Time'], timer_dict.items()) +
'\n')
csv_str = '\nTest, Result\n'
for i, j in timer_dict.items():
csv_str += "{}, {}\n".format(i, j)
st.log(csv_str)
st.report_pass('test_case_passed')
def check_logging_result(data=[]):
st.log('Checking logging result')
msglist = slog_obj.show_logging(data.D1,
severity='WARNING',
filter_list=["THRESHOLD"])
global crm_test_result
family_list = crm_obj.crm_get_family_list(data.D1)
for family in family_list:
crm_test_result[family] = 0
if family != 'all':
if crmlogPresent(family,
"THRESHOLD_EXCEEDED",
"TH_USED",
msglist=msglist,
data=data):
crm_test_result[family] += 1
st.log("Successsfully generated max thresholds for [{}] used".
format(family))
else:
st.error(
"Failed to create max thresholds for [{}] used".format(
family))
if crmlogPresent(family,
"THRESHOLD_CLEAR",
"TH_USED",
msglist=msglist,
data=data):
crm_test_result[family] += 1
st.log(
"Successsfully generated minimum thresholds for [{}] used".
format(family))
else:
st.error(
"Failed to create minimum thresholds for [{}] used".format(
family))
if crmlogPresent(family,
"THRESHOLD_EXCEEDED",
"TH_PERCENTAGE",
msglist=msglist,
data=data):
crm_test_result[family] += 1
st.log(
"Successsfully generated max thresholds for [{}] percentage"
.format(family))
else:
st.error("Failed to create max thresholds for [{}] percentage".
format(family))
if crmlogPresent(family,
"THRESHOLD_CLEAR",
"TH_PERCENTAGE",
msglist=msglist,
data=data):
crm_test_result[family] += 1
st.log(
"Successsfully generated minimum thresholds for [{}] percentage"
.format(family))
else:
st.error(
"Failed to create minimum thresholds for [{}] percentage".
format(family))
if crmlogPresent(family,
"THRESHOLD_EXCEEDED",
"TH_FREE",
msglist=msglist,
data=data):
crm_test_result[family] += 1
st.log("Successsfully generated max thresholds for [{}] free".
format(family))
else:
st.error(
"Failed to create max thresholds for [{}] free".format(
family))
if crmlogPresent(family,
"THRESHOLD_CLEAR",
"TH_FREE",
msglist=msglist,
data=data):
crm_test_result[family] += 1
st.log(
"Successsfully generated minimum thresholds for [{}] free".
format(family))
else:
st.error(
"Failed to create minimum thresholds for [{}] free".format(
family))
for family in family_list:
if check_test_status(family):
st.wait(5)
return False
return True
def verify_thresholds(data=[]):
max_threshold = 999999
var_delay = 2
opt_delay = 2
clear_wait = 8
final_wait = 20
mymode = ""
family_list = crm_obj.crm_get_family_list(data.D1)
for family in family_list:
if family != 'all':
(data.used_counter[family],
data.free_counter[family]) = crm_obj.crm_get_resources_count(
data.D1, family)
data.resource_count_max[
family] = data.used_counter[family] + data.free_counter[family]
st.log("verify_thresholds: {} used {} free {} max {}".format(
family, data.used_counter[family], data.free_counter[family],
data.resource_count_max[family]))
##################### USED #############################
for family in family_list:
if family != 'all':
crm_obj.set_crm_thresholds_type(data.D1,
family=family,
type="used")
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode="high",
value=max_threshold)
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode="low",
value=max_threshold)
#show logs
st.log("show log messages:")
slog_obj.show_logging(data.D1, lines=50)
# Clear Logs
slog_obj.clear_logging(data.D1)
st.log("configure Thresholds for used")
for family in family_list:
if family != 'all':
hi_th = data.used_counter[family] - 1
if hi_th < 0:
hi_th = 0
mymode = "high"
if family in acl_family_list:
mymode = "low"
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode=mymode,
value=hi_th)
mymode = "low"
if family in acl_family_list:
mymode = "high"
low_th = hi_th - 1
if low_th < 0:
low_th = 0
#crm_obj.set_crm_thresholds_type(data.D1, family=family, type="used")
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode=mymode,
value=low_th)
crm_obj.set_crm_thresholds_type(data.D1,
family=family,
type="used")
st.wait(opt_delay) ## EXCEED
st.wait(var_delay) ## EXCEED
crm_obj.get_crm_resources(data.D1, "all")
interface_obj.interface_shutdown(data.D1,
data.dut_p1_interface,
skip_verify=False)
interface_obj.interface_shutdown(data.D1,
data.dut_p2_interface,
skip_verify=False)
macapi.clear_mac(data.D1)
crm_fdb_config_clear(data)
st.wait(opt_delay) ## CLEAR
# Restore
interface_obj.interface_noshutdown(data.D1,
data.dut_p1_interface,
skip_verify=False)
interface_obj.interface_noshutdown(data.D1,
data.dut_p2_interface,
skip_verify=False)
st.wait(opt_delay) # delay is required to populate tables
##################### PERCENTAGE #############################
for family in family_list:
if family != 'all':
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode="high",
value=max_threshold)
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode="low",
value=max_threshold)
crm_fdb_send_traffic(data)
st.log("Configure Thresholds for percentage")
for family in family_list:
if family != 'all' and family != 'snat' and family != 'dnat' and family != 'ipmc':
hi_th = 0
mymode = "high"
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode=mymode,
value=hi_th)
mymode = "low"
low_th = 100
#crm_obj.set_crm_thresholds_type(data.D1, family=family, type="percentage")
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode=mymode,
value=low_th)
crm_obj.set_crm_thresholds_type(data.D1,
family=family,
type="percentage")
st.wait(opt_delay) ## EXCEED
st.wait(var_delay) ## EXCEED
crm_obj.get_crm_resources(data.D1, "all")
crm_acl_unconfig(data)
crm_acl_config(data)
interface_obj.interface_shutdown(data.D1,
data.dut_p1_interface,
skip_verify=False)
interface_obj.interface_shutdown(data.D1,
data.dut_p2_interface,
skip_verify=False)
macapi.clear_mac(data.D1)
crm_fdb_config_clear(data)
st.wait(opt_delay) ## CLEAR
st.wait(var_delay) ## EXCEED
##################### FREE #############################
crm_obj.get_crm_resources(data.D1, "all")
for family in family_list:
if family != 'all':
crm_obj.set_crm_thresholds_type(data.D1,
family=family,
type="used")
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode="high",
value=max_threshold)
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode="low",
value=max_threshold)
st.wait(clear_wait)
st.log("configure Thresholds for free")
for family in family_list:
if family != 'all':
mymode = "high"
hi_th = 0
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode=mymode,
value=hi_th)
mymode = "low"
low_th = max_threshold
#crm_obj.set_crm_thresholds_type(data.D1, family=family, type="free")
crm_obj.set_crm_thresholds_value(data.D1,
family=family,
mode=mymode,
value=low_th)
crm_obj.set_crm_thresholds_type(data.D1,
family=family,
type="free")
st.wait(opt_delay) ## EXCEED
crm_obj.get_crm_resources(data.D1, "all")
interface_obj.interface_noshutdown(data.D1,
data.dut_p1_interface,
skip_verify=False)
interface_obj.interface_noshutdown(data.D1,
data.dut_p2_interface,
skip_verify=False)
crm_fdb_send_traffic(data)
# CLEAR TH
st.wait(final_wait) ## CLEAR
if not poll_wait(check_logging_result, 60, data):
crm_obj.get_crm_resources(data.D1, "all")
st.error('Failed to get threshold logs, CRM threshold tests failed')