Fix loganalyzer no common config issue and re-balance PR testing

ansible/roles/test/files/tools/loganalyzer/loganalyzer_common_ignore.txt

@@ -19,3 +19,14 @@ r, ".* WARNING syncd#SDK:.* check_attribs_metadata: Not supported attribute SAI_
 r, ".* WARNING syncd#SDK:.* sai_get_attributes: Failed attribs check.*"
 r, ".* ERR swss#buffermgrd:.* doSpeedUpdateTask: Unable to create/update PG profile for port Ethernet(128|132|256|260).*"
 r, ".* ERR macsec#wpa_supplicant.*l2_packet_send.*Network is down.*"
+r, ".* ERR systemd.*Failed to start dhcp_relay container.*"
+r, ".* ERR monit.* 'rsyslog' failed to get service data.*"
+r, ".* ERR monit.* 'rsyslog' process is not running.*"
+r, ".* ERR ntpd.*syntax error.*"
+r, ".* ERR teamd#tlm_teamd.*Can't get dump for LAG.*"
+r, ".* ERR bgp#root: Error: zebra is not ready to accept connections.*"
+r, ".* ERR bgp#/supervisor-proc-exit-listener: Process .* is not running in namespace.*"
+r, ".* ERR syncd#syncd.*collectMACsecSACounters: Failed to get stats of MACsec SA.*"
+r, ".* ERR syncd#syncd.*meta_sai_validate_oid.*"
+r, ".* ERR syncd#syncd.*meta_validate_stats: object.*don't exists.*"
+r, ".* ERR syncd#syncd.*translateVidToRid: unable to get RID for VID.*"

tests/common/helpers/parallel.py

@@ -105,7 +105,6 @@ def force_terminate(workers):
                         Unable to kill {}:{}, error:{}""".format(target.__name__, p.pid, p.name, err)
                     )
 
-
     workers = []
     results = Manager().dict()
     start_time = datetime.datetime.now()
@@ -186,19 +185,17 @@ def force_terminate(workers):
     # of each Process and fail
     if len(failed_processes.keys()):
         for process_name, process in failed_processes.items():
+            p_exitcode = ""
+            p_exception = ""
+            p_traceback = ""
             if 'exception' in process and process['exception']:
                 p_exception = process['exception'][0]
                 p_traceback = process['exception'][1]
                 p_exitcode = process['exit_code']
-                logger.error("""Process {} had exit code {} and exception {}
-                    and traceback {}""".format(
-                        process_name, p_exitcode, p_exception, p_traceback
-                    )
-                )
             pt_assert(
                 False,
-                'Processes "{}" had failures. Please check the logs'.format(
-                    list(failed_processes.keys())
+                'Processes "{}" failed with exit code "{}"\nException:\n{}\nTraceback:\n{}'.format(
+                    list(failed_processes.keys()), p_exitcode, p_exception, p_traceback
                 )
             )
 

tests/common/plugins/loganalyzer/__init__.py

@@ -30,9 +30,6 @@ def analyzer_add_marker(analyzers, node=None, results=None):
     loganalyzer = analyzers[node.hostname]
     logging.info("Add start marker into DUT syslog for host {}".format(node.hostname))
     marker = loganalyzer.init()
-    logging.info("Load config and analyze log for host {}".format(node.hostname))
-    # Read existed common regular expressions located with legacy loganalyzer module
-    loganalyzer.load_common_config()
     results[node.hostname] = marker
 
 
@@ -53,7 +50,9 @@ def loganalyzer(duthosts, request):
     analyzers = {}
     parallel_run(analyzer_logrotate, [], {}, duthosts, timeout=120)
     for duthost in duthosts:
-        analyzers[duthost.hostname] = LogAnalyzer(ansible_host=duthost, marker_prefix=request.node.name)
+        analyzer = LogAnalyzer(ansible_host=duthost, marker_prefix=request.node.name)
+        analyzer.load_common_config()
+        analyzers[duthost.hostname] = analyzer
     markers = parallel_run(analyzer_add_marker, [analyzers], {}, duthosts, timeout=120)
 
     yield analyzers
@@ -64,4 +63,3 @@ def loganalyzer(duthosts, request):
         return
     logging.info("Starting to analyse on all DUTs")
     parallel_run(analyze_logs, [analyzers, markers], {}, duthosts, timeout=120)
-

tests/common/plugins/loganalyzer/loganalyzer.py

@@ -1,4 +1,3 @@
-import sys
 import logging
 import os
 import re
@@ -9,7 +8,6 @@
 
 from .system_msg_handler import AnsibleLogAnalyzer as ansible_loganalyzer
 from os.path import join, split
-from os.path import normpath
 
 ANSIBLE_LOGANALYZER_MODULE = system_msg_handler.__file__.replace(r".pyc", ".py")
 COMMON_MATCH = join(split(__file__)[0], "loganalyzer_common_match.txt")
@@ -152,6 +150,7 @@ def load_common_config(self):
         self.match_regex = self.ansible_loganalyzer.create_msg_regex([COMMON_MATCH])[1]
         self.ignore_regex = self.ansible_loganalyzer.create_msg_regex([COMMON_IGNORE])[1]
         self.expect_regex = self.ansible_loganalyzer.create_msg_regex([COMMON_EXPECT])[1]
+        logging.debug('Loaded common config.')
 
     def parse_regexp_file(self, src):
         """
