Bug 696596

get the libvirtd.log from ftp://10.66.4.220/pub since the log is 36M

get the libvirtd.log from ftp://10.66.4.220/pub since the log is 36M

> 
> Steps to Reproduce:
> 1.for i in {a..z}; do virsh attach-device xp-sp3-new vm$i.xml; done
> 2.for i in {a..z}; do virsh attach-device xp-sp3-new vm$i.xml; done
 
  The second step should be 
  for i in {a..z}; do virsh detach-device xp-sp3-new vm$i.xml; done
  
> 3.for i in {a..z}; do virsh attach-device xp-sp3-new vm$i.xml; done

I believe this error is being returned by qemu, so reassigning.  Please return it to libvirt if that's incorrect.

Won't we wait for event before the hot unplug now?

libvirtd.log from comment#1 has the following entries:

19:06:46.341: 27873: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/vmn.img","id":"drive-virtio-disk13","format":"raw"}}' for write with FD -1
19:06:46.344: 27873: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"device_add","arguments":{"driver":"virtio-blk-pci","bus":"pci.0","addr":"0x13","drive":"drive-virtio-disk13","id":"virtio-disk13"}}' for write with FD -1
19:06:59.894: 27873: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"device_del","arguments":{"id":"virtio-disk13"}}' for write with FD -1
19:06:59.987: 27873: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"drive_del","arguments":{"id":"drive-virtio-disk13"}}' for write with FD -1
19:06:59.989: 27868: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"error": {"class": "CommandNotFound", "desc": "The command drive_del has not been found", "data": {"name": "drive_del"}}}]
19:07:06.761: 27871: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/vmn.img","id":"drive-virtio-disk13","format":"raw"}}' for write with FD -1
19:07:06.763: 27868: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"error": {"class": "DuplicateId", "desc": "Duplicate ID 'drive-virtio-disk13' for drive", "data": {"object": "drive", "id": "drive-virtio-disk13"}}}]

Translated into readable form:

--> {"execute":"__com.redhat_drive_add",
     "arguments":{"file":"/var/lib/libvirt/images/vmn.img",
                  "id":"drive-virtio-disk13","format":"raw"}}
--> {"execute":"device_add",
     "arguments":{"driver":"virtio-blk-pci",
                  "bus":"pci.0",
                  "addr":"0x13",
                  "drive":"drive-virtio-disk13",
                  "id":"virtio-disk13"}}
--> {"execute":"device_del",
               "arguments":{"id":"virtio-disk13"}}
--> {"execute":"drive_del",
               "arguments":{"id":"drive-virtio-disk13"}}
<-- {"error": {"class": "CommandNotFound",
               "desc": "The command drive_del has not been found",
               "data": {"name": "drive_del"}}}
--> {"execute":"__com.redhat_drive_add",
     "arguments":{"file":"/var/lib/libvirt/images/vmn.img",
                  "id":"drive-virtio-disk13","format":"raw"}}
<-- {"error": {"class": "DuplicateId",
               "desc": "Duplicate ID 'drive-virtio-disk13' for drive",
               "data": {"object": "drive",
	                "id": "drive-virtio-disk13"}}}

libvirt attempts to delete drive-virtio-disk13.  But it gets the command wrong, so that doesn't work.

"Fortunately", the drive gets automatically deleted when unplug of virtio-disk13 completes.  Happens at an unpredictable time after device_del.

Thus, we have a race condition: if unplug completes quickly enough, the drive is gone by the time we add another one with the same ID, and all is well.  Else, the old drive still exists, and we get a DuplicateId error.  This is what the log shows.

I suspect libvirt needs to use __com.redhat_drive_del instead.  See qemu-kvm-rhel6 commit 95687dc6 for why we had to name it that way.

Reassigning back to libvirt.

Created attachment 523993 [details]
reporter's libvirtd.log

Same log as in comment#1, but attached for more convenient access.

Solution is RHEL-specific (no upstream counterpart).

In POST:
http://post-office.corp.redhat.com/archives/rhvirt-patches/2011-September/msg00801.html

Test with libvirt-0.9.4-13.el6.x86_64,loop attach and detach 26 disks more than 3 times, all successfully.
Move to VRTIFIED.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2011-1513.html