Comment 4 for bug 1964940

Revision history for this message
Slawek Kaplonski (slaweq) wrote :

It seems like some Neutron (or OVN) issue here. I took a look at logs from https://logserver.rdoproject.org/54/36254/80/check/periodic-tripleo-ci-centos-9-ovb-3ctlr_1comp-featureset001-wallaby/ad62ee9/logs/undercloud/var/log/tempest/stestr_results.html.gz and I checked vm created in the test tempest.api.compute.security_groups.test_security_groups.SecurityGroupsTestJSON.test_server_security_groups (uuid of the vm: 2b66e196-c206-4f0c-bfab-5a2eefe112ad)

VM was created by Nova around 16:42, and it updated port in Neutron at that time:

2022-03-15 16:42:07.030 2 DEBUG nova.network.neutron [req-ca324b7c-1fa7-4463-9fd3-1873ad272a60 33dd76647428416bade2e9761ac1c966 7845cd695c68496f8586c041a92a25b9 - default default] [instance: 2b66e196-c206-4f0c-bfab-5a2eefe112ad] Successfully updated port: 6a712e97-bc61-49a0-aee6-66d4fcd7b72d _update_port /usr/lib/python3.9/site-packages/nova/network/neutron.py:585

And later timedout waiting for vif plugging event to be send by Neutron about 300 seconds later:

2022-03-15 16:47:08.554 2 ERROR nova.compute.manager [req-ca324b7c-1fa7-4463-9fd3-1873ad272a60 33dd76647428416bade2e9761ac1c966 7845cd695c68496f8586c041a92a25b9 - default default] [instance: 2b66e196-c206-4f0c-bfab-5a2eefe112ad] Instance failed to spawn: nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2022-03-15 16:47:08.554 2 ERROR nova.compute.manager [instance: 2b66e196-c206-4f0c-bfab-5a2eefe112ad] Traceback (most recent call last):

Now, in Neutron logs, the only things related to the port provisioning are:

- transition to active not triggered due to provisioning block by L2 entity:
2022-03-15 16:42:06.338 15 DEBUG neutron.db.provisioning_blocks [req-f30cecff-57fd-4141-b963-a8e3a8dbd1f0 662983d3036b4e7a9cd55bfd01284d06 bcbe34bb1407478089c9e4bb99594495 - default default] Transition to ACTIVE for port object 6a712e97-bc61-49a0-aee6-66d4fcd7b72d will not be triggered until provisioned by entity L2. add_provisioning_component /usr/lib/python3.9/site-packages/neutron/db/provisioning_blocks.py:73

- port binding:
2022-03-15 16:42:06.724 15 DEBUG neutron.plugins.ml2.managers [req-f30cecff-57fd-4141-b963-a8e3a8dbd1f0 662983d3036b4e7a9cd55bfd01284d06 bcbe34bb1407478089c9e4bb99594495 - default default] Bound port: 6a712e97-bc61-49a0-aee6-66d4fcd7b72d, host: overcloud-novacompute-0.localdomain, vif_type: ovs, vif_details: {"port_filter": true, "connectivity": "l2"}, binding_levels: [{'bound_driver': 'ovn', 'bound_segment': {'id': '743a70a6-b626-4738-8845-0b904456acdc', 'network_type': 'geneve', 'physical_network': None, 'segmentation_id': 49632, 'network_id': 'e00f2b59-05a7-4921-8b34-4ee494c04abc'}}] _bind_port_level /usr/lib/python3.9/site-packages/neutron/plugins/ml2/managers.py:928

- and OVN reports status UP, but it's way to long after vm was already deleted:

2022-03-15 16:50:31.218 15 INFO neutron.plugins.ml2.drivers.ovn.mech_driver.mech_driver [req-dbbfd0fb-bec7-4a80-83af-c863ca531175 - - - - -] OVN reports status up for port: 6a712e97-bc61-49a0-aee6-66d4fcd7b72d