Skip to content

Bug 2048352: ovn-kubernetes: Fixed ofport_request for physical ports#2941

Merged
openshift-merge-robot merged 1 commit intoopenshift:masterfrom
andreaskaris:BZ2048352
Mar 3, 2022
Merged

Bug 2048352: ovn-kubernetes: Fixed ofport_request for physical ports#2941
openshift-merge-robot merged 1 commit intoopenshift:masterfrom
andreaskaris:BZ2048352

Conversation

@andreaskaris
Copy link
Copy Markdown
Contributor

When NetworkManager is restarted, all interfaces are removed from the
external bridge (br-ex / breth0). By default, ports' OVS IDs
change and the existing flows point to wrong 'output:' port numbers
leading to packet drops of all traffic that originates at
LOCAL and the node will not be able to request an IP address via DHCP.
Request fixed ofport numbers via the ofport_request field.

Signed-off-by: Andreas Karis ak.karis@gmail.com

- What I did

- How to verify it

- Description for the changelog

@kikisdeliveryservice
Copy link
Copy Markdown
Contributor

/assign @trozet

@andreaskaris
Copy link
Copy Markdown
Contributor Author

andreaskaris commented Feb 2, 2022

Verification:

[akaris@linux ~]$ export KUBECONFIG=/home/akaris/development/aws-env/ipi-us-east-1/install-config/auth/kubeconfig
[akaris@linux ~]$ oc get clusterversion
oc get nodNAME      VERSION                              AVAILABLE   PROGRESSING   SINCE   STATUS
version   4.10.0-0.nightly-2022-01-30-073053   True        False         4h13m   Cluster version is 4.10.0-0.nightly-2022-01-30-073053
[akaris@linux ~]$ oc get nodes
ocNAME                           STATUS   ROLES    AGE     VERSION
ip-10-0-135-187.ec2.internal   Ready    master   4h30m   v1.23.3+b63be7f
ip-10-0-141-123.ec2.internal   Ready    worker   4h21m   v1.23.3+b63be7f
ip-10-0-144-223.ec2.internal   Ready    master   4h31m   v1.23.3+b63be7f
ip-10-0-145-66.ec2.internal    Ready    worker   4h22m   v1.23.3+b63be7f
ip-10-0-169-190.ec2.internal   Ready    master   4h31m   v1.23.3+b63be7f
ip-10-0-175-119.ec2.internal   Ready    worker   4h21m   v1.23.3+b63be7f
[akaris@linux ~]$ oc get co
NAME                                       VERSION                              AVAILABLE   PROGRESSING   DEGRADED   SINCE   MESSAGE
authentication                             4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h14m   
baremetal                                  4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h26m   
cloud-controller-manager                   4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h31m   
cloud-credential                           4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h31m   
cluster-autoscaler                         4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h25m   
config-operator                            4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h27m   
console                                    4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h16m   
csi-snapshot-controller                    4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h26m   
dns                                        4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h25m   
etcd                                       4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h25m   
image-registry                             4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h19m   
ingress                                    4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h19m   
insights                                   4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h15m   
kube-apiserver                             4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h15m   
kube-controller-manager                    4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h23m   
kube-scheduler                             4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h22m   
kube-storage-version-migrator              4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h27m   
machine-api                                4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h22m   
machine-approver                           4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h26m   
machine-config                             4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h25m   
marketplace                                4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h25m   
monitoring                                 4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h13m   
network                                    4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h27m   
node-tuning                                4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h26m   
openshift-apiserver                        4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h19m   
openshift-controller-manager               4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h22m   
openshift-samples                          4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h21m   
operator-lifecycle-manager                 4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h26m   
operator-lifecycle-manager-catalog         4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h26m   
operator-lifecycle-manager-packageserver   4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h21m   
service-ca                                 4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h27m   
storage                                    4.10.0-0.nightly-2022-01-30-073053   True        False         False      4h26m   
o[akaris@linux ~]$ oc debug node/ip-10-0-141-123.ec2.internal
Starting pod/ip-10-0-141-123ec2internal-debug ...
To use host binaries, run `chroot /host`
chroot /host
Pod IP: 10.0.141.123
If you don't see a command prompt, try pressing enter.
chroot /host
sh-4.4# ls /etc/NetworkManager/
NetworkManager.conf  conf.d/              dispatcher.d/        dnsmasq-shared.d/    dnsmasq.d/           system-connections/  
sh-4.4# ls /etc/NetworkManager/
NetworkManager.conf  conf.d/              dispatcher.d/        dnsmasq-shared.d/    dnsmasq.d/           system-connections/  
sh-4.4# ls /etc/NetworkManager/dispatcher.d/   
20-chrony                                       90-console-login-helper-messages-gensnippet_if  no-wait.d/                                      pre-up.d/
20-coreos-chrony-dhcp                           99-vsphere-disable-tx-udp-tnl                   pre-down.d/                                     
sh-4.4# ls /etc/NetworkManager/dispatcher.d/
20-chrony                                       90-console-login-helper-messages-gensnippet_if  no-wait.d/                                      pre-up.d/
20-coreos-chrony-dhcp                           99-vsphere-disable-tx-udp-tnl                   pre-down.d/                                     
sh-4.4# ls /etc/NetworkManager/dispatcher.d/pre-up.d/
ofport-request.sh
sh-4.4# ovs-ofctl show br-ex
OFPT_FEATURES_REPLY (xid=0x2): dpid:00000aefa0ad77b1
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
 3(patch-br-ex_ip-): addr:9a:bc:e7:2f:e2:c4
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 9194(ens5): addr:0a:ef:a0:ad:77:b1
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 LOCAL(br-ex): addr:0a:ef:a0:ad:77:b1
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
OFPT_GET_CONFIG_REPLY (xid=0x4): frags=normal miss_send_len=0
sh-4.4# ovs-ofctl show br-int
OFPT_FEATURES_REPLY (xid=0x2): dpid:000042bd58befa9e
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(ovn-k8s-mp0): addr:2e:7e:5d:1f:69:a7
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 2(ovn-6be044-0): addr:ae:a3:39:d3:6b:71
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 3(ovn-a86eb5-0): addr:2e:37:23:14:ed:07
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 4(ovn-40b93d-0): addr:ae:5c:e8:bc:52:65
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 5(ovn-1a6e55-0): addr:fe:f6:ba:dd:af:fe
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 6(ovn-60f15a-0): addr:0a:d8:32:6e:90:b0
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 7(patch-br-int-to): addr:b6:85:b2:ea:34:0e
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 8(3d00f8fde240293): addr:ee:1d:2e:c0:4f:9b
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 9(000e8b443b5846f): addr:4a:43:f1:71:4b:35
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 10(b91014fae2deaaf): addr:0e:43:54:12:e4:4e
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 11(e6d568dd9821e04): addr:e6:e2:80:32:ed:14
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 12(39f0407df76fb70): addr:b2:96:c0:58:6f:ed
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 13(d02da4ee35ea31b): addr:7e:62:3f:fc:51:2e
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 14(6b7f4a2f4cd600d): addr:2e:e9:28:f7:ab:33
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 16(9e04c437062f726): addr:32:27:2c:0c:09:a6
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 17(3ad224fd16fa721): addr:a6:5d:90:a8:b8:be
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 18(82cfe3b25c829da): addr:b6:00:66:c4:71:8b
     config:     0
     state:      0
     current:    10GB-FD COPPER
     speed: 10000 Mbps now, 0 Mbps max
 LOCAL(br-int): addr:42:bd:58:be:fa:9e
     config:     PORT_DOWN
     state:      LINK_DOWN
     speed: 0 Mbps now, 0 Mbps max
