diff mbox series

[ovs-dev,v8,14/15] tests: Fix reading of OpenFlow byte counters in GRE test cases.

Message ID 167456527812.1023551.764296808826006469.stgit@ebuild.local
State Changes Requested
Headers show
Series tests: Add system-traffic.at tests to check-offloads. | expand

Checks

Context Check Description
ovsrobot/apply-robot success apply and check: success
ovsrobot/github-robot-_Build_and_Test success github build: passed

Commit Message

Eelco Chaudron Jan. 24, 2023, 1:01 p.m. UTC 
With some datapaths, read TC, it takes a bit longer to update the
OpenFlow statistics. Rather than adding an additional delay, try
to read the counters multiple times until we get the desired value.

Signed-off-by: Eelco Chaudron <echaudro@redhat.com>
Acked-by: Roi Dayan <roid@nvidia.com>
---
 tests/system-offloads.at |    2 --
 tests/system-traffic.at  |   15 ++++++---------
 2 files changed, 6 insertions(+), 11 deletions(-)

Comments

Simon Horman Jan. 26, 2023, 4:58 p.m. UTC | #1 
On Tue, Jan 24, 2023 at 02:01:19PM +0100, Eelco Chaudron wrote:
> With some datapaths, read TC, it takes a bit longer to update the
> OpenFlow statistics. Rather than adding an additional delay, try
> to read the counters multiple times until we get the desired value.
> 
> Signed-off-by: Eelco Chaudron <echaudro@redhat.com>
> Acked-by: Roi Dayan <roid@nvidia.com>

When, possibly unwisely, running this test on my laptop,
with a somewhat old kernel the tests fail with absurd byte counts.
I haven't had time to dig into why.

$ uname -spv
Linux #1 SMP Debian 5.10.158-2 (2022-12-13) unknown

The first test appears to fail with n_bytes=18446744073709159596
And the second, with n_bytes=18446744073703563162

Log follows:

make  all-am
make[1]: Map '/home/horms/projects/openvswitch/ovs' wordt binnengegaan
make[1]: Map '/home/horms/projects/openvswitch/ovs' wordt verlaten
set /bin/bash './tests/system-offloads-testsuite' -C tests  AUTOTEST_PATH='utilities:vswitchd:ovsdb:vtep:tests:ipsec::'; \
"$@" -k "datapath - truncate and output" -v -j1 || (test X'' = Xyes && "$@" --recheck)
Illegal "police"
## ------------------------------ ##
## openvswitch 3.1.90 test suite. ##
## ------------------------------ ##

datapath-sanity

50. system-traffic.at:1639: testing datapath - truncate and output to gre tunnel by simulated packets ...
./system-traffic.at:1642: modprobe openvswitch
Module vport_lisp not loaded.
Module vport_stt not loaded.
./system-traffic.at:1642: ovsdb-tool create conf.db $abs_top_srcdir/vswitchd/vswitch.ovsschema
./system-traffic.at:1642: ovsdb-server --detach --no-chdir --pidfile --log-file --remote=punix:$OVS_RUNDIR/db.sock
stderr:
2023-01-26T16:43:57Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovsdb-server.log
./system-traffic.at:1642: sed < stderr '
/vlog|INFO|opened log file/d
/ovsdb_server|INFO|ovsdb-server (Open vSwitch)/d'
./system-traffic.at:1642: ovs-vsctl --no-wait init -- set Open_vSwitch . other_config:hw-offload=true
   
./system-traffic.at:1642: ovs-vswitchd  --detach --no-chdir --pidfile --log-file -vvconn -vofproto_dpif -vunixctl
stderr:
2023-01-26T16:43:57Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovs-vswitchd.log
2023-01-26T16:43:57Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
2023-01-26T16:43:57Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
2023-01-26T16:43:57Z|00004|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/db.sock: connecting...
2023-01-26T16:43:57Z|00005|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/db.sock: connected
2023-01-26T16:43:57Z|00006|netdev_offload|INFO|netdev: Flow API Enabled
2023-01-26T16:43:57Z|00007|tc|INFO|tc: Using policy 'none'
./system-traffic.at:1642: sed < stderr '
/ovs_numa|INFO|Discovered /d
/odp_execute_impl|INFO|Action implementation /d
/vlog|INFO|opened log file/d
/vswitchd|INFO|ovs-vswitchd (Open vSwitch)/d
/reconnect|INFO|/d
/dpif_netlink|INFO|Generic Netlink family .ovs_datapath. does not exist/d
/ofproto|INFO|using datapath ID/d
/netdev_linux|INFO|.*device has unknown hardware address family/d
/ofproto|INFO|datapath ID changed to fedcba9876543210/d
/dpdk|INFO|DPDK Disabled - Use other_config:dpdk-init to enable/d
/netlink_socket|INFO|netlink: could not enable listening to all nsid/d
/netdev_offload|INFO|netdev: Flow API Enabled/d
/probe tc:/d
/setting extended ack support failed/d
/tc: Using policy/d'
./system-traffic.at:1642: ovs-vsctl -- add-br br0 -- set Bridge br0 protocols=OpenFlow10,OpenFlow11,OpenFlow12,OpenFlow13,OpenFlow14,OpenFlow15 fail-mode=secure  --  
Cannot remove namespace file "/run/netns/at_ns0": No such file or directory
./system-traffic.at:1645: ip netns add at_ns0 || return 77
net.netfilter.nf_conntrack_helper = 0
Cannot remove namespace file "/run/netns/at_ns1": No such file or directory
./system-traffic.at:1646: ip netns add at_ns1 || return 77
net.netfilter.nf_conntrack_helper = 0
./system-traffic.at:1647: ovs-ofctl add-flow br0 "actions=normal"
./system-traffic.at:1648: ovs-ofctl add-flow br-underlay "actions=normal"
./system-traffic.at:1651: ip link add p0 type veth peer name ovs-p0 || return 77
./system-traffic.at:1651: ip link set p0 netns at_ns0
./system-traffic.at:1651: ip link set dev ovs-p0 up
./system-traffic.at:1651: ovs-vsctl add-port br-underlay ovs-p0 -- \
                set interface ovs-p0 external-ids:iface-id="p0"
./system-traffic.at:1651: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip addr add "172.31.1.1/24" dev p0
NS_EXEC_HEREDOC
./system-traffic.at:1651: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip link set dev p0 up
NS_EXEC_HEREDOC
./system-traffic.at:1651: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip link set dev p0 address fa:ad:fa:25:05:60
NS_EXEC_HEREDOC
./system-traffic.at:1652: ip addr add dev br-underlay "172.31.1.100/24"
./system-traffic.at:1653: ip link set dev br-underlay up
./system-traffic.at:1657: ovs-vsctl add-port br0 at_gre0 -- \
              set int at_gre0 type=gre options:remote_ip=172.31.1.1 
./system-traffic.at:1657: ip addr add dev br0 10.1.1.100/24
./system-traffic.at:1657: ip link set dev br0 up
./system-traffic.at:1657: ip link set dev br0 mtu 1450
./system-traffic.at:1667: ip link add p1 type veth peer name ovs-p1 || return 77
./system-traffic.at:1667: ip link set p1 netns at_ns1
./system-traffic.at:1667: ip link set dev ovs-p1 up
./system-traffic.at:1667: ovs-vsctl add-port br0 ovs-p1 -- \
                set interface ovs-p1 external-ids:iface-id="p1"
./system-traffic.at:1667: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
ip addr add '10.1.1.2/24' dev p1
NS_EXEC_HEREDOC
./system-traffic.at:1667: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
ip link set dev p1 up
NS_EXEC_HEREDOC
./system-traffic.at:1668: ovs-vsctl -- set interface ovs-p1 ofport_request=2
./system-traffic.at:1669: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
ip link set dev p1 address e6:66:c1:22:22:22
NS_EXEC_HEREDOC
./system-traffic.at:1670: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
arp -s 10.1.1.1 e6:66:c1:11:11:11
NS_EXEC_HEREDOC
./system-traffic.at:1673: ip link add p2 type veth peer name ovs-p2
./system-traffic.at:1675: ip link set dev ovs-p2 up
./system-traffic.at:1676: ip link set dev p2 up
./system-traffic.at:1677: ovs-vsctl add-port br0 ovs-p2 -- set interface ovs-p2 ofport_request=3
./system-traffic.at:1678: ovs-vsctl add-port br0 p2 -- set interface p2 ofport_request=4
./system-traffic.at:1681: dd if=/dev/urandom of=payload200.bin bs=200 count=1 2> /dev/null
./system-traffic.at:1684: ovs-ofctl del-flows br0
./system-traffic.at:1691: ovs-ofctl add-flows br0 flows.txt
./system-traffic.at:1693: ovs-ofctl del-flows br-underlay
./system-traffic.at:1700: ovs-ofctl add-flows br-underlay flows-underlay.txt
./system-traffic.at:1703: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
nc $NC_EOF_OPT -u 10.1.1.1 1234 < payload200.bin
NS_EXEC_HEREDOC
./system-traffic.at:1704: sleep 2; ovs-appctl revalidator/purge
./system-traffic.at:1707: ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p'
system-traffic.at:1711: waiting until ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p' | grep "n_bytes=138"...
system-traffic.at:1711: wait failed after 30 seconds
n_bytes=18446744073709159596
./ovs-macros.at:247: hard failure
2023-01-26T16:44:33Z|00001|daemon_unix|WARN|/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovs-vswitchd.pid: open: No such file or directory
ovs-appctl: cannot read pidfile "/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovs-vswitchd.pid" (No such file or directory)
ovs-dpctl: opening datapath (No such device)
50. system-traffic.at:1639:  FAILED (ovs-macros.at:247)

51. system-traffic.at:1768: testing datapath - truncate and output to gre tunnel ...
./system-traffic.at:1772: modprobe openvswitch
Module vport_lisp not loaded.
Module vport_stt not loaded.
./system-traffic.at:1772: ovsdb-tool create conf.db $abs_top_srcdir/vswitchd/vswitch.ovsschema
./system-traffic.at:1772: ovsdb-server --detach --no-chdir --pidfile --log-file --remote=punix:$OVS_RUNDIR/db.sock
stderr:
2023-01-26T16:44:35Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovsdb-server.log
./system-traffic.at:1772: sed < stderr '
/vlog|INFO|opened log file/d
/ovsdb_server|INFO|ovsdb-server (Open vSwitch)/d'
./system-traffic.at:1772: ovs-vsctl --no-wait init -- set Open_vSwitch . other_config:hw-offload=true
   
./system-traffic.at:1772: ovs-vswitchd  --detach --no-chdir --pidfile --log-file -vvconn -vofproto_dpif -vunixctl
stderr:
2023-01-26T16:44:35Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.log
2023-01-26T16:44:35Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
2023-01-26T16:44:35Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
2023-01-26T16:44:35Z|00004|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connecting...
2023-01-26T16:44:35Z|00005|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connected
2023-01-26T16:44:35Z|00006|netdev_offload|INFO|netdev: Flow API Enabled
2023-01-26T16:44:35Z|00007|tc|INFO|tc: Using policy 'none'
./system-traffic.at:1772: sed < stderr '
/ovs_numa|INFO|Discovered /d
/odp_execute_impl|INFO|Action implementation /d
/vlog|INFO|opened log file/d
/vswitchd|INFO|ovs-vswitchd (Open vSwitch)/d
/reconnect|INFO|/d
/dpif_netlink|INFO|Generic Netlink family .ovs_datapath. does not exist/d
/ofproto|INFO|using datapath ID/d
/netdev_linux|INFO|.*device has unknown hardware address family/d
/ofproto|INFO|datapath ID changed to fedcba9876543210/d
/dpdk|INFO|DPDK Disabled - Use other_config:dpdk-init to enable/d
/netlink_socket|INFO|netlink: could not enable listening to all nsid/d
/netdev_offload|INFO|netdev: Flow API Enabled/d
/probe tc:/d
/setting extended ack support failed/d
/tc: Using policy/d'
./system-traffic.at:1772: ovs-vsctl -- add-br br0 -- set Bridge br0 protocols=OpenFlow10,OpenFlow11,OpenFlow12,OpenFlow13,OpenFlow14,OpenFlow15 fail-mode=secure  --  
Cannot remove namespace file "/run/netns/at_ns0": No such file or directory
./system-traffic.at:1775: ip netns add at_ns0 || return 77
net.netfilter.nf_conntrack_helper = 0
Cannot remove namespace file "/run/netns/at_ns1": No such file or directory
./system-traffic.at:1776: ip netns add at_ns1 || return 77
net.netfilter.nf_conntrack_helper = 0
./system-traffic.at:1777: ovs-ofctl add-flow br0 "actions=normal"
./system-traffic.at:1778: ovs-ofctl add-flow br-underlay "actions=normal"
./system-traffic.at:1781: ip link add p0 type veth peer name ovs-p0 || return 77
./system-traffic.at:1781: ip link set p0 netns at_ns0
./system-traffic.at:1781: ip link set dev ovs-p0 up
./system-traffic.at:1781: ovs-vsctl add-port br-underlay ovs-p0 -- \
                set interface ovs-p0 external-ids:iface-id="p0"
./system-traffic.at:1781: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip addr add "172.31.1.1/24" dev p0
NS_EXEC_HEREDOC
./system-traffic.at:1781: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip link set dev p0 up
NS_EXEC_HEREDOC
./system-traffic.at:1782: ip addr add dev br-underlay "172.31.1.100/24"
./system-traffic.at:1783: ip link set dev br-underlay up
./system-traffic.at:1787: ovs-vsctl add-port br0 at_gre0 -- \
              set int at_gre0 type=gre options:remote_ip=172.31.1.1 
