[Qemu-devel] qmp problems with --enable-kvm

[Qemu-devel] qmp problems with --enable-kvm

[Dietmar Maurer]

I use the following qmp commands (file cmds.txt) for testing:

--------- cmds.txt start--------
{"execute":"qmp_capabilities", "arguments":{}}
{"execute":"migrate", "arguments":{ "uri":"exec:cat >/dev/null"}}
{"execute":"query-migrate", "arguments":{}}
--------- cmds.txt end--------

and the following command line to start qemu:

#  ./x86_64-softmmu/qemu-system-x86_64 -chardev socket,id=qmp,path=/tmp/test.qmp,server,nowait -mon chardev=qmp,mode=control  --enable-kvm

I then execute the qmp commands with:

# cat cmds.txt | socat - /tmp/test.qmp 
{"QMP": {"version": {"qemu": {"micro": 90, "minor": 2, "major": 1}, "package": ""}, "capabilities": []}}
{"return": {}}
{"return": {}}
{"timestamp": {"seconds": 1353587785, "microseconds": 134907}, "event": "STOP"}
{"return": {"status": "completed", "downtime": 8, "ram": {"total": 143065088, "remaining": 0, "transferred": 772035, "duplicate": 34755, "dirty-pages-rate": 0, "normal-bytes": 737280, "normal": 180}}}

so far so good.

But if I execute that again I get an error:

# cat cmds.txt | socat - /tmp/test.qmp 
{"error": {"class": "CommandNotFound", "desc": "The command qmp_capabilities has not been found"}}
{"return": {}}
{"return": {"expected-downtime": 0, "status": "active", "total-time": 33, "ram": {"total": 143065088, "remaining": 8937472, "transferred": 495481, "duplicate": 67388, "dirty-pages-rate": 0, "normal-bytes": 1200128, "normal": 293}}}


The interesting thing is that it works perfectly without --enable-kvm. 

Can somebody reproduce that?

Re: [Qemu-devel] qmp problems with --enable-kvm

[Luiz Capitulino]

On Thu, 22 Nov 2012 12:41:31 +0000
Dietmar Maurer <dietmar@proxmox.com> wrote:

> I use the following qmp commands (file cmds.txt) for testing:
> 
> --------- cmds.txt start--------
> {"execute":"qmp_capabilities", "arguments":{}}
> {"execute":"migrate", "arguments":{ "uri":"exec:cat >/dev/null"}}
> {"execute":"query-migrate", "arguments":{}}
> --------- cmds.txt end--------
> 
> and the following command line to start qemu:
> 
> #  ./x86_64-softmmu/qemu-system-x86_64 -chardev socket,id=qmp,path=/tmp/test.qmp,server,nowait -mon chardev=qmp,mode=control  --enable-kvm
> 
> I then execute the qmp commands with:
> 
> # cat cmds.txt | socat - /tmp/test.qmp 
> {"QMP": {"version": {"qemu": {"micro": 90, "minor": 2, "major": 1}, "package": ""}, "capabilities": []}}
> {"return": {}}
> {"return": {}}
> {"timestamp": {"seconds": 1353587785, "microseconds": 134907}, "event": "STOP"}
> {"return": {"status": "completed", "downtime": 8, "ram": {"total": 143065088, "remaining": 0, "transferred": 772035, "duplicate": 34755, "dirty-pages-rate": 0, "normal-bytes": 737280, "normal": 180}}}
> 
> so far so good.
> 
> But if I execute that again I get an error:
> 
> # cat cmds.txt | socat - /tmp/test.qmp 
> {"error": {"class": "CommandNotFound", "desc": "The command qmp_capabilities has not been found"}}
> {"return": {}}
> {"return": {"expected-downtime": 0, "status": "active", "total-time": 33, "ram": {"total": 143065088, "remaining": 8937472, "transferred": 495481, "duplicate": 67388, "dirty-pages-rate": 0, "normal-bytes": 1200128, "normal": 293}}}
> 
> 
> The interesting thing is that it works perfectly without --enable-kvm. 