@@ -270,15 +269,16 @@ def analyze(self, marker, fail=True):
         expect_messages_regex = re.compile('|'.join(self.expect_regex)) if len(self.expect_regex) else None
 
         logging.debug("Analyze files {}".format(file_list))
+        logging.debug('    match_regex="{}"'.format(match_messages_regex.pattern if match_messages_regex else ''))
+        logging.debug('    ignore_regex="{}"'.format(ignore_messages_regex.pattern if ignore_messages_regex else ''))
+        logging.debug('    expect_regex="{}"'.format(expect_messages_regex.pattern if expect_messages_regex else ''))
         analyzer_parse_result = self.ansible_loganalyzer.analyze_file_list(file_list, match_messages_regex, ignore_messages_regex, expect_messages_regex)
         # Print file content and remove the file
         for folder in file_list:
             with open(folder) as fo:
                 logging.debug("{} file content:\n\n{}".format(folder, fo.read()))
             os.remove(folder)
 
-        total_match_cnt = 0
-        total_expect_cnt = 0
         expected_lines_total = []
         unused_regex_messages = []
 
@@ -300,6 +300,7 @@ def analyze(self, marker, fail=True):
                 unused_regex_messages.append(regex)
         analyzer_summary["total"]["expected_missing_match"] = len(unused_regex_messages)
         analyzer_summary["unused_expected_regexp"] = unused_regex_messages
+        logging.debug("Analyzer summary: {}".format(pprint.pformat(analyzer_summary)))
 
         if fail:
             self._verify_log(analyzer_summary)

tests/kvmtest.sh

@@ -88,7 +88,8 @@ RUNTEST_CLI_COMMON_OPTS="\
 -q 1 \
 -a False \
 -O \
--r"
+-r \
+-e --allow_recover"
 
 if [ -n "$exit_on_error" ]; then
     RUNTEST_CLI_COMMON_OPTS="$RUNTEST_CLI_COMMON_OPTS -E"