./system-traffic.at:1787: ip addr add dev br0 10.1.1.100/24
./system-traffic.at:1787: ip link set dev br0 up
./system-traffic.at:1787: ip link set dev br0 mtu 1450
./system-traffic.at:1788: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip link add dev ns_gre0 type gretap remote 172.31.1.100
NS_EXEC_HEREDOC
./system-traffic.at:1788: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip addr add dev ns_gre0 10.1.1.1/24
NS_EXEC_HEREDOC
./system-traffic.at:1788: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
ip link set dev ns_gre0 mtu 1450 address e6:66:c1:11:11:11 up
NS_EXEC_HEREDOC
./system-traffic.at:1790: ovs-vsctl -- set interface at_gre0 ofport_request=1
./system-traffic.at:1791: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
arp -s 10.1.1.2 e6:66:c1:22:22:22
NS_EXEC_HEREDOC
./system-traffic.at:1794: ip link add p1 type veth peer name ovs-p1 || return 77
./system-traffic.at:1794: ip link set p1 netns at_ns1
./system-traffic.at:1794: ip link set dev ovs-p1 up
./system-traffic.at:1794: ovs-vsctl add-port br0 ovs-p1 -- \
                set interface ovs-p1 external-ids:iface-id="p1"
./system-traffic.at:1794: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
ip addr add '10.1.1.2/24' dev p1
NS_EXEC_HEREDOC
./system-traffic.at:1794: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
ip link set dev p1 up
NS_EXEC_HEREDOC
./system-traffic.at:1795: ovs-vsctl -- set interface ovs-p1 ofport_request=2
./system-traffic.at:1796: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
ip link set dev p1 address e6:66:c1:22:22:22
NS_EXEC_HEREDOC
./system-traffic.at:1797: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
arp -s 10.1.1.1 e6:66:c1:11:11:11
NS_EXEC_HEREDOC
./system-traffic.at:1800: ip link add p2 type veth peer name ovs-p2
./system-traffic.at:1802: ip link set dev ovs-p2 up
./system-traffic.at:1803: ip link set dev p2 up
./system-traffic.at:1804: ovs-vsctl add-port br0 ovs-p2 -- set interface ovs-p2 ofport_request=3
./system-traffic.at:1805: ovs-vsctl add-port br0 p2 -- set interface p2 ofport_request=4
./system-traffic.at:1808: dd if=/dev/urandom of=payload200.bin bs=200 count=1 2> /dev/null
./system-traffic.at:1811: ovs-ofctl del-flows br0
./system-traffic.at:1818: ovs-ofctl add-flows br0 flows.txt
./system-traffic.at:1820: ovs-ofctl del-flows br-underlay
./system-traffic.at:1827: ovs-ofctl add-flows br-underlay flows-underlay.txt
./system-traffic.at:1830: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
nc $NC_EOF_OPT -u 10.1.1.1 1234 < payload200.bin
NS_EXEC_HEREDOC
./system-traffic.at:1831: sleep 2; ovs-appctl revalidator/purge
./system-traffic.at:1834: ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p'
./system-traffic.at:1838: ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p'
--- -	2023-01-26 17:44:41.102671600 +0100
+++ /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/at-groups/51/stdout	2023-01-26 17:44:41.098239330 +0100
@@ -1,2 +1,2 @@
-n_bytes=138
+n_bytes=18446744073703563162
 