OFPT_GET_CONFIG_REPLY (xid=0x4): frags=normal miss_send_len=0
sh-4.4# systemctl restart NetworkManager
sh-4.4# 
sh-4.4# 
sh-4.4# 
sh-4.4# ovs-ofctl show br-ex 
OFPT_FEATURES_REPLY (xid=0x2): dpid:00000aefa0ad77b1
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
 3(patch-br-ex_ip-): addr:9a:bc:e7:2f:e2:c4
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 9194(ens5): addr:0a:ef:a0:ad:77:b1
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 LOCAL(br-ex): addr:0a:ef:a0:ad:77:b1
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
OFPT_GET_CONFIG_REPLY (xid=0x4): frags=normal miss_send_len=0
sh-4.4# ovs-ofctl dump-flows br-ex
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=0, n_bytes=0, priority=500,ip,in_port="patch-br-ex_ip-",nw_src=10.0.141.123,nw_dst=169.254.169.2 actions=ct(commit,table=4,zone=64001,nat(dst=10.0.141.123))
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=0, n_bytes=0, priority=500,ip,in_port=LOCAL,nw_dst=169.254.169.1 actions=ct(table=5,zone=64002,nat)
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=11421, n_bytes=2382466, priority=500,ip,in_port=LOCAL,nw_dst=172.30.0.0/16 actions=ct(commit,table=2,zone=64001,nat(src=169.254.169.2))
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=10530, n_bytes=8425138, priority=500,ip,in_port="patch-br-ex_ip-",nw_src=172.30.0.0/16,nw_dst=169.254.169.2 actions=ct(table=3,zone=64001,nat)
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=457521, n_bytes=1020393102, priority=205,udp,in_port=ens5,dl_dst=0a:ef:a0:ad:77:b1,tp_dst=6081 actions=LOCAL
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=0, n_bytes=0, priority=200,udp,in_port=ens5,tp_dst=6081 actions=NORMAL
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=419714, n_bytes=168905449, priority=200,udp,in_port=LOCAL,tp_dst=6081 actions=output:ens5
 cookie=0xaa0b41acc2257187, duration=15680.501s, table=0, n_packets=0, n_bytes=0, priority=110,tcp,in_port=ens5,tp_dst=32638 actions=check_pkt_larger(8915)->NXM_NX_REG0[0],resubmit(,11)
 cookie=0xa2aba4acbe55e48d, duration=15680.501s, table=0, n_packets=0, n_bytes=0, priority=110,tcp,in_port=ens5,tp_dst=32140 actions=check_pkt_larger(8915)->NXM_NX_REG0[0],resubmit(,11)
 cookie=0xaa0b41acc2257187, duration=15680.501s, table=0, n_packets=0, n_bytes=0, priority=110,tcp,in_port="patch-br-ex_ip-",tp_src=32638 actions=output:ens5
 cookie=0xa2aba4acbe55e48d, duration=15680.501s, table=0, n_packets=0, n_bytes=0, priority=110,tcp,in_port="patch-br-ex_ip-",tp_src=32140 actions=output:ens5
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=675026, n_bytes=69479352, priority=100,ip,in_port="patch-br-ex_ip-" actions=ct(commit,zone=64000,exec(load:0x1->NXM_NX_CT_MARK[])),output:ens5
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=246979, n_bytes=223101224, priority=100,ip,in_port=LOCAL actions=ct(commit,zone=64000,exec(load:0x2->NXM_NX_CT_MARK[])),output:ens5
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=1144739, n_bytes=3204782062, priority=50,ip,in_port=ens5 actions=ct(table=1,zone=64000)
 cookie=0xdeff105, duration=15680.501s, table=0, n_packets=5, n_bytes=210, priority=10,in_port=ens5,dl_dst=0a:ef:a0:ad:77:b1 actions=output:"patch-br-ex_ip-",LOCAL
 cookie=0x0, duration=15768.116s, table=0, n_packets=389297, n_bytes=1811923492, priority=0 actions=NORMAL
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=841308, n_bytes=2604157699, priority=100,ct_state=+est+trk,ct_mark=0x1,ip actions=check_pkt_larger(8915)->NXM_NX_REG0[0],resubmit(,11)
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=303371, n_bytes=600508271, priority=100,ct_state=+est+trk,ct_mark=0x2,ip actions=LOCAL
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=0, n_bytes=0, priority=100,ct_state=+rel+trk,ct_mark=0x1,ip actions=check_pkt_larger(8915)->NXM_NX_REG0[0],resubmit(,11)
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=0, n_bytes=0, priority=100,ct_state=+rel+trk,ct_mark=0x2,ip actions=LOCAL
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=0, n_bytes=0, priority=15,ip,nw_dst=10.128.0.0/14 actions=check_pkt_larger(8915)->NXM_NX_REG0[0],resubmit(,11)
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=0, n_bytes=0, priority=13,udp,in_port=ens5,tp_dst=3784 actions=output:"patch-br-ex_ip-",LOCAL
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=52, n_bytes=114552, priority=10,dl_dst=0a:ef:a0:ad:77:b1 actions=LOCAL
 cookie=0xdeff105, duration=15680.501s, table=1, n_packets=0, n_bytes=0, priority=0 actions=NORMAL
 cookie=0xdeff105, duration=14.218s, table=2, n_packets=11421, n_bytes=2382466, actions=mod_dl_dst:0a:ef:a0:ad:77:b1,output:"patch-br-ex_ip-"
 cookie=0xdeff105, duration=14.218s, table=3, n_packets=10530, n_bytes=8425138, actions=move:NXM_OF_ETH_DST[]->NXM_OF_ETH_SRC[],mod_dl_dst:0a:ef:a0:ad:77:b1,LOCAL
 cookie=0xdeff105, duration=15680.501s, table=4, n_packets=0, n_bytes=0, ip actions=ct(commit,table=3,zone=64002,nat(src=169.254.169.1))
 cookie=0xdeff105, duration=15680.501s, table=5, n_packets=0, n_bytes=0, ip actions=ct(commit,table=2,zone=64001,nat)
 cookie=0xdeff105, duration=15680.501s, table=11, n_packets=841308, n_bytes=2604157699, priority=10,reg0=0x1 actions=LOCAL
 cookie=0xdeff105, duration=15680.501s, table=11, n_packets=841308, n_bytes=2604157699, priority=1 actions=output:"patch-br-ex_ip-"
