Description of problem: ~~~ [root@standalone ~]# podman ps | grep neutron c0f71c87753a registry-proxy.engineering.redhat.com/rh-osbs/rhosp16-openstack-neutron-server-ovn:16.2_20220609.1 kolla_start 5 weeks ago Up 5 weeks ago neutron_api 8002f415d5c4 registry-proxy.engineering.redhat.com/rh-osbs/rhosp16-openstack-neutron-metadata-agent-ovn:16.2_20220609.1 kolla_start 5 weeks ago Up 5 weeks ago ovn_metadata_agent 0bc5974e8fb8 registry-proxy.engineering.redhat.com/rh-osbs/rhosp16-openstack-neutron-metadata-agent-ovn:16.2_20220609.1 /bin/bash -c HAPR... 5 weeks ago Up 5 weeks ago neutron-haproxy-ovnmeta-b9cfe6b5-831b-419c-bc25-49ba01a33c84 578bb7cab9d2 registry-proxy.engineering.redhat.com/rh-osbs/rhosp16-openstack-neutron-metadata-agent-ovn:16.2_20220609.1 /bin/bash -c HAPR... 4 weeks ago Up 4 weeks ago neutron-haproxy-ovnmeta-ed889e25-f8fa-4684-a9c4-54fff8de37b8 [root@standalone ~]# ~~~ neutron's revision number handling for ports is broken. It doesn't catch conflicts for updates that happen with short delays: Here's the client log (just because it's easier to read). The client sends 2 conflicting updates with revision number 131 in short succession, and both updates are accepted by neutron: ~~~ "PUT /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nContent-Length: 225\r\nAccept: application/json\r\nContent-Type: application/json\r\nIf-Match: revision_number=131\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n{\"port\":{\"allowed_address_pairs\":[{\"ip_address\":\"10.196.0.5\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.0.7\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.10.101\",\"mac_address\":\"fa:16:3e:fe:80:35\"}]}} ~~~ And: ~~~ "PUT /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nContent-Length: 225\r\nAccept: application/json\r\nContent-Type: application/json\r\nIf-Match: revision_number=131\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n{\"port\":{\"allowed_address_pairs\":[{\"ip_address\":\"10.196.0.5\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.0.7\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.10.100\",\"mac_address\":\"fa:16:3e:fe:80:35\"}]}}" ~~~ Full client log: ~~~ "GET /v2.0/ports?device_id=382c107f-a082-4e9b-8adb-2ba45323c479&device_owner=compute%3Anova HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9 dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n" I0817 20:39:34.480120 1 controller.go:182] Assigning key: 10.196.10.101 to cloud-private-ip-config workqueue I0817 20:39:34.484610 1 cloudprivateipconfig_controller.go:187] CloudPrivateIPConfig: "10.196.10.101" will be deleted from node: "ostest-lq27s-worker-0-cz6gw" "GET /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3 PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n" I0817 20:39:34.492376 1 controller.go:182] Assigning key: 10.196.10.101 to cloud-private-ip-config workqueue "GET /v2.0/ports?device_id=382c107f-a082-4e9b-8adb-2ba45323c479&device_owner=compute%3Anova HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n""GET /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n" I0817 20:39:34.586995 1 openstack.go:659] ---- (10.196.10.100)----------- Running unallow, got port &{2ec4488a-35c2-4a14-adfb-a9ec3af61154 ed889e25-f8fa-4684-a9c4-54fff8de37b8 ostest-lq27s-worker-0-cz6gw-0 Created by cluster-api-provider-openstack cluster openshift-machine-api-ostest-lq27s true ACTIVE fa:16:3e:fe:80:35 [{ba4e5cdb-a0e3-47f2-9233-47d5a444412c 10.196.2.215}] 6f69c87fe95b469c8c7709382818acf6 6f69c87fe95b469c8c7709382818acf6 compute:nova [d426fa6b-74e1-4272-95c0-e7edd4978cef] 382c107f-a082-4e9b-8adb-2ba45323c479 [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.100 fa:16:3e:fe:80:35} {10.196.10.101 fa:16:3e:fe:80:35}] [cluster-api-provider-openstack openshift-machine-api-ostest-lq27s openshiftClusterID=ostest-lq27s] 131} I0817 20:39:34.587033 1 openstack.go:660] ---- (10.196.10.100)----------- Running unallow, got port revision number 131 I0817 20:39:34.587039 1 openstack.go:661] ---- (10.196.10.100)----------- Running unallow, got port allowed address pairs [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.100 fa:16:3e:fe:80:35} {10.196.10.101 fa:16:3e:fe:80:35}] I0817 20:39:34.587053 1 openstack.go:678] ---- (10.196.10.100)----------- built new allowedPairs [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.101 fa:16:3e:fe:80:35}] I0817 20:39:34.587063 1 openstack.go:687] ---- (10.196.10.100)----------- sending update p.ID: 2ec4488a-35c2-4a14-adfb-a9ec3af61154, opts.AllowedAddressPairs: [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.101 fa:16:3e:fe:80:35}], opts.RevisionNumber: 131 "PUT /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nContent-Length: 225\r\nAccept: application/json\r\nContent-Type: application/json\r\nIf-Match: revision_number=131\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n{\"port\":{\"allowed_address_pairs\":[{\"ip_address\":\"10.196.0.5\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.0.7\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.10.101\",\"mac_address\":\"fa:16:3e:fe:80:35\"}]}}" I0817 20:39:34.668150 1 openstack.go:659] ---- (10.196.10.101)----------- Running unallow, got port &{2ec4488a-35c2-4a14-adfb-a9ec3af61154 ed889e25-f8fa-4684-a9c4-54fff8de37b8 ostest-lq27s-worker-0-cz6gw-0 Created by cluster-api-provider-openstack cluster openshift-machine-api-ostest-lq27s true ACTIVE fa:16:3e:fe:80:35 [{ba4e5cdb-a0e3-47f2-9233-47d5a444412c 10.196.2.215}] 6f69c87fe95b469c8c7709382818acf6 6f69c87fe95b469c8c7709382818acf6 compute:nova [d426fa6b-74e1-4272-95c0-e7edd4978cef] 382c107f-a082-4e9b-8adb-2ba45323c479 [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.100 fa:16:3e:fe:80:35} {10.196.10.101 fa:16:3e:fe:80:35}] [cluster-api-provider-openstack openshift-machine-api-ostest-lq27s openshiftClusterID=ostest-lq27s] 131} I0817 20:39:34.668192 1 openstack.go:660] ---- (10.196.10.101)----------- Running unallow, got port revision number 131 I0817 20:39:34.668201 1 openstack.go:661] ---- (10.196.10.101)----------- Running unallow, got port allowed address pairs [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.100 fa:16:3e:fe:80:35} {10.196.10.101 fa:16:3e:fe:80:35}] I0817 20:39:34.668216 1 openstack.go:678] ---- (10.196.10.101)----------- built new allowedPairs [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.100 fa:16:3e:fe:80:35}] I0817 20:39:34.668226 1 openstack.go:687] ---- (10.196.10.101)----------- sending update p.ID: 2ec4488a-35c2-4a14-adfb-a9ec3af61154, opts.AllowedAddressPairs: [{10.196.0.5 fa:16:3e:fe:80:35} {10.196.0.7 fa:16:3e:fe:80:35} {10.196.10.100 fa:16:3e:fe:80:35}], opts.RevisionNumber: 131 "PUT /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nContent-Length: 225\r\nAccept: application/json\r\nContent-Type: application/json\r\nIf-Match: revision_number=131\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n{\"port\":{\"allowed_address_pairs\":[{\"ip_address\":\"10.196.0.5\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.0.7\",\"mac_address\":\"fa:16:3e:fe:80:35\"},{\"ip_address\":\"10.196.10.100\",\"mac_address\":\"fa:16:3e:fe:80:35\"}]}}" I0817 20:39:35.613084 1 openstack.go:703] ---- (10.196.10.100)----------- done with update, err: <nil> "GET /v2.0/subnets?network_id=ed889e25-f8fa-4684-a9c4-54fff8de37b8 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n""GET /v2.0/ports?network_id=ed889e25-f8fa-4684-a9c4-54fff8de37b8 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n" I0817 20:39:35.848105 1 openstack.go:703] ---- (10.196.10.101)----------- done with update, err: <nil> "GET /v2.0/subnets?network_id=ed889e25-f8fa-4684-a9c4-54fff8de37b8 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n""DELETE /v2.0/ports/dbcf5cf7-4bf4-4b1b-adb8-48db663dac0d HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n""GET /v2.0/ports?network_id=ed889e25-f8fa-4684-a9c4-54fff8de37b8 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n""DELETE /v2.0/ports/4de9645e-d49b-4f02-a873-186645e1ea23 HTTP/1.1\r\nHost: 10.1.8.109:13696\r\nUser-Agent: gophercloud/2.0.0\r\nAccept: application/json\r\nX-Auth-Token: gAAAAABi_VJdMWYkBokiAWe2dfR4bxiRddzESQ47nbMKHHDQq3P8lNCacfRNP0ugdNpCb3PLFhuD1S7HElmB2oizSyczoHTwWACQ9W1wZ1E-Ias9dx_9wqRGkZCHqO8DJ7qwAdk3zY776fgcbqvlnUf0V2yvpr4hHxwJ9_GFx3TKMeWSwpsCaS0\r\nAccept-Encoding: gzip\r\n\r\n" I0817 20:39:36.753163 1 cloudprivateipconfig_controller.go:242] CloudPrivateIPConfig: 10.196.10.101 object has been marked for complete deletion I0817 20:39:36.753210 1 cloudprivateipconfig_controller.go:249] Cleaning up IP address and finalizer for CloudPrivateIPConfig: "10.196.10.101", deleting it completely I0817 20:39:36.764505 1 controller.go:160] Dropping key '10.196.10.101' from the cloud-private-ip-config workqueue I0817 20:39:36.766042 1 controller.go:182] Assigning key: 10.196.10.101 to cloud-private-ip-config workqueue I0817 20:39:36.768778 1 cloudprivateipconfig_controller.go:421] CloudPrivateIPConfig: "10.196.10.101" in work queue no longer exists ~~~ Here is the neutron log for that; it accepts both updates with revision number 131, and then bumps the revision to 132 and 133 respectively: ~~~ [root@standalone ~]# grep req-196744ef-304f-426e-9fa3-16137eafb0af /var/log/containers/neutron/server.log 2022-08-17 20:41:45.516 21 DEBUG neutron.api.v2.base [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Request body: {'port': {'allowed_address_pairs': [{'ip_address': '10.196.0.5', 'mac_address': 'fa:16:3e:fe:80:35'}, {'ip_address': '10.196.0.7', 'mac_address': 'fa:16:3e:fe:80:35'}, {'ip_address': '10.196.10.101', 'mac_address': 'fa:16:3e:fe:80:35'}]}} prepare_request_body /usr/lib/python3.6/site-packages/neutron/api/v2/base.py:719 2022-08-17 20:41:45.763 21 DEBUG neutron_lib.callbacks.manager [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.plugins.ml2.plugin.SecurityGroupDbMixin._ensure_default_security_group_handler-3170459', 'networking_ovn.l3.l3_ovn.OVNL3RouterPlugin._port_update--9223363258570713375'] for port, before_update _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.232 21 DEBUG neutron.plugins.ml2.db [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] For port 2ec4488a-35c2-4a14-adfb-a9ec3af61154, host standalone.shiftstack, got binding levels [PortBindingLevel(driver='ovn',host='standalone.shiftstack',level=0,port_id=2ec4488a-35c2-4a14-adfb-a9ec3af61154,segment=NetworkSegment(498d3767-87ec-4ae6-a7d0-0c315e928f01),segment_id=498d3767-87ec-4ae6-a7d0-0c315e928f01)] get_binding_level_objs /usr/lib/python3.6/site-packages/neutron/plugins/ml2/db.py:99 2022-08-17 20:41:46.284 21 DEBUG neutron_lib.callbacks.manager [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.services.qos.qos_plugin.QoSPlugin._validate_update_port_callback-687895'] for port, precommit_update _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.285 21 DEBUG networking_ovn.ml2.mech_driver [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] No provisioning block for port 2ec4488a-35c2-4a14-adfb-a9ec3af61154 since it is active _is_port_provisioning_required /usr/lib/python3.6/site-packages/networking_ovn/ml2/mech_driver.py:598 2022-08-17 20:41:46.287 21 DEBUG neutron_lib.callbacks.manager [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.plugins.ml2.plugin.SecurityGroupServerNotifierRpcMixin.notify_sg_on_port_change-3170336', 'neutron.plugins.ml2.extensions.dns_integration._update_port_in_external_dns_service-8778285656554', 'neutron.plugins.ml2.ovo_rpc._ObjectChangeHandler.handle_event-1755367', 'neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._native_event_send_dhcp_notification-14770236', 'neutron.db.l3_db.L3RpcNotifierMixin._notify_gateway_port_ip_changed--9223363258569049204', 'networking_ovn.l3.l3_ovn.OVNL3RouterPlugin._port_update--9223363258570713375', 'neutron.services.trunk.plugin.TrunkPlugin._trigger_trunk_status_change--9223372036854647104', 'neutron.services.segments.plugin.NovaSegmentNotifier._notify_port_updated--9223372036853128850', 'neutron.services.portforwarding.pf_plugin.PortForwardingPlugin._process_port_request-16707852', 'neutron.services.segments.plugin.NovaSegmentNotifier._notify_port_updated--9223372036839036187'] for port, after_update _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.324 21 DEBUG neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Network ed889e25-f8fa-4684-a9c4-54fff8de37b8 is not hosted by any dhcp agent _notify_agents /usr/lib/python3.6/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py:227 2022-08-17 20:41:46.384 21 DEBUG neutron.api.rpc.handlers.resources_rpc [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - - -] Pushing event updated for resources: {'Port': ['ID=2ec4488a-35c2-4a14-adfb-a9ec3af61154,revision_number=132']} push /usr/lib/python3.6/site-packages/neutron/api/rpc/handlers/resources_rpc.py:243 2022-08-17 20:41:46.439 21 DEBUG networking_ovn.common.ovn_client [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Parent port 2ec4488a-35c2-4a14-adfb-a9ec3af61154 found for virtual port dbcf5cf7-4bf4-4b1b-adb8-48db663dac0d _set_unset_virtual_port_type /usr/lib/python3.6/site-packages/networking_ovn/common/ovn_client.py:457 2022-08-17 20:41:46.523 21 INFO networking_ovn.db.revision [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Successfully bumped revision number for resource 2ec4488a-35c2-4a14-adfb-a9ec3af61154 (type: ports) to 132 2022-08-17 20:41:46.535 21 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Attributes excluded by policy engine: ['binding:profile', 'binding:host_id', 'binding:vif_type', 'binding:vif_details', 'resource_request'] _exclude_attributes_by_policy /usr/lib/python3.6/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2022-08-17 20:41:46.535 21 DEBUG neutron_lib.callbacks.manager [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.notifiers.nova.Notifier._send_nova_notification-1632080'] for port, before_response _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.536 21 INFO neutron.wsgi [req-196744ef-304f-426e-9fa3-16137eafb0af 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] 192.168.24.1 "PUT /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1" status: 200 len: 1639 time: 1.0243335 ~~~ ~~~ [root@standalone ~]# grep req-460b66b3-5111-4822-b55e-f8bb3067bafb /var/log/containers/neutron/server.log 2022-08-17 20:41:45.597 26 DEBUG neutron.api.v2.base [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Request body: {'port': {'allowed_address_pairs': [{'ip_address': '10.196.0.5', 'mac_address': 'fa:16:3e:fe:80:35'}, {'ip_address': '10.196.0.7', 'mac_address': 'fa:16:3e:fe:80:35'}, {'ip_address': '10.196.10.100', 'mac_address': 'fa:16:3e:fe:80:35'}]}} prepare_request_body /usr/lib/python3.6/site-packages/neutron/api/v2/base.py:719 2022-08-17 20:41:45.846 26 DEBUG neutron_lib.callbacks.manager [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.plugins.ml2.plugin.SecurityGroupDbMixin._ensure_default_security_group_handler-3170459', 'networking_ovn.l3.l3_ovn.OVNL3RouterPlugin._port_update--9223363258570713375'] for port, before_update _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.398 26 DEBUG neutron.plugins.ml2.db [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] For port 2ec4488a-35c2-4a14-adfb-a9ec3af61154, host standalone.shiftstack, got binding levels [PortBindingLevel(driver='ovn',host='standalone.shiftstack',level=0,port_id=2ec4488a-35c2-4a14-adfb-a9ec3af61154,segment=NetworkSegment(498d3767-87ec-4ae6-a7d0-0c315e928f01),segment_id=498d3767-87ec-4ae6-a7d0-0c315e928f01)] get_binding_level_objs /usr/lib/python3.6/site-packages/neutron/plugins/ml2/db.py:99 2022-08-17 20:41:46.455 26 DEBUG neutron_lib.callbacks.manager [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.services.qos.qos_plugin.QoSPlugin._validate_update_port_callback-687895'] for port, precommit_update _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.456 26 DEBUG networking_ovn.ml2.mech_driver [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] No provisioning block for port 2ec4488a-35c2-4a14-adfb-a9ec3af61154 since it is active _is_port_provisioning_required /usr/lib/python3.6/site-packages/networking_ovn/ml2/mech_driver.py:598 2022-08-17 20:41:46.459 26 DEBUG neutron_lib.callbacks.manager [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.plugins.ml2.plugin.SecurityGroupServerNotifierRpcMixin.notify_sg_on_port_change-3170336', 'neutron.plugins.ml2.extensions.dns_integration._update_port_in_external_dns_service-8778285656554', 'neutron.plugins.ml2.ovo_rpc._ObjectChangeHandler.handle_event-1755367', 'neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._native_event_send_dhcp_notification-14770236', 'neutron.db.l3_db.L3RpcNotifierMixin._notify_gateway_port_ip_changed--9223363258569049204', 'networking_ovn.l3.l3_ovn.OVNL3RouterPlugin._port_update--9223363258570713375', 'neutron.services.trunk.plugin.TrunkPlugin._trigger_trunk_status_change--9223372036854647104', 'neutron.services.segments.plugin.NovaSegmentNotifier._notify_port_updated--9223372036853128850', 'neutron.services.portforwarding.pf_plugin.PortForwardingPlugin._process_port_request-16707852', 'neutron.services.segments.plugin.NovaSegmentNotifier._notify_port_updated-15298048'] for port, after_update _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.520 26 DEBUG neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Network ed889e25-f8fa-4684-a9c4-54fff8de37b8 is not hosted by any dhcp agent _notify_agents /usr/lib/python3.6/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py:227 2022-08-17 20:41:46.561 26 DEBUG neutron.api.rpc.handlers.resources_rpc [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - - -] Pushing event updated for resources: {'Port': ['ID=2ec4488a-35c2-4a14-adfb-a9ec3af61154,revision_number=133']} push /usr/lib/python3.6/site-packages/neutron/api/rpc/handlers/resources_rpc.py:243 2022-08-17 20:41:46.632 26 DEBUG networking_ovn.common.ovn_client [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Parent port 2ec4488a-35c2-4a14-adfb-a9ec3af61154 found for virtual port dbcf5cf7-4bf4-4b1b-adb8-48db663dac0d _set_unset_virtual_port_type /usr/lib/python3.6/site-packages/networking_ovn/common/ovn_client.py:457 2022-08-17 20:41:46.683 26 DEBUG networking_ovn.common.ovn_client [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Parent port 2ec4488a-35c2-4a14-adfb-a9ec3af61154 found for virtual port 4de9645e-d49b-4f02-a873-186645e1ea23 _set_unset_virtual_port_type /usr/lib/python3.6/site-packages/networking_ovn/common/ovn_client.py:457 2022-08-17 20:41:46.758 26 INFO networking_ovn.db.revision [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Successfully bumped revision number for resource 2ec4488a-35c2-4a14-adfb-a9ec3af61154 (type: ports) to 133 2022-08-17 20:41:46.769 26 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Attributes excluded by policy engine: ['binding:profile', 'binding:host_id', 'binding:vif_type', 'binding:vif_details', 'resource_request'] _exclude_attributes_by_policy /usr/lib/python3.6/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2022-08-17 20:41:46.770 26 DEBUG neutron_lib.callbacks.manager [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Notify callbacks ['neutron.notifiers.nova.Notifier._send_nova_notification-1632080'] for port, before_response _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193 2022-08-17 20:41:46.771 26 INFO neutron.wsgi [req-460b66b3-5111-4822-b55e-f8bb3067bafb 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] 192.168.24.1 "PUT /v2.0/ports/2ec4488a-35c2-4a14-adfb-a9ec3af61154 HTTP/1.1" status: 200 len: 1639 time: 1.1779168 ~~~ I do know for a fact that the revision number conflict detection does work from time to time because sometimes it does show up in the logs: ~~~ 2022-08-17 19:49:44.221 22 INFO networking_ovn.db.revision [req-7d32fd8e-4732-4bb4-ab12-3635a0ec334e 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Successfully bumped revision number for resource 2e c4488a-35c2-4a14-adfb-a9ec3af61154 (type: ports) to 98 2022-08-17 19:49:44.222 16 ERROR ovsdbapp.backend.ovs_idl.transaction [req-c14b8ded-600b-45f5-bfe1-bb0e1596f9a7 3c88c234ba004865bbae69a2a28f0dfe 6f69c87fe95b469c8c7709382818acf6 - default default] Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/connection.py", line 130, in run txn.results.put(txn.do_commit()) File "/usr/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 91, in do_commit command.run_idl(txn) File "/usr/lib/python3.6/site-packages/networking_ovn/ovsdb/commands.py", line 938, in run_idl resource_id=self.name, resource_type=self.resource_type) networking_ovn.common.exceptions.RevisionConflict: OVN revision number for 2ec4488a-35c2-4a14-adfb-a9ec3af61154 (type: ports) is equal or higher than the given resource. Skipping update ~~~ Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info:
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 120 days