ovsdb-server.log:
> 2023-01-26T16:44:35.719Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovsdb-server.log
> 2023-01-26T16:44:35.748Z|00002|ovsdb_server|INFO|ovsdb-server (Open vSwitch) 3.1.90
ovs-vswitchd.log:
> 2023-01-26T16:44:35.760Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.log
> 2023-01-26T16:44:35.761Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
> 2023-01-26T16:44:35.761Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
> 2023-01-26T16:44:35.761Z|00004|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connecting...
> 2023-01-26T16:44:35.761Z|00005|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connected
> 2023-01-26T16:44:35.763Z|00006|netdev_offload|INFO|netdev: Flow API Enabled
> 2023-01-26T16:44:35.763Z|00007|tc|INFO|tc: Using policy 'none'
> 2023-01-26T16:44:35.765Z|00008|bridge|INFO|ovs-vswitchd (Open vSwitch) 3.1.90
> 2023-01-26T16:44:35.775Z|00009|dpif_netlink|INFO|Datapath dispatch mode: per-vport
> 2023-01-26T16:44:35.851Z|00010|netdev_offload_tc|INFO|probe tc: block offload is supported.
> 2023-01-26T16:44:35.895Z|00011|netdev_offload_tc|INFO|probe tc: multiple masks on single tc prio is supported.
> 2023-01-26T16:44:36.055Z|00012|netdev_offload_tc|INFO|probe tc: supported ovs ct_state bits: 0x27
> 2023-01-26T16:44:36.055Z|00013|netdev_offload_tc|INFO|added ingress qdisc to ovs-system
> 2023-01-26T16:44:36.055Z|00014|netdev_offload|INFO|ovs-system: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.056Z|00015|ofproto_dpif|INFO|system@ovs-system: Datapath supports recirculation
> 2023-01-26T16:44:36.056Z|00016|ofproto_dpif|INFO|system@ovs-system: VLAN header stack length probed as 2
> 2023-01-26T16:44:36.056Z|00017|ofproto_dpif|INFO|system@ovs-system: MPLS label stack length probed as 3
> 2023-01-26T16:44:36.056Z|00018|ofproto_dpif|INFO|system@ovs-system: Datapath supports truncate action
> 2023-01-26T16:44:36.056Z|00019|ofproto_dpif|INFO|system@ovs-system: Datapath supports unique flow ids
> 2023-01-26T16:44:36.056Z|00020|ofproto_dpif|INFO|system@ovs-system: Datapath supports clone action
> 2023-01-26T16:44:36.057Z|00021|ofproto_dpif|INFO|system@ovs-system: Max sample nesting level probed as 10
> 2023-01-26T16:44:36.057Z|00022|ofproto_dpif|INFO|system@ovs-system: Datapath supports eventmask in conntrack action
> 2023-01-26T16:44:36.057Z|00023|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_clear action
> 2023-01-26T16:44:36.057Z|00024|ofproto_dpif|INFO|system@ovs-system: Max dp_hash algorithm probed to be 0
> 2023-01-26T16:44:36.057Z|00025|ofproto_dpif|INFO|system@ovs-system: Datapath supports check_pkt_len action
> 2023-01-26T16:44:36.057Z|00026|ofproto_dpif|INFO|system@ovs-system: Datapath supports timeout policy in conntrack action
> 2023-01-26T16:44:36.057Z|00027|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_zero_snat
> 2023-01-26T16:44:36.057Z|00028|ofproto_dpif|INFO|system@ovs-system: Datapath supports add_mpls action
> 2023-01-26T16:44:36.057Z|00029|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_state
> 2023-01-26T16:44:36.058Z|00030|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_zone
> 2023-01-26T16:44:36.058Z|00031|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_mark
> 2023-01-26T16:44:36.058Z|00032|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_label
> 2023-01-26T16:44:36.058Z|00033|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_state_nat
> 2023-01-26T16:44:36.058Z|00034|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_orig_tuple
> 2023-01-26T16:44:36.058Z|00035|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_orig_tuple6
> 2023-01-26T16:44:36.058Z|00036|ofproto_dpif|INFO|system@ovs-system: Datapath does not support IPv6 ND Extensions
> 2023-01-26T16:44:36.058Z|00037|ofproto_dpif_upcall|INFO|Setting n-handler-threads to 5, setting n-revalidator-threads to 3
> 2023-01-26T16:44:36.058Z|00038|ofproto_dpif_upcall|INFO|Starting 8 threads
> 2023-01-26T16:44:36.072Z|00039|netdev_offload_tc|INFO|added ingress qdisc to br0
> 2023-01-26T16:44:36.072Z|00040|netdev_offload|INFO|br0: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.072Z|00041|bridge|INFO|bridge br0: added interface br0 on port 65534
> 2023-01-26T16:44:36.073Z|00042|bridge|INFO|bridge br0: using datapath ID 000016215abb444a
> 2023-01-26T16:44:36.073Z|00043|connmgr|INFO|br0: added service controller "punix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/br0.mgmt"
> 2023-01-26T16:44:36.106Z|00044|netdev_offload_tc|INFO|added ingress qdisc to br-underlay
> 2023-01-26T16:44:36.106Z|00045|netdev_offload|INFO|br-underlay: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.106Z|00046|bridge|INFO|bridge br-underlay: added interface br-underlay on port 65534
> 2023-01-26T16:44:36.107Z|00047|bridge|INFO|bridge br-underlay: using datapath ID 00002a96e384084e
> 2023-01-26T16:44:36.107Z|00048|connmgr|INFO|br-underlay: added service controller "punix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/br-underlay.mgmt"
> 2023-01-26T16:44:36.147Z|00049|vconn|DBG|unix#0: sent (Success): OFPT_HELLO (OF1.5) (xid=0x1):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:36.147Z|00050|vconn|DBG|unix#0: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:36.147Z|00051|vconn|DBG|unix#0: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:36.147Z|00052|vconn|DBG|unix#0: received: OFPST_TABLE request (xid=0x2):
> 2023-01-26T16:44:36.148Z|00053|vconn|DBG|unix#0: sent (Success): OFPST_TABLE reply (xid=0x2):
>   table 0:
>     active=0, lookup=0, matched=0
>     max_entries=1000000
>     matching:
>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
> 
>   tables 1...253: ditto
> 2023-01-26T16:44:36.148Z|00054|vconn|DBG|unix#1: sent (Success): OFPT_HELLO (OF1.5) (xid=0x2):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:36.148Z|00055|vconn|DBG|unix#1: received: OFPT_HELLO (xid=0x3):
>  version bitmap: 0x01
> 2023-01-26T16:44:36.148Z|00056|vconn|DBG|unix#1: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:36.148Z|00057|vconn|DBG|unix#1: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2023-01-26T16:44:36.148Z|00058|vconn|DBG|unix#1: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:000016215abb444a
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>  LOCAL(br0): addr:16:21:5a:bb:44:4a
>      config:     PORT_DOWN
>      state:      LINK_DOWN
>      speed: 0 Mbps now, 0 Mbps max
> 2023-01-26T16:44:36.148Z|00059|vconn|DBG|unix#2: sent (Success): OFPT_HELLO (OF1.5) (xid=0x3):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:36.148Z|00060|vconn|DBG|unix#2: received: OFPT_HELLO (xid=0x5):
>  version bitmap: 0x01
> 2023-01-26T16:44:36.148Z|00061|vconn|DBG|unix#2: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:36.148Z|00062|vconn|DBG|unix#2: received: OFPT_FLOW_MOD (xid=0x6): ADD actions=NORMAL
> 2023-01-26T16:44:36.148Z|00063|vconn|DBG|unix#2: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2023-01-26T16:44:36.148Z|00064|vconn|DBG|unix#2: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2023-01-26T16:44:36.148Z|00065|connmgr|INFO|br0<->unix#2: 1 flow_mods in the last 0 s (1 adds)
> 2023-01-26T16:44:36.152Z|00066|vconn|DBG|unix#3: sent (Success): OFPT_HELLO (OF1.5) (xid=0x4):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:36.152Z|00067|vconn|DBG|unix#3: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:36.152Z|00068|vconn|DBG|unix#3: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:36.152Z|00069|vconn|DBG|unix#3: received: OFPST_TABLE request (xid=0x2):
> 2023-01-26T16:44:36.152Z|00070|vconn|DBG|unix#3: sent (Success): OFPST_TABLE reply (xid=0x2):
>   table 0:
>     active=0, lookup=0, matched=0
>     max_entries=1000000
>     matching:
>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
> 
>   tables 1...253: ditto
> 2023-01-26T16:44:36.152Z|00071|vconn|DBG|unix#4: sent (Success): OFPT_HELLO (OF1.5) (xid=0x5):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:36.152Z|00072|vconn|DBG|unix#4: received: OFPT_HELLO (xid=0x3):
>  version bitmap: 0x01
> 2023-01-26T16:44:36.152Z|00073|vconn|DBG|unix#4: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:36.152Z|00074|vconn|DBG|unix#4: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2023-01-26T16:44:36.153Z|00075|vconn|DBG|unix#4: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:00002a96e384084e
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>  LOCAL(br-underlay): addr:2a:96:e3:84:08:4e
>      config:     PORT_DOWN
>      state:      LINK_DOWN
>      speed: 0 Mbps now, 0 Mbps max
> 2023-01-26T16:44:36.153Z|00076|vconn|DBG|unix#5: sent (Success): OFPT_HELLO (OF1.5) (xid=0x6):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:36.153Z|00077|vconn|DBG|unix#5: received: OFPT_HELLO (xid=0x5):
>  version bitmap: 0x01
> 2023-01-26T16:44:36.153Z|00078|vconn|DBG|unix#5: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:36.153Z|00079|vconn|DBG|unix#5: received: OFPT_FLOW_MOD (xid=0x6): ADD actions=NORMAL
> 2023-01-26T16:44:36.153Z|00080|vconn|DBG|unix#5: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2023-01-26T16:44:36.153Z|00081|vconn|DBG|unix#5: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2023-01-26T16:44:36.153Z|00082|connmgr|INFO|br-underlay<->unix#5: 1 flow_mods in the last 0 s (1 adds)
> 2023-01-26T16:44:36.213Z|00083|netdev_offload_tc|INFO|added ingress qdisc to ovs-p0
> 2023-01-26T16:44:36.213Z|00084|netdev_offload|INFO|ovs-p0: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.213Z|00085|bridge|INFO|bridge br-underlay: added interface ovs-p0 on port 1
> 2023-01-26T16:44:36.231Z|00086|netdev_offload_tc|INFO|added ingress qdisc to at_gre0
> 2023-01-26T16:44:36.231Z|00087|netdev_offload|INFO|at_gre0: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.231Z|00088|bridge|INFO|bridge br0: added interface at_gre0 on port 1
> 2023-01-26T16:44:36.695Z|00089|netdev_offload_tc|INFO|added ingress qdisc to ovs-p1
> 2023-01-26T16:44:36.695Z|00090|netdev_offload|INFO|ovs-p1: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.695Z|00091|bridge|INFO|bridge br0: added interface ovs-p1 on port 2
> 2023-01-26T16:44:36.851Z|00092|netdev_offload_tc|INFO|added ingress qdisc to ovs-p2
> 2023-01-26T16:44:36.851Z|00093|netdev_offload|INFO|ovs-p2: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.851Z|00094|bridge|INFO|bridge br0: added interface ovs-p2 on port 3
> 2023-01-26T16:44:36.879Z|00095|netdev_offload_tc|INFO|added ingress qdisc to p2
> 2023-01-26T16:44:36.879Z|00096|netdev_offload|INFO|p2: Assigned flow API 'linux_tc'.
> 2023-01-26T16:44:36.879Z|00097|bridge|INFO|bridge br0: added interface p2 on port 4
> 2023-01-26T16:44:36.902Z|00001|ofproto_dpif_upcall(handler1)|INFO|received packet on unassociated datapath port 7 (no OpenFlow port for datapath port 7)
> 2023-01-26T16:44:37.122Z|00098|vconn|DBG|unix#6: sent (Success): OFPT_HELLO (OF1.5) (xid=0x7):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.122Z|00099|vconn|DBG|unix#6: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.122Z|00100|vconn|DBG|unix#6: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.122Z|00101|vconn|DBG|unix#6: received: OFPST_TABLE request (xid=0x2):
> 2023-01-26T16:44:37.127Z|00102|vconn|DBG|unix#6: sent (Success): OFPST_TABLE reply (xid=0x2):
>   table 0:
>     active=1, lookup=1190, matched=1190
>     max_entries=1000000
>     matching:
>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
> 
>   table 1:
>     active=0, lookup=0, matched=0
>     (same features)
> 
>   tables 2...253: ditto
> 2023-01-26T16:44:37.206Z|00103|vconn|DBG|unix#7: sent (Success): OFPT_HELLO (OF1.5) (xid=0x8):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.206Z|00104|vconn|DBG|unix#7: received: OFPT_HELLO (xid=0x3):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.206Z|00105|vconn|DBG|unix#7: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.228Z|00106|vconn|DBG|unix#7: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2023-01-26T16:44:37.228Z|00107|vconn|DBG|unix#7: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:000016215abb444a
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>  1(at_gre0): addr:a2:f9:64:45:eb:65
>      config:     0
>      state:      0
>      speed: 0 Mbps now, 0 Mbps max
>  2(ovs-p1): addr:32:68:ed:0f:cc:60
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  3(ovs-p2): addr:0e:8a:4c:65:90:6c
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  4(p2): addr:8e:57:dd:84:91:3f
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  LOCAL(br0): addr:16:21:5a:bb:44:4a
>      config:     0
>      state:      0
>      speed: 0 Mbps now, 0 Mbps max
> 2023-01-26T16:44:37.282Z|00108|vconn|DBG|unix#8: sent (Success): OFPT_HELLO (OF1.5) (xid=0x9):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.282Z|00109|vconn|DBG|unix#8: received: OFPT_HELLO (xid=0x5):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.283Z|00110|vconn|DBG|unix#8: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.294Z|00001|dpif_netlink(handler5)|WARN|system@ovs-system: lost packet on port channel 2 of handler 3 (last polled 11 ms ago)
> 2023-01-26T16:44:37.322Z|00111|vconn|DBG|unix#8: received: OFPT_FLOW_MOD (xid=0x6): DEL actions=drop
> 2023-01-26T16:44:37.322Z|00112|vconn|DBG|unix#8: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2023-01-26T16:44:37.322Z|00113|vconn|DBG|unix#8: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2023-01-26T16:44:37.428Z|00002|dpif_netlink(handler1)|WARN|system@ovs-system: lost packet on port channel 2 of handler 0 (last polled 0 ms ago)
> 2023-01-26T16:44:37.526Z|00114|connmgr|INFO|br0<->unix#8: 1 flow_mods in the last 0 s (1 deletes)
> 2023-01-26T16:44:37.528Z|00115|vconn|DBG|unix#9: sent (Success): OFPT_HELLO (OF1.5) (xid=0xa):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.528Z|00116|vconn|DBG|unix#9: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.528Z|00117|vconn|DBG|unix#9: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.528Z|00118|vconn|DBG|unix#9: received: OFPST_TABLE request (xid=0x2):
> 2023-01-26T16:44:37.528Z|00119|vconn|DBG|unix#9: sent (Success): OFPST_TABLE reply (xid=0x2):
>   table 0:
>     active=0, lookup=225928, matched=153998
>     max_entries=1000000
>     matching:
>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
> 
>   table 1:
>     active=0, lookup=0, matched=0
>     (same features)
> 
>   tables 2...253: ditto
> 2023-01-26T16:44:37.528Z|00120|vconn|DBG|unix#10: sent (Success): OFPT_HELLO (OF1.5) (xid=0xb):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.528Z|00121|vconn|DBG|unix#10: received: OFPT_HELLO (xid=0x3):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.528Z|00122|vconn|DBG|unix#10: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.528Z|00123|vconn|DBG|unix#10: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2023-01-26T16:44:37.528Z|00124|vconn|DBG|unix#10: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:000016215abb444a
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>  1(at_gre0): addr:a2:f9:64:45:eb:65
>      config:     0
>      state:      0
>      speed: 0 Mbps now, 0 Mbps max
>  2(ovs-p1): addr:32:68:ed:0f:cc:60
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  3(ovs-p2): addr:0e:8a:4c:65:90:6c
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  4(p2): addr:8e:57:dd:84:91:3f
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  LOCAL(br0): addr:16:21:5a:bb:44:4a
>      config:     0
>      state:      0
>      speed: 0 Mbps now, 0 Mbps max
> 2023-01-26T16:44:37.528Z|00125|vconn|DBG|unix#11: sent (Success): OFPT_HELLO (OF1.5) (xid=0xc):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.528Z|00126|vconn|DBG|unix#11: received: OFPT_HELLO (xid=0x5):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.528Z|00127|vconn|DBG|unix#11: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.528Z|00128|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0x6): ADD priority=99,in_port=1 actions=output(port=2,max_len=100),output(port=3,max_len=100)
> 2023-01-26T16:44:37.529Z|00129|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2023-01-26T16:44:37.529Z|00130|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2023-01-26T16:44:37.529Z|00131|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0x8): ADD priority=99,udp,in_port=2 actions=output(port=1,max_len=100)
> 2023-01-26T16:44:37.529Z|00132|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0x9):
> 2023-01-26T16:44:37.529Z|00133|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0x9):
> 2023-01-26T16:44:37.529Z|00134|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0xa): ADD priority=1,ip,in_port=4 actions=drop
> 2023-01-26T16:44:37.529Z|00135|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0xb):
> 2023-01-26T16:44:37.529Z|00136|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0xb):
> 2023-01-26T16:44:37.529Z|00137|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0xc): ADD priority=1 actions=drop
> 2023-01-26T16:44:37.529Z|00138|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0xd):
> 2023-01-26T16:44:37.529Z|00139|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0xd):
> 2023-01-26T16:44:37.529Z|00140|connmgr|INFO|br0<->unix#11: 4 flow_mods in the last 0 s (4 adds)
> 2023-01-26T16:44:37.531Z|00141|vconn|DBG|unix#12: sent (Success): OFPT_HELLO (OF1.5) (xid=0xd):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.531Z|00142|vconn|DBG|unix#12: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.531Z|00143|vconn|DBG|unix#12: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.531Z|00144|vconn|DBG|unix#12: received: OFPST_TABLE request (xid=0x2):
> 2023-01-26T16:44:37.532Z|00145|vconn|DBG|unix#12: sent (Success): OFPST_TABLE reply (xid=0x2):
>   table 0:
>     active=1, lookup=79377, matched=79377
>     max_entries=1000000
>     matching:
>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
> 
>   table 1:
>     active=0, lookup=0, matched=0
>     (same features)
> 
>   tables 2...253: ditto
> 2023-01-26T16:44:37.532Z|00146|vconn|DBG|unix#13: sent (Success): OFPT_HELLO (OF1.5) (xid=0xe):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.532Z|00147|vconn|DBG|unix#13: received: OFPT_HELLO (xid=0x3):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.532Z|00148|vconn|DBG|unix#13: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.532Z|00149|vconn|DBG|unix#13: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2023-01-26T16:44:37.532Z|00150|vconn|DBG|unix#13: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:00002a96e384084e
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>  1(ovs-p0): addr:1e:12:f0:27:f1:79
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  LOCAL(br-underlay): addr:2a:96:e3:84:08:4e
>      config:     0
>      state:      0
>      speed: 0 Mbps now, 0 Mbps max
> 2023-01-26T16:44:37.532Z|00151|vconn|DBG|unix#14: sent (Success): OFPT_HELLO (OF1.5) (xid=0xf):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.532Z|00152|vconn|DBG|unix#14: received: OFPT_HELLO (xid=0x5):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.532Z|00153|vconn|DBG|unix#14: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.532Z|00154|vconn|DBG|unix#14: received: OFPT_FLOW_MOD (xid=0x6): DEL actions=drop
> 2023-01-26T16:44:37.532Z|00155|vconn|DBG|unix#14: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2023-01-26T16:44:37.532Z|00156|vconn|DBG|unix#14: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2023-01-26T16:44:37.720Z|00157|connmgr|INFO|br-underlay<->unix#14: 1 flow_mods in the last 0 s (1 deletes)
> 2023-01-26T16:44:37.721Z|00158|vconn|DBG|unix#15: sent (Success): OFPT_HELLO (OF1.5) (xid=0x10):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.721Z|00159|vconn|DBG|unix#15: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.721Z|00160|vconn|DBG|unix#15: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.721Z|00161|vconn|DBG|unix#15: received: OFPST_TABLE request (xid=0x2):
> 2023-01-26T16:44:37.723Z|00162|vconn|DBG|unix#15: sent (Success): OFPST_TABLE reply (xid=0x2):
>   table 0:
>     active=0, lookup=79377, matched=79377
>     max_entries=1000000
>     matching:
>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
> 
>   table 1:
>     active=0, lookup=0, matched=0
>     (same features)
> 
>   tables 2...253: ditto
> 2023-01-26T16:44:37.724Z|00163|vconn|DBG|unix#16: sent (Success): OFPT_HELLO (OF1.5) (xid=0x11):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.724Z|00164|vconn|DBG|unix#16: received: OFPT_HELLO (xid=0x3):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.724Z|00165|vconn|DBG|unix#16: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.724Z|00166|vconn|DBG|unix#16: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2023-01-26T16:44:37.725Z|00167|vconn|DBG|unix#16: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:00002a96e384084e
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>  1(ovs-p0): addr:1e:12:f0:27:f1:79
>      config:     0
>      state:      0
>      current:    10GB-FD COPPER
>      speed: 10000 Mbps now, 0 Mbps max
>  LOCAL(br-underlay): addr:2a:96:e3:84:08:4e
>      config:     0
>      state:      0
>      speed: 0 Mbps now, 0 Mbps max
> 2023-01-26T16:44:37.726Z|00168|vconn|DBG|unix#17: sent (Success): OFPT_HELLO (OF1.5) (xid=0x12):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:37.726Z|00169|vconn|DBG|unix#17: received: OFPT_HELLO (xid=0x5):
>  version bitmap: 0x01
> 2023-01-26T16:44:37.726Z|00170|vconn|DBG|unix#17: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:37.726Z|00171|vconn|DBG|unix#17: received: OFPT_FLOW_MOD (xid=0x6): ADD priority=99,ip,in_port=1,nw_proto=47 actions=LOCAL
> 2023-01-26T16:44:37.727Z|00172|vconn|DBG|unix#17: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2023-01-26T16:44:37.727Z|00173|vconn|DBG|unix#17: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2023-01-26T16:44:37.807Z|00174|vconn|DBG|unix#17: received: OFPT_FLOW_MOD (xid=0x8): ADD priority=99,ip,in_port=LOCAL,nw_dst=172.31.1.0/24,nw_proto=47 actions=output:1
> 2023-01-26T16:44:37.807Z|00175|vconn|DBG|unix#17: received: OFPT_BARRIER_REQUEST (xid=0x9):
> 2023-01-26T16:44:37.807Z|00176|vconn|DBG|unix#17: sent (Success): OFPT_BARRIER_REPLY (xid=0x9):
> 2023-01-26T16:44:37.808Z|00177|vconn|DBG|unix#17: received: OFPT_FLOW_MOD (xid=0xa): ADD priority=1 actions=drop
> 2023-01-26T16:44:37.808Z|00178|vconn|DBG|unix#17: received: OFPT_BARRIER_REQUEST (xid=0xb):
> 2023-01-26T16:44:37.809Z|00179|vconn|DBG|unix#17: sent (Success): OFPT_BARRIER_REPLY (xid=0xb):
> 2023-01-26T16:44:37.850Z|00180|connmgr|INFO|br-underlay<->unix#17: 3 flow_mods in the last 0 s (3 adds)
> 2023-01-26T16:44:40.839Z|00181|unixctl|DBG|received request revalidator/purge[], id=0
> 2023-01-26T16:44:40.991Z|00001|dpif(revalidator9)|WARN|system@ovs-system: failed to flow_get (No such file or directory) ufid:36468b48-f637-4680-820e-67d0e80cb6f3 <empty>, packets:0, bytes:0, used:never
> 2023-01-26T16:44:40.992Z|00002|ofproto_dpif_upcall(revalidator9)|WARN|Failed to acquire udpif_key corresponding to unexpected flow (No such file or directory): ufid:36468b48-f637-4680-820e-67d0e80cb6f3
> 2023-01-26T16:44:40.992Z|00003|dpif(revalidator9)|WARN|system@ovs-system: failed to flow_get (No such file or directory) ufid:b6c69a20-4978-4923-89d9-17f32746ab9e <empty>, packets:0, bytes:0, used:never
> 2023-01-26T16:44:40.992Z|00004|ofproto_dpif_upcall(revalidator9)|WARN|Failed to acquire udpif_key corresponding to unexpected flow (No such file or directory): ufid:b6c69a20-4978-4923-89d9-17f32746ab9e
> 2023-01-26T16:44:41.083Z|00182|unixctl|DBG|replying with success, id=0: ""
> 2023-01-26T16:44:41.094Z|00183|vconn|DBG|unix#19: sent (Success): OFPT_HELLO (OF1.5) (xid=0x13):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:41.094Z|00184|vconn|DBG|unix#19: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:41.094Z|00185|vconn|DBG|unix#19: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:41.094Z|00186|vconn|DBG|unix#19: received: NXT_SET_FLOW_FORMAT (xid=0x2): format=nxm
> 2023-01-26T16:44:41.094Z|00187|vconn|DBG|unix#19: received: OFPT_BARRIER_REQUEST (xid=0x3):
> 2023-01-26T16:44:41.094Z|00188|vconn|DBG|unix#19: sent (Success): OFPT_BARRIER_REPLY (xid=0x3):
> 2023-01-26T16:44:41.094Z|00189|vconn|DBG|unix#19: received: NXST_FLOW request (xid=0x4):
> 2023-01-26T16:44:41.094Z|00190|vconn|DBG|unix#19: sent (Success): NXST_FLOW reply (xid=0x4):
>  cookie=0x0, duration=3.565s, table=0, n_packets=3, n_bytes=250, idle_age=2, priority=99,in_port=1 actions=output(port=2,max_len=100),output(port=3,max_len=100)
>  cookie=0x0, duration=3.565s, table=0, n_packets=1, n_bytes=242, idle_age=3, priority=99,udp,in_port=2 actions=output(port=1,max_len=100)
>  cookie=0x0, duration=3.565s, table=0, n_packets=0, n_bytes=0, idle_age=3, priority=1,ip,in_port=4 actions=drop
>  cookie=0x0, duration=3.566s, table=0, n_packets=73, n_bytes=11575, idle_age=0, priority=1 actions=drop
> 2023-01-26T16:44:41.100Z|00191|vconn|DBG|unix#20: sent (Success): OFPT_HELLO (OF1.5) (xid=0x14):
>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2023-01-26T16:44:41.100Z|00192|vconn|DBG|unix#20: received: OFPT_HELLO (xid=0x1):
>  version bitmap: 0x01
> 2023-01-26T16:44:41.100Z|00193|vconn|DBG|unix#20: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2023-01-26T16:44:41.100Z|00194|vconn|DBG|unix#20: received: NXT_SET_FLOW_FORMAT (xid=0x2): format=nxm
> 2023-01-26T16:44:41.100Z|00195|vconn|DBG|unix#20: received: OFPT_BARRIER_REQUEST (xid=0x3):
> 2023-01-26T16:44:41.100Z|00196|vconn|DBG|unix#20: sent (Success): OFPT_BARRIER_REPLY (xid=0x3):
> 2023-01-26T16:44:41.100Z|00197|vconn|DBG|unix#20: received: NXST_FLOW request (xid=0x4):
> 2023-01-26T16:44:41.100Z|00198|vconn|DBG|unix#20: sent (Success): NXST_FLOW reply (xid=0x4):
>  cookie=0x0, duration=3.373s, table=0, n_packets=3, n_bytes=364, idle_age=2, priority=99,ip,in_port=1,nw_proto=47 actions=LOCAL
>  cookie=0x0, duration=3.293s, table=0, n_packets=18446744073709511148, n_bytes=18446744073703563162, idle_age=3, priority=99,ip,in_port=LOCAL,nw_dst=172.31.1.0/24,nw_proto=47 actions=output:1
>  cookie=0x0, duration=3.291s, table=0, n_packets=20, n_bytes=3265, idle_age=0, priority=1 actions=drop
2023-01-26T16:44:41Z|00001|daemon_unix|WARN|/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.pid: open: No such file or directory
ovs-appctl: cannot read pidfile "/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.pid" (No such file or directory)
ovs-dpctl: opening datapath (No such device)
51. system-traffic.at:1768:  FAILED (system-traffic.at:1838)

