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 = <function search at 0x7f405b7bb0a0>('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 <function search at 0x7f405b7bb0a0> = 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 = <function search at 0x7f405b7bb0a0>('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 <function search at 0x7f405b7bb0a0> = 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 = <function search at 0x7f405b7bb0a0>('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 <function search at 0x7f405b7bb0a0> = 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 <sharpd@nvidia.com>

diff --git a/tests/topotests/static_simple/test_static_simple.py b/tests/topotests/static_simple/test_static_simple.py
index 817336ac21a6d0859482db228dd61a777274999b..fd87224b5743efdf88abe353468c92bc8b7e40e6 100644 (file)
--- 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 ""