These tests are executing group updates and then check the logs, but it is possible that logs are not yet flushed to the disk. That is causing sporadic failures like this one:
+awk: stddev.awk:10: fatal: division by zero attempted This happens when we run the awk script to check the bucket load before the logs actually appear in the file. Fix that by always waiting for the logs. FreeBSD also has a long standing issue with async IO where some logs can be re-ordered and jammed together. This mostly happens in the 'equal weights' test due to high amount of logging. Changing the pattern from 'ofproto_dpif|DBG|.*Bucket' to a shorter '|DBG|.*Bucket' should solve most of the issues of this kind in this particular test. Signed-off-by: Ilya Maximets <[email protected]> --- tests/ofproto-dpif.at | 89 ++++++++++++++++++++++++------------------- 1 file changed, 49 insertions(+), 40 deletions(-) diff --git a/tests/ofproto-dpif.at b/tests/ofproto-dpif.at index 663fd55ec..7ebbee56d 100644 --- a/tests/ofproto-dpif.at +++ b/tests/ofproto-dpif.at @@ -1158,15 +1158,16 @@ add_of_ports br0 1 10 11 ovs-appctl vlog/set ofproto_dpif:file:dbg AT_CHECK([ovs-ofctl -O OpenFlow12 add-group br0 'group_id=1234,type=select,bucket=output:10,bucket=output:11']) -AT_CHECK([grep -A6 "Constructing select group 1234" ovs-vswitchd.log | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([grep -A6 "Constructing select group 1234" ovs-vswitchd.log \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1234 ofproto_dpif|DBG|No selection method specified. Trying dp_hash. ofproto_dpif|DBG| Minimum weight: 1, total weight: 2 ofproto_dpif|DBG| Using 16 hash values: ofproto_dpif|DBG| Bucket 0: weight=1, target=8.00 hits=8 ofproto_dpif|DBG| Bucket 1: weight=1, target=8.00 hits=8 -ofproto_dpif|DBG|Use dp_hash with 16 hash values using algorithm 1. -]) +ofproto_dpif|DBG|Use dp_hash with 16 hash values using algorithm 1.]) + AT_CHECK([ovs-ofctl -O OpenFlow12 add-flow br0 'ip actions=write_actions(group:1234)']) # Try a bunch of different flows and make sure that they get distributed @@ -1231,7 +1232,8 @@ add_of_ports br0 1 10 11 12 13 14 ovs-appctl vlog/set ofproto_dpif:file:dbg AT_CHECK([ovs-ofctl -O OpenFlow13 add-group br0 'group_id=1234,type=select,bucket=weight:5,output:10,bucket=weight:10,output:11,bucket=weight:25,output:12,bucket=weight:60,output:13,bucket=weight:0,output:14']) -AT_CHECK([grep -A9 "Constructing select group 1234" ovs-vswitchd.log | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([grep -A9 "Constructing select group 1234" ovs-vswitchd.log \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1234 ofproto_dpif|DBG|No selection method specified. Trying dp_hash. ofproto_dpif|DBG| Minimum weight: 5, total weight: 100 @@ -1241,8 +1243,8 @@ ofproto_dpif|DBG| Bucket 1: weight=10, target=3.20 hits=3 ofproto_dpif|DBG| Bucket 2: weight=25, target=8.00 hits=8 ofproto_dpif|DBG| Bucket 3: weight=60, target=19.20 hits=19 ofproto_dpif|DBG| Bucket 4: weight=0, target=0.00 hits=0 -ofproto_dpif|DBG|Use dp_hash with 32 hash values using algorithm 1. -]) +ofproto_dpif|DBG|Use dp_hash with 32 hash values using algorithm 1.]) + AT_CHECK([ovs-ofctl -O OpenFlow12 add-flow br0 'ip actions=write_actions(group:1234)']) # Try 1000 different flows and make sure that they get distributed according to weights @@ -1312,7 +1314,9 @@ AT_DATA([stddev.awk], [ ]) m4_define([CHECK_DISTRIBUTION], [ - AT_CHECK([tail -n $1 ovs-vswitchd.log | grep 'ofproto_dpif|DBG|.*Bucket' \ + OVS_WAIT_UNTIL([test $(tail -n $1 ovs-vswitchd.log \ + | grep -c '|DBG|.*Bucket') -eq $2]) + AT_CHECK([tail -n $1 ovs-vswitchd.log | grep '|DBG|.*Bucket' \ | sed 's/.*target=\([[0-9\.]]*\) hits=\([[0-9]]*\)/\1 \2/' \ | awk -f stddev.awk], [0], [stdout]) AT_CHECK([grep -q "buckets: $2" stdout]) @@ -1359,30 +1363,33 @@ dnl Add two buckets one by one. get_log_next_line_num AT_CHECK([ovs-ofctl -O OpenFlow15 insert-buckets br0 \ group_id=1235,command_bucket_id=last,OFG_BUCKET([5])]) -AT_CHECK([tail -n +$LINENUM ovs-vswitchd.log | grep -E '(Bucket|group 1235)' \ - | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([tail -n +$LINENUM ovs-vswitchd.log \ + | grep -E '(Bucket|group 1235)' \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1235 ofproto_dpif|DBG| Bucket 5: weight=5, target=16.00 hits=16 ofproto_dpif|DBG|Modifying select group 1235 -ofproto_dpif|DBG| Bucket 5: weight=5, target=16.00 hits=16 -]) +ofproto_dpif|DBG| Bucket 5: weight=5, target=16.00 hits=16]) + get_log_next_line_num AT_CHECK([ovs-ofctl -O OpenFlow15 insert-buckets br0 \ group_id=1235,command_bucket_id=last,OFG_BUCKET([6])]) -AT_CHECK([tail -n +$LINENUM ovs-vswitchd.log | grep -E '(Bucket|group 1235)' \ - | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([tail -n +$LINENUM ovs-vswitchd.log \ + | grep -E '(Bucket|group 1235)' \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1235 ofproto_dpif|DBG| Bucket 6: weight=6, target=16.00 hits=16 ofproto_dpif|DBG|Modifying select group 1235 ofproto_dpif|DBG| Bucket 5: weight=5, target=7.27 hits=7 -ofproto_dpif|DBG| Bucket 6: weight=6, target=8.73 hits=9 -]) +ofproto_dpif|DBG| Bucket 6: weight=6, target=8.73 hits=9]) + dnl Add two more in the middle. get_log_next_line_num AT_CHECK([ovs-ofctl -O OpenFlow15 insert-buckets br0 \ group_id=1235,command_bucket_id=5,OFG_BUCKET([7]),OFG_BUCKET([8])]) -AT_CHECK([tail -n +$LINENUM ovs-vswitchd.log | grep -E '(Bucket|group 1235)' \ - | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([tail -n +$LINENUM ovs-vswitchd.log \ + | grep -E '(Bucket|group 1235)' \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1235 ofproto_dpif|DBG| Bucket 7: weight=7, target=7.47 hits=7 ofproto_dpif|DBG| Bucket 8: weight=8, target=8.53 hits=9 @@ -1390,40 +1397,42 @@ ofproto_dpif|DBG|Modifying select group 1235 ofproto_dpif|DBG| Bucket 5: weight=5, target=3.08 hits=3 ofproto_dpif|DBG| Bucket 7: weight=7, target=4.31 hits=4 ofproto_dpif|DBG| Bucket 8: weight=8, target=4.92 hits=5 -ofproto_dpif|DBG| Bucket 6: weight=6, target=3.69 hits=4 -]) +ofproto_dpif|DBG| Bucket 6: weight=6, target=3.69 hits=4]) + dnl Remove the last bucket. get_log_next_line_num AT_CHECK([ovs-ofctl -O OpenFlow15 remove-buckets br0 \ group_id=1235,command_bucket_id=last]) -AT_CHECK([tail -n +$LINENUM ovs-vswitchd.log | grep -E '(Bucket|group 1235)' \ - | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([tail -n +$LINENUM ovs-vswitchd.log \ + | grep -E '(Bucket|group 1235)' \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1235 ofproto_dpif|DBG|Modifying select group 1235 ofproto_dpif|DBG| Bucket 5: weight=5, target=4.00 hits=4 ofproto_dpif|DBG| Bucket 7: weight=7, target=5.60 hits=6 -ofproto_dpif|DBG| Bucket 8: weight=8, target=6.40 hits=6 -]) +ofproto_dpif|DBG| Bucket 8: weight=8, target=6.40 hits=6]) + dnl Remove the one in the middle. get_log_next_line_num AT_CHECK([ovs-ofctl -O OpenFlow15 remove-buckets br0 \ group_id=1235,command_bucket_id=7]) -AT_CHECK([tail -n +$LINENUM ovs-vswitchd.log | grep -E '(Bucket|group 1235)' \ - | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([tail -n +$LINENUM ovs-vswitchd.log \ + | grep -E '(Bucket|group 1235)' \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1235 ofproto_dpif|DBG|Modifying select group 1235 ofproto_dpif|DBG| Bucket 5: weight=5, target=6.15 hits=6 -ofproto_dpif|DBG| Bucket 8: weight=8, target=9.85 hits=10 -]) +ofproto_dpif|DBG| Bucket 8: weight=8, target=9.85 hits=10]) + dnl Remove all the remaining. get_log_next_line_num AT_CHECK([ovs-ofctl -O OpenFlow15 remove-buckets br0 \ group_id=1235,command_bucket_id=all]) -AT_CHECK([tail -n +$LINENUM ovs-vswitchd.log | grep -E '(Bucket|group 1235)' \ - | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([tail -n +$LINENUM ovs-vswitchd.log \ + | grep -E '(Bucket|group 1235)' \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1235 -ofproto_dpif|DBG|Modifying select group 1235 -]) +ofproto_dpif|DBG|Modifying select group 1235]) OVS_VSWITCHD_STOP AT_CLEANUP @@ -1435,34 +1444,34 @@ add_of_ports br0 1 10 11 ovs-appctl vlog/set ofproto_dpif:file:dbg AT_CHECK([ovs-ofctl -O OpenFlow15 add-group br0 'group_id=1234,type=select,selection_method=dp_hash,bucket=output:10,bucket=output:11']) -AT_CHECK([grep -A6 "Constructing select group 1234" ovs-vswitchd.log | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([grep -A6 "Constructing select group 1234" ovs-vswitchd.log \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1234 ofproto_dpif|DBG|Selection method specified: dp_hash. ofproto_dpif|DBG| Minimum weight: 1, total weight: 2 ofproto_dpif|DBG| Using 16 hash values: ofproto_dpif|DBG| Bucket 0: weight=1, target=8.00 hits=8 ofproto_dpif|DBG| Bucket 1: weight=1, target=8.00 hits=8 -ofproto_dpif|DBG|Use dp_hash with 16 hash values using algorithm 0. -]) +ofproto_dpif|DBG|Use dp_hash with 16 hash values using algorithm 0.]) # Fall back to legacy hash with zero buckets AT_CHECK([ovs-ofctl -O OpenFlow15 add-group br0 'group_id=1235,type=select,selection_method=dp_hash']) -AT_CHECK([grep -A3 "Constructing select group 1235" ovs-vswitchd.log | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([grep -A3 "Constructing select group 1235" ovs-vswitchd.log \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1235 ofproto_dpif|DBG|Selection method specified: dp_hash. ofproto_dpif|DBG| Don't apply dp_hash method without buckets. -ofproto_dpif|DBG|Falling back to default hash method. -]) +ofproto_dpif|DBG|Falling back to default hash method.]) # Fall back to legacy hash with zero buckets AT_CHECK([ovs-ofctl -O OpenFlow15 add-group br0 'group_id=1236,type=select,selection_method=dp_hash,bucket=weight=1,output:10,bucket=weight=1000,output:11']) -AT_CHECK([grep -A4 "Constructing select group 1236" ovs-vswitchd.log | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [0], [dnl +OVS_WAIT_UNTIL_EQUAL([grep -A4 "Constructing select group 1236" ovs-vswitchd.log \ + | sed 's/^.*ofproto_dpif/ofproto_dpif/'], [dnl ofproto_dpif|DBG|Constructing select group 1236 ofproto_dpif|DBG|Selection method specified: dp_hash. ofproto_dpif|DBG| Minimum weight: 1, total weight: 1001 ofproto_dpif|DBG| Too many hash values required: 1024 -ofproto_dpif|DBG|Falling back to default hash method. -]) +ofproto_dpif|DBG|Falling back to default hash method.]) OVS_VSWITCHD_STOP AT_CLEANUP -- 2.51.0 _______________________________________________ dev mailing list [email protected] https://mail.openvswitch.org/mailman/listinfo/ovs-dev