## ------------- ##
## Test results. ##
## ------------- ##

ERROR: All 2 tests were run,
2 failed unexpectedly.
## ------------------------------------------ ##
## system-offloads-testsuite.log was created. ##
## ------------------------------------------ ##

Please send `tests/system-offloads-testsuite.log' and all information you think might help:

   To: <bugs@openvswitch.org>
   Subject: [openvswitch 3.1.90] system-offloads-testsuite: 50 51 failed

You may investigate any problem if you feel able to do so, in which
case the test suite provides a good starting point.  Its output may
be found below `tests/system-offloads-testsuite.dir'.

make: *** [Makefile:7042: check-offloads] Fout 1
Eelco Chaudron Jan. 26, 2023, 5:21 p.m. UTC | #2 
On 26 Jan 2023, at 17:58, Simon Horman wrote:

> On Tue, Jan 24, 2023 at 02:01:19PM +0100, Eelco Chaudron wrote:
>> With some datapaths, read TC, it takes a bit longer to update the
>> OpenFlow statistics. Rather than adding an additional delay, try
>> to read the counters multiple times until we get the desired value.
>>
>> Signed-off-by: Eelco Chaudron <echaudro@redhat.com>
>> Acked-by: Roi Dayan <roid@nvidia.com>
>
> When, possibly unwisely, running this test on my laptop,
> with a somewhat old kernel the tests fail with absurd byte counts.
> I haven't had time to dig into why.

I noticed this happens sometimes, and I excluded this test from the total set in the last patch :)

However, I also fixed some counter issues recently which fixed it in my setup:

https://patchwork.ozlabs.org/project/openvswitch/patch/167361458369.1145547.15786262052264455216.stgit@ebuild/

Can you try this?

//Eelco