sh-4.4# ovs-ofctl dump-flows br-ex | grep 9194
 cookie=0xdeff105, duration=15690.386s, table=0, n_packets=457847, n_bytes=1023094729, idle_age=0, priority=205,udp,in_port=9194,dl_dst=0a:ef:a0:ad:77:b1,tp_dst=6081 actions=LOCAL
 cookie=0xdeff105, duration=15690.386s, table=0, n_packets=0, n_bytes=0, idle_age=15690, priority=200,udp,in_port=9194,tp_dst=6081 actions=NORMAL
 cookie=0xdeff105, duration=15690.386s, table=0, n_packets=420006, n_bytes=169028398, idle_age=0, priority=200,udp,in_port=LOCAL,tp_dst=6081 actions=output:9194
 cookie=0xaa0b41acc2257187, duration=15690.386s, table=0, n_packets=0, n_bytes=0, idle_age=15690, priority=110,tcp,in_port=9194,tp_dst=32638 actions=check_pkt_larger(8915)->NXM_NX_REG0[0],resubmit(,11)
 cookie=0xa2aba4acbe55e48d, duration=15690.386s, table=0, n_packets=0, n_bytes=0, idle_age=15690, priority=110,tcp,in_port=9194,tp_dst=32140 actions=check_pkt_larger(8915)->NXM_NX_REG0[0],resubmit(,11)
 cookie=0xaa0b41acc2257187, duration=15690.386s, table=0, n_packets=0, n_bytes=0, idle_age=15690, priority=110,tcp,in_port=3,tp_src=32638 actions=output:9194
 cookie=0xa2aba4acbe55e48d, duration=15690.386s, table=0, n_packets=0, n_bytes=0, idle_age=15690, priority=110,tcp,in_port=3,tp_src=32140 actions=output:9194
 cookie=0xdeff105, duration=15690.386s, table=0, n_packets=675352, n_bytes=69513937, idle_age=0, priority=100,ip,in_port=3 actions=ct(commit,zone=64000,exec(load:0x1->NXM_NX_CT_MARK[])),output:9194
 cookie=0xdeff105, duration=15690.386s, table=0, n_packets=247122, n_bytes=223139654, idle_age=0, priority=100,ip,in_port=LOCAL actions=ct(commit,zone=64000,exec(load:0x2->NXM_NX_CT_MARK[])),output:9194
 cookie=0xdeff105, duration=15690.386s, table=0, n_packets=1145304, n_bytes=3205825675, idle_age=0, priority=50,ip,in_port=9194 actions=ct(table=1,zone=64000)
 cookie=0xdeff105, duration=15690.386s, table=0, n_packets=5, n_bytes=210, idle_age=23, priority=10,in_port=9194,dl_dst=0a:ef:a0:ad:77:b1 actions=output:3,LOCAL
 cookie=0xdeff105, duration=15690.386s, table=1, n_packets=0, n_bytes=0, idle_age=15690, priority=13,udp,in_port=9194,tp_dst=3784 actions=output:3,LOCAL

And the logs will show:

sh-4.4# journalctl | grep nm-dispatcher | tail -n 30
Feb 02 19:14:19 ip-10-0-141-123 nm-dispatcher[245448]: Error: Device '' not found.
Feb 02 19:14:19 ip-10-0-141-123 nm-dispatcher[245448]: Error: Device '' not found.
Feb 02 19:14:19 ip-10-0-141-123 nm-dispatcher[245448]: Error: Device '' not found.
Feb 02 19:14:19 ip-10-0-141-123 nm-dispatcher[245448]: Error: Device '' not found.
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + [[ OVNKubernetes != \O\V\N\K\u\b\e\r\n\e\t\e\s ]]
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + INTERFACE_NAME=ens5
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + OPERATION=pre-up
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: ++ nmcli -t -f device,type,uuid conn
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: ++ awk -F : '/ens5:802-3-ethernet/ {print $NF}'
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + CONNECTION_UUID=890f9951-c74f-4c4f-9402-f5b524115c90
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + '[' 890f9951-c74f-4c4f-9402-f5b524115c90 == '' ']'
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: ++ nmcli -t -f connection.slave-type conn show 890f9951-c74f-4c4f-9402-f5b524115c90
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: ++ awk -F : '{print $NF}'
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + OVS_SLAVE_TYPE=ovs-port
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + '[' ovs-port '!=' ovs-port ']'
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: ++ echo ens5
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: ++ md5sum
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: ++ awk '{print "9" substr(strtonum("0x" $1),0,3)}'
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + OFPORT_REQUEST=9194
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + logger 'nmcli pre-up: Detected interface ens5 on ovs bridge. Setting ofport_request=9194'
Feb 02 19:14:20 ip-10-0-141-123 nm-dispatcher[245448]: + ovs-vsctl set Interface ens5 ofport_request=9194
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: + [[ OVNKubernetes != \O\V\N\K\u\b\e\r\n\e\t\e\s ]]
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: + INTERFACE_NAME=br-ex
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: + OPERATION=pre-up
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: ++ nmcli -t -f device,type,uuid conn
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: ++ awk -F : '/br-ex:802-3-ethernet/ {print $NF}'
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: + CONNECTION_UUID=
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: + '[' '' == '' ']'
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: + exit 0
Feb 02 19:14:21 ip-10-0-141-123 nm-dispatcher[245448]: Error: Device '' not found.

And the script looks like this:

sh-4.4# cat /etc/NetworkManager/dispatcher.d/pre-up.d/ofport-request.sh 
#!/bin/bash
# Set interface ofport_request to guarantee stable ofport numbers. This is important for flow matches.
# Otherwise, another ofport number is assigned to the interface on every restart of NetworkManager.
# If the same request ID exists for ports without ofport_request set such as patch ports then these
# interfaces will be moved by OVS to a different ID. We choose a high ofport_request number so that such
# conflict are extremely unlikely to happen.
# In the case of duplicate assignments by this script, this will not fail but instead one of the interfaces
# will take the assigned value and the other one will take the value that was preassigned to it.
# We must only have a single physical, NM managed physical interface on the bridge, so this case should
# never happen.
set -eux -o pipefail
if [[ "OVNKubernetes" != "OVNKubernetes" ]]; then
    exit 0
fi

INTERFACE_NAME=$1
OPERATION=$2

CONNECTION_UUID=$(nmcli -t -f  device,type,uuid conn | awk -F ':' "/$INTERFACE_NAME:802-3-ethernet/ {print \$NF}")
if [ "$CONNECTION_UUID" == "" ]; then
    exit 0
fi

OVS_SLAVE_TYPE=$(nmcli -t -f connection.slave-type conn show "$CONNECTION_UUID" | awk -F ':' '{print $NF}')
if [ "$OVS_SLAVE_TYPE" != "ovs-port" ] && [ "$OVS_SLAVE_TYPE" != "ovs-bridge" ]; then
    exit 0
fi

# This will yield ofport_requests 9xxx where xxx is always fix for the same interface name
OFPORT_REQUEST=$(echo "$INTERFACE_NAME" | md5sum | awk '{print "9" substr(strtonum("0x" $1),0,3)}')

logger "nmcli pre-up: Detected interface $INTERFACE_NAME on ovs bridge. Setting ofport_request=$OFPORT_REQUEST"
ovs-vsctl set Interface "$INTERFACE_NAME" ofport_request=$OFPORT_REQUEST

@andreaskaris andreaskaris changed the title ovn-kubernetes: Fixed ofport_request for physical prots Bug 2048352: ovn-kubernetes: Fixed ofport_request for physical prots Feb 2, 2022
@openshift-ci openshift-ci Bot added the bugzilla/severity-high Referenced Bugzilla bug's severity is high for the branch this PR is targeting. label Feb 2, 2022
@openshift-ci
Copy link
Copy Markdown
Contributor

