10:31 p.m.
On 05/17, Michal Privoznik wrote:
On 17.05.2013 11:37, Li Wei wrote:
> On 05/17/2013 04:52 PM, Michal Privoznik wrote:
>> On 17.05.2013 10:16, Li Wei wrote:
>>> On 05/17/2013 04:07 PM, Michal Privoznik wrote:
>>>> On 17.05.2013 07:47, Li Wei wrote:
>>>>> Hi Michal, Daniel
>>>>>
>>>>> It seems there is something wrong with the 2/2 part of this
patchset.
>>>>> When I do an "change-media" command in virsh, it
doesn't do any better
>>>>> than before, but even worse(I must to wait 5 secs to see the
error).
>>>>>
>>>>> I'm not family with libvirt, just add some log things in the
qemu_hotplug.c
>>>>> and found the tray_status never change to open, but with
michal's original
>>>>> patch (which do active poll on tray_status), I can do
"change-media" successfully
>>>>> every time.
>>>>
>>>> Yes & no. Thing is - originally we ignored tray status in the guest.
So
>>>> in case guest has locked the tray and thus ignored our eject request,
we
>>>> have changed the media anyway, resulting in possible I/O errors within
>>>> guest.
>>>>
>>>> With my patch, we send eject request to the qemu, and actively poll for
>>>> the tray to open. We check for up to 10 times every 200ms. So guest has
>>>> 2 seconds to open the tray. If the guest doesn't eject media and
open
>>>> the tray we don't proceed with forcibly changing the media.
>>>>
>>>> These patches are actually a bug fix for
>>>> https://bugzilla.redhat.com/show_bug.cgi?id=892289
>>>
>>> Hmm... I think you misunderstood my meaning(sorry for my pool english),
>>> simply to say, I can get expected behavior by apply patch V1 but not V2.
>>>
>>> In V1, we do active poll on qemuMonitorGetBlockInfo(), and in V2 we just
>>> wait for origdisk->tray_status to become VIR_DOMAIN_DISK_TRAY_OPEN but
>>> this never happened.
>>>
>>> Thanks,
>>> Wei
>>
>> Aaah, now I understand. So you are saying that the event is not being
>> delivered. What's the qemu version?
>
>
> I have the following version:
>
> virsh # version
> Compiled against library: libvirt 1.0.5
> Using library: libvirt 1.0.5
> Using API: QEMU 1.0.5
> Running hypervisor: QEMU 1.4.1
>
>>
>> If you turn the debug logs on, do you see DEVICE_TRAY_MOVED in them?
>> http://wiki.libvirt.org/page/DebugLogs
>>
>> Or maybe the timeout is just short for your guest to eject the tray. So
>> after a while, does 'virsh change-media' succeed?
>
> Yes, I can see the DEVICE_TRAY_MOVED in the log file, it goes after
> the debug message "qemuDomainChangeEjectableMedia:103 : Waiting 500ms for tray
to open. Retries left 0".
> does that mean the timeout is too short?
>
> If the guest needs too much time to eject, I'm wondering why when I use
> the v1 patch, I can get succeed in about 1 to 2 seconds. I doubt if there
> are other problems cause tray_status not updated in time?
>
> I appended the log file for your reference, if you need any other information,
> please tell me.
>
> Thanks,
> Wei
I am pasting some interesting knobs from the log:
2013-05-17 09:04:46.234+0000: 27004: debug : qemuMonitorSend:892 : QEMU_MONITOR_SEND_MSG:
mon=0x7f7ac4000bd0
msg={"execute":"eject","arguments":{"device":"drive-ide0-1-0","force":false},"id":"libvirt-7"}
fd=-1
2013-05-17 09:04:46.234+0000: 27001: debug : virObjectRef:295 : OBJECT_REF:
obj=0x7f7ac4000bd0
2013-05-17 09:04:46.234+0000: 27001: debug : qemuMonitorIOWrite:458 :
QEMU_MONITOR_IO_WRITE: mon=0x7f7ac4000bd0
buf={"execute":"eject","arguments":{"device":"drive-ide0-1-0","force":false},"id":"libvirt-7"}
len=92 ret=92 errno=2
2013-05-17 09:04:46.234+0000: 27001: debug : virObjectUnref:258 : OBJECT_UNREF:
obj=0x7f7ac4000bd0
2013-05-17 09:04:46.234+0000: 27001: debug : virObjectRef:295 : OBJECT_REF:
obj=0x7f7ac4000bd0
2013-05-17 09:04:46.234+0000: 27001: debug : qemuMonitorIOProcess:350 :
QEMU_MONITOR_IO_PROCESS: mon=0x7f7ac4000bd0 buf={"id": "libvirt-7",
"error": {"class": "GenericError", "desc":
"Device 'drive-ide0-1-0' is locked"}}
len=102
2013-05-17 09:04:46.234+0000: 27001: debug : virObjectUnref:258 : OBJECT_UNREF:
obj=0x7f7ac4000bd0
2013-05-17 09:04:46.235+0000: 27004: error : qemuMonitorJSONCheckError:352 : internal
error unable to execute QEMU command 'eject': Device 'drive-ide0-1-0' is
locked
2013-05-17 09:04:46.235+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 9
2013-05-17 09:04:46.735+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 8
2013-05-17 09:04:47.235+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 7
2013-05-17 09:04:47.735+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 6
2013-05-17 09:04:48.186+0000: 27001: debug : virObjectRef:295 : OBJECT_REF:
obj=0x7f7ac4000bd0
2013-05-17 09:04:48.235+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 5
2013-05-17 09:04:48.735+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 4
2013-05-17 09:04:49.235+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 3
2013-05-17 09:04:49.736+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 2
2013-05-17 09:04:50.236+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 1
2013-05-17 09:04:50.736+0000: 27004: debug : qemuDomainChangeEjectableMedia:103 : Waiting
500ms for tray to open. Retries left 0
2013-05-17 09:04:51.236+0000: 27004: error : qemuDomainChangeEjectableMedia:117 :
operation failed: Unable to eject media before changing it
2013-05-17 09:04:51.236+0000: 27004: debug : virObjectUnref:258 : OBJECT_UNREF:
obj=0x7f7ac4000bd0
2013-05-17 09:04:51.236+0000: 27004: debug : virDomainLockDiskDetach:282 :
plugin=0x7f7acc007c00 dom=0x7f7acc0a4160 disk=0x7f7ac4003690
2013-05-17 09:04:51.236+0000: 27004: debug : virDomainLockManagerNew:128 :
plugin=0x7f7acc007c00 dom=0x7f7acc0a4160 withResources=0
2013-05-17 09:04:51.236+0000: 27004: debug : virLockManagerPluginGetDriver:295 :
plugin=0x7f7acc007c00
2013-05-17 09:04:51.236+0000: 27004: debug : virLockManagerNew:319 :
driver=0x7f7ae53dc5e0 type=0 nparams=5 params=0x7f7ad7d25830 flags=0
2013-05-17 09:04:51.236+0000: 27001: debug : qemuMonitorIOProcess:350 :
QEMU_MONITOR_IO_PROCESS: mon=0x7f7ac4000bd0 buf={"timestamp":
{"seconds": 1368781488, "microseconds": 186399}, "event":
"DEVICE_TRAY_MOVED", "data": {"device":
"drive-ide0-1-0", "tray-open": true}}
len=151
What we can see here is:
1) libvirt asks qemu to eject
2) qemu responds with "Device is locked" - which is correct as it emulates
guest request
3) However, after a while, the guest decides it's now safe to eject the media (e.g.
all reads have finished, and the device has been unmounted) which is done
4) [not in the pasted log] After a while, you've decided to try again and this time
it succeeded, as the tray is already opened.
What we may do here is lifting the number of retries up. You can try yourself:
I have indeed increased retries to 20 and unfortunately that didn't work either,
we can see in the log file that the DEVICE_TRAY_MOVED event received immediately
after the final retry. After we doubled the retries, that would be more that enough
time for the guest to eject the tray. So, maybe there is something wrong otherwhere.
Thanks,
Wei
diff --git a/src/qemu/qemu_hotplug.c b/src/qemu/qemu_hotplug.c
index d037c9d..ddd8d17 100644
--- a/src/qemu/qemu_hotplug.c
+++ b/src/qemu/qemu_hotplug.c
@@ -50,7 +50,7 @@
#include "virstring.h"
#define VIR_FROM_THIS VIR_FROM_QEMU
-#define CHANGE_MEDIA_RETRIES 10
+#define CHANGE_MEDIA_RETRIES 20
int qemuDomainChangeEjectableMedia(virQEMUDriverPtr driver,
virDomainObjPtr vm,
Michal
--