> $ uname -spv
> Linux #1 SMP Debian 5.10.158-2 (2022-12-13) unknown
>
> The first test appears to fail with n_bytes=18446744073709159596
> And the second, with n_bytes=18446744073703563162
>
> Log follows:
>
> make  all-am
> make[1]: Map '/home/horms/projects/openvswitch/ovs' wordt binnengegaan
> make[1]: Map '/home/horms/projects/openvswitch/ovs' wordt verlaten
> set /bin/bash './tests/system-offloads-testsuite' -C tests  AUTOTEST_PATH='utilities:vswitchd:ovsdb:vtep:tests:ipsec::'; \
> "$@" -k "datapath - truncate and output" -v -j1 || (test X'' = Xyes && "$@" --recheck)
> Illegal "police"
> ## ------------------------------ ##
> ## openvswitch 3.1.90 test suite. ##
> ## ------------------------------ ##
>
> datapath-sanity
>
> 50. system-traffic.at:1639: testing datapath - truncate and output to gre tunnel by simulated packets ...
> ./system-traffic.at:1642: modprobe openvswitch
> Module vport_lisp not loaded.
> Module vport_stt not loaded.
> ./system-traffic.at:1642: ovsdb-tool create conf.db $abs_top_srcdir/vswitchd/vswitch.ovsschema
> ./system-traffic.at:1642: ovsdb-server --detach --no-chdir --pidfile --log-file --remote=punix:$OVS_RUNDIR/db.sock
> stderr:
> 2023-01-26T16:43:57Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovsdb-server.log
> ./system-traffic.at:1642: sed < stderr '
> /vlog|INFO|opened log file/d
> /ovsdb_server|INFO|ovsdb-server (Open vSwitch)/d'
> ./system-traffic.at:1642: ovs-vsctl --no-wait init -- set Open_vSwitch . other_config:hw-offload=true
>
> ./system-traffic.at:1642: ovs-vswitchd  --detach --no-chdir --pidfile --log-file -vvconn -vofproto_dpif -vunixctl
> stderr:
> 2023-01-26T16:43:57Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovs-vswitchd.log
> 2023-01-26T16:43:57Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
> 2023-01-26T16:43:57Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
> 2023-01-26T16:43:57Z|00004|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/db.sock: connecting...
> 2023-01-26T16:43:57Z|00005|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/db.sock: connected
> 2023-01-26T16:43:57Z|00006|netdev_offload|INFO|netdev: Flow API Enabled
> 2023-01-26T16:43:57Z|00007|tc|INFO|tc: Using policy 'none'
> ./system-traffic.at:1642: sed < stderr '
> /ovs_numa|INFO|Discovered /d
> /odp_execute_impl|INFO|Action implementation /d
> /vlog|INFO|opened log file/d
> /vswitchd|INFO|ovs-vswitchd (Open vSwitch)/d
> /reconnect|INFO|/d
> /dpif_netlink|INFO|Generic Netlink family .ovs_datapath. does not exist/d
> /ofproto|INFO|using datapath ID/d
> /netdev_linux|INFO|.*device has unknown hardware address family/d
> /ofproto|INFO|datapath ID changed to fedcba9876543210/d
> /dpdk|INFO|DPDK Disabled - Use other_config:dpdk-init to enable/d
> /netlink_socket|INFO|netlink: could not enable listening to all nsid/d
> /netdev_offload|INFO|netdev: Flow API Enabled/d
> /probe tc:/d
> /setting extended ack support failed/d
> /tc: Using policy/d'
> ./system-traffic.at:1642: ovs-vsctl -- add-br br0 -- set Bridge br0 protocols=OpenFlow10,OpenFlow11,OpenFlow12,OpenFlow13,OpenFlow14,OpenFlow15 fail-mode=secure  --
> Cannot remove namespace file "/run/netns/at_ns0": No such file or directory
> ./system-traffic.at:1645: ip netns add at_ns0 || return 77
> net.netfilter.nf_conntrack_helper = 0
> Cannot remove namespace file "/run/netns/at_ns1": No such file or directory
> ./system-traffic.at:1646: ip netns add at_ns1 || return 77
> net.netfilter.nf_conntrack_helper = 0
> ./system-traffic.at:1647: ovs-ofctl add-flow br0 "actions=normal"
> ./system-traffic.at:1648: ovs-ofctl add-flow br-underlay "actions=normal"
> ./system-traffic.at:1651: ip link add p0 type veth peer name ovs-p0 || return 77
> ./system-traffic.at:1651: ip link set p0 netns at_ns0
> ./system-traffic.at:1651: ip link set dev ovs-p0 up
> ./system-traffic.at:1651: ovs-vsctl add-port br-underlay ovs-p0 -- \
>                 set interface ovs-p0 external-ids:iface-id="p0"
> ./system-traffic.at:1651: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip addr add "172.31.1.1/24" dev p0
> NS_EXEC_HEREDOC
> ./system-traffic.at:1651: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip link set dev p0 up
> NS_EXEC_HEREDOC
> ./system-traffic.at:1651: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip link set dev p0 address fa:ad:fa:25:05:60
> NS_EXEC_HEREDOC
> ./system-traffic.at:1652: ip addr add dev br-underlay "172.31.1.100/24"
> ./system-traffic.at:1653: ip link set dev br-underlay up
> ./system-traffic.at:1657: ovs-vsctl add-port br0 at_gre0 -- \
>               set int at_gre0 type=gre options:remote_ip=172.31.1.1
> ./system-traffic.at:1657: ip addr add dev br0 10.1.1.100/24
> ./system-traffic.at:1657: ip link set dev br0 up
> ./system-traffic.at:1657: ip link set dev br0 mtu 1450
> ./system-traffic.at:1667: ip link add p1 type veth peer name ovs-p1 || return 77
> ./system-traffic.at:1667: ip link set p1 netns at_ns1
> ./system-traffic.at:1667: ip link set dev ovs-p1 up
> ./system-traffic.at:1667: ovs-vsctl add-port br0 ovs-p1 -- \
>                 set interface ovs-p1 external-ids:iface-id="p1"
> ./system-traffic.at:1667: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> ip addr add '10.1.1.2/24' dev p1
> NS_EXEC_HEREDOC
> ./system-traffic.at:1667: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> ip link set dev p1 up
> NS_EXEC_HEREDOC
> ./system-traffic.at:1668: ovs-vsctl -- set interface ovs-p1 ofport_request=2
> ./system-traffic.at:1669: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> ip link set dev p1 address e6:66:c1:22:22:22
> NS_EXEC_HEREDOC
> ./system-traffic.at:1670: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> arp -s 10.1.1.1 e6:66:c1:11:11:11
> NS_EXEC_HEREDOC
> ./system-traffic.at:1673: ip link add p2 type veth peer name ovs-p2
> ./system-traffic.at:1675: ip link set dev ovs-p2 up
> ./system-traffic.at:1676: ip link set dev p2 up
> ./system-traffic.at:1677: ovs-vsctl add-port br0 ovs-p2 -- set interface ovs-p2 ofport_request=3
> ./system-traffic.at:1678: ovs-vsctl add-port br0 p2 -- set interface p2 ofport_request=4
> ./system-traffic.at:1681: dd if=/dev/urandom of=payload200.bin bs=200 count=1 2> /dev/null
> ./system-traffic.at:1684: ovs-ofctl del-flows br0
> ./system-traffic.at:1691: ovs-ofctl add-flows br0 flows.txt
> ./system-traffic.at:1693: ovs-ofctl del-flows br-underlay
> ./system-traffic.at:1700: ovs-ofctl add-flows br-underlay flows-underlay.txt
> ./system-traffic.at:1703: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> nc $NC_EOF_OPT -u 10.1.1.1 1234 < payload200.bin
> NS_EXEC_HEREDOC
> ./system-traffic.at:1704: sleep 2; ovs-appctl revalidator/purge
> ./system-traffic.at:1707: ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p'
> system-traffic.at:1711: waiting until ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p' | grep "n_bytes=138"...
> system-traffic.at:1711: wait failed after 30 seconds
> n_bytes=18446744073709159596
> ./ovs-macros.at:247: hard failure
> 2023-01-26T16:44:33Z|00001|daemon_unix|WARN|/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovs-vswitchd.pid: open: No such file or directory
> ovs-appctl: cannot read pidfile "/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/050/ovs-vswitchd.pid" (No such file or directory)
> ovs-dpctl: opening datapath (No such device)
> 50. system-traffic.at:1639:  FAILED (ovs-macros.at:247)
>
> 51. system-traffic.at:1768: testing datapath - truncate and output to gre tunnel ...
> ./system-traffic.at:1772: modprobe openvswitch
> Module vport_lisp not loaded.
> Module vport_stt not loaded.
> ./system-traffic.at:1772: ovsdb-tool create conf.db $abs_top_srcdir/vswitchd/vswitch.ovsschema
> ./system-traffic.at:1772: ovsdb-server --detach --no-chdir --pidfile --log-file --remote=punix:$OVS_RUNDIR/db.sock
> stderr:
> 2023-01-26T16:44:35Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovsdb-server.log
> ./system-traffic.at:1772: sed < stderr '
> /vlog|INFO|opened log file/d
> /ovsdb_server|INFO|ovsdb-server (Open vSwitch)/d'
> ./system-traffic.at:1772: ovs-vsctl --no-wait init -- set Open_vSwitch . other_config:hw-offload=true
>
> ./system-traffic.at:1772: ovs-vswitchd  --detach --no-chdir --pidfile --log-file -vvconn -vofproto_dpif -vunixctl
> stderr:
> 2023-01-26T16:44:35Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.log
> 2023-01-26T16:44:35Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
> 2023-01-26T16:44:35Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
> 2023-01-26T16:44:35Z|00004|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connecting...
> 2023-01-26T16:44:35Z|00005|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connected
> 2023-01-26T16:44:35Z|00006|netdev_offload|INFO|netdev: Flow API Enabled
> 2023-01-26T16:44:35Z|00007|tc|INFO|tc: Using policy 'none'
> ./system-traffic.at:1772: sed < stderr '
> /ovs_numa|INFO|Discovered /d
> /odp_execute_impl|INFO|Action implementation /d
> /vlog|INFO|opened log file/d
> /vswitchd|INFO|ovs-vswitchd (Open vSwitch)/d
> /reconnect|INFO|/d
> /dpif_netlink|INFO|Generic Netlink family .ovs_datapath. does not exist/d
> /ofproto|INFO|using datapath ID/d
> /netdev_linux|INFO|.*device has unknown hardware address family/d
> /ofproto|INFO|datapath ID changed to fedcba9876543210/d
> /dpdk|INFO|DPDK Disabled - Use other_config:dpdk-init to enable/d
> /netlink_socket|INFO|netlink: could not enable listening to all nsid/d
> /netdev_offload|INFO|netdev: Flow API Enabled/d
> /probe tc:/d
> /setting extended ack support failed/d
> /tc: Using policy/d'
> ./system-traffic.at:1772: ovs-vsctl -- add-br br0 -- set Bridge br0 protocols=OpenFlow10,OpenFlow11,OpenFlow12,OpenFlow13,OpenFlow14,OpenFlow15 fail-mode=secure  --
> Cannot remove namespace file "/run/netns/at_ns0": No such file or directory
> ./system-traffic.at:1775: ip netns add at_ns0 || return 77
> net.netfilter.nf_conntrack_helper = 0
> Cannot remove namespace file "/run/netns/at_ns1": No such file or directory
> ./system-traffic.at:1776: ip netns add at_ns1 || return 77
> net.netfilter.nf_conntrack_helper = 0
> ./system-traffic.at:1777: ovs-ofctl add-flow br0 "actions=normal"
> ./system-traffic.at:1778: ovs-ofctl add-flow br-underlay "actions=normal"
> ./system-traffic.at:1781: ip link add p0 type veth peer name ovs-p0 || return 77
> ./system-traffic.at:1781: ip link set p0 netns at_ns0
> ./system-traffic.at:1781: ip link set dev ovs-p0 up
> ./system-traffic.at:1781: ovs-vsctl add-port br-underlay ovs-p0 -- \
>                 set interface ovs-p0 external-ids:iface-id="p0"
> ./system-traffic.at:1781: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip addr add "172.31.1.1/24" dev p0
> NS_EXEC_HEREDOC
> ./system-traffic.at:1781: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip link set dev p0 up
> NS_EXEC_HEREDOC
> ./system-traffic.at:1782: ip addr add dev br-underlay "172.31.1.100/24"
> ./system-traffic.at:1783: ip link set dev br-underlay up
> ./system-traffic.at:1787: ovs-vsctl add-port br0 at_gre0 -- \
>               set int at_gre0 type=gre options:remote_ip=172.31.1.1
> ./system-traffic.at:1787: ip addr add dev br0 10.1.1.100/24
> ./system-traffic.at:1787: ip link set dev br0 up
> ./system-traffic.at:1787: ip link set dev br0 mtu 1450
> ./system-traffic.at:1788: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip link add dev ns_gre0 type gretap remote 172.31.1.100
> NS_EXEC_HEREDOC
> ./system-traffic.at:1788: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip addr add dev ns_gre0 10.1.1.1/24
> NS_EXEC_HEREDOC
> ./system-traffic.at:1788: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> ip link set dev ns_gre0 mtu 1450 address e6:66:c1:11:11:11 up
> NS_EXEC_HEREDOC
> ./system-traffic.at:1790: ovs-vsctl -- set interface at_gre0 ofport_request=1
> ./system-traffic.at:1791: ip netns exec at_ns0 sh << NS_EXEC_HEREDOC
> arp -s 10.1.1.2 e6:66:c1:22:22:22
> NS_EXEC_HEREDOC
> ./system-traffic.at:1794: ip link add p1 type veth peer name ovs-p1 || return 77
> ./system-traffic.at:1794: ip link set p1 netns at_ns1
> ./system-traffic.at:1794: ip link set dev ovs-p1 up
> ./system-traffic.at:1794: ovs-vsctl add-port br0 ovs-p1 -- \
>                 set interface ovs-p1 external-ids:iface-id="p1"
> ./system-traffic.at:1794: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> ip addr add '10.1.1.2/24' dev p1
> NS_EXEC_HEREDOC
> ./system-traffic.at:1794: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> ip link set dev p1 up
> NS_EXEC_HEREDOC
> ./system-traffic.at:1795: ovs-vsctl -- set interface ovs-p1 ofport_request=2
> ./system-traffic.at:1796: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> ip link set dev p1 address e6:66:c1:22:22:22
> NS_EXEC_HEREDOC
> ./system-traffic.at:1797: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> arp -s 10.1.1.1 e6:66:c1:11:11:11
> NS_EXEC_HEREDOC
> ./system-traffic.at:1800: ip link add p2 type veth peer name ovs-p2
> ./system-traffic.at:1802: ip link set dev ovs-p2 up
> ./system-traffic.at:1803: ip link set dev p2 up
> ./system-traffic.at:1804: ovs-vsctl add-port br0 ovs-p2 -- set interface ovs-p2 ofport_request=3
> ./system-traffic.at:1805: ovs-vsctl add-port br0 p2 -- set interface p2 ofport_request=4
> ./system-traffic.at:1808: dd if=/dev/urandom of=payload200.bin bs=200 count=1 2> /dev/null
> ./system-traffic.at:1811: ovs-ofctl del-flows br0
> ./system-traffic.at:1818: ovs-ofctl add-flows br0 flows.txt
> ./system-traffic.at:1820: ovs-ofctl del-flows br-underlay
> ./system-traffic.at:1827: ovs-ofctl add-flows br-underlay flows-underlay.txt
> ./system-traffic.at:1830: ip netns exec at_ns1 sh << NS_EXEC_HEREDOC
> nc $NC_EOF_OPT -u 10.1.1.1 1234 < payload200.bin
> NS_EXEC_HEREDOC
> ./system-traffic.at:1831: sleep 2; ovs-appctl revalidator/purge
> ./system-traffic.at:1834: ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p'
> ./system-traffic.at:1838: ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[0-9]*\).*/\1/p'
> --- -	2023-01-26 17:44:41.102671600 +0100
> +++ /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/at-groups/51/stdout	2023-01-26 17:44:41.098239330 +0100
> @@ -1,2 +1,2 @@
> -n_bytes=138
> +n_bytes=18446744073703563162
>
> ovsdb-server.log:
>> 2023-01-26T16:44:35.719Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovsdb-server.log
>> 2023-01-26T16:44:35.748Z|00002|ovsdb_server|INFO|ovsdb-server (Open vSwitch) 3.1.90
> ovs-vswitchd.log:
>> 2023-01-26T16:44:35.760Z|00001|vlog|INFO|opened log file /home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.log
>> 2023-01-26T16:44:35.761Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
>> 2023-01-26T16:44:35.761Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
>> 2023-01-26T16:44:35.761Z|00004|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connecting...
>> 2023-01-26T16:44:35.761Z|00005|reconnect|INFO|unix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/db.sock: connected
>> 2023-01-26T16:44:35.763Z|00006|netdev_offload|INFO|netdev: Flow API Enabled
>> 2023-01-26T16:44:35.763Z|00007|tc|INFO|tc: Using policy 'none'
>> 2023-01-26T16:44:35.765Z|00008|bridge|INFO|ovs-vswitchd (Open vSwitch) 3.1.90
>> 2023-01-26T16:44:35.775Z|00009|dpif_netlink|INFO|Datapath dispatch mode: per-vport
>> 2023-01-26T16:44:35.851Z|00010|netdev_offload_tc|INFO|probe tc: block offload is supported.
>> 2023-01-26T16:44:35.895Z|00011|netdev_offload_tc|INFO|probe tc: multiple masks on single tc prio is supported.
>> 2023-01-26T16:44:36.055Z|00012|netdev_offload_tc|INFO|probe tc: supported ovs ct_state bits: 0x27
>> 2023-01-26T16:44:36.055Z|00013|netdev_offload_tc|INFO|added ingress qdisc to ovs-system
>> 2023-01-26T16:44:36.055Z|00014|netdev_offload|INFO|ovs-system: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.056Z|00015|ofproto_dpif|INFO|system@ovs-system: Datapath supports recirculation
>> 2023-01-26T16:44:36.056Z|00016|ofproto_dpif|INFO|system@ovs-system: VLAN header stack length probed as 2
>> 2023-01-26T16:44:36.056Z|00017|ofproto_dpif|INFO|system@ovs-system: MPLS label stack length probed as 3
>> 2023-01-26T16:44:36.056Z|00018|ofproto_dpif|INFO|system@ovs-system: Datapath supports truncate action
>> 2023-01-26T16:44:36.056Z|00019|ofproto_dpif|INFO|system@ovs-system: Datapath supports unique flow ids
>> 2023-01-26T16:44:36.056Z|00020|ofproto_dpif|INFO|system@ovs-system: Datapath supports clone action
>> 2023-01-26T16:44:36.057Z|00021|ofproto_dpif|INFO|system@ovs-system: Max sample nesting level probed as 10
>> 2023-01-26T16:44:36.057Z|00022|ofproto_dpif|INFO|system@ovs-system: Datapath supports eventmask in conntrack action
>> 2023-01-26T16:44:36.057Z|00023|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_clear action
>> 2023-01-26T16:44:36.057Z|00024|ofproto_dpif|INFO|system@ovs-system: Max dp_hash algorithm probed to be 0
>> 2023-01-26T16:44:36.057Z|00025|ofproto_dpif|INFO|system@ovs-system: Datapath supports check_pkt_len action
>> 2023-01-26T16:44:36.057Z|00026|ofproto_dpif|INFO|system@ovs-system: Datapath supports timeout policy in conntrack action
>> 2023-01-26T16:44:36.057Z|00027|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_zero_snat
>> 2023-01-26T16:44:36.057Z|00028|ofproto_dpif|INFO|system@ovs-system: Datapath supports add_mpls action
>> 2023-01-26T16:44:36.057Z|00029|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_state
>> 2023-01-26T16:44:36.058Z|00030|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_zone
>> 2023-01-26T16:44:36.058Z|00031|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_mark
>> 2023-01-26T16:44:36.058Z|00032|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_label
>> 2023-01-26T16:44:36.058Z|00033|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_state_nat
>> 2023-01-26T16:44:36.058Z|00034|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_orig_tuple
>> 2023-01-26T16:44:36.058Z|00035|ofproto_dpif|INFO|system@ovs-system: Datapath supports ct_orig_tuple6
>> 2023-01-26T16:44:36.058Z|00036|ofproto_dpif|INFO|system@ovs-system: Datapath does not support IPv6 ND Extensions
>> 2023-01-26T16:44:36.058Z|00037|ofproto_dpif_upcall|INFO|Setting n-handler-threads to 5, setting n-revalidator-threads to 3
>> 2023-01-26T16:44:36.058Z|00038|ofproto_dpif_upcall|INFO|Starting 8 threads
>> 2023-01-26T16:44:36.072Z|00039|netdev_offload_tc|INFO|added ingress qdisc to br0
>> 2023-01-26T16:44:36.072Z|00040|netdev_offload|INFO|br0: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.072Z|00041|bridge|INFO|bridge br0: added interface br0 on port 65534
>> 2023-01-26T16:44:36.073Z|00042|bridge|INFO|bridge br0: using datapath ID 000016215abb444a
>> 2023-01-26T16:44:36.073Z|00043|connmgr|INFO|br0: added service controller "punix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/br0.mgmt"
>> 2023-01-26T16:44:36.106Z|00044|netdev_offload_tc|INFO|added ingress qdisc to br-underlay
>> 2023-01-26T16:44:36.106Z|00045|netdev_offload|INFO|br-underlay: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.106Z|00046|bridge|INFO|bridge br-underlay: added interface br-underlay on port 65534
>> 2023-01-26T16:44:36.107Z|00047|bridge|INFO|bridge br-underlay: using datapath ID 00002a96e384084e
>> 2023-01-26T16:44:36.107Z|00048|connmgr|INFO|br-underlay: added service controller "punix:/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/br-underlay.mgmt"
>> 2023-01-26T16:44:36.147Z|00049|vconn|DBG|unix#0: sent (Success): OFPT_HELLO (OF1.5) (xid=0x1):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:36.147Z|00050|vconn|DBG|unix#0: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:36.147Z|00051|vconn|DBG|unix#0: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:36.147Z|00052|vconn|DBG|unix#0: received: OFPST_TABLE request (xid=0x2):
>> 2023-01-26T16:44:36.148Z|00053|vconn|DBG|unix#0: sent (Success): OFPST_TABLE reply (xid=0x2):
>>   table 0:
>>     active=0, lookup=0, matched=0
>>     max_entries=1000000
>>     matching:
>>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>>
>>   tables 1...253: ditto
>> 2023-01-26T16:44:36.148Z|00054|vconn|DBG|unix#1: sent (Success): OFPT_HELLO (OF1.5) (xid=0x2):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:36.148Z|00055|vconn|DBG|unix#1: received: OFPT_HELLO (xid=0x3):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:36.148Z|00056|vconn|DBG|unix#1: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:36.148Z|00057|vconn|DBG|unix#1: received: OFPT_FEATURES_REQUEST (xid=0x4):
>> 2023-01-26T16:44:36.148Z|00058|vconn|DBG|unix#1: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:000016215abb444a
>> n_tables:254, n_buffers:0
>> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
>> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>>  LOCAL(br0): addr:16:21:5a:bb:44:4a
>>      config:     PORT_DOWN
>>      state:      LINK_DOWN
>>      speed: 0 Mbps now, 0 Mbps max
>> 2023-01-26T16:44:36.148Z|00059|vconn|DBG|unix#2: sent (Success): OFPT_HELLO (OF1.5) (xid=0x3):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:36.148Z|00060|vconn|DBG|unix#2: received: OFPT_HELLO (xid=0x5):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:36.148Z|00061|vconn|DBG|unix#2: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:36.148Z|00062|vconn|DBG|unix#2: received: OFPT_FLOW_MOD (xid=0x6): ADD actions=NORMAL
>> 2023-01-26T16:44:36.148Z|00063|vconn|DBG|unix#2: received: OFPT_BARRIER_REQUEST (xid=0x7):
>> 2023-01-26T16:44:36.148Z|00064|vconn|DBG|unix#2: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
>> 2023-01-26T16:44:36.148Z|00065|connmgr|INFO|br0<->unix#2: 1 flow_mods in the last 0 s (1 adds)
>> 2023-01-26T16:44:36.152Z|00066|vconn|DBG|unix#3: sent (Success): OFPT_HELLO (OF1.5) (xid=0x4):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:36.152Z|00067|vconn|DBG|unix#3: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:36.152Z|00068|vconn|DBG|unix#3: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:36.152Z|00069|vconn|DBG|unix#3: received: OFPST_TABLE request (xid=0x2):
>> 2023-01-26T16:44:36.152Z|00070|vconn|DBG|unix#3: sent (Success): OFPST_TABLE reply (xid=0x2):
>>   table 0:
>>     active=0, lookup=0, matched=0
>>     max_entries=1000000
>>     matching:
>>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>>
>>   tables 1...253: ditto
>> 2023-01-26T16:44:36.152Z|00071|vconn|DBG|unix#4: sent (Success): OFPT_HELLO (OF1.5) (xid=0x5):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:36.152Z|00072|vconn|DBG|unix#4: received: OFPT_HELLO (xid=0x3):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:36.152Z|00073|vconn|DBG|unix#4: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:36.152Z|00074|vconn|DBG|unix#4: received: OFPT_FEATURES_REQUEST (xid=0x4):
>> 2023-01-26T16:44:36.153Z|00075|vconn|DBG|unix#4: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:00002a96e384084e
>> n_tables:254, n_buffers:0
>> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
>> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>>  LOCAL(br-underlay): addr:2a:96:e3:84:08:4e
>>      config:     PORT_DOWN
>>      state:      LINK_DOWN
>>      speed: 0 Mbps now, 0 Mbps max
>> 2023-01-26T16:44:36.153Z|00076|vconn|DBG|unix#5: sent (Success): OFPT_HELLO (OF1.5) (xid=0x6):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:36.153Z|00077|vconn|DBG|unix#5: received: OFPT_HELLO (xid=0x5):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:36.153Z|00078|vconn|DBG|unix#5: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:36.153Z|00079|vconn|DBG|unix#5: received: OFPT_FLOW_MOD (xid=0x6): ADD actions=NORMAL
>> 2023-01-26T16:44:36.153Z|00080|vconn|DBG|unix#5: received: OFPT_BARRIER_REQUEST (xid=0x7):
>> 2023-01-26T16:44:36.153Z|00081|vconn|DBG|unix#5: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
>> 2023-01-26T16:44:36.153Z|00082|connmgr|INFO|br-underlay<->unix#5: 1 flow_mods in the last 0 s (1 adds)
>> 2023-01-26T16:44:36.213Z|00083|netdev_offload_tc|INFO|added ingress qdisc to ovs-p0
>> 2023-01-26T16:44:36.213Z|00084|netdev_offload|INFO|ovs-p0: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.213Z|00085|bridge|INFO|bridge br-underlay: added interface ovs-p0 on port 1
>> 2023-01-26T16:44:36.231Z|00086|netdev_offload_tc|INFO|added ingress qdisc to at_gre0
>> 2023-01-26T16:44:36.231Z|00087|netdev_offload|INFO|at_gre0: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.231Z|00088|bridge|INFO|bridge br0: added interface at_gre0 on port 1
>> 2023-01-26T16:44:36.695Z|00089|netdev_offload_tc|INFO|added ingress qdisc to ovs-p1
>> 2023-01-26T16:44:36.695Z|00090|netdev_offload|INFO|ovs-p1: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.695Z|00091|bridge|INFO|bridge br0: added interface ovs-p1 on port 2
>> 2023-01-26T16:44:36.851Z|00092|netdev_offload_tc|INFO|added ingress qdisc to ovs-p2
>> 2023-01-26T16:44:36.851Z|00093|netdev_offload|INFO|ovs-p2: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.851Z|00094|bridge|INFO|bridge br0: added interface ovs-p2 on port 3
>> 2023-01-26T16:44:36.879Z|00095|netdev_offload_tc|INFO|added ingress qdisc to p2
>> 2023-01-26T16:44:36.879Z|00096|netdev_offload|INFO|p2: Assigned flow API 'linux_tc'.
>> 2023-01-26T16:44:36.879Z|00097|bridge|INFO|bridge br0: added interface p2 on port 4
>> 2023-01-26T16:44:36.902Z|00001|ofproto_dpif_upcall(handler1)|INFO|received packet on unassociated datapath port 7 (no OpenFlow port for datapath port 7)
>> 2023-01-26T16:44:37.122Z|00098|vconn|DBG|unix#6: sent (Success): OFPT_HELLO (OF1.5) (xid=0x7):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.122Z|00099|vconn|DBG|unix#6: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.122Z|00100|vconn|DBG|unix#6: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.122Z|00101|vconn|DBG|unix#6: received: OFPST_TABLE request (xid=0x2):
>> 2023-01-26T16:44:37.127Z|00102|vconn|DBG|unix#6: sent (Success): OFPST_TABLE reply (xid=0x2):
>>   table 0:
>>     active=1, lookup=1190, matched=1190
>>     max_entries=1000000
>>     matching:
>>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>>
>>   table 1:
>>     active=0, lookup=0, matched=0
>>     (same features)
>>
>>   tables 2...253: ditto
>> 2023-01-26T16:44:37.206Z|00103|vconn|DBG|unix#7: sent (Success): OFPT_HELLO (OF1.5) (xid=0x8):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.206Z|00104|vconn|DBG|unix#7: received: OFPT_HELLO (xid=0x3):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.206Z|00105|vconn|DBG|unix#7: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.228Z|00106|vconn|DBG|unix#7: received: OFPT_FEATURES_REQUEST (xid=0x4):
>> 2023-01-26T16:44:37.228Z|00107|vconn|DBG|unix#7: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:000016215abb444a
>> n_tables:254, n_buffers:0
>> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
>> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>>  1(at_gre0): addr:a2:f9:64:45:eb:65
>>      config:     0
>>      state:      0
>>      speed: 0 Mbps now, 0 Mbps max
>>  2(ovs-p1): addr:32:68:ed:0f:cc:60
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  3(ovs-p2): addr:0e:8a:4c:65:90:6c
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  4(p2): addr:8e:57:dd:84:91:3f
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  LOCAL(br0): addr:16:21:5a:bb:44:4a
>>      config:     0
>>      state:      0
>>      speed: 0 Mbps now, 0 Mbps max
>> 2023-01-26T16:44:37.282Z|00108|vconn|DBG|unix#8: sent (Success): OFPT_HELLO (OF1.5) (xid=0x9):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.282Z|00109|vconn|DBG|unix#8: received: OFPT_HELLO (xid=0x5):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.283Z|00110|vconn|DBG|unix#8: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.294Z|00001|dpif_netlink(handler5)|WARN|system@ovs-system: lost packet on port channel 2 of handler 3 (last polled 11 ms ago)
>> 2023-01-26T16:44:37.322Z|00111|vconn|DBG|unix#8: received: OFPT_FLOW_MOD (xid=0x6): DEL actions=drop
>> 2023-01-26T16:44:37.322Z|00112|vconn|DBG|unix#8: received: OFPT_BARRIER_REQUEST (xid=0x7):
>> 2023-01-26T16:44:37.322Z|00113|vconn|DBG|unix#8: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
>> 2023-01-26T16:44:37.428Z|00002|dpif_netlink(handler1)|WARN|system@ovs-system: lost packet on port channel 2 of handler 0 (last polled 0 ms ago)
>> 2023-01-26T16:44:37.526Z|00114|connmgr|INFO|br0<->unix#8: 1 flow_mods in the last 0 s (1 deletes)
>> 2023-01-26T16:44:37.528Z|00115|vconn|DBG|unix#9: sent (Success): OFPT_HELLO (OF1.5) (xid=0xa):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.528Z|00116|vconn|DBG|unix#9: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.528Z|00117|vconn|DBG|unix#9: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.528Z|00118|vconn|DBG|unix#9: received: OFPST_TABLE request (xid=0x2):
>> 2023-01-26T16:44:37.528Z|00119|vconn|DBG|unix#9: sent (Success): OFPST_TABLE reply (xid=0x2):
>>   table 0:
>>     active=0, lookup=225928, matched=153998
>>     max_entries=1000000
>>     matching:
>>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>>
>>   table 1:
>>     active=0, lookup=0, matched=0
>>     (same features)
>>
>>   tables 2...253: ditto
>> 2023-01-26T16:44:37.528Z|00120|vconn|DBG|unix#10: sent (Success): OFPT_HELLO (OF1.5) (xid=0xb):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.528Z|00121|vconn|DBG|unix#10: received: OFPT_HELLO (xid=0x3):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.528Z|00122|vconn|DBG|unix#10: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.528Z|00123|vconn|DBG|unix#10: received: OFPT_FEATURES_REQUEST (xid=0x4):
>> 2023-01-26T16:44:37.528Z|00124|vconn|DBG|unix#10: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:000016215abb444a
>> n_tables:254, n_buffers:0
>> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
>> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>>  1(at_gre0): addr:a2:f9:64:45:eb:65
>>      config:     0
>>      state:      0
>>      speed: 0 Mbps now, 0 Mbps max
>>  2(ovs-p1): addr:32:68:ed:0f:cc:60
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  3(ovs-p2): addr:0e:8a:4c:65:90:6c
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  4(p2): addr:8e:57:dd:84:91:3f
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  LOCAL(br0): addr:16:21:5a:bb:44:4a
>>      config:     0
>>      state:      0
>>      speed: 0 Mbps now, 0 Mbps max
>> 2023-01-26T16:44:37.528Z|00125|vconn|DBG|unix#11: sent (Success): OFPT_HELLO (OF1.5) (xid=0xc):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.528Z|00126|vconn|DBG|unix#11: received: OFPT_HELLO (xid=0x5):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.528Z|00127|vconn|DBG|unix#11: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.528Z|00128|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0x6): ADD priority=99,in_port=1 actions=output(port=2,max_len=100),output(port=3,max_len=100)
>> 2023-01-26T16:44:37.529Z|00129|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0x7):
>> 2023-01-26T16:44:37.529Z|00130|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
>> 2023-01-26T16:44:37.529Z|00131|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0x8): ADD priority=99,udp,in_port=2 actions=output(port=1,max_len=100)
>> 2023-01-26T16:44:37.529Z|00132|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0x9):
>> 2023-01-26T16:44:37.529Z|00133|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0x9):
>> 2023-01-26T16:44:37.529Z|00134|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0xa): ADD priority=1,ip,in_port=4 actions=drop
>> 2023-01-26T16:44:37.529Z|00135|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0xb):
>> 2023-01-26T16:44:37.529Z|00136|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0xb):
>> 2023-01-26T16:44:37.529Z|00137|vconn|DBG|unix#11: received: OFPT_FLOW_MOD (xid=0xc): ADD priority=1 actions=drop
>> 2023-01-26T16:44:37.529Z|00138|vconn|DBG|unix#11: received: OFPT_BARRIER_REQUEST (xid=0xd):
>> 2023-01-26T16:44:37.529Z|00139|vconn|DBG|unix#11: sent (Success): OFPT_BARRIER_REPLY (xid=0xd):
>> 2023-01-26T16:44:37.529Z|00140|connmgr|INFO|br0<->unix#11: 4 flow_mods in the last 0 s (4 adds)
>> 2023-01-26T16:44:37.531Z|00141|vconn|DBG|unix#12: sent (Success): OFPT_HELLO (OF1.5) (xid=0xd):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.531Z|00142|vconn|DBG|unix#12: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.531Z|00143|vconn|DBG|unix#12: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.531Z|00144|vconn|DBG|unix#12: received: OFPST_TABLE request (xid=0x2):
>> 2023-01-26T16:44:37.532Z|00145|vconn|DBG|unix#12: sent (Success): OFPST_TABLE reply (xid=0x2):
>>   table 0:
>>     active=1, lookup=79377, matched=79377
>>     max_entries=1000000
>>     matching:
>>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>>
>>   table 1:
>>     active=0, lookup=0, matched=0
>>     (same features)
>>
>>   tables 2...253: ditto
>> 2023-01-26T16:44:37.532Z|00146|vconn|DBG|unix#13: sent (Success): OFPT_HELLO (OF1.5) (xid=0xe):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.532Z|00147|vconn|DBG|unix#13: received: OFPT_HELLO (xid=0x3):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.532Z|00148|vconn|DBG|unix#13: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.532Z|00149|vconn|DBG|unix#13: received: OFPT_FEATURES_REQUEST (xid=0x4):
>> 2023-01-26T16:44:37.532Z|00150|vconn|DBG|unix#13: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:00002a96e384084e
>> n_tables:254, n_buffers:0
>> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
>> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>>  1(ovs-p0): addr:1e:12:f0:27:f1:79
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  LOCAL(br-underlay): addr:2a:96:e3:84:08:4e
>>      config:     0
>>      state:      0
>>      speed: 0 Mbps now, 0 Mbps max
>> 2023-01-26T16:44:37.532Z|00151|vconn|DBG|unix#14: sent (Success): OFPT_HELLO (OF1.5) (xid=0xf):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.532Z|00152|vconn|DBG|unix#14: received: OFPT_HELLO (xid=0x5):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.532Z|00153|vconn|DBG|unix#14: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.532Z|00154|vconn|DBG|unix#14: received: OFPT_FLOW_MOD (xid=0x6): DEL actions=drop
>> 2023-01-26T16:44:37.532Z|00155|vconn|DBG|unix#14: received: OFPT_BARRIER_REQUEST (xid=0x7):
>> 2023-01-26T16:44:37.532Z|00156|vconn|DBG|unix#14: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
>> 2023-01-26T16:44:37.720Z|00157|connmgr|INFO|br-underlay<->unix#14: 1 flow_mods in the last 0 s (1 deletes)
>> 2023-01-26T16:44:37.721Z|00158|vconn|DBG|unix#15: sent (Success): OFPT_HELLO (OF1.5) (xid=0x10):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.721Z|00159|vconn|DBG|unix#15: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.721Z|00160|vconn|DBG|unix#15: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.721Z|00161|vconn|DBG|unix#15: received: OFPST_TABLE request (xid=0x2):
>> 2023-01-26T16:44:37.723Z|00162|vconn|DBG|unix#15: sent (Success): OFPST_TABLE reply (xid=0x2):
>>   table 0:
>>     active=0, lookup=79377, matched=79377
>>     max_entries=1000000
>>     matching:
>>       exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>>
>>   table 1:
>>     active=0, lookup=0, matched=0
>>     (same features)
>>
>>   tables 2...253: ditto
>> 2023-01-26T16:44:37.724Z|00163|vconn|DBG|unix#16: sent (Success): OFPT_HELLO (OF1.5) (xid=0x11):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.724Z|00164|vconn|DBG|unix#16: received: OFPT_HELLO (xid=0x3):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.724Z|00165|vconn|DBG|unix#16: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.724Z|00166|vconn|DBG|unix#16: received: OFPT_FEATURES_REQUEST (xid=0x4):
>> 2023-01-26T16:44:37.725Z|00167|vconn|DBG|unix#16: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:00002a96e384084e
>> n_tables:254, n_buffers:0
>> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
>> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
>>  1(ovs-p0): addr:1e:12:f0:27:f1:79
>>      config:     0
>>      state:      0
>>      current:    10GB-FD COPPER
>>      speed: 10000 Mbps now, 0 Mbps max
>>  LOCAL(br-underlay): addr:2a:96:e3:84:08:4e
>>      config:     0
>>      state:      0
>>      speed: 0 Mbps now, 0 Mbps max
>> 2023-01-26T16:44:37.726Z|00168|vconn|DBG|unix#17: sent (Success): OFPT_HELLO (OF1.5) (xid=0x12):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:37.726Z|00169|vconn|DBG|unix#17: received: OFPT_HELLO (xid=0x5):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:37.726Z|00170|vconn|DBG|unix#17: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:37.726Z|00171|vconn|DBG|unix#17: received: OFPT_FLOW_MOD (xid=0x6): ADD priority=99,ip,in_port=1,nw_proto=47 actions=LOCAL
>> 2023-01-26T16:44:37.727Z|00172|vconn|DBG|unix#17: received: OFPT_BARRIER_REQUEST (xid=0x7):
>> 2023-01-26T16:44:37.727Z|00173|vconn|DBG|unix#17: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
>> 2023-01-26T16:44:37.807Z|00174|vconn|DBG|unix#17: received: OFPT_FLOW_MOD (xid=0x8): ADD priority=99,ip,in_port=LOCAL,nw_dst=172.31.1.0/24,nw_proto=47 actions=output:1
>> 2023-01-26T16:44:37.807Z|00175|vconn|DBG|unix#17: received: OFPT_BARRIER_REQUEST (xid=0x9):
>> 2023-01-26T16:44:37.807Z|00176|vconn|DBG|unix#17: sent (Success): OFPT_BARRIER_REPLY (xid=0x9):
>> 2023-01-26T16:44:37.808Z|00177|vconn|DBG|unix#17: received: OFPT_FLOW_MOD (xid=0xa): ADD priority=1 actions=drop
>> 2023-01-26T16:44:37.808Z|00178|vconn|DBG|unix#17: received: OFPT_BARRIER_REQUEST (xid=0xb):
>> 2023-01-26T16:44:37.809Z|00179|vconn|DBG|unix#17: sent (Success): OFPT_BARRIER_REPLY (xid=0xb):
>> 2023-01-26T16:44:37.850Z|00180|connmgr|INFO|br-underlay<->unix#17: 3 flow_mods in the last 0 s (3 adds)
>> 2023-01-26T16:44:40.839Z|00181|unixctl|DBG|received request revalidator/purge[], id=0
>> 2023-01-26T16:44:40.991Z|00001|dpif(revalidator9)|WARN|system@ovs-system: failed to flow_get (No such file or directory) ufid:36468b48-f637-4680-820e-67d0e80cb6f3 <empty>, packets:0, bytes:0, used:never
>> 2023-01-26T16:44:40.992Z|00002|ofproto_dpif_upcall(revalidator9)|WARN|Failed to acquire udpif_key corresponding to unexpected flow (No such file or directory): ufid:36468b48-f637-4680-820e-67d0e80cb6f3
>> 2023-01-26T16:44:40.992Z|00003|dpif(revalidator9)|WARN|system@ovs-system: failed to flow_get (No such file or directory) ufid:b6c69a20-4978-4923-89d9-17f32746ab9e <empty>, packets:0, bytes:0, used:never
>> 2023-01-26T16:44:40.992Z|00004|ofproto_dpif_upcall(revalidator9)|WARN|Failed to acquire udpif_key corresponding to unexpected flow (No such file or directory): ufid:b6c69a20-4978-4923-89d9-17f32746ab9e
>> 2023-01-26T16:44:41.083Z|00182|unixctl|DBG|replying with success, id=0: ""
>> 2023-01-26T16:44:41.094Z|00183|vconn|DBG|unix#19: sent (Success): OFPT_HELLO (OF1.5) (xid=0x13):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:41.094Z|00184|vconn|DBG|unix#19: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:41.094Z|00185|vconn|DBG|unix#19: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:41.094Z|00186|vconn|DBG|unix#19: received: NXT_SET_FLOW_FORMAT (xid=0x2): format=nxm
>> 2023-01-26T16:44:41.094Z|00187|vconn|DBG|unix#19: received: OFPT_BARRIER_REQUEST (xid=0x3):
>> 2023-01-26T16:44:41.094Z|00188|vconn|DBG|unix#19: sent (Success): OFPT_BARRIER_REPLY (xid=0x3):
>> 2023-01-26T16:44:41.094Z|00189|vconn|DBG|unix#19: received: NXST_FLOW request (xid=0x4):
>> 2023-01-26T16:44:41.094Z|00190|vconn|DBG|unix#19: sent (Success): NXST_FLOW reply (xid=0x4):
>>  cookie=0x0, duration=3.565s, table=0, n_packets=3, n_bytes=250, idle_age=2, priority=99,in_port=1 actions=output(port=2,max_len=100),output(port=3,max_len=100)
>>  cookie=0x0, duration=3.565s, table=0, n_packets=1, n_bytes=242, idle_age=3, priority=99,udp,in_port=2 actions=output(port=1,max_len=100)
>>  cookie=0x0, duration=3.565s, table=0, n_packets=0, n_bytes=0, idle_age=3, priority=1,ip,in_port=4 actions=drop
>>  cookie=0x0, duration=3.566s, table=0, n_packets=73, n_bytes=11575, idle_age=0, priority=1 actions=drop
>> 2023-01-26T16:44:41.100Z|00191|vconn|DBG|unix#20: sent (Success): OFPT_HELLO (OF1.5) (xid=0x14):
>>  version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2023-01-26T16:44:41.100Z|00192|vconn|DBG|unix#20: received: OFPT_HELLO (xid=0x1):
>>  version bitmap: 0x01
>> 2023-01-26T16:44:41.100Z|00193|vconn|DBG|unix#20: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2023-01-26T16:44:41.100Z|00194|vconn|DBG|unix#20: received: NXT_SET_FLOW_FORMAT (xid=0x2): format=nxm
>> 2023-01-26T16:44:41.100Z|00195|vconn|DBG|unix#20: received: OFPT_BARRIER_REQUEST (xid=0x3):
>> 2023-01-26T16:44:41.100Z|00196|vconn|DBG|unix#20: sent (Success): OFPT_BARRIER_REPLY (xid=0x3):
>> 2023-01-26T16:44:41.100Z|00197|vconn|DBG|unix#20: received: NXST_FLOW request (xid=0x4):
>> 2023-01-26T16:44:41.100Z|00198|vconn|DBG|unix#20: sent (Success): NXST_FLOW reply (xid=0x4):
>>  cookie=0x0, duration=3.373s, table=0, n_packets=3, n_bytes=364, idle_age=2, priority=99,ip,in_port=1,nw_proto=47 actions=LOCAL
>>  cookie=0x0, duration=3.293s, table=0, n_packets=18446744073709511148, n_bytes=18446744073703563162, idle_age=3, priority=99,ip,in_port=LOCAL,nw_dst=172.31.1.0/24,nw_proto=47 actions=output:1
>>  cookie=0x0, duration=3.291s, table=0, n_packets=20, n_bytes=3265, idle_age=0, priority=1 actions=drop
> 2023-01-26T16:44:41Z|00001|daemon_unix|WARN|/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.pid: open: No such file or directory
> ovs-appctl: cannot read pidfile "/home/horms/projects/openvswitch/ovs/tests/system-offloads-testsuite.dir/051/ovs-vswitchd.pid" (No such file or directory)
> ovs-dpctl: opening datapath (No such device)
> 51. system-traffic.at:1768:  FAILED (system-traffic.at:1838)
>
> ## ------------- ##
> ## Test results. ##
> ## ------------- ##
>
> ERROR: All 2 tests were run,
> 2 failed unexpectedly.
> ## ------------------------------------------ ##
> ## system-offloads-testsuite.log was created. ##
> ## ------------------------------------------ ##
>
> Please send `tests/system-offloads-testsuite.log' and all information you think might help:
>
>    To: <bugs@openvswitch.org>
>    Subject: [openvswitch 3.1.90] system-offloads-testsuite: 50 51 failed
>
> You may investigate any problem if you feel able to do so, in which
> case the test suite provides a good starting point.  Its output may
> be found below `tests/system-offloads-testsuite.dir'.
>
> make: *** [Makefile:7042: check-offloads] Fout 1
Simon Horman Jan. 26, 2023, 7:03 p.m. UTC | #3 
On Thu, Jan 26, 2023 at 06:21:34PM +0100, Eelco Chaudron wrote:
> 
> 
> On 26 Jan 2023, at 17:58, Simon Horman wrote:
> 
> > On Tue, Jan 24, 2023 at 02:01:19PM +0100, Eelco Chaudron wrote:
> >> With some datapaths, read TC, it takes a bit longer to update the
> >> OpenFlow statistics. Rather than adding an additional delay, try
> >> to read the counters multiple times until we get the desired value.
> >>
> >> Signed-off-by: Eelco Chaudron <echaudro@redhat.com>
> >> Acked-by: Roi Dayan <roid@nvidia.com>
> >
> > When, possibly unwisely, running this test on my laptop,
> > with a somewhat old kernel the tests fail with absurd byte counts.
> > I haven't had time to dig into why.
> 
> I noticed this happens sometimes, and I excluded this test from the total set in the last patch :)
> 
> However, I also fixed some counter issues recently which fixed it in my setup:
> 
> https://patchwork.ozlabs.org/project/openvswitch/patch/167361458369.1145547.15786262052264455216.stgit@ebuild/
> 
> Can you try this?