openshift-ci Bot commented Feb 2, 2022

@andreaskaris: This pull request references Bugzilla bug 2048352, which is invalid:

  • expected the bug to target the "4.11.0" release, but it targets "4.10.0" instead

Comment /bugzilla refresh to re-evaluate validity if changes to the Bugzilla bug are made, or edit the title of this pull request to link to a different bug.

Details

In response to this:

Bug 2048352: ovn-kubernetes: Fixed ofport_request for physical prots

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@openshift-ci openshift-ci Bot added the bugzilla/invalid-bug Indicates that a referenced Bugzilla bug is invalid for the branch this PR is targeting. label Feb 2, 2022
@andreaskaris
Copy link
Copy Markdown
Contributor Author

/bugzilla refresh

@openshift-ci openshift-ci Bot added the bugzilla/valid-bug Indicates that a referenced Bugzilla bug is valid for the branch this PR is targeting. label Feb 2, 2022
@openshift-ci
Copy link
Copy Markdown
Contributor

openshift-ci Bot commented Feb 2, 2022

@andreaskaris: This pull request references Bugzilla bug 2048352, which is valid. The bug has been moved to the POST state. The bug has been updated to refer to the pull request using the external bug tracker.

3 validation(s) were run on this bug
  • bug is open, matching expected state (open)
  • bug target release (4.11.0) matches configured target release for branch (4.11.0)
  • bug is in the state ASSIGNED, which is one of the valid states (NEW, ASSIGNED, ON_DEV, POST, POST)

Requesting review from QA contact:
/cc @anuragthehatter

Details

In response to this:

/bugzilla refresh

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@openshift-ci openshift-ci Bot removed the bugzilla/invalid-bug Indicates that a referenced Bugzilla bug is invalid for the branch this PR is targeting. label Feb 2, 2022
@andreaskaris
Copy link
Copy Markdown
Contributor Author

@jcaamano Wdyt?

@andreaskaris
Copy link
Copy Markdown
Contributor Author

/retest

1 similar comment
@andreaskaris
Copy link
Copy Markdown
Contributor Author

/retest

@andreaskaris andreaskaris force-pushed the BZ2048352 branch 2 times, most recently from ba7d11c to 99a127a Compare February 3, 2022 13:38
@jcaamano
Copy link
Copy Markdown
Contributor

jcaamano commented Feb 3, 2022

@andreaskaris on your verification, when you restart NM, how does the NM dhcp request correlate in time with the execution of the dispatcher script? Because there is a time window when the ofport is not the one we expect right?

@andreaskaris
Copy link
Copy Markdown
Contributor Author

Yeah, we lose 1 DHCP DISCOVER, at least for my test. That's not bad though: 2048352-nm-pre-up.txt
There's about 1 second where the ofport ID is set to whatever OVS picks before we set it back.

Comment thread templates/common/_base/files/ofport-request.yaml Outdated
Comment thread templates/common/_base/files/ofport-request.yaml Outdated
@andreaskaris andreaskaris force-pushed the BZ2048352 branch 3 times, most recently from 88a667e to 2b8f100 Compare February 7, 2022 13:01
@andreaskaris
Copy link
Copy Markdown
Contributor Author

@jcaamano I modified the script, now it will:

  • save its state to a file per bridge which keeps track of: interface name -> ofport number
  • use the match from the configuration file
  • if no match in config file: use the current ofport number as ofport_request if that is still free
  • if no match in config file and current ofport number not free: otherwise get the lowest available ofport number and reserve that

It works for linux vlan, linux bond, ovs bond (I tested those on a VM). The only thing that comes to my mind that I haven't tested is an OVS VLAN on the interface and attached to the bridge, if that's even possible.
Unless I missed something, that script should cover more than what we support / handle right now, anyway.

@andreaskaris andreaskaris requested a review from jcaamano February 7, 2022 13:09
@andreaskaris
Copy link
Copy Markdown
Contributor Author

andreaskaris commented Feb 7, 2022

Just FYI - no idea why it landed on ID 2 for this run, but it's stable on 2 with the script:

sh-4.4# systemctl restart NetworkManager
Feb 07 13:58:51 ip-10-0-164-26 systemd[1]: NetworkManager-wait-online.service: Succeeded.
Feb 07 13:58:51 ip-10-0-164-26 systemd[1]: Stopped Network Manager Wait Online.
Feb 07 13:58:51 ip-10-0-164-26 systemd[1]: NetworkManager-wait-online.service: Consumed 64ms CPU time
Feb 07 13:58:51 ip-10-0-164-26 systemd[1]: Stopping Network Manager Wait Online...
Feb 07 13:58:51 ip-10-0-164-26 systemd[1]: Stopping Network Manager...
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9356] caught SIGTERM, shutting down normally.
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9418] device (ens5): ovs interface ens5 was released
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9428] device (br-ex): state change: activated -> deactivating (reason 'unmanaged', sys-iface-state: 'managed')
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9435] device (br-ex): released from master device br-ex
Feb 07 13:58:51 ip-10-0-164-26 dbus-daemon[1011]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.362' (uid=0 pid=21754 comm="/usr/sbin/NetworkManager --no-daemon " label="system_u:system_r:NetworkManager_t:s0")
Feb 07 13:58:51 ip-10-0-164-26 systemd[1]: Starting Network Manager Script Dispatcher Service...
Feb 07 13:58:51 ip-10-0-164-26 systemd[1]: Started Network Manager Script Dispatcher Service.
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9575] device (br-ex): state change: deactivating -> unmanaged (reason 'removed', sys-iface-state: 'managed')
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9576] device (br-ex): releasing ovs interface br-ex
Feb 07 13:58:51 ip-10-0-164-26 ovs-vswitchd[1216]: ovs|00214|bridge|INFO|bridge br-ex: deleted interface br-ex on port 65534
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9593] device (br-ex): state change: activated -> deactivating (reason 'unmanaged', sys-iface-state: 'managed')
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9724] device (br-ex): state change: deactivating -> unmanaged (reason 'removed', sys-iface-state: 'managed')
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9739] device (ens5): state change: activated -> deactivating (reason 'unmanaged', sys-iface-state: 'managed')
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9787] device (ens5): state change: deactivating -> unmanaged (reason 'removed', sys-iface-state: 'managed')
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9798] device (br-ex): state change: activated -> deactivating (reason 'unmanaged', sys-iface-state: 'managed')
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9844] manager: NetworkManager state is now CONNECTED_LOCAL
Feb 07 13:58:51 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242331.9846] device (br-ex): state change: deactivating -> unmanaged (reason 'removed', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242332.0415] dhcp4 (br-ex): canceled DHCP transaction
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242332.0415] dhcp4 (br-ex): state changed bound -> done
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242332.0481] device (patch-br-ex_ip-10-0-164-26.us-west-1.compute.internal-to-br-int): state change: disconnected -> unmanaged (reason 'unmanaged', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242332.0488] device (patch-br-int-to-br-ex_ip-10-0-164-26.us-west-1.compute.internal): state change: disconnected -> unmanaged (reason 'unmanaged', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[21754]: <info>  [1644242332.0704] exiting (success)
sh-4.4# Feb 07 13:58:52 ip-10-0-164-26 systemd[1]: NetworkManager.service: Succeeded.
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: Error: NetworkManager is not running.
Feb 07 13:58:52 ip-10-0-164-26 systemd[1]: Stopped Network Manager.
Feb 07 13:58:52 ip-10-0-164-26 systemd[1]: NetworkManager.service: Consumed 338ms CPU time
Feb 07 13:58:52 ip-10-0-164-26 systemd[1]: Starting Network Manager...
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: Error: NetworkManager is not running.
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.2528] NetworkManager (version 1.30.0-13.el8_4) is starting... (after a restart)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.2529] Read config: /etc/NetworkManager/NetworkManager.conf (lib: 10-disable-default-plugins.conf, 20-client-id-from-mac.conf) (etc: 20-keyfiles.conf, sdn.conf)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.2547] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
Feb 07 13:58:52 ip-10-0-164-26 systemd[1]: Started Network Manager.
Feb 07 13:58:52 ip-10-0-164-26 systemd[1]: Starting Network Manager Wait Online...
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.2661] manager[0x55866d05e0a0]: monitoring kernel firmware directory '/lib/firmware'.
Feb 07 13:58:52 ip-10-0-164-26 dbus-daemon[1011]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.390' (uid=0 pid=23376 comm="/usr/sbin/NetworkManager --no-daemon " label="system_u:system_r:NetworkManager_t:s0")
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4600] hostname: hostname: using hostnamed
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4603] dns-mgr[0x55866d040170]: init: dns=default,systemd-resolved rc-manager=symlink
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4626] Loaded device plugin: NMOvsFactory (/usr/lib64/NetworkManager/1.30.0-13.el8_4/libnm-device-plugin-ovs.so)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4637] Loaded device plugin: NMTeamFactory (/usr/lib64/NetworkManager/1.30.0-13.el8_4/libnm-device-plugin-team.so)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4638] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4639] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4639] manager: Networking is enabled by state file
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4640] dhcp-init: Using DHCP client 'internal'
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4641] settings: Loaded settings plugin: keyfile (internal)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4645] settings: Loaded settings plugin: ifcfg-rh ("/usr/lib64/NetworkManager/1.30.0-13.el8_4/libnm-settings-plugin-ifcfg-rh.so")
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4685] device (lo): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4688] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4696] manager: (br-int): new Open vSwitch Interface device (/org/freedesktop/NetworkManager/Devices/2)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4702] device (ovn-k8s-mp0): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4706] manager: (ovn-k8s-mp0): new Open vSwitch Interface device (/org/freedesktop/NetworkManager/Devices/3)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4712] device (16147bcf5e1f4d0): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4716] manager: (16147bcf5e1f4d0): new Veth device (/org/freedesktop/NetworkManager/Devices/4)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4724] device (2b8c7a20307b049): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4726] manager: (2b8c7a20307b049): new Veth device (/org/freedesktop/NetworkManager/Devices/5)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4731] device (4814a4bd533b5a7): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4733] manager: (4814a4bd533b5a7): new Veth device (/org/freedesktop/NetworkManager/Devices/6)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4738] device (70830a7f5286db3): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4741] manager: (70830a7f5286db3): new Veth device (/org/freedesktop/NetworkManager/Devices/7)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4748] device (99ed29f2729e37f): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4751] manager: (99ed29f2729e37f): new Veth device (/org/freedesktop/NetworkManager/Devices/8)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4758] device (dbbfe654704c49f): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4760] manager: (dbbfe654704c49f): new Veth device (/org/freedesktop/NetworkManager/Devices/9)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4767] device (dc925f44c1082db): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4770] manager: (dc925f44c1082db): new Veth device (/org/freedesktop/NetworkManager/Devices/10)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4779] device (ens5): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4783] manager: (ens5): new Ethernet device (/org/freedesktop/NetworkManager/Devices/11)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4790] manager: (ens5): assume: will attempt to assume matching connection 'ovs-if-phys0' (8917ce7d-dbac-4f14-ad81-ed3c059576c0) (indicated)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4790] device (ens5): state change: unmanaged -> unavailable (reason 'connection-assumed', sys-iface-state: 'assume')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4797] device (ens5): state change: unavailable -> disconnected (reason 'connection-assumed', sys-iface-state: 'assume')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4803] device (ens5): Activation: starting connection 'ovs-if-phys0' (8917ce7d-dbac-4f14-ad81-ed3c059576c0)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4806] device (genev_sys_6081): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4809] manager: (genev_sys_6081): new Generic device (/org/freedesktop/NetworkManager/Devices/12)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4816] manager: (br-ex): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/13)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4821] manager: (br-ex): new Open vSwitch Bridge device (/org/freedesktop/NetworkManager/Devices/14)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4825] device (br-ex): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4835] manager: (ens5): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/15)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4839] device (ens5): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4848] manager: (br-ex): new Open vSwitch Interface device (/org/freedesktop/NetworkManager/Devices/16)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4852] device (br-ex): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4924] device (ens5): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'assume')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4927] device (ens5): state change: prepare -> config (reason 'none', sys-iface-state: 'assume')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4951] manager: (patch-br-ex_ip-10-0-164-26.us-west-1.compute.internal-to-br-int): new Open vSwitch Interface device (/org/freedesktop/NetworkManager/Devices/17)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4954] device (patch-br-ex_ip-10-0-164-26.us-west-1.compute.internal-to-br-int): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4967] manager: (patch-br-int-to-br-ex_ip-10-0-164-26.us-west-1.compute.internal): new Open vSwitch Interface device (/org/freedesktop/NetworkManager/Devices/18)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4970] device (patch-br-int-to-br-ex_ip-10-0-164-26.us-west-1.compute.internal): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4981] manager: (patch-br-int-to-br-ex_ip-10-0-164-26.us-west-1.compute.internal): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/19)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4987] manager: (dbbfe654704c49f): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/20)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.4992] manager: (2b8c7a20307b049): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/21)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5000] manager: (ovn-2749c0-0): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/22)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5007] manager: (16147bcf5e1f4d0): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/23)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5013] manager: (br-int): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/24)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5019] manager: (ovn-f3a74d-0): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/25)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5026] manager: (dc925f44c1082db): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/26)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5035] manager: (70830a7f5286db3): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/27)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5042] manager: (ovn-1eead2-0): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/28)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5048] manager: (99ed29f2729e37f): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/29)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5055] manager: (patch-br-ex_ip-10-0-164-26.us-west-1.compute.internal-to-br-int): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/30)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5061] manager: (ovn-a30de6-0): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/31)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5068] manager: (ovn-k8s-mp0): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/32)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5073] manager: (ovn-7de617-0): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/33)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5080] manager: (4814a4bd533b5a7): new Open vSwitch Port device (/org/freedesktop/NetworkManager/Devices/34)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5086] manager: (br-int): new Open vSwitch Bridge device (/org/freedesktop/NetworkManager/Devices/35)
Feb 07 13:58:52 ip-10-0-164-26 ovs-vswitchd[1216]: ovs|00215|bridge|INFO|bridge br-ex: deleted interface ens5 on port 2
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5226] device (ens5): state change: config -> deactivating (reason 'removed', sys-iface-state: 'assume')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5233] policy: auto-activating connection 'ovs-port-br-ex' (0d8641a3-a462-4956-a37c-ce9599eb8d03)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5235] device (br-ex): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5238] device (ens5): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5245] device (br-ex): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5255] device (br-ex): state change: unavailable -> disconnected (reason 'user-requested', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5260] device (br-ex): Activation: starting connection 'ovs-port-br-ex' (0d8641a3-a462-4956-a37c-ce9599eb8d03)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5261] policy: auto-activating connection 'br-ex' (bef2aa5c-0d7d-43de-92b5-e2700f84c0f5)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5261] policy: auto-activating connection 'ovs-port-phys0' (ea931652-3586-49d0-9dec-c857e132ba05)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5262] device (br-ex): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5275] device (patch-br-ex_ip-10-0-164-26.us-west-1.compute.internal-to-br-int): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5278] device (patch-br-int-to-br-ex_ip-10-0-164-26.us-west-1.compute.internal): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5282] device (br-ex): Activation: starting connection 'br-ex' (bef2aa5c-0d7d-43de-92b5-e2700f84c0f5)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5283] device (br-ex): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5286] manager: NetworkManager state is now CONNECTING
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5290] device (ens5): Activation: starting connection 'ovs-port-phys0' (ea931652-3586-49d0-9dec-c857e132ba05)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5290] policy: auto-activating connection 'ovs-if-br-ex' (fbf0f0a9-545d-475f-b8f7-41371140e0c8)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5293] device (br-ex): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5298] device (br-ex): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5301] device (ens5): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5306] device (ens5): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5310] device (br-ex): Activation: starting connection 'ovs-if-br-ex' (fbf0f0a9-545d-475f-b8f7-41371140e0c8)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5310] device (br-ex): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5325] device (br-ex): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5327] device (br-ex): state change: ip-config -> secondaries (reason 'ip-config-unavailable', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5329] device (ens5): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5331] device (ens5): Activation: connection 'ovs-port-phys0' enslaved, continuing activation
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5331] device (ens5): state change: ip-config -> secondaries (reason 'ip-config-unavailable', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5334] device (br-ex): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5339] device (br-ex): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5342] device (br-ex): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5344] device (br-ex): Activation: connection 'ovs-port-br-ex' enslaved, continuing activation
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5345] device (br-ex): state change: ip-config -> secondaries (reason 'ip-config-unavailable', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5347] device (br-ex): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5357] device (br-ex): Activation: successful, device activated.
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5362] device (ens5): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5372] device (ens5): Activation: successful, device activated.
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5375] device (br-ex): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5379] device (br-ex): Activation: connection 'ovs-if-br-ex' enslaved, continuing activation
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5381] device (br-ex): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5396] device (br-ex): Activation: successful, device activated.
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5400] device (ens5): state change: deactivating -> disconnected (reason 'removed', sys-iface-state: 'assume')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5417] policy: auto-activating connection 'ovs-if-phys0' (8917ce7d-dbac-4f14-ad81-ed3c059576c0)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5423] device (ens5): Activation: starting connection 'ovs-if-phys0' (8917ce7d-dbac-4f14-ad81-ed3c059576c0)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5424] device (ens5): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5429] device (ens5): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5434] device (ens5): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5439] device (ens5): Activation: connection 'ovs-if-phys0' enslaved, continuing activation
Feb 07 13:58:52 ip-10-0-164-26 ovs-vswitchd[1216]: ovs|00216|netdev|WARN|failed to set MTU for network device br-ex: No such device
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5443] device (ens5): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5473] device (br-ex): set-hw-addr: set-cloned MAC address to 06:89:4F:37:29:89 (06:89:4F:37:29:89)
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5475] device (br-ex): carrier: link connected
Feb 07 13:58:52 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242332.5485] dhcp4 (br-ex): activation: beginning transaction (timeout in 45 seconds)
Feb 07 13:58:52 ip-10-0-164-26 ovs-vswitchd[1216]: ovs|00217|bridge|INFO|bridge br-ex: added interface br-ex on port 65534
Feb 07 13:58:52 ip-10-0-164-26 ovs-vswitchd[1216]: ovs|00218|bridge|INFO|bridge br-ex: added interface ens5 on port 5
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: Error: Device '' not found.
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: Error: Device '' not found.
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: Error: Device '' not found.
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: Error: Device '' not found.
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: Error: Device '' not found.
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: + [[ OVNKubernetes != \O\V\N\K\u\b\e\r\n\e\t\e\s ]]
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: + INTERFACE_NAME=ens5
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: + OPERATION=pre-up
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: + '[' pre-up '!=' pre-up ']'
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: ++ nmcli -t -f device,type,uuid conn
Feb 07 13:58:52 ip-10-0-164-26 nm-dispatcher[23344]: ++ awk -F : '{if($1=="ens5" && $2!~/^ovs*/) print $NF}'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + INTERFACE_CONNECTION_UUID=8917ce7d-dbac-4f14-ad81-ed3c059576c0
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' 8917ce7d-dbac-4f14-ad81-ed3c059576c0 == '' ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ nmcli -t -f connection.slave-type conn show 8917ce7d-dbac-4f14-ad81-ed3c059576c0
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ awk -F : '{print $NF}'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + INTERFACE_OVS_SLAVE_TYPE=ovs-port
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' ovs-port '!=' ovs-port ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ nmcli -t -f connection.master conn show 8917ce7d-dbac-4f14-ad81-ed3c059576c0
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ awk -F : '{print $NF}'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + PORT=ea931652-3586-49d0-9dec-c857e132ba05
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' ea931652-3586-49d0-9dec-c857e132ba05 == '' ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ nmcli -t -f device,type,uuid conn
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ awk -F : '{if( ($1=="ea931652-3586-49d0-9dec-c857e132ba05" || $3=="ea931652-3586-49d0-9dec-c857e132ba05") && $2~/^ovs*/) print $NF}'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + PORT_CONNECTION_UUID=ea931652-3586-49d0-9dec-c857e132ba05
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' ea931652-3586-49d0-9dec-c857e132ba05 == '' ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ nmcli -t -f connection.slave-type conn show ea931652-3586-49d0-9dec-c857e132ba05
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ awk -F : '{print $NF}'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + PORT_OVS_SLAVE_TYPE=ovs-bridge
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' ovs-bridge '!=' ovs-bridge ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ nmcli -t -f connection.master conn show ea931652-3586-49d0-9dec-c857e132ba05
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ awk -F : '{print $NF}'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + BRIDGE_NAME=br-ex
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' br-ex == '' ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + CONFIGURATION_FILE=/etc/NetworkManager/ofport_requests.br-ex.conf
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + declare -A INTERFACES
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' -f /etc/NetworkManager/ofport_requests.br-ex.conf ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ cat /etc/NetworkManager/ofport_requests.br-ex.conf
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + echo 'Sourcing configuration file '\''/etc/NetworkManager/ofport_requests.br-ex.conf'\'' with contents: declare -A INTERFACES=([ens5]="2" )'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: Sourcing configuration file '/etc/NetworkManager/ofport_requests.br-ex.conf' with contents: declare -A INTERFACES=([ens5]="2" )
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + source /etc/NetworkManager/ofport_requests.br-ex.conf
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ INTERFACES=([ens5]="2")
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: ++ declare -A INTERFACES
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + '[' a ']'
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + ovs-vsctl set Interface ens5 ofport_request=2
Feb 07 13:58:53 ip-10-0-164-26 ovs-vsctl[23607]: ovs|00001|vsctl|INFO|Called as ovs-vsctl set Interface ens5 ofport_request=2
Feb 07 13:58:53 ip-10-0-164-26 ovs-vswitchd[1216]: ovs|00219|bridge|INFO|bridge br-ex: deleted interface ens5 on port 5
Feb 07 13:58:53 ip-10-0-164-26 ovs-vswitchd[1216]: ovs|00220|bridge|INFO|bridge br-ex: added interface ens5 on port 2
Feb 07 13:58:53 ip-10-0-164-26 nm-dispatcher[23344]: + declare -p INTERFACES
Feb 07 13:58:53 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242333.1214] device (ens5): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:53 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242333.1217] device (ens5): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:53 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242333.1229] device (ens5): Activation: successful, device activated.
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5521] dhcp4 (br-ex): state changed unknown -> bound, address=10.0.164.26
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5535] device (br-ex): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: + [[ OVNKubernetes != \O\V\N\K\u\b\e\r\n\e\t\e\s ]]
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: + INTERFACE_NAME=br-ex
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: + OPERATION=pre-up
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: + '[' pre-up '!=' pre-up ']'
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: ++ nmcli -t -f device,type,uuid conn
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: ++ awk -F : '{if($1=="br-ex" && $2!~/^ovs*/) print $NF}'
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: + INTERFACE_CONNECTION_UUID=
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: + '[' '' == '' ']'
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: + exit 0
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5927] device (br-ex): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5930] device (br-ex): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5935] manager: NetworkManager state is now CONNECTED_LOCAL
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5944] manager: NetworkManager state is now CONNECTED_SITE
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5945] policy: set 'ovs-if-br-ex' (br-ex) as default for IPv4 routing and DNS
Feb 07 13:58:54 ip-10-0-164-26 dbus-daemon[1011]: [system] Activating via systemd: service name='org.freedesktop.resolve1' unit='dbus-org.freedesktop.resolve1.service' requested by ':1.390' (uid=0 pid=23376 comm="/usr/sbin/NetworkManager --no-daemon " label="system_u:system_r:NetworkManager_t:s0")
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5971] device (br-ex): Activation: successful, device activated.
Feb 07 13:58:54 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242334.5976] manager: NetworkManager state is now CONNECTED_GLOBAL
Feb 07 13:58:54 ip-10-0-164-26 nm-dispatcher[23344]: Error: Device '' not found.
fgFeb 07 13:58:58 ip-10-0-164-26 NetworkManager[23376]: <info>  [1644242338.4994] manager: startup complete
Feb 07 13:58:58 ip-10-0-164-26 systemd[1]: Started Network Manager Wait Online.

