Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2022-02-10
12:32:09 gibi kashyap: thanks
12:32:21 gibi kashyap: could be the guest keeping the dev busy?
12:32:37 sean-k-mooney kashyap: unplug requries the guest kernel to cooperate
12:32:40 kashyap gibi: Right, this is a negative test of server rescue, right? I'm trying to look at the exact test
12:32:41 gibi sean-k-mooney: do you have a qemu version number from which we should never retry?
12:32:51 sean-k-mooney so if the guest is not fully booted or busy that can delay it
12:32:58 kashyap sean-k-mooney: But note: there's no QEMU guest agent installed here
12:33:10 sean-k-mooney kashyap: it is not realted to the guest agent
12:33:39 sean-k-mooney its related to hardware interupts that are sent by qemu that guest must process
12:34:22 sean-k-mooney either via achi or the pci native hotplug mechium depend on you machinetype and qemu version
12:34:25 gibi kashyap: we have a positive test test_stable_device_rescue_disk_virtio_with_volume_attached and a negative test_stable_device_rescue_disk_virtio_with_volume_attached both failing
12:34:29 gibi ahh
12:34:34 gibi this is the negative test_rescued_vm_detach_volume
12:35:05 kashyap Yeah, this is negative that's failing
12:35:16 kashyap What exactly is the negative test doing? /me looks...
12:35:18 sean-k-mooney gibi: in terms of the exact vesion i think its in the release notes but ill see if i can find it
12:35:43 kashyap sean-k-mooney: Are you confident it is "related to hardware interupts that are sent by QEMU?" What evidence there is for it?
12:36:12 gibi sean-k-mooney: thanks. if we know the version number then I can craft a patch that conditionally set the detach attempts to 1 if the qemu is new enough
12:37:02 sean-k-mooney kashyap: we dont know that for certin and in fact i think https://bugzilla.redhat.com/show_bug.cgi?id=2007129 is a large part of the problem
12:37:55 sean-k-mooney unless you use virtio-scsi which we dont by default each volume attach and deatch is a pci hotplug form teh guest perspective as we add a seperte pci device for each virtio-blk device
12:38:28 frickler kashyap: for downloading logs, I think wget may have issues because the source is swift and not a "normal" webserver. you may want to look at https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_3e2/828280/1/check/devstack-platform-centos-9-stream/3e24d97/download-logs.sh and maybe filter if you need only some subdirs
12:38:44 kashyap Okay, that bug is about PCI hotplug emulation
12:38:46 sean-k-mooney kashyap: that bug might be unrealted but artom suggested it might be in a different context
12:38:52 kashyap sean-k-mooney: Do you know what the negative test is exaclty doing?
12:39:09 sean-k-mooney i have not looked expictly
12:39:34 sean-k-mooney i guess botting into rescue mode and detaching a cinder volume
12:40:21 gibi yepp it does that, I try to correlate that with the logs
12:40:21 sean-k-mooney https://github.com/openstack/tempest/blob/7e96c8e854386f43604ad098a6ec7606ee676145/tempest/api/compute/servers/test_server_rescue_negative.py#L136
12:40:26 kashyap So it is trying to rescue a paused instance, and a non-existing instance
12:40:44 sean-k-mooney no
12:41:17 sean-k-mooney its booting a vm, attaching a volume, then puting it in rescue mode which reboot with a new root disk
12:41:26 sean-k-mooney waiting for ti to get to rescue meaning its running
12:41:57 sean-k-mooney then asserting that detach raises a 409 conflict
12:42:25 sean-k-mooney there is not paused instance
12:42:47 kashyap sean-k-mooney: Well. What do you think this is doing, then? - test_rescue_non_existent_server()?
12:43:01 kashyap And test_rescue_paused_instance()
12:43:22 sean-k-mooney its just asserting that if the server does not exist the rescue call returns a 404
12:43:40 kashyap And there are also: test_rescued_vm_attach_volume() and test_rescued_vm_detach_volume()
12:43:42 sean-k-mooney paused is asserting that you cant call resuce when its paused
12:43:56 sean-k-mooney yep
12:43:59 sean-k-mooney how is this relevent
12:44:38 sean-k-mooney the test all look valid and are asserting what i woudl expect
12:44:47 kashyap It is relevant in the sense that these are the different tests being run here
12:45:09 sean-k-mooney yes they are differnt test but they are not using the same vm
12:45:18 kashyap Yep, noted
12:45:22 sean-k-mooney so they should have no impact on each other
12:45:58 sean-k-mooney although i will say if we get very very unlucky the random uuid could colide with a real on ein the non_existent_instance test
12:46:24 sean-k-mooney statistically however we are not going to get uuid collisions
12:48:46 gibi wait a bit I think we are looking at the wrong test case
12:49:29 kashyap gibi: So you don't think this is the failing test? test_rescued_vm_detach_volume()?
12:49:40 gibi Im confused
12:49:51 gibi Im looking at this run https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_3e2/828280/1/check/devstack-platform-centos-9-stream/3e24d97/controller/logs/index.html
12:50:29 kashyap Same here.
12:53:10 kashyap gibi: If we can narrow down the exact test action that is causing this, then we can debug it further from libvirt/QEMU angle.
12:53:26 gibi yeah I'm trying that
12:53:42 gibi I mean trying to collect the steps the test took
12:53:43 kashyap Sure, no rush. (I just want to arrive at a reproducer w/ just libvirt - APIs or shell)
12:55:53 gibi https://paste.opendev.org/show/bEtFDBoLqDfotDMPDOq8/
12:56:16 gibi OK so that test case is failing similarly than the other so we can look at any of the too
12:56:26 gibi that paste has the steps from test_rescued_vm_detach_volume
12:57:06 gibi so yeah the log correlates with the test case
12:57:39 kashyap gibi: So, it is indeed test_rescued_vm_detach_volume(), then
12:57:48 gibi we boot an instance then rescue it (basically destory the domina and start it again with different disk config) then we attempt to detach a volume while the rescue domin is running
12:57:52 gibi kashyap: yes
12:58:02 kashyap gibi: Please post this info in the bug as a record.
12:58:11 gibi kashyap: but the other test_stable_device_rescue_disk_virtio_with_volume_attached also failing similarly
12:58:23 gibi kashyap: hence my confusion
12:58:37 kashyap Hm, so both positive and negative are failing similarly
12:58:43 gibi updating the bug...
13:00:11 kashyap gibi: During rescue, by "different disk config" do you mean a fresh, similar config? Or actually different? If so, how is the disk config different before rescue?
13:00:47 gibi we create a domain in a way that it boots from a rescue image but also has the original root fs attached
13:02:28 kashyap I see, noted.
13:05:21 gibi kashyap: https://paste.opendev.org/show/bf9JaJYMYDOX9onjFFy0/ here are the domain xmls for that nova instance
13:07:38 kashyap gibi: Excellent; I just asked Peter Krempa (he meditates on libvirt block layer) on #virt (OFTC)
13:10:13 kashyap Corresponding QEMU log:
13:10:15 kashyap https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_3e2/828280/1/check/devstack-platform-centos-9-stream/3e24d97/controller/logs/libvirt/libvirt/qemu/instance-0000004d_log.txt
13:10:47 sean-k-mooney kashyap: lyarwood implemented a stabel rescue feature but basiclly we add a new disk on the hw_rescue_bus typeicly usb as the boot disk
13:11:27 sean-k-mooney the default rescue disk is the same image from glance that the vm booted wiht but it will be a clean copy of it
13:11:50 sean-k-mooney you can specify an alternitive image to use via config or the rescue action but these tests do not
13:12:26 kashyap I see, noted.
13:26:52 gibi kashyap: these are the nova request ids from the compute log correlated with actions: https://paste.opendev.org/show/bS5Jmmw4PbLirMXtAUyj/
13:27:03 gibi there is two rescue / unrescue pair
13:27:19 kashyap gibi: Noted; meanwhile, the libvirt dev says:
13:27:29 kashyap "weird, we [libvirt] indeed try to detach a blockdev node that wasn't ever attached"
13:27:43 gibi that is wierd indeed :)
13:27:45 kashyap gibi: I sent him an email with you in Cc. He asked it, as he's in a hurry
13:28:23 gibi thanks for the cc
13:28:32 gibi I have to jump on a call I will be back in an hour
13:28:41 kashyap No rush; we can deal with this async.
13:29:35 kashyap gibi: Oh, I don't think we have this output captured anywhere, right? The dev was asking me
13:29:39 kashyap "please also get me the output of 'qemu-img info' of the copy destination image if it wasn't removed"
13:30:41 gibi copy destination?
13:31:11 kashyap [quote] What breaks is a block copy into a image with "--reuse-external" [this is what Nova uses - i.e. reuse an external file], so we try to obey the metadata. [/quote]
13:31:37 kashyap gibi: Here an image copy is involved under the hood
13:31:48 gibi interesting..
13:32:03 kashyap Okay, Peter says: "it's okay to just point me to the place formatting the image, I don't need an actual example, just what's put into the metadata"
13:33:58 kashyap gibi: He does admit that there's a potential libvirt bug here.
13:43:57 gibi bahh there are multiple test cases reusing the same nova instance during the testing https://paste.opendev.org/show/b0OYtRRb5FyZ5pyWgBCu/
13:44:15 gibi hence the more action on the instance in the compute log than what is in the test case that fails
13:48:16 gibi OK, see a bit more.

Earlier   Later