From: Donald Sharp Date: Sun, 20 Aug 2023 22:43:48 +0000 (-0400) Subject: tests: static_simple gives up after 3 seconds X-Git-Tag: base_9.1~141^2 X-Git-Url: https://git.puffer.fish/?a=commitdiff_plain;h=9f4c654c59a8c7bec8339d0f1ed1a23e27124676;p=mirror%2Ffrr.git tests: static_simple gives up after 3 seconds Under heavy system load we can see that the static_simple test is giving up too early in this micronet run: 8-17 15:00:27,105 DEBUG: topo: Waiting for [0.1]s as initial delay 2023-08-17 15:00:27,206 DEBUG: r1: cmd_status("/bin/bash -c 'ip -4 route show'") 2023-08-17 15:00:28,209 DEBUG: r1: stdout: 101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 2023-08-17 15:00:28,209 DEBUG: topo: checking kernel routing table: 101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 2023-08-17 15:00:28,210 INFO: topo: Function raised exception: Failed to find '10.0.0.0/8(?: nhid [0-9]+)? via 101.0.0.2 dev r1-eth0 proto (static|196) metric 20' in '101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 ' assert None + where None = ('10.0.0.0/8(?: nhid [0-9]+)? via 101.0.0.2 dev r1-eth0 proto (static|196) metric 20', '101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 \n') + where = re.search 2023-08-17 15:00:28,210 DEBUG: topo: Sleeping 2s until next retry with 3.0 retry time left 2023-08-17 15:00:30,211 DEBUG: r1: cmd_status("/bin/bash -c 'ip -4 route show'") 2023-08-17 15:00:31,703 DEBUG: r1: stdout: 101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 2023-08-17 15:00:31,703 DEBUG: topo: checking kernel routing table: 101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 2023-08-17 15:00:31,704 INFO: topo: Function raised exception: Failed to find '10.0.0.0/8(?: nhid [0-9]+)? via 101.0.0.2 dev r1-eth0 proto (static|196) metric 20' in '101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 ' assert None + where None = ('10.0.0.0/8(?: nhid [0-9]+)? via 101.0.0.2 dev r1-eth0 proto (static|196) metric 20', '101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 \n') + where = re.search 2023-08-17 15:00:31,704 INFO: topo: Retry timeout of 3s reached 2023-08-17 15:00:31,704 INFO: topo: Spawn collection of support bundle for r1 2023-08-17 15:00:31,704 DEBUG: r1: cmd_status("/bin/bash -c 'mkdir -p /tmp/topotests/static_simple.test_static_simple/r1/support_bundles/test_static_cli'") 2023-08-17 15:00:31,710 DEBUG: r1: popen("/usr/lib/frr/generate_support_bundle.py --log-dir=/tmp/topotests/static_simple.test_static_simple/r1/support_bundles/test_static_cli") 2023-08-17 15:00:31,711 DEBUG: topo: Waiting on support bundle for r1 2023-08-17 15:00:31,751 DEBUG: topo: RETRY DIAG: [failure] Sleeping 2s until next retry with 2.2 retry time left - too see if timeout was too short 2023-08-17 15:00:33,751 DEBUG: r1: cmd_status("/bin/bash -c 'ip -4 route show'") 2023-08-17 15:00:35,137 DEBUG: r1: stdout: 10.0.0.0/8 nhid 12 via 101.0.0.2 dev r1-eth0 proto 196 metric 20... 2023-08-17 15:00:35,137 DEBUG: topo: checking kernel routing table: 10.0.0.0/8 nhid 12 via 101.0.0.2 dev r1-eth0 proto 196 metric 20 101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 2023-08-17 15:00:35,137 DEBUG: topo: Function returned None 2023-08-17 15:00:35,138 WARN: topo: RETRY DIAGNOSTIC: SUCCEED after FAILED with requested timeout of 3.0s; however, succeeded in 8.0s, investigate timeout timing 2023-08-17 15:00:35,138 INFO: topo: Function raised exception: Failed to find '10.0.0.0/8(?: nhid [0-9]+)? via 101.0.0.2 dev r1-eth0 proto (static|196) metric 20' in '101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 ' assert None + where None = ('10.0.0.0/8(?: nhid [0-9]+)? via 101.0.0.2 dev r1-eth0 proto (static|196) metric 20', '101.0.0.0/24 dev r1-eth0 proto kernel scope link src 101.0.0.1 \n') + where = re.search 2023-08-17 15:00:35,138 DEBUG: topo: RETRY DIAG: [failure] Sleeping 2s until next retry with 0.2 retry time left - too see if timeout was too short 2023-08-17 15:00:37,139 DEBUG: r1: cmd_status("/bin/bash -c 'ip -4 route show'") 2023-08-17 15:00:37,247 DEBUG: r1: stdout: 10.0.0.0/8 nhid 12 via 101.0.0.2 dev r1-eth0 proto 196 metric 20... Of course it works in the extra couple of times it tries but the test still fails. Signed-off-by: Donald Sharp --- diff --git a/tests/topotests/static_simple/test_static_simple.py b/tests/topotests/static_simple/test_static_simple.py index 817336ac21..fd87224b57 100644 --- a/tests/topotests/static_simple/test_static_simple.py +++ b/tests/topotests/static_simple/test_static_simple.py @@ -68,7 +68,7 @@ def disable_debug(router): router.vtysh_cmd("no debug northbound callbacks configuration") -@retry(retry_timeout=3, initial_wait=0.1) +@retry(retry_timeout=30, initial_wait=0.1) def check_kernel(r1, super_prefix, count, add, is_blackhole, vrf, matchvia): network = ipaddress.ip_network(super_prefix) vrfstr = f" vrf {vrf}" if vrf else ""