journalctl -f | egrep 'ovs|Network|nm-dis'
^C
sh-4.4# 
sh-4.4# ovs-ofctl show br-ex
OFPT_FEATURES_REPLY (xid=0x2): dpid:000006894f372989
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
 2(ens5): addr:06:89:4f:37:29:89
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 3(patch-br-ex_ip-): addr:62:7e:6b:1a:91:92
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 LOCAL(br-ex): addr:06:89:4f:37:29:89
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
OFPT_GET_CONFIG_REPLY (xid=0x4): frags=normal miss_send_len=0

@andreaskaris
Copy link
Copy Markdown
Contributor Author

/retest

Comment thread templates/common/_base/files/ofport-request.yaml Outdated
@andreaskaris
Copy link
Copy Markdown
Contributor Author

Output of the latest test:
out.txt

@andreaskaris andreaskaris requested a review from jcaamano February 9, 2022 11:32
@andreaskaris
Copy link
Copy Markdown
Contributor Author

/retest

@andreaskaris andreaskaris changed the title Bug 2048352: ovn-kubernetes: Fixed ofport_request for physical prots Bug 2048352: ovn-kubernetes: Fixed ofport_request for physical ports Feb 9, 2022
@jcaamano
Copy link
Copy Markdown
Contributor

/lgtm
/cc @trozet
PTAL

