DHCP test is flaking again #1170
Description
not ok 2 basic setup
# (from function `die' in file test-dhcp/helpers.bash, line 108,
# from function `run_helper' in file test-dhcp/helpers.bash, line 84,
# from function `run_in_container_netns' in file test-dhcp/helpers.bash, line 97,
# from function `run_client' in file test-dhcp/helpers.bash, line 410,
# from function `run_setup' in file test-dhcp/helpers.bash, line 394,
# in test file test-dhcp/002-setup.bats, line 24)
# `run_setup "$input_config"' failed
# ### Setup ###
# ip netns exec i1vQGHx8q6 ip link add br0 type bridge
# ip netns exec i1vQGHx8q6 ip addr add 10.68.151.1 dev br0
# ip netns exec i1vQGHx8q6 ip link set br0 up
# ip netns exec i1vQGHx8q6 ip link add veth0br type veth peer name veth0
# ip netns exec i1vQGHx8q6 ip link set veth0br master br0
# ip netns exec i1vQGHx8q6 ip link set veth0br up
# ip netns exec i1vQGHx8q6 ip link set veth0 up
# ip netns exec i1vQGHx8q6 ip -j link show veth0
# [{"ifindex":3,"link":"veth0br","ifname":"veth0","flags":["BROADCAST","MULTICAST","UP","LOWER_UP"],"mtu":1500,"qdisc":"noqueue","operstate":"UP","linkmode":"DEFAULT","group":"default","txqlen":1000,"link_type":"ether","address":"82:61:32:eb:06:73","broadcast":"ff:ff:ff:ff:ff:ff"}]
# ip netns exec i1vQGHx8q6 ip link add veth1br type veth peer name veth1
# ip netns exec i1vQGHx8q6 ip link set veth1br master br0
# ip netns exec i1vQGHx8q6 ip link set veth1br up
# ip netns exec i1vQGHx8q6 ip link set veth1 up
# ip netns exec i1vQGHx8q6 ip link set lo up
# ip netns exec i1vQGHx8q6 ./bin/netavark-dhcp-proxy-client --uds /tmp/nv-proxyDYB/nv-proxy.sock -f /tmp/nv-proxyDYB/setup.json setup
# Error: dhcp proxy error: status: Aborted, message: "Timeout: Timeout", details: [], metadata: MetadataMap { headers: {"content-type": "application/grpc", "date": "Tue, 04 Feb 2025 18:35:00 GMT", "content-length": "0"} }
# [ rc=1 (** EXPECTED 0 **) ]
# #/vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
# #| FAIL: exit code is 1; expected 0
# #\^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
# ### Teardown ###
# proxy log:
# [ERROR mozim::client] Timeout: Timeout
# ip netns exec i1vQGHx8q6 ip link del veth0br
# ip netns exec i1vQGHx8q6 ip link set br0 down
# /usr/lib/bats-core/test_functions.bash: line 389: 23512 Killed RUST_LOG=info ip netns exec "$NS_NAME" $NETAVARK dhcp-proxy --dir "$TMP_TESTDIR" --uds "$TMP_TESTDIR" &> "$TMP_TESTDIR/proxy.log"
# ip netns exec i1vQGHx8q6 ip link del br0
# dnsmasq log:
# dnsmasq: started, version 2.90 DNS disabled
# dnsmasq: compile time options: IPv6 GNU-getopt DBus no-UBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset no-nftset auth cryptohash DNSSEC loop-detect inotify dumpfile
# dnsmasq-dhcp: DHCP, IP range 10.68.151.50 -- 10.68.151.59, lease time 2m
# dnsmasq-dhcp: 2278499307 available DHCP range: 10.68.151.50 -- 10.68.151.59
# dnsmasq-dhcp: 2278499307 client provides name: foobar
# dnsmasq-dhcp: 2278499307 DHCPDISCOVER(br0) 82:61:32:eb:06:73
# dnsmasq-dhcp: 2278499307 tags: br0
# dnsmasq-dhcp: 2278499307 DHCPOFFER(br0) 10.68.151.51 82:61:32:eb:06:73
# dnsmasq-dhcp: 2278499307 requested options: 12:hostname, 1:netmask, 3:router, 6:dns-server,
# dnsmasq-dhcp: 2278499307 requested options: 15:domain-name, 26:mtu, 42:ntp-server
# dnsmasq-dhcp: 2278499307 next server: 10.68.151.1
# dnsmasq-dhcp: 2278499307 sent size: 1 option: 53 message-type 2
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 54 server-identifier 10.68.151.1
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 51 lease-time 2m
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 58 T1 1m
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 59 T2 1m45s
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 1 netmask 255.255.255.0
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 28 broadcast 10.68.151.255
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 6 dns-server 10.68.151.1
# dnsmasq-dhcp: 2278499307 sent size: 4 option: 3 router 10.68.151.1
# ip netns exec i1vQGHx8q6 ip link set lo down
# /var/tmp/netavark/test-dhcp/helpers.bash: line 258: 23511 Killed ip netns exec "${NS_NAME}" dnsmasq --log-debug --log-dhcp --no-daemon --conf-dir "${dnsmasq_testdir}" &>> "$TMP_TESTDIR/dnsmasq.log"
I have seen it on several PRs, one example log https://cirrus-ci.com/task/6168884966850560
Looks like it is different from #618 which had a parser error but here we a timeout.