@@ -100,58 +101,55 @@ test_t0() {
     tgname=1vlan
     if [ x$section == x"part-1" ]; then
       tests="\
-      monit/test_monit_status.py \
-      platform_tests/test_advanced_reboot.py::test_warm_reboot \
-      test_interfaces.py \
       arp/test_arp_dualtor.py \
+      arp/test_neighbor_mac.py \
+      arp/test_neighbor_mac_noptf.py\
       bgp/test_bgp_fact.py \
       bgp/test_bgp_gr_helper.py::test_bgp_gr_helper_routes_perserved \
       bgp/test_bgp_speaker.py \
+      bgp/test_bgpmon.py \
       bgp/test_bgp_update_timer.py \
-      cacl/test_ebtables_application.py \
+      container_checker/test_container_checker.py \
       cacl/test_cacl_application.py \
       cacl/test_cacl_function.py \
+      cacl/test_ebtables_application.py \
       dhcp_relay/test_dhcp_relay.py \
       dhcp_relay/test_dhcpv6_relay.py \
+      iface_namingmode/test_iface_namingmode.py \
       lldp/test_lldp.py \
+      monit/test_monit_status.py \
       ntp/test_ntp.py \
       pc/test_po_cleanup.py \
       pc/test_po_update.py \
+      platform_tests/test_advanced_reboot.py::test_warm_reboot \
+      platform_tests/test_cpu_memory_usage.py \
       route/test_default_route.py \
       route/test_static_route.py \
-      arp/test_neighbor_mac.py \
-      arp/test_neighbor_mac_noptf.py\
       snmp/test_snmp_cpu.py \
+      snmp/test_snmp_default_route.py \
       snmp/test_snmp_interfaces.py \
       snmp/test_snmp_lldp.py \
+      snmp/test_snmp_loopback.py \
       snmp/test_snmp_pfc_counters.py \
       snmp/test_snmp_queue.py \
-      snmp/test_snmp_loopback.py \
-      snmp/test_snmp_default_route.py \
-      tacacs/test_rw_user.py \
-      tacacs/test_ro_user.py \
-      tacacs/test_ro_disk.py \
-      tacacs/test_jit_user.py \
+      ssh/test_ssh_ciphers.py \
+      syslog/test_syslog.py\
+      tacacs/test_accounting.py \
       tacacs/test_authorization.py \
-      tacacs/test_accounting.py"
+      tacacs/test_jit_user.py \
+      tacacs/test_ro_disk.py \
+      tacacs/test_ro_user.py \
+      tacacs/test_rw_user.py \
+      telemetry/test_telemetry.py \
+      test_features.py \
+      test_interfaces.py \
+      test_procdockerstatsd.py"
 
       pushd $SONIC_MGMT_DIR/tests
       ./run_tests.sh $RUNTEST_CLI_COMMON_OPTS -c "$tests" -p logs/$tgname
       popd
     else
       tests="\
-      ssh/test_ssh_stress.py \
-      ssh/test_ssh_ciphers.py \
-      syslog/test_syslog.py\
-      telemetry/test_telemetry.py \
-      test_features.py \
-      test_procdockerstatsd.py \
-      iface_namingmode/test_iface_namingmode.py \
-      platform_tests/test_cpu_memory_usage.py \
-      bgp/test_bgpmon.py \
-      container_checker/test_container_checker.py \
-      process_monitoring/test_critical_process_monitoring.py \
-      system_health/test_system_status.py \
       generic_config_updater/test_aaa.py \
       generic_config_updater/test_bgpl.py \
       generic_config_updater/test_bgp_prefix.py \
@@ -161,7 +159,9 @@ test_t0() {
       generic_config_updater/test_portchannel_interface.py \
       generic_config_updater/test_syslog.py \
       generic_config_updater/test_vlan_interface.py \
-      show_techsupport/test_techsupport_no_secret.py"
+      process_monitoring/test_critical_process_monitoring.py \
+      show_techsupport/test_techsupport_no_secret.py \
+      system_health/test_system_status.py"
 
       pushd $SONIC_MGMT_DIR/tests
       ./run_tests.sh $RUNTEST_CLI_COMMON_OPTS -c "$tests" -p logs/$tgname
@@ -217,25 +217,25 @@ test_t2() {
 test_t1_lag() {
     tgname=t1_lag
     tests="\
-    monit/test_monit_status.py \
-    test_interfaces.py \
-    bgp/test_bgp_fact.py \
     bgp/test_bgp_allow_list.py \
-    bgp/test_bgp_multipath_relax.py \
     bgp/test_bgp_bbr.py \
     bgp/test_bgp_bounce.py \
+    bgp/test_bgp_fact.py \
+    bgp/test_bgp_multipath_relax.py \
     bgp/test_bgp_update_timer.py \
+    bgp/test_bgpmon.py \
     bgp/test_traffic_shift.py \
+    container_checker/test_container_checker.py \
     http/test_http_copy.py \
     ipfwd/test_mtu.py \
     lldp/test_lldp.py \
-    route/test_default_route.py \
+    monit/test_monit_status.py \
+    pc/test_lag_2.py \
     platform_tests/test_cpu_memory_usage.py \
-    bgp/test_bgpmon.py \
-    container_checker/test_container_checker.py \
     process_monitoring/test_critical_process_monitoring.py \
+    route/test_default_route.py \
     scp/test_scp_copy.py \
-    pc/test_lag_2.py"
+    test_interfaces.py"
 
     pushd $SONIC_MGMT_DIR/tests
     ./run_tests.sh $RUNTEST_CLI_COMMON_OPTS -c "$tests" -p logs/$tgname
@@ -246,16 +246,16 @@ test_multi_asic_t1_lag() {
     tgname=multi_asic_t1_lag
     tests="\
     bgp/test_bgp_fact.py \
+    snmp/test_snmp_default_route.py \
+    snmp/test_snmp_loopback.py \
     snmp/test_snmp_pfc_counters.py \
     snmp/test_snmp_queue.py \
-    snmp/test_snmp_loopback.py \
-    snmp/test_snmp_default_route.py \
-    tacacs/test_rw_user.py \
-    tacacs/test_ro_user.py \
-    tacacs/test_ro_disk.py \
-    tacacs/test_jit_user.py \
+    tacacs/test_accounting.py \
     tacacs/test_authorization.py \
-    tacacs/test_accounting.py"
+    tacacs/test_jit_user.py \
+    tacacs/test_ro_disk.py \
+    tacacs/test_ro_user.py \
+    tacacs/test_rw_user.py"
 
     pushd $SONIC_MGMT_DIR/tests
     # TODO: Remove disable of loganaler and sanity check once multi-asic testbed is stable.