@openshift-ci openshift-ci Bot added the lgtm Indicates that a PR is ready to be merged. label Feb 10, 2022
@kikisdeliveryservice
Copy link
Copy Markdown
Contributor

@trozet can you PTAL and give final review?

/test e2e-agnostic-upgrade

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With pre-up, has the interface been created in OVS already? Are we guaranteed that?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

According to the documentation: https://developer-old.gnome.org/NetworkManager/stable/NetworkManager.html

pre-up | The interface is connected to the network but is not         yet fully activated.  Scripts acting on this event must be placed or         symlinked into the /etc/NetworkManager/dispatcher.d/pre-up.d         directory, and NetworkManager will wait for script execution to complete before         indicating to applications that the interface is fully activated.
-- | --

So, The interface is connected to the network. There are several traces attached above with debug logging for NM where we can see that the interface is attached to OVS first, and pre-up is run only after that. I also tested on a dedicated virtual machine (RHEL 8.4) with the following setup with various port types (vlan, bond, standalone interfaces), and it works and the behavior is consistent:

[root@rhel84 ~]# ovs-vsctl show
0c29b398-2f10-497a-ba0f-ad834737cbd6
    Bridge br-ex
        Port eth2
            Interface eth2
                type: system
        Port vlan10
            Interface vlan10
                type: system
        Port br-ex
            Interface br-ex
                type: internal
        Port bond0
            Interface eth4
                type: system
            Interface eth5
                type: system
        Port patch-to-br-int
            Interface patch-to-br-int
                type: patch
                options: {peer=patch-to-br-ex}
        Port eth1
            Interface eth1
                type: system
        Port bond1
            Interface bond1
                type: system
    Bridge br-int
        Port patch-to-br-ex
            Interface patch-to-br-ex
                type: patch
                options: {peer=patch-to-br-int}
        Port br-int
            Interface br-int
                type: internal
    Bridge br-ex2
        Port eth3
            Interface eth3
                type: system
    ovs_version: "2.15.3"
