@@ -17,13 +17,11 @@ m4_divert_text([PREPARE_TESTS],
rcv_text=`echo "$rcv_pcap.packets" | sed 's/\.pcap//'`
exp_text=$2
exp_n=`wc -l < "$exp_text"`
- ovs_wait_cond () {
- $PYTHON "$top_srcdir/utilities/ovs-pcap.in" $rcv_pcap > $rcv_text
- rcv_n=`wc -l < "$rcv_text"`
- test $rcv_n -ge $exp_n
- }
- ovs_wait || echo "expected $exp_n packets, only received $rcv_n"
-
+ OVS_WAIT_UNTIL(
+ [$PYTHON "$top_srcdir/utilities/ovs-pcap.in" $rcv_pcap > $rcv_text
+ rcv_n=`wc -l < "$rcv_text"`
+ echo "rcv_n=$rcv_n exp_n=$exp_n"
+ test $rcv_n -ge $exp_n])
sort $exp_text > expout
}
])
@@ -4290,6 +4288,9 @@ test_dhcp() {
# dhcp message type
request=${request}3501${dhcp_type}ff
+ for port in $inport "$@"; do
+ : >> $port.expected
+ done
if test $offer_ip != 0; then
local srv_mac=$1 srv_ip=$2 expected_dhcp_opts=$3
# total IP length will be the IP length of the request packet
@@ -48,24 +48,6 @@ ovs_setenv() {
OVS_PKGDATADIR=$ovs_dir; export OVS_PKGDATADIR
}
-ovs_wait () {
- # First try the condition without waiting.
- ovs_wait_cond && return 0
-
- # Try a quick sleep, so that the test completes very quickly
- # in the normal case. POSIX doesn't require fractional times to
- # work, so this might not work.
- sleep 0.1
- ovs_wait_cond && return 0
-
- # Then wait up to 10 seconds.
- for d in 0 1 2 3 4 5 6 7 8 9; do
- sleep 1
- ovs_wait_cond && return 0
- done
- return 1
-}
-
# Prints the integers from $1 to $2, increasing by $3 (default 1) on stdout.
seq () {
if test $# = 1; then
@@ -197,17 +179,40 @@ fi
]
m4_divert_pop([PREPARE_TESTS])
+OVS_START_SHELL_HELPERS
+ovs_wait () {
+ echo "$1: waiting $2..." >&AS_MESSAGE_LOG_FD
+
+ # First try the condition without waiting.
+ if ovs_wait_cond; then echo "$1: immediate success" >&AS_MESSAGE_LOG_FD; return 0; fi
+
+ # Try a quick sleep, so that the test completes very quickly
+ # in the normal case. POSIX doesn't require fractional times to
+ # work, so this might not work.
+ sleep 0.1
+ if ovs_wait_cond; then echo "$1: quick success" >&AS_MESSAGE_LOG_FD; return 0; fi
+
+ # Then wait up to 10 seconds.
+ local d
+ for d in 1 2 3 4 5 6 7 8 9 10; do
+ sleep 1
+ if ovs_wait_cond; then echo "$1: success after $d seconds" >&AS_MESSAGE_LOG_FD; return 0; fi
+ done
+
+ echo "$1: wait failed" >&AS_MESSAGE_LOG_FD
+ ovs_wait_failed
+ AT_FAIL_IF([:])
+}
+OVS_END_SHELL_HELPERS
m4_define([OVS_WAIT], [dnl
-AS_ECHO(["AS_ESCAPE([$3: waiting $4...])"]) >&AS_MESSAGE_LOG_FD
ovs_wait_cond () {
$1
}
-if ovs_wait; then :
-else
- AS_ECHO(["AS_ESCAPE([$3: wait failed])"]) >&AS_MESSAGE_LOG_FD
+ovs_wait_failed () {
+ :
$2
- AT_FAIL_IF([:])
-fi
+}
+ovs_wait "AS_ESCAPE([$3])" "AS_ESCAPE([$4])"
])
dnl OVS_WAIT_UNTIL(COMMAND)
Many OVS tests wait up for 10 seconds for a condition to become true. Usually these conditions are ones that should take only a second or so to actually become true in practice, but on a busy and slow machine it's possible that some tests might fail or come close to failing because 10 seconds is simply not enough there. This commit adds logging for the case where a condition actually succeeds to indicate the amount of time that was waited. This should make it easier to identify whether we need to increase the maximum wait time from 10 seconds to something longer, by allowing us to see whether some of the successful waits came close to timing out. Reported-by: Thomas Goirand <zigo@debian.org> Reported-at: https://mail.openvswitch.org/pipermail/ovs-discuss/2018-September/047340.html Signed-off-by: Ben Pfaff <blp@ovn.org> --- tests/ovn.at | 15 ++++++++------- tests/ovs-macros.at | 53 +++++++++++++++++++++++++++++------------------------ 2 files changed, 37 insertions(+), 31 deletions(-)