Can you please try the following patch?

 https://lists.gnu.org/archive/html/qemu-devel/2012-11/msg00174.html

Re: [Qemu-devel] qmp problems with --enable-kvm

[Dietmar Maurer]

> > The interesting thing is that it works perfectly without --enable-kvm.
> 
> Can you please try the following patch?
> 
>  https://lists.gnu.org/archive/html/qemu-devel/2012-11/msg00174.html

I am unable to apply that patch?

patching file vl.c
Hunk #1 FAILED at 3551.
Hunk #2 succeeded at 3729 with fuzz 2 (offset 138 lines).

Re: [Qemu-devel] qmp problems with --enable-kvm

[Luiz Capitulino]

On Thu, 22 Nov 2012 13:44:24 +0000
Dietmar Maurer <dietmar@proxmox.com> wrote:

> > > The interesting thing is that it works perfectly without --enable-kvm.
> > 
> > Can you please try the following patch?
> > 
> >  https://lists.gnu.org/archive/html/qemu-devel/2012-11/msg00174.html
> 
> I am unable to apply that patch?
> 
> patching file vl.c
> Hunk #1 FAILED at 3551.
> Hunk #2 succeeded at 3729 with fuzz 2 (offset 138 lines).

Thanks for reporting, I've replied to the original thread and put
you in the CC.

Re: [Qemu-devel] qmp problems with --enable-kvm

[Paolo Bonzini]

Il 22/11/2012 14:20, Luiz Capitulino ha scritto:
>> > --------- cmds.txt start--------
>> > {"execute":"qmp_capabilities", "arguments":{}}
>> > {"execute":"migrate", "arguments":{ "uri":"exec:cat >/dev/null"}}
>> > {"execute":"query-migrate", "arguments":{}}
>> > --------- cmds.txt end--------
>> > 
>> > and the following command line to start qemu:
>> > 
>> > #  ./x86_64-softmmu/qemu-system-x86_64 -chardev socket,id=qmp,path=/tmp/test.qmp,server,nowait -mon chardev=qmp,mode=control  --enable-kvm
>> > 
>> > I then execute the qmp commands with:
>> > 
>> > # cat cmds.txt | socat - /tmp/test.qmp 
>> > {"QMP": {"version": {"qemu": {"micro": 90, "minor": 2, "major": 1}, "package": ""}, "capabilities": []}}
>> > {"return": {}}
>> > {"return": {}}
>> > {"timestamp": {"seconds": 1353587785, "microseconds": 134907}, "event": "STOP"}
>> > {"return": {"status": "completed", "downtime": 8, "ram": {"total": 143065088, "remaining": 0, "transferred": 772035, "duplicate": 34755, "dirty-pages-rate": 0, "normal-bytes": 737280, "normal": 180}}}
>> > 
>> > so far so good.
>> > 
>> > But if I execute that again I get an error:
>> > 
>> > # cat cmds.txt | socat - /tmp/test.qmp 
>> > {"error": {"class": "CommandNotFound", "desc": "The command qmp_capabilities has not been found"}}
>> > {"return": {}}
>> > {"return": {"expected-downtime": 0, "status": "active", "total-time": 33, "ram": {"total": 143065088, "remaining": 8937472, "transferred": 495481, "duplicate": 67388, "dirty-pages-rate": 0, "normal-bytes": 1200128, "normal": 293}}}
>> > 
>> > 
>> > The interesting thing is that it works perfectly without --enable-kvm. 
> Can you please try the following patch?
> 
>  https://lists.gnu.org/archive/html/qemu-devel/2012-11/msg00174.html

I don't think that's related.  The only problem I see here, is that
"qmp_capabilities" can only be executed once.  That's by design, as I
understand it.

What do you get without --enable-kvm?

Paolo

Re: [Qemu-devel] qmp problems with --enable-kvm

[Dietmar Maurer]

> >> > The interesting thing is that it works perfectly without --enable-kvm.
> > Can you please try the following patch?
> >
> >  https://lists.gnu.org/archive/html/qemu-devel/2012-11/msg00174.html
> 
> I don't think that's related.  The only problem I see here, is that
> "qmp_capabilities" can only be executed once.  That's by design, as I
> understand it.

Executed once per qmp connection!

> What do you get without --enable-kvm?

The first output (without the error).

Re: [Qemu-devel] qmp problems with --enable-kvm

[Paolo Bonzini]

Il 22/11/2012 16:53, Dietmar Maurer ha scritto:
>>>>> The interesting thing is that it works perfectly without --enable-kvm.
>>> > > Can you please try the following patch?
>>> > >
>>> > >  https://lists.gnu.org/archive/html/qemu-devel/2012-11/msg00174.html
>> > 
>> > I don't think that's related.  The only problem I see here, is that
>> > "qmp_capabilities" can only be executed once.  That's by design, as I
>> > understand it.
> Executed once per qmp connection!

Hmm, right.

>> > What do you get without --enable-kvm?
> The first output (without the error).

Ok, in any case Jan's patch was for a QEMU that didn't start at all with
--enable-kvm -monitor stdio, i.e. really unrelated.

In any case, I cannot reproduce it here.

Paolo

Re: [Qemu-devel] qmp problems with --enable-kvm

[Dietmar Maurer]

> Ok, in any case Jan's patch was for a QEMU that didn't start at all with --
> enable-kvm -monitor stdio, i.e. really unrelated.
> 
> In any case, I cannot reproduce it here.

Any idea what can cause such behaviour?

Re: [Qemu-devel] qmp problems with --enable-kvm

[Paolo Bonzini]

Il 22/11/2012 17:04, Dietmar Maurer ha scritto:
>> Ok, in any case Jan's patch was for a QEMU that didn't start at all with --
>> > enable-kvm -monitor stdio, i.e. really unrelated.
>> > 
>> > In any case, I cannot reproduce it here.
> Any idea what can cause such behaviour?

It seems like mon->mc->command_mode is set wrong, looking at
qmp_cmd_mode and its callers.  Luiz may have more ideas.

Paolo

Re: [Qemu-devel] qmp problems with --enable-kvm

[Luiz Capitulino]

On Thu, 22 Nov 2012 17:09:24 +0100
Paolo Bonzini <pbonzini@redhat.com> wrote:

> Il 22/11/2012 17:04, Dietmar Maurer ha scritto:
> >> Ok, in any case Jan's patch was for a QEMU that didn't start at all with --
> >> > enable-kvm -monitor stdio, i.e. really unrelated.

Right. When I saw qmp and --enable-kvm in the same sentence I automatically
thought about Jan's patch I saw the other day.

> >> > In any case, I cannot reproduce it here.
> > Any idea what can cause such behaviour?
> 
> It seems like mon->mc->command_mode is set wrong, looking at
> qmp_cmd_mode and its callers.  Luiz may have more ideas.

Checking. What I've just found is that qmp_capabilites will fail if the
VM is stopped (!?).

Re: [Qemu-devel] qmp problems with --enable-kvm

[Luiz Capitulino]

On Thu, 22 Nov 2012 14:24:14 -0200
Luiz Capitulino <lcapitulino@redhat.com> wrote:

> > It seems like mon->mc->command_mode is set wrong, looking at
> > qmp_cmd_mode and its callers.  Luiz may have more ideas.
> 
> Checking. What I've just found is that qmp_capabilites will fail if the
> VM is stopped (!?).

It's a regression somewhere. I doubt it's qmp, but could be.

Here are the symptoms, Doc:

 1. Start qemu and stop it right away. Connect to the QMP socket and you
    won't get qmp's greeting

 2. Start qemu, connect to the QMP socket and run the qmp_capabilities
    command. Then stop qemu and disconnect from the qmp socket and connect
    again: you'll see you're still in the previous session

I do not get this with qemu 1.0.

Dietmar got this because the suspend command automatically stops the VM
after migration...

Bisecting...

Re: [Qemu-devel] qmp problems with --enable-kvm

[Luiz Capitulino]

On Thu, 22 Nov 2012 14:33:24 -0200
Luiz Capitulino <lcapitulino@redhat.com> wrote:

> On Thu, 22 Nov 2012 14:24:14 -0200
> Luiz Capitulino <lcapitulino@redhat.com> wrote:
> 
> > > It seems like mon->mc->command_mode is set wrong, looking at
> > > qmp_cmd_mode and its callers.  Luiz may have more ideas.
> > 
> > Checking. What I've just found is that qmp_capabilites will fail if the
> > VM is stopped (!?).
> 
> It's a regression somewhere. I doubt it's qmp, but could be.
> 
> Here are the symptoms, Doc:
> 
>  1. Start qemu and stop it right away. Connect to the QMP socket and you
>     won't get qmp's greeting
> 
>  2. Start qemu, connect to the QMP socket and run the qmp_capabilities
>     command. Then stop qemu and disconnect from the qmp socket and connect
>     again: you'll see you're still in the previous session
> 
> I do not get this with qemu 1.0.
> 
> Dietmar got this because the suspend command automatically stops the VM
> after migration...
> 
> Bisecting...

Didn't try to understand what's wrong with it, but bisect brings:

commit ac4119c023c72b15f54238af43e4a178fcf41494
Author: Jan Kiszka <jan.kiszka@siemens.com>
Date:   Fri Oct 12 09:52:49 2012 +0200

    chardev: Use timer instead of bottom-half to postpone open event
    
    As the block layer may decide to flush bottom-halfs while the machine is
    still initializing (e.g. to read geometry data from the disk), our
    postponed open event may be processed before the last frontend
    registered with a muxed chardev.
    
    Until the semantics of BHs have been clarified, use an expired timer to
    achieve the same effect (suggested by Paolo Bonzini). This requires to
    perform the alarm timer initialization earlier as otherwise timer
    subsystem can be used before being ready.
    
    Signed-off-by: Jan Kiszka <jan.kiszka@siemens.com>

Re: [Qemu-devel] qmp problems with --enable-kvm

[Paolo Bonzini]

Il 22/11/2012 17:58, Luiz Capitulino ha scritto:
>>>> It seems like mon->mc->command_mode is set wrong, looking at
>>>> qmp_cmd_mode and its callers.  Luiz may have more ideas.
>>>
>>> Checking. What I've just found is that qmp_capabilites will fail if the
>>> VM is stopped (!?).
>>
>> It's a regression somewhere. I doubt it's qmp, but could be.
>>
>> Here are the symptoms, Doc:
>>
>>  1. Start qemu and stop it right away. Connect to the QMP socket and you
>>     won't get qmp's greeting
>>
>>  2. Start qemu, connect to the QMP socket and run the qmp_capabilities
>>     command. Then stop qemu and disconnect from the qmp socket and connect
>>     again: you'll see you're still in the previous session
>>
>> I do not get this with qemu 1.0.
>>
>> Dietmar got this because the suspend command automatically stops the VM
>> after migration...
>>
>> Bisecting...
> 
> Didn't try to understand what's wrong with it, but bisect brings:
> 
> commit ac4119c023c72b15f54238af43e4a178fcf41494
> Author: Jan Kiszka <jan.kiszka@siemens.com>
> Date:   Fri Oct 12 09:52:49 2012 +0200
> 
>     chardev: Use timer instead of bottom-half to postpone open event
>     
>     As the block layer may decide to flush bottom-halfs while the machine is
>     still initializing (e.g. to read geometry data from the disk), our
>     postponed open event may be processed before the last frontend
>     registered with a muxed chardev.
>     
>     Until the semantics of BHs have been clarified, use an expired timer to
>     achieve the same effect (suggested by Paolo Bonzini). This requires to
>     perform the alarm timer initialization earlier as otherwise timer
>     subsystem can be used before being ready.
>     
>     Signed-off-by: Jan Kiszka <jan.kiszka@siemens.com>

Ouch, in retrospect it actually makes sense since this patch uses a
vm_clock timer.  Elementary, Watson... :)

I don't think there is a fix, short of reverting this commit.

Paolo

Re: [Qemu-devel] qmp problems with --enable-kvm

[Jan Kiszka]

On 2012-11-22 18:07, Paolo Bonzini wrote:
> Il 22/11/2012 17:58, Luiz Capitulino ha scritto:
>>>>> It seems like mon->mc->command_mode is set wrong, looking at
>>>>> qmp_cmd_mode and its callers.  Luiz may have more ideas.
>>>>
>>>> Checking. What I've just found is that qmp_capabilites will fail if the
>>>> VM is stopped (!?).
>>>
>>> It's a regression somewhere. I doubt it's qmp, but could be.
>>>
>>> Here are the symptoms, Doc:
>>>
>>>  1. Start qemu and stop it right away. Connect to the QMP socket and you
>>>     won't get qmp's greeting
>>>
>>>  2. Start qemu, connect to the QMP socket and run the qmp_capabilities
>>>     command. Then stop qemu and disconnect from the qmp socket and connect
>>>     again: you'll see you're still in the previous session
>>>
>>> I do not get this with qemu 1.0.
>>>
>>> Dietmar got this because the suspend command automatically stops the VM
>>> after migration...
>>>
>>> Bisecting...
>>
>> Didn't try to understand what's wrong with it, but bisect brings:
>>
>> commit ac4119c023c72b15f54238af43e4a178fcf41494
>> Author: Jan Kiszka <jan.kiszka@siemens.com>
>> Date:   Fri Oct 12 09:52:49 2012 +0200
>>
>>     chardev: Use timer instead of bottom-half to postpone open event
>>     
>>     As the block layer may decide to flush bottom-halfs while the machine is
>>     still initializing (e.g. to read geometry data from the disk), our
>>     postponed open event may be processed before the last frontend
>>     registered with a muxed chardev.
>>     
>>     Until the semantics of BHs have been clarified, use an expired timer to
>>     achieve the same effect (suggested by Paolo Bonzini). This requires to
>>     perform the alarm timer initialization earlier as otherwise timer
>>     subsystem can be used before being ready.
>>     
>>     Signed-off-by: Jan Kiszka <jan.kiszka@siemens.com>
> 
> Ouch, in retrospect it actually makes sense since this patch uses a
> vm_clock timer.  Elementary, Watson... :)
> 
> I don't think there is a fix, short of reverting this commit.

We have more timers than the one based on vm_clock. Does this help?

diff --git a/qemu-char.c b/qemu-char.c
index 88f4025..242b799 100644
--- a/qemu-char.c
+++ b/qemu-char.c
@@ -134,9 +134,9 @@ static void qemu_chr_fire_open_event(void *opaque)
 void qemu_chr_generic_open(CharDriverState *s)
 {
     if (s->open_timer == NULL) {
-        s->open_timer = qemu_new_timer_ms(vm_clock,
+        s->open_timer = qemu_new_timer_ms(rt_clock,
                                           qemu_chr_fire_open_event, s);
-        qemu_mod_timer(s->open_timer, qemu_get_clock_ms(vm_clock) - 1);
+        qemu_mod_timer(s->open_timer, qemu_get_clock_ms(rt_clock) - 1);
     }
 }
 
Jan

-- 
Siemens AG, Corporate Technology, CT RTC ITP SDP-DE
Corporate Competence Center Embedded Linux

Re: [Qemu-devel] qmp problems with --enable-kvm

[Luiz Capitulino]

On Thu, 22 Nov 2012 18:09:44 +0100
Jan Kiszka <jan.kiszka@siemens.com> wrote:

> On 2012-11-22 18:07, Paolo Bonzini wrote:
> > Il 22/11/2012 17:58, Luiz Capitulino ha scritto:
> >>>>> It seems like mon->mc->command_mode is set wrong, looking at
> >>>>> qmp_cmd_mode and its callers.  Luiz may have more ideas.
> >>>>
> >>>> Checking. What I've just found is that qmp_capabilites will fail if the
> >>>> VM is stopped (!?).
> >>>
> >>> It's a regression somewhere. I doubt it's qmp, but could be.
> >>>
> >>> Here are the symptoms, Doc:
> >>>
> >>>  1. Start qemu and stop it right away. Connect to the QMP socket and you
> >>>     won't get qmp's greeting
> >>>
> >>>  2. Start qemu, connect to the QMP socket and run the qmp_capabilities
> >>>     command. Then stop qemu and disconnect from the qmp socket and connect
> >>>     again: you'll see you're still in the previous session
> >>>
> >>> I do not get this with qemu 1.0.
> >>>
> >>> Dietmar got this because the suspend command automatically stops the VM
> >>> after migration...
> >>>
> >>> Bisecting...
> >>
> >> Didn't try to understand what's wrong with it, but bisect brings:
> >>
> >> commit ac4119c023c72b15f54238af43e4a178fcf41494
> >> Author: Jan Kiszka <jan.kiszka@siemens.com>
> >> Date:   Fri Oct 12 09:52:49 2012 +0200
> >>
> >>     chardev: Use timer instead of bottom-half to postpone open event
> >>     
> >>     As the block layer may decide to flush bottom-halfs while the machine is
> >>     still initializing (e.g. to read geometry data from the disk), our
> >>     postponed open event may be processed before the last frontend
> >>     registered with a muxed chardev.
> >>     
> >>     Until the semantics of BHs have been clarified, use an expired timer to
> >>     achieve the same effect (suggested by Paolo Bonzini). This requires to
> >>     perform the alarm timer initialization earlier as otherwise timer
> >>     subsystem can be used before being ready.
> >>     
> >>     Signed-off-by: Jan Kiszka <jan.kiszka@siemens.com>
> > 
> > Ouch, in retrospect it actually makes sense since this patch uses a
> > vm_clock timer.  Elementary, Watson... :)
> > 
> > I don't think there is a fix, short of reverting this commit.
> 
> We have more timers than the one based on vm_clock. Does this help?

It helps to the point of fixing the issue to me :) Thanks!

Tested-by: Luiz Capitulino <lcapitulino@redhat.com>

> 
> diff --git a/qemu-char.c b/qemu-char.c
> index 88f4025..242b799 100644
> --- a/qemu-char.c
> +++ b/qemu-char.c
> @@ -134,9 +134,9 @@ static void qemu_chr_fire_open_event(void *opaque)
>  void qemu_chr_generic_open(CharDriverState *s)
>  {
>      if (s->open_timer == NULL) {
> -        s->open_timer = qemu_new_timer_ms(vm_clock,
> +        s->open_timer = qemu_new_timer_ms(rt_clock,
>                                            qemu_chr_fire_open_event, s);
> -        qemu_mod_timer(s->open_timer, qemu_get_clock_ms(vm_clock) - 1);
> +        qemu_mod_timer(s->open_timer, qemu_get_clock_ms(rt_clock) - 1);
>      }
>  }
>  
> Jan
> 

Re: [Qemu-devel] qmp problems with --enable-kvm

[Dietmar Maurer]

> We have more timers than the one based on vm_clock. Does this help?

Yes, that patch fixes the problem for me.

> 
> diff --git a/qemu-char.c b/qemu-char.c
> index 88f4025..242b799 100644
> --- a/qemu-char.c
> +++ b/qemu-char.c
> @@ -134,9 +134,9 @@ static void qemu_chr_fire_open_event(void
> *opaque)  void qemu_chr_generic_open(CharDriverState *s)  {
>      if (s->open_timer == NULL) {
> -        s->open_timer = qemu_new_timer_ms(vm_clock,
> +        s->open_timer = qemu_new_timer_ms(rt_clock,
>                                            qemu_chr_fire_open_event, s);
> -        qemu_mod_timer(s->open_timer, qemu_get_clock_ms(vm_clock) - 1);
> +        qemu_mod_timer(s->open_timer, qemu_get_clock_ms(rt_clock) - 1);
>      }
>  }