Hi, it's not clear from the issue report if the logs are actually duplicates, or if similar style messages might be emitted from different contexts within ovn-controller into the logs. Could you please post a redacted ovn-controller.log as an attachment on this issue? Thanks.
Hello Mark, Logs are actually generated by ingress and egress pipelines. But as packets (in most cases) are identical - we have duplicate lines in the log file that is a bit confusing. Please let me know if you still need exact logs from the controller. Best regards, Alex
Hi Alex, yes please provide logs. Also, if you can provide the ovn northbound database from a reproducer, we can have a look and determine if 1) This can be fixed through configuration, or 2) If this is a bug that needs to be fixed in OVN. For now, I'm changing the priority from "low" to "unspecified" so that we can reprioritize at a later date.
If we cannot target FDP 21.I then let's target FDP 21.J.
OK, having two log entries for two ACLs makes sense, but it probably makes sense to put some differentiating factor in the log messages so that it's possible to know which of the two ACLs is which.
Patch posted for review: http://patchwork.ozlabs.org/project/ovn/list/?series=284087&state=*
v2 posted for review: http://patchwork.ozlabs.org/project/ovn/list/?series=284151&state=*
v3 posted for review: http://patchwork.ozlabs.org/project/ovn/list/?series=285670&state=*
v4 posted for review: http://patchwork.ozlabs.org/project/ovn/list/?series=286103&state=*
v5 posted for review: http://patchwork.ozlabs.org/project/ovn/list/?series=286297&state=*
Patch accepted upstream, will be available in the next OVN release. https://github.com/ovn-org/ovn/commit/d7514abe1172dd677af1ce2e61c86ae3885eb344
Moving back to POST to make sure QE gets a change to test the feature.
Reproducer: systemctl start ovn-northd ovn-nbctl set-connection ptcp:6641 ovn-sbctl set-connection ptcp:6642 systemctl start openvswitch ovs-vsctl set open . external_ids:system-id=hv1 ovs-vsctl set open . external_ids:ovn-remote=tcp:172.16.1.1:6642 ovs-vsctl set open . external_ids:ovn-encap-type=geneve ovs-vsctl set open . external_ids:ovn-encap-ip=172.16.1.1 systemctl start ovn-controller ovn-nbctl ls-add ls1 ovn-nbctl lsp-add ls1 lp1 ovn-nbctl lsp-set-addresses lp1 "00:00:00:01:00:02 172.16.1.1 3001::1" ovn-nbctl lsp-add ls1 lp2 ovn-nbctl lsp-set-addresses lp2 "00:00:00:02:00:02 172.16.1.2 3001::2" ip netns add server0 ip link add veth0_s0 type veth peer name veth0_s0_p ip link set veth0_s0 netns server0 ip netns exec server0 ip link set lo up ip netns exec server0 ip link set veth0_s0 up ip netns exec server0 ip link set veth0_s0 address 00:00:00:01:00:02 ip netns exec server0 ip addr add 172.16.1.1/24 dev veth0_s0 ip netns exec server0 ip -6 addr add 3001::1/64 dev veth0_s0 ovs-vsctl add-port br-int veth0_s0_p ip link set veth0_s0_p up ovs-vsctl set interface veth0_s0_p external_ids:iface-id=lp1 ip netns add client1 ip link add veth0_c1 type veth peer name veth0_c1_p ip link set veth0_c1 netns client1 ip netns exec client1 ip link set lo up ip netns exec client1 ip link set veth0_c1 up ip netns exec client1 ip link set veth0_c1 address 00:00:00:02:00:02 ip netns exec client1 ip addr add 172.16.1.2/24 dev veth0_c1 ip netns exec client1 ip -6 addr add 3001::2/64 dev veth0_c1 ovs-vsctl add-port br-int veth0_c1_p ip link set veth0_c1_p up ovs-vsctl set interface veth0_c1_p external_ids:iface-id=lp2 ip netns exec server0 ping 172.16.1.2 -c 3 ovn-nbctl acl-add ls1 from-lport 1000 'tcp.dst==80' drop ovn-nbctl --log --severity=alert --name=drop-flow acl-add ls1 from-lport 1000 'tcp.dst==81' drop ovn-nbctl acl-add ls1 to-lport 1000 'tcp.dst==180' drop ovn-nbctl --log --severity=alert --name=drop-flow acl-add ls1 to-lport 1000 'tcp.dst==181' drop ovn-nbctl acl-add ls1 from-lport 1000 'tcp.dst==82' allow ovn-nbctl --log --severity=info --name=allow-flow acl-add ls1 from-lport 1000 'tcp.dst==83' allow ovn-nbctl acl-add ls1 to-lport 1000 'tcp.dst==82' allow ovn-nbctl --log --severity=info --name=allow-flow acl-add ls1 to-lport 1000 'tcp.dst==83' allow ovn-nbctl acl-add ls1 from-lport 1000 'tcp.dst==84' allow-related ovn-nbctl --log acl-add ls1 from-lport 1000 'tcp.dst==85' allow-related ovn-nbctl acl-add ls1 to-lport 1000 'tcp.dst==84' allow-related ovn-nbctl --log acl-add ls1 to-lport 1000 'tcp.dst==85' allow-related ovn-nbctl acl-add ls1 from-lport 1000 'tcp.dst==86' reject ovn-nbctl --log --severity=alert --name=reject-flow acl-add ls1 from-lport 1000 'tcp.dst==87' reject ovn-nbctl acl-add ls1 to-lport 1000 'tcp.dst==186' reject ovn-nbctl --log --severity=alert --name=reject-flow acl-add ls1 to-lport 1000 'tcp.dst==187' reject ovn-nbctl --wait=hv sync ovn-sbctl dump-flows > sbflows ip netns exec client1 nc -l -k 80 & ip netns exec client1 nc -l -k 81 & ip netns exec client1 nc -l -k 180 & ip netns exec client1 nc -l -k 181 & ip netns exec client1 nc -l -k 82 & ip netns exec client1 nc -l -k 83 & ip netns exec client1 nc -l -k 84 & ip netns exec client1 nc -l -k 85 & ip netns exec client1 nc -l -k 86 & ip netns exec client1 nc -l -k 87 & ip netns exec client1 nc -l -k 186 & ip netns exec client1 nc -l -k 187 & # Send packet that should be dropped without logging in the ingress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4360 172.16.1.2 80 <<< hello Ncat: Connection timed out. # Send packet that should be dropped with logging in the ingress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4361 172.16.1.2 81 <<< hello Ncat: Connection timed out. # Send packet that should be dropped without logging in the eggress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4360 172.16.1.2 180 <<< hello Ncat: Connection timed out. # Send packet that should be dropped with logging in the egress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4361 172.16.1.2 181 <<< hello Ncat: Connection timed out. # Send packet that should be allowed without logging. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4362 172.16.1.2 82 <<< hello hello # Send packet that should be allowed with logging. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4363 172.16.1.2 83 <<< hello hello # Send packet that should allow related flows without logging. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4364 172.16.1.2 84 <<< hello hello # Send packet that should allow related flows with logging. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4365 172.16.1.2 85 <<< hello hello # Send packet that should be rejected without logging in the ingress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4366 172.16.1.2 86 <<< hello Ncat: Connection refused. # Send packet that should be rejected with logging in the ingress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4367 172.16.1.2 87 <<< hello Ncat: Connection refused. # Send packet that should be rejected without logging in the egress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4366 172.16.1.2 186 <<< hello Ncat: Connection refused. # Send packet that should be rejected with logging in the egress pipeline. [root@bz-1992641 ~]# ip netns exec server0 nc -p 4367 172.16.1.2 187 <<< hello Ncat: Connection refused. # Reproduced on [root@bz-1992641 ~]# rpm -qa |grep -E "ovn|openvswitch" ovn-2021-central-21.12.0-32.el8fdp.x86_64 openvswitch-selinux-extra-policy-1.0-28.el8fdp.noarch ovn-2021-host-21.12.0-32.el8fdp.x86_64 openvswitch2.15-2.15.0-93.el8fdp.x86_64 ovn-2021-21.12.0-32.el8fdp.x86_64 # ovn-controller acl_log duplicate entries. [root@bz-1992641 ~]# cat /var/log/ovn/ovn-controller.log |grep acl_log|sed 's/.*name=/name=/'|grep tcp_flags=syn| sort|uniq -c 2 name="allow-flow", verdict=allow, severity=info: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4363,tp_dst=83,tcp_flags=syn 4 name="drop-flow", verdict=drop, severity=alert: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4361,tp_dst=181,tcp_flags=syn 4 name="drop-flow", verdict=drop, severity=alert: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4361,tp_dst=81,tcp_flags=syn 1 name="reject-flow", verdict=reject, severity=alert: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4367,tp_dst=187,tcp_flags=syn 1 name="reject-flow", verdict=reject, severity=alert: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4367,tp_dst=87,tcp_flags=syn 2 name="<unnamed>", verdict=allow, severity=info: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4365,tp_dst=85,tcp_flags=syn verified on [root@bz-1992641 ~]# rpm -qa |grep -E "ovn|openvswitch" ovn-2021-central-21.12.0-42.el8fdp.x86_64 openvswitch-selinux-extra-policy-1.0-28.el8fdp.noarch openvswitch2.15-2.15.0-93.el8fdp.x86_64 ovn-2021-21.12.0-42.el8fdp.x86_64 ovn-2021-host-21.12.0-42.el8fdp.x86_64 # Duplicate entries exist where acl action is "drop", this is due to multiple retries of the syn packets. [root@bz-1992641 ~]# cat /var/log/ovn/ovn-controller.log |grep acl_log|sed 's/.*name=/name=/'|grep tcp_flags=syn| sort|uniq -c 1 name="allow-flow", verdict=allow, severity=info, direction=from-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4363,tp_dst=83,tcp_flags=syn 1 name="allow-flow", verdict=allow, severity=info, direction=to-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4363,tp_dst=83,tcp_flags=syn 4 name="drop-flow", verdict=drop, severity=alert, direction=from-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4361,tp_dst=81,tcp_flags=syn 4 name="drop-flow", verdict=drop, severity=alert, direction=to-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4361,tp_dst=181,tcp_flags=syn 1 name="reject-flow", verdict=reject, severity=alert, direction=from-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4367,tp_dst=87,tcp_flags=syn 1 name="reject-flow", verdict=reject, severity=alert, direction=to-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4367,tp_dst=187,tcp_flags=syn 1 name="<unnamed>", verdict=allow, severity=info, direction=from-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4365,tp_dst=85,tcp_flags=syn 1 name="<unnamed>", verdict=allow, severity=info, direction=to-lport: tcp,vlan_tci=0x0000,dl_src=00:00:00:01:00:02,dl_dst=00:00:00:02:00:02,nw_src=172.16.1.1,nw_dst=172.16.1.2,nw_tos=0,nw_ecn=0,nw_ttl=64,tp_src=4365,tp_dst=85,tcp_flags=syn [root@bz-1992641 ~]#
Also verified on [root@bz-1992641 ~]# rpm -qa |grep -E "ovn|openvswitch" openvswitch-selinux-extra-policy-1.0-31.el9fdp.noarch openvswitch2.16-2.16.0-52.el9fdp.x86_64 ovn22.03-22.03.0-9.el9fdp.x86_64 ovn22.03-central-22.03.0-9.el9fdp.x86_64 ovn22.03-host-22.03.0-9.el9fdp.x86_64
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (ovn-2021 bug fix and enhancement update), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2022:1523