On Tue, Nov 30 2021 at 02:46:30 AM +0000, Tony Liu tonyliu0592@hotmail.com wrote:

Hi,

With Ussuri, when launch VM, I see this from nova-compute.

Received unexpected event network-vif-plugged-32b7af8a-ef81-4785-bd79-3a5619823638 ========

That caused VM to be destroyed, rescheduled and relaunched. And that recreation worked fine. From user POV, it just takes a bit longer to launch the VM. What's the event nova-compute expects from Neutron for vif-plug? Any hints where I can look into it?

More logs here.

2021-11-29 18:28:10.064 7 INFO os_vif [req-2a89f605-6972-41dc-83f1-1ef6a444e486 b8de8d37a30147fd98681c22fc515874 b5938e7ebb0645e396b19e99bb7f9868 - default default] Successfully plugged vif VIFOpenVSwitch(active=False,address=fa:16:3e:f1:94:a0,bridge_name='br-int',has_traffic_filtering=True,id=32b7af8a-ef81-4785-bd79-3a5619823638,network=Network(27ea27c6-3d1e-4d37-ad4a-de2ae1578f1e),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=False,vif_name='tap32b7af8a-ef') 2021-11-29 18:28:10.515 7 INFO nova.compute.manager [req-01cbb5ac-d453-4484-9384-1a2173b532a9 - - - - -] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce] VM Started (Lifecycle Event) 2021-11-29 18:28:10.544 7 INFO nova.compute.manager [req-01cbb5ac-d453-4484-9384 -1a2173b532a9 - - - - -] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce] VM Paused (Lifecycle Event) 2021-11-29 18:28:10.604 7 INFO nova.compute.manager [req-01cbb5ac-d453-4484-9384 -1a2173b532a9 - - - - -] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce] During sync_power_state the instance has a pending task (spawning). Skip. 2021-11-29 18:28:25.441 7 INFO nova.compute.manager [req-01cbb5ac-d453-4484-9384 -1a2173b532a9 - - - - -] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce] VM Res umed (Lifecycle Event) 2021-11-29 18:28:25.445 7 INFO nova.virt.libvirt.driver [-] [instance: a8eb2a2a- 8c83-46b2-bfd4-fd3a7d00f2ce] Instance spawned successfully. 2021-11-29 18:28:25.445 7 INFO nova.compute.manager [req-2a89f605-6972-41dc-83f1-1ef6a444e486 b8de8d37a30147fd98681c22fc515874 b5938e7ebb0645e396b19e99bb7f9868

• default default] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce]

Took 18.75 seconds to spawn the instance on the hypervisor. 2021-11-29 18:28:25.502 7 INFO nova.compute.manager [req-01cbb5ac-d453-4484-9384-1a2173b532a9 - - - - -] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce] During sync_power_state the instance has a pending task (spawning). Skip. 2021-11-29 18:28:25.514 7 INFO nova.compute.manager [req-2a89f605-6972-41dc-83f1-1ef6a444e486 b8de8d37a30147fd98681c22fc515874 b5938e7ebb0645e396b19e99bb7f9868

• default default] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce]

Took 19.46 seconds to build instance. 2021-11-29 18:28:27.466 7 WARNING nova.compute.manager [req-82314965-fe71-4993-bbf6-f0aa9e708529 f0c1375066214e24ab7942d72d829097 3ec2940fc10d4e57bcf929d1fe678c79 - default default] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce] Received unexpected event network-vif-plugged-32b7af8a-ef81-4785-bd79-3a5619823638 for instance with vm_state active and task_state None. 2021-11-29 18:28:55.829 7 INFO nova.compute.manager [req-e36e4a81-4755-4d7f-9ee4-d43d00629765 b8de8d37a30147fd98681c22fc515874 b5938e7ebb0645e396b19e99bb7f9868

• default default] [instance: a8eb2a2a-8c83-46b2-bfd4-fd3a7d00f2ce]

Terminating instance ========

Probably something is missing from the log as there are almost 30 seconds between the unexpected vif-plugged event and the termination of the instance. Could you turn on the debug logging and reproduce the issue? In general unexpected vif events just logged and then ignored so it should not cause any issue directly.

Cheers, gibi

Thanks! Tony