Yes. I made a quick attempt just now and it does change things.

n_bytes now seems to be 0 for both cases (closer to but still not 138).
Perhaps that is explained by a timing issue.

I'll see if I can poke a little more.
But likely not today.
Ilya Maximets Jan. 26, 2023, 9:47 p.m. UTC | #4 
On 1/24/23 14:01, Eelco Chaudron wrote:
> With some datapaths, read TC, it takes a bit longer to update the
> OpenFlow statistics. Rather than adding an additional delay, try
> to read the counters multiple times until we get the desired value.
> 
> Signed-off-by: Eelco Chaudron <echaudro@redhat.com>
> Acked-by: Roi Dayan <roid@nvidia.com>
> ---
>  tests/system-offloads.at |    2 --
>  tests/system-traffic.at  |   15 ++++++---------
>  2 files changed, 6 insertions(+), 11 deletions(-)
> 
> diff --git a/tests/system-offloads.at b/tests/system-offloads.at
> index f4adac7b3..18e542aea 100644
> --- a/tests/system-offloads.at
> +++ b/tests/system-offloads.at
> @@ -60,8 +60,6 @@ m4_define([CHECK_CONNTRACK_TIMEOUT],
>  # issue.
>  m4_define([OVS_TEST_SKIP_LIST],
>      [ovs_test_skip_list="
> -datapath - truncate and output to gre tunnel by simulated packets
> -datapath - truncate and output to gre tunnel
>  conntrack - multiple namespaces, internal ports
>  conntrack - ct metadata, multiple zones
>  conntrack - ICMP related
> diff --git a/tests/system-traffic.at b/tests/system-traffic.at
> index d162674c9..60cda6a4a 100644
> --- a/tests/system-traffic.at
> +++ b/tests/system-traffic.at
> @@ -1708,9 +1708,8 @@ AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
>  n_bytes=242
>  ])
>  dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
> -AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
> -n_bytes=138
> -])
> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
> +               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
>  
>  dnl check tunnel pop path, from at_ns0 to at_ns1
>  dnl This 200-byte packet is simulated on behalf of ns_gre0
> @@ -1745,9 +1744,8 @@ AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
>  n_bytes=242
>  ])
>  dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
> -AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
> -n_bytes=138
> -])
> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
> +               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
>  
>  dnl check tunnel pop path, from at_ns0 to at_ns1
>  dnl This 200-byte packet is simulated on behalf of ns_gre0
> @@ -1755,9 +1753,8 @@ ovs-ofctl -O OpenFlow13 packet-out br-underlay "in_port=1 packet=02908ca8a149faa
>  
>  dnl After truncation = 100 byte at loopback device p2(4)
>  OVS_REVALIDATOR_PURGE()
> -AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip], [0], [dnl
> - n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop
> -])
> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip | grep "n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop"],
> +               [ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip])

OVS_WAIT_UNTIL_EQUAL() might be better suited for this.
It will print out the diff if the result it not equal.

Best regards, Ilya Maximets.
Eelco Chaudron Jan. 31, 2023, 9:42 a.m. UTC | #5 
On 26 Jan 2023, at 22:47, Ilya Maximets wrote:

> On 1/24/23 14:01, Eelco Chaudron wrote:
>> With some datapaths, read TC, it takes a bit longer to update the
>> OpenFlow statistics. Rather than adding an additional delay, try
>> to read the counters multiple times until we get the desired value.
>>
>> Signed-off-by: Eelco Chaudron <echaudro@redhat.com>
>> Acked-by: Roi Dayan <roid@nvidia.com>
>> ---
>>  tests/system-offloads.at |    2 --
>>  tests/system-traffic.at  |   15 ++++++---------
>>  2 files changed, 6 insertions(+), 11 deletions(-)
>>
>> diff --git a/tests/system-offloads.at b/tests/system-offloads.at
>> index f4adac7b3..18e542aea 100644
>> --- a/tests/system-offloads.at
>> +++ b/tests/system-offloads.at
>> @@ -60,8 +60,6 @@ m4_define([CHECK_CONNTRACK_TIMEOUT],
>>  # issue.
>>  m4_define([OVS_TEST_SKIP_LIST],
>>      [ovs_test_skip_list="
>> -datapath - truncate and output to gre tunnel by simulated packets
>> -datapath - truncate and output to gre tunnel
>>  conntrack - multiple namespaces, internal ports
>>  conntrack - ct metadata, multiple zones
>>  conntrack - ICMP related
>> diff --git a/tests/system-traffic.at b/tests/system-traffic.at
>> index d162674c9..60cda6a4a 100644
>> --- a/tests/system-traffic.at
>> +++ b/tests/system-traffic.at
>> @@ -1708,9 +1708,8 @@ AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
>>  n_bytes=242
>>  ])
>>  dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
>> -AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
>> -n_bytes=138
>> -])
>> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
>> +               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
>>
>>  dnl check tunnel pop path, from at_ns0 to at_ns1
>>  dnl This 200-byte packet is simulated on behalf of ns_gre0
>> @@ -1745,9 +1744,8 @@ AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
>>  n_bytes=242
>>  ])
>>  dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
>> -AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
>> -n_bytes=138
>> -])
>> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
>> +               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
>>
>>  dnl check tunnel pop path, from at_ns0 to at_ns1
>>  dnl This 200-byte packet is simulated on behalf of ns_gre0
>> @@ -1755,9 +1753,8 @@ ovs-ofctl -O OpenFlow13 packet-out br-underlay "in_port=1 packet=02908ca8a149faa
>>
>>  dnl After truncation = 100 byte at loopback device p2(4)
>>  OVS_REVALIDATOR_PURGE()
>> -AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip], [0], [dnl
>> - n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop
>> -])
>> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip | grep "n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop"],
>> +               [ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip])
>
> OVS_WAIT_UNTIL_EQUAL() might be better suited for this.
> It will print out the diff if the result it not equal.

Move all three instances to OVS_WAIT_UNTIL_EQUAL()

Any idea when https://patchwork.ozlabs.org/project/openvswitch/patch/167361458369.1145547.15786262052264455216.stgit@ebuild/ will be applied, as it makes this test fail sometimes?

//Eelco
Ilya Maximets Jan. 31, 2023, 1:21 p.m. UTC | #6 
On 1/31/23 10:42, Eelco Chaudron wrote:
> 
> 
> On 26 Jan 2023, at 22:47, Ilya Maximets wrote:
> 
>> On 1/24/23 14:01, Eelco Chaudron wrote:
>>> With some datapaths, read TC, it takes a bit longer to update the
>>> OpenFlow statistics. Rather than adding an additional delay, try
>>> to read the counters multiple times until we get the desired value.
>>>
>>> Signed-off-by: Eelco Chaudron <echaudro@redhat.com>
>>> Acked-by: Roi Dayan <roid@nvidia.com>
>>> ---
>>>  tests/system-offloads.at |    2 --
>>>  tests/system-traffic.at  |   15 ++++++---------
>>>  2 files changed, 6 insertions(+), 11 deletions(-)
>>>
>>> diff --git a/tests/system-offloads.at b/tests/system-offloads.at
>>> index f4adac7b3..18e542aea 100644
>>> --- a/tests/system-offloads.at
>>> +++ b/tests/system-offloads.at
>>> @@ -60,8 +60,6 @@ m4_define([CHECK_CONNTRACK_TIMEOUT],
>>>  # issue.
>>>  m4_define([OVS_TEST_SKIP_LIST],
>>>      [ovs_test_skip_list="
>>> -datapath - truncate and output to gre tunnel by simulated packets
>>> -datapath - truncate and output to gre tunnel
>>>  conntrack - multiple namespaces, internal ports
>>>  conntrack - ct metadata, multiple zones
>>>  conntrack - ICMP related
>>> diff --git a/tests/system-traffic.at b/tests/system-traffic.at
>>> index d162674c9..60cda6a4a 100644
>>> --- a/tests/system-traffic.at
>>> +++ b/tests/system-traffic.at
>>> @@ -1708,9 +1708,8 @@ AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
>>>  n_bytes=242
>>>  ])
>>>  dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
>>> -AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
>>> -n_bytes=138
>>> -])
>>> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
>>> +               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
>>>
>>>  dnl check tunnel pop path, from at_ns0 to at_ns1
>>>  dnl This 200-byte packet is simulated on behalf of ns_gre0
>>> @@ -1745,9 +1744,8 @@ AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
>>>  n_bytes=242
>>>  ])
>>>  dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
>>> -AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
>>> -n_bytes=138
>>> -])
>>> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
>>> +               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
>>>
>>>  dnl check tunnel pop path, from at_ns0 to at_ns1
>>>  dnl This 200-byte packet is simulated on behalf of ns_gre0
>>> @@ -1755,9 +1753,8 @@ ovs-ofctl -O OpenFlow13 packet-out br-underlay "in_port=1 packet=02908ca8a149faa
>>>
>>>  dnl After truncation = 100 byte at loopback device p2(4)
>>>  OVS_REVALIDATOR_PURGE()
>>> -AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip], [0], [dnl
>>> - n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop
>>> -])
>>> +OVS_WAIT_UNTIL([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip | grep "n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop"],
>>> +               [ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip])
>>
>> OVS_WAIT_UNTIL_EQUAL() might be better suited for this.
>> It will print out the diff if the result it not equal.
> 
> Move all three instances to OVS_WAIT_UNTIL_EQUAL()
> 
> Any idea when https://patchwork.ozlabs.org/project/openvswitch/patch/167361458369.1145547.15786262052264455216.stgit@ebuild/ will be applied, as it makes this test fail sometimes?

I posted some comments for this one.  It also needs a slight re-base.

> 
> //Eelco
>
diff mbox series

Patch

diff --git a/tests/system-offloads.at b/tests/system-offloads.at
index f4adac7b3..18e542aea 100644
--- a/tests/system-offloads.at
+++ b/tests/system-offloads.at
@@ -60,8 +60,6 @@  m4_define([CHECK_CONNTRACK_TIMEOUT],
 # issue.
 m4_define([OVS_TEST_SKIP_LIST],
     [ovs_test_skip_list="
-datapath - truncate and output to gre tunnel by simulated packets
-datapath - truncate and output to gre tunnel
 conntrack - multiple namespaces, internal ports
 conntrack - ct metadata, multiple zones
 conntrack - ICMP related
diff --git a/tests/system-traffic.at b/tests/system-traffic.at
index d162674c9..60cda6a4a 100644
--- a/tests/system-traffic.at
+++ b/tests/system-traffic.at
@@ -1708,9 +1708,8 @@  AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
 n_bytes=242
 ])
 dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
-AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
-n_bytes=138
-])
+OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
+               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
 
 dnl check tunnel pop path, from at_ns0 to at_ns1
 dnl This 200-byte packet is simulated on behalf of ns_gre0
@@ -1745,9 +1744,8 @@  AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=2" | sed -n 's/.*\(n\_bytes=[
 n_bytes=242
 ])
 dnl After truncation = outer ETH(14) + outer IP(20) + GRE(4) + 100 = 138B
-AT_CHECK([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'], [0], [dnl
-n_bytes=138
-])
+OVS_WAIT_UNTIL([ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p' | grep "n_bytes=138"],
+               [ovs-ofctl dump-flows br-underlay | grep "in_port=LOCAL" | sed -n 's/.*\(n\_bytes=[[0-9]]*\).*/\1/p'])
 
 dnl check tunnel pop path, from at_ns0 to at_ns1
 dnl This 200-byte packet is simulated on behalf of ns_gre0
@@ -1755,9 +1753,8 @@  ovs-ofctl -O OpenFlow13 packet-out br-underlay "in_port=1 packet=02908ca8a149faa
 
 dnl After truncation = 100 byte at loopback device p2(4)
 OVS_REVALIDATOR_PURGE()
-AT_CHECK([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip], [0], [dnl
- n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop
-])
+OVS_WAIT_UNTIL([ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip | grep "n_packets=1, n_bytes=100, priority=1,ip,in_port=4 actions=drop"],
+               [ovs-ofctl dump-flows br0 | grep "in_port=4" | ofctl_strip])
 
 OVS_TRAFFIC_VSWITCHD_STOP
 AT_CLEANUP