OpenStack Compute (nova)

detach_interface doesn't take an instance.uuid and can race requests that do such as delete.

Bug #1914664 reported by Dan Smith on 2021-02-04

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	OpenStack Compute (nova)	Confirmed	Medium	Lee Yarwood

Bug Description

Seeing this failure in the gate:

https://zuul.opendev.org/t/openstack/build/7c71502b04fe47039b87f76fbe04fe56/log/controller/logs/screen-n-cpu.txt#33096

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [req-77f51485-cbc2-4f2a-8a6d-4a8ed910e585 req-a221d4f9-401e-420a-911e-8d32536a1d23 service nova] [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] detaching network adapter failed.: libvirt.libvirtError: internal error: End of file from qemu monitor

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] Traceback (most recent call last):

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] ctx.reraise = True

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] self.force_reraise()

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] raise value

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] six.reraise(c, e, tb)

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] raise value

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431] rv = meth(*args, **kwargs)

Feb 04 20:54:32.857198 ubuntu-focal-limestone-regionone-0022873642 nova-compute[90163]: ERROR nova.virt.libvirt.driver [instance: 7174e97c-8cf4-46c7-9498-2c5dbc452431]

This was in a cinder-glance-multistore test, but I'm not sure it has anything to do with those. That test backs glance with cinder, but otherwise I wouldn't think nova would notice unless it was a failure to snapshot, use a volume, etc.

Revision history for this message

Balazs Gibizer (balazs-gibizer) wrote on 2021-02-11:

This is the affected domain's log: https://zuul.opendev.org/t/openstack/build/7c71502b04fe47039b87f76fbe04fe56/log/controller/logs/libvirt/qemu/instance-0000004a_log.txt but it does not help.

The libvirtd log full of

qemuProcessHandleMonitorEOF:293 : Received EOF on 0x7f046c0de400 'instance-0000004a

lines but other than that I don't see anything helpful there either.

I cannot really put a signature on this as [1] shows mostly successful build as well as [2]

[1] http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22raise%20libvirtError('virDomainDetachDeviceFlags()%20failed')%5C%22
[2] http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22libvirt.libvirtError%3A%20internal%20error%3A%20End%20of%20file%20from%20qemu%20monitor%5C%22

Revision history for this message

Balazs Gibizer (balazs-gibizer) wrote on 2021-02-11:

The quota issue is tracked in a separate bug https://bugs.launchpad.net/glance/+bug/1914665

Lee Yarwood (lyarwood) on 2021-02-11

summary:

- QEMU monitor read failure in ServerStableDeviceRescueTest
+ QEMU monitor read failure in AttachInterfacesTest

Revision history for this message

Lee Yarwood (lyarwood) wrote on 2021-02-11: Re: QEMU monitor read failure in AttachInterfacesTest

Thanks for pointing to that gibi.

Ignoring c#2 now, talking to Dan it looks like this is a race in the cleanup code for AttachInterfacesTestJSON where n-cpu was handling a request (req-77f51485-cbc2-4f2a-8a6d-4a8ed910e585) to detach an interface when another request (req-1547ac08-96e2-4878-a7d2-b71a33849aad) to delete the instance came in causing the monitor error as we destroyed the domain.

I wonder if detach_interface [1] should be taking an instance.uuid lock instead of an interface specific lock? We already do this for detach_volume [2] that would stop the same happening there when terminate_instance [3] is called, taking an instance.uuid lock.

[1] https://github.com/openstack/nova/blob/fec44e5d38baa0232bf41367303b82dc332eb512/nova/compute/manager.py#L7730-L7738
[2] https://github.com/openstack/nova/blob/fec44e5d38baa0232bf41367303b82dc332eb512/nova/compute/manager.py#L7145-L7165
[3] https://github.com/openstack/nova/blob/fec44e5d38baa0232bf41367303b82dc332eb512/nova/compute/manager.py#L3018-L3055

Revision history for this message

Balazs Gibizer (balazs-gibizer) wrote on 2021-02-18:

For me taking the instance lock feels like a good solution.

Revision history for this message

Balazs Gibizer (balazs-gibizer) wrote on 2021-02-18:

Marking this as Triaged as we now see a way forward.

Changed in nova:
status:	New → Triaged

Lee Yarwood (lyarwood) on 2021-06-10

Changed in nova:
importance:	Undecided → Medium
status:	Triaged → Confirmed
tags:	removed: gate-failure
summary:	- QEMU monitor read failure in AttachInterfacesTest + detach_interface doesn't take an instance.uuid and can race requests + that do such as delete.
Changed in nova:
assignee:	nobody → Lee Yarwood (lyarwood)

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.