[root@rhel84 ~]# nmcli conn
NAME                UUID                                  TYPE           DEVICE 
Wired connection 2  923b22f9-8cc8-32fa-aa0d-54cffb024215  ethernet       eth10  
Wired connection 3  2b1f9ef1-5fb3-35f5-9269-5ab7ef70f5c9  ethernet       eth8   
Wired connection 4  9432aa2c-d1aa-30a1-b852-970bc72b687d  ethernet       eth9   
Wired connection 1  a63944ec-3426-3ec1-b485-5b1603aadf3d  ethernet       eth0   
ovs-if-br-ex        74c03eca-f6a0-4409-b4e5-2698e0e0665a  ovs-interface  br-ex  
bond1               cd4c8622-8ccd-4a3e-b2a1-9b1d57667e80  bond           bond1  
bond1-eth6          23969750-49ef-4145-99c3-6af53b54f4a4  ethernet       eth6   
bond1-eth7          d20b59c8-99c8-4521-980f-9422b1682ab4  ethernet       eth7   
bond1-ovsport       1cc55059-da8f-4838-873c-6458e4c2682b  ovs-port       bond1  
br-ex               9e0055c1-23e7-473c-8444-015d4aa11dac  ovs-bridge     br-ex  
br-ex2              34109401-5f47-44ca-9f3b-5fc1b37422a5  ovs-bridge     br-ex2 
ovs-if-eth1         ec425a9c-9128-4d6e-a367-8cb0493f688f  ethernet       eth1   
ovs-if-eth2         c98f0470-7955-4195-bc0e-2174dc49085f  ethernet       eth2   
ovs-if-eth3         195a5964-2eff-4ead-8bda-0b071739e9d6  ethernet       eth3   
ovs-port-br-ex      0d18b6a6-2fe5-4c44-b705-d2fc4301aafc  ovs-port       br-ex  
ovs-port-br-ex2     8ba11cc7-a222-40f5-86a4-c569a85f81f4  ovs-port       br-ex2 
ovs-port-eth1       47871482-b875-4ba0-bb26-5e213135583f  ovs-port       eth1   
ovs-port-eth2       5b9bdfeb-7238-45dc-b7af-714b9a12ab11  ovs-port       eth2   
ovs-port-eth3       2f4f0995-7ead-4ffe-873c-e1f544ce1b7d  ovs-port       eth3   
ovs-slave-bond0     676b62a4-63b8-4c85-8cba-c1a091616e19  ovs-port       bond0  
ovs-slave-eth4      261b0374-1446-4f19-a2dd-5494b70212fe  ethernet       eth4   
ovs-slave-eth5      5d0fc00d-17e0-471a-b0a9-4bd851876d83  ethernet       eth5   
vlan10              4dfb2bb4-45ed-4fff-b746-6432874fde5a  vlan           vlan10 
vlan10-ovsport      1e7cf87e-a6c0-467c-ae88-70fb0e0d701b  ovs-port       vlan10 
ovs-if-br-ex2       4f70d1f0-48f7-42fa-b4bd-d7f69e4477de  ovs-interface  --   

All traces show that the interface is connected first (and gets a preassigned ID) and then the script kicks in.

Copy link
Copy Markdown
Contributor Author

@andreaskaris andreaskaris Feb 23, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I threw in 545bc39#diff-bfb1096d30a23088db321d88004b44a807716f56cad84e920f3e5451f3d6f1e0R65 as a sanity check to exit gracefully if the interface does not exist.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Comment thread templates/common/_base/files/ofport-request.yaml Outdated
Comment thread templates/common/_base/files/ofport-request.yaml Outdated
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this is really an array. Why use an array to store a single value? There can only be one physical port at a time right?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

a) I wrote the script on a RHEL VM and purposefully added lots of interfaces and interface variatoins to make the script more capable, flexible and future proof. I did not want the script to be a point of failure if for some reason we decide to change anything (as unlikely as it may be).

b) As a more compelling argument, OVS bonds are implemented based on flows and they consist of multiple interfaces each with their own index, so they look like this:

    Bridge br-ex
        Port bond0
            Interface eth4
                type: system
            Interface eth5
                type: system

And each of them get their own port ID:

 5(eth4): addr:52:54:00:df:9c:35
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max
 6(eth5): addr:52:54:00:15:ec:29
     config:     0
     state:      0
     speed: 0 Mbps now, 0 Mbps max

So the array solution is a must if we don't want to exclude OVS bonding. Granted, ovs-configure.sh doesn't do ovs-bonding at the moment, but we don't know for how long this script would be around and what changes we make to ovs-configure.sh, so me might as well do it right in this script here and keep it general purpose and have it handle anything we throw at it.

Comment thread templates/common/_base/files/ofport-request.yaml Outdated
@openshift-ci openshift-ci Bot removed the lgtm Indicates that a PR is ready to be merged. label Feb 23, 2022
@andreaskaris andreaskaris force-pushed the BZ2048352 branch 2 times, most recently from bb3f353 to 9c63e55 Compare February 23, 2022 10:40
When NetworkManager is restarted, all interfaces are removed from the
external bridge (br-ex / breth0). By default, ports' OVS IDs
change and the existing flows point to wrong 'output:' port numbers
leading to packet drops of all traffic that originates at
LOCAL and the node will not be able to request an IP address via DHCP.
Request fixed ofport numbers via the ofport_request field.

Signed-off-by: Andreas Karis <ak.karis@gmail.com>
Copy link
Copy Markdown
Contributor

@trozet trozet left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

/lgtm

@trozet
Copy link
Copy Markdown
Contributor

trozet commented Feb 25, 2022

/assign @kikisdeliveryservice

@openshift-ci openshift-ci Bot added the lgtm Indicates that a PR is ready to be merged. label Feb 25, 2022
@andreaskaris
Copy link
Copy Markdown
Contributor Author

@kikisdeliveryservice Can you approve this? Thanks :-)

@kikisdeliveryservice
Copy link
Copy Markdown
Contributor

/approve

@openshift-ci
Copy link
Copy Markdown
Contributor

openshift-ci Bot commented Mar 2, 2022

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: andreaskaris, jcaamano, kikisdeliveryservice, trozet

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Details Needs approval from an approver in each of these files:
  • OWNERS [kikisdeliveryservice]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@openshift-ci openshift-ci Bot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Mar 2, 2022
@openshift-bot
Copy link
Copy Markdown
Contributor

/retest-required

Please review the full test history for this PR and help us cut down flakes.

@openshift-ci
Copy link
Copy Markdown
Contributor

openshift-ci Bot commented Mar 2, 2022

@andreaskaris: The following tests failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name Commit Details Required Rerun command
ci/prow/e2e-aws-upgrade-single-node 545bc39 link false /test e2e-aws-upgrade-single-node
ci/prow/e2e-aws-workers-rhel8 545bc39 link false /test e2e-aws-workers-rhel8
ci/prow/e2e-metal-ipi 545bc39 link false /test e2e-metal-ipi
ci/prow/e2e-aws-single-node 545bc39 link false /test e2e-aws-single-node
ci/prow/e2e-aws-disruptive 545bc39 link false /test e2e-aws-disruptive
ci/prow/e2e-aws-workers-rhel7 545bc39 link false /test e2e-aws-workers-rhel7

Full PR test history. Your PR dashboard.

Details

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. I understand the commands that are listed here.

@openshift-bot
Copy link
Copy Markdown
Contributor

/retest-required

Please review the full test history for this PR and help us cut down flakes.

1 similar comment
@openshift-bot
Copy link
Copy Markdown
Contributor

/retest-required

Please review the full test history for this PR and help us cut down flakes.

@openshift-merge-robot openshift-merge-robot merged commit 95b6524 into openshift:master Mar 3, 2022
@openshift-ci
Copy link
Copy Markdown
Contributor

openshift-ci Bot commented Mar 3, 2022

@andreaskaris: All pull requests linked via external trackers have merged:

Bugzilla bug 2048352 has been moved to the MODIFIED state.

Details

In response to this:

Bug 2048352: ovn-kubernetes: Fixed ofport_request for physical ports

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

approved Indicates a PR has been approved by an approver from all required OWNERS files. bugzilla/severity-high Referenced Bugzilla bug's severity is high for the branch this PR is targeting. bugzilla/valid-bug Indicates that a referenced Bugzilla bug is valid for the branch this PR is targeting. lgtm Indicates that a PR is ready to be merged.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants