[Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Auger Eric]

Hi,

I observe a regression on KVM accelerated qemu-system-aarch64:

Unexpected error in kvm_device_access() at
/home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
failed: Group 6 attr 0x000000000000c664: Device or resource busy
2018-03-23 10:00:00.085+0000: shutting down, reason=crashed

I did a bisect and it looks the commit that introduces the regression is

"
commit 3fd2457d18edf5736f713dfe1ada9c87a9badab1
Author: Peter Xu <peterx@redhat.com>
Date:   Fri Mar 9 17:00:03 2018 +0800

    monitor: enable IO thread for (qmp & !mux) typed

    Start to use dedicate IO thread for QMP monitors that are not using
    MUXed chardev.

    Reviewed-by: Fam Zheng <famz@redhat.com>
    Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
    Signed-off-by: Peter Xu <peterx@redhat.com>
    Message-Id: <20180309090006.10018-21-peterx@redhat.com>
    Signed-off-by: Eric Blake <eblake@redhat.com>
"

If reverted on top of v2.12.0-rc0, the guest boots fine again. The link
is not obvious though.

Thanks

Eric

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Peter Maydell]

On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
> Hi,
>
> I observe a regression on KVM accelerated qemu-system-aarch64:
>
> Unexpected error in kvm_device_access() at
> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
> failed: Group 6 attr 0x000000000000c664: Device or resource busy
> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed

Can you get a backtrace for this? (I guess you'd need to fiddle
with the kvm_device_access() code to make it assert rather
than passing back the error).

thanks
-- PMM

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Auger Eric]

Hi,

On 23/03/18 11:26, Peter Maydell wrote:
> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
>> Hi,
>>
>> I observe a regression on KVM accelerated qemu-system-aarch64:
>>
>> Unexpected error in kvm_device_access() at
>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
> 
> Can you get a backtrace for this? (I guess you'd need to fiddle
> with the kvm_device_access() code to make it assert rather
> than passing back the error).

OK. I will try to do so. As I could have expected, I cannot reproduce on
a standalone qemu command line. The problem observed above is seen with
libvirt launch which may be doing some other QMP stuff concurrently?

Thanks

Eric
> 
> thanks
> -- PMM
> 

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Peter Maydell]

On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
> Hi,
>
> On 23/03/18 11:26, Peter Maydell wrote:
>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
>>> Hi,
>>>
>>> I observe a regression on KVM accelerated qemu-system-aarch64:
>>>
>>> Unexpected error in kvm_device_access() at
>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
>>
>> Can you get a backtrace for this? (I guess you'd need to fiddle
>> with the kvm_device_access() code to make it assert rather
>> than passing back the error).
>
> OK. I will try to do so. As I could have expected, I cannot reproduce on
> a standalone qemu command line. The problem observed above is seen with
> libvirt launch which may be doing some other QMP stuff concurrently?

Hmm, that could be a bit painful to debug. I dunno if libvirt
has a "launch QEMU under gdb" option. If not, you could try
something like:
   if (condition we want to get a backtrace on) {
       printf("hit condition, attach gdb to process %d\n", (int)getpid());
       for (;;) { }
   }

and then QEMU will sit in a loop waiting for you to do a
  gdb path/to/qemu <pid>

thanks
-- PMM

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Christian Borntraeger]

On 03/23/2018 01:11 PM, Peter Maydell wrote:
> On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
>> Hi,
>>
>> On 23/03/18 11:26, Peter Maydell wrote:
>>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
>>>> Hi,
>>>>
>>>> I observe a regression on KVM accelerated qemu-system-aarch64:
>>>>
>>>> Unexpected error in kvm_device_access() at
>>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
>>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
>>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
>>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
>>>
>>> Can you get a backtrace for this? (I guess you'd need to fiddle
>>> with the kvm_device_access() code to make it assert rather
>>> than passing back the error).
>>
>> OK. I will try to do so. As I could have expected, I cannot reproduce on
>> a standalone qemu command line. The problem observed above is seen with
>> libvirt launch which may be doing some other QMP stuff concurrently?
> 
> Hmm, that could be a bit painful to debug. I dunno if libvirt
> has a "launch QEMU under gdb" option. If not, you could try
> something like:
>    if (condition we want to get a backtrace on) {
>        printf("hit condition, attach gdb to process %d\n", (int)getpid());
>        for (;;) { }
>    }
> 
> and then QEMU will sit in a loop waiting for you to do a
>   gdb path/to/qemu <pid>
> 
> thanks
> -- PMM
> 

This patch also breaks the qemu iotest. (qemu hangs).

backtrace for that is


Thread 4 (Thread 0x3ffa9c3c910 (LWP 171339)):
#0  0x000003ffb9d11a70 in __lll_lock_wait () at /lib64/libpthread.so.0
#1  0x000003ffb9d0a630 in pthread_mutex_lock () at /lib64/libpthread.so.0
#2  0x0000000001557e90 in qemu_mutex_lock_impl (mutex=0x1a63f90 <qemu_global_mutex>, file=0x160bc36 "/home/cborntra/REPOS/qemu/cpus.c", line=1757)
    at /home/cborntra/REPOS/qemu/util/qemu-thread-posix.c:67
#3  0x000000000108ad5e in qemu_mutex_lock_iothread () at /home/cborntra/REPOS/qemu/cpus.c:1757
#4  0x0000000001089c70 in qemu_dummy_cpu_thread_fn (arg=0x3d4f9eb0) at /home/cborntra/REPOS/qemu/cpus.c:1258
#5  0x000003ffb9d07a88 in start_thread () at /lib64/libpthread.so.0
#6  0x000003ffb731940e in thread_start () at /lib64/libc.so.6

Thread 3 (Thread 0x3ffaa43d910 (LWP 171338)):
#0  0x000003ffb730c050 in poll () at /lib64/libc.so.6
#1  0x000003ffb8bd13b4 in g_main_context_iterate.isra () at /lib64/libglib-2.0.so.0
#2  0x000003ffb8bd1840 in g_main_loop_run () at /lib64/libglib-2.0.so.0
#3  0x00000000011f499e in iothread_run (opaque=0x3d2a4110) at /home/cborntra/REPOS/qemu/iothread.c:70
#4  0x000003ffb9d07a88 in start_thread () at /lib64/libpthread.so.0
#5  0x000003ffb731940e in thread_start () at /lib64/libc.so.6

Thread 2 (Thread 0x3ffab743910 (LWP 171336)):
#0  0x000003ffb7313ada in syscall () at /lib64/libc.so.6
#1  0x0000000001558b5e in qemu_futex_wait (f=0x1e9b41c <rcu_call_ready_event>, val=4294967295) at /home/cborntra/REPOS/qemu/include/qemu/futex.h:29
#2  0x0000000001558e16 in qemu_event_wait (ev=0x1e9b41c <rcu_call_ready_event>) at /home/cborntra/REPOS/qemu/util/qemu-thread-posix.c:445
#3  0x000000000157af82 in call_rcu_thread (opaque=0x0) at /home/cborntra/REPOS/qemu/util/rcu.c:261
#4  0x000003ffb9d07a88 in start_thread () at /lib64/libpthread.so.0
#5  0x000003ffb731940e in thread_start () at /lib64/libc.so.6

Thread 1 (Thread 0x3ffba146290 (LWP 171335)):
#0  0x000003ffb730c1a2 in ppoll () at /lib64/libc.so.6
#1  0x00000000015502da in qemu_poll_ns (fds=0x3d3b2720, nfds=1, timeout=-1) at /home/cborntra/REPOS/qemu/util/qemu-timer.c:322
#2  0x0000000001554882 in aio_poll (ctx=0x3d3924e0, blocking=true) at /home/cborntra/REPOS/qemu/util/aio-posix.c:629
#3  0x000000000145533e in bdrv_drain_recurse (bs=0x3d3a6a70) at /home/cborntra/REPOS/qemu/block/io.c:197
#4  0x0000000001455f1a in bdrv_drain_all_begin () at /home/cborntra/REPOS/qemu/block/io.c:447
#5  0x00000000014560d6 in bdrv_drain_all () at /home/cborntra/REPOS/qemu/block/io.c:476
#6  0x0000000001089216 in do_vm_stop (state=RUN_STATE_SHUTDOWN, send_stop=false) at /home/cborntra/REPOS/qemu/cpus.c:1010
#7  0x0000000001089266 in vm_shutdown () at /home/cborntra/REPOS/qemu/cpus.c:1022
#8  0x0000000001208c08 in main (argc=18, argv=0x3fffbcfdbd8, envp=0x3fffbcfdc70) at /home/cborntra/REPOS/qemu/vl.c:4732

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Daniel P. Berrangé]

On Fri, Mar 23, 2018 at 12:11:17PM +0000, Peter Maydell wrote:
> On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
> > Hi,
> >
> > On 23/03/18 11:26, Peter Maydell wrote:
> >> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
> >>> Hi,
> >>>
> >>> I observe a regression on KVM accelerated qemu-system-aarch64:
> >>>
> >>> Unexpected error in kvm_device_access() at
> >>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
> >>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
> >>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
> >>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
> >>
> >> Can you get a backtrace for this? (I guess you'd need to fiddle
> >> with the kvm_device_access() code to make it assert rather
> >> than passing back the error).
> >
> > OK. I will try to do so. As I could have expected, I cannot reproduce on
> > a standalone qemu command line. The problem observed above is seen with
> > libvirt launch which may be doing some other QMP stuff concurrently?
> 
> Hmm, that could be a bit painful to debug. I dunno if libvirt
> has a "launch QEMU under gdb" option. If not, you could try

Nothing official, but the following trick should still work:

https://www.berrange.com/posts/2011/10/12/debugging-early-startup-of-kvm-with-gdb-when-launched-by-libvirtd/


Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Peter Xu]

On Fri, Mar 23, 2018 at 01:01:43PM +0100, Auger Eric wrote:
> Hi,
> 
> On 23/03/18 11:26, Peter Maydell wrote:
> > On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
> >> Hi,
> >>
> >> I observe a regression on KVM accelerated qemu-system-aarch64:
> >>
> >> Unexpected error in kvm_device_access() at
> >> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
> >> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
> >> failed: Group 6 attr 0x000000000000c664: Device or resource busy
> >> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
> > 
> > Can you get a backtrace for this? (I guess you'd need to fiddle
> > with the kvm_device_access() code to make it assert rather
> > than passing back the error).
> 
> OK. I will try to do so. As I could have expected, I cannot reproduce on
> a standalone qemu command line. The problem observed above is seen with
> libvirt launch which may be doing some other QMP stuff concurrently?

Maybe not concurrently inside libvirt, but after the patches AFAIK the
QMP part can be concurrent with something else or break some timing.

Anyway, sorry for that!  I'll see what I can do to help.

-- 
Peter Xu

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Auger Eric]

Hi,

On 23/03/18 13:11, Peter Maydell wrote:
> On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
>> Hi,
>>
>> On 23/03/18 11:26, Peter Maydell wrote:
>>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
>>>> Hi,
>>>>
>>>> I observe a regression on KVM accelerated qemu-system-aarch64:
>>>>
>>>> Unexpected error in kvm_device_access() at
>>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
>>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
>>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
>>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
>>>
>>> Can you get a backtrace for this? (I guess you'd need to fiddle
>>> with the kvm_device_access() code to make it assert rather
>>> than passing back the error).
>>
>> OK. I will try to do so. As I could have expected, I cannot reproduce on
>> a standalone qemu command line. The problem observed above is seen with
>> libvirt launch which may be doing some other QMP stuff concurrently?
> 
> Hmm, that could be a bit painful to debug. I dunno if libvirt
> has a "launch QEMU under gdb" option. If not, you could try
> something like:
>    if (condition we want to get a backtrace on) {
>        printf("hit condition, attach gdb to process %d\n", (int)getpid());
>        for (;;) { }
>    }

Thanks for the hint. Here is the stack I get.

#0  kvm_device_access (fd=31, group=6, attr=50788, val=0x5937c88, write=false, errp=0x16984a8 <error_abort>) at /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164
#1  0x00000000004f8ce4 in arm_gicv3_icc_reset (env=0xffffa1fc8330, ri=0x597f910) at /home/augere/UPSTREAM/qemu/hw/intc/arm_gicv3_kvm.c:632
#2  0x00000000006351ac in cp_reg_reset (key=0x597f730, value=0x597f910, opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:78
#3  0x0000ffffa47edce4 in g_hash_table_foreach () from /lib64/libglib-2.0.so.0
#4  0x0000000000635394 in arm_cpu_reset (s=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:130
#5  0x000000000090c888 in cpu_reset (cpu=0xffffa1fc0010) at qom/cpu.c:249
#6  0x00000000005793d8 in do_cpu_reset (opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/hw/arm/boot.c:665
#7  0x000000000073095c in qemu_devices_reset () at hw/core/reset.c:69
#8  0x00000000006976e0 in qemu_system_reset (reason=SHUTDOWN_CAUSE_NONE) at vl.c:1731
#9  0x000000000069fd60 in main (argc=69, argv=0xffffe877d1a8, envp=0xffffe877d3d8) at vl.c:4697

Thanks

Eric
> 
> and then QEMU will sit in a loop waiting for you to do a
>   gdb path/to/qemu <pid>
> 
> thanks
> -- PMM
> 

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Auger Eric]

Hi Peter,

On 23/03/18 13:19, Peter Xu wrote:
> On Fri, Mar 23, 2018 at 01:01:43PM +0100, Auger Eric wrote:
>> Hi,
>>
>> On 23/03/18 11:26, Peter Maydell wrote:
>>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
>>>> Hi,
>>>>
>>>> I observe a regression on KVM accelerated qemu-system-aarch64:
>>>>
>>>> Unexpected error in kvm_device_access() at
>>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
>>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
>>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
>>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
>>>
>>> Can you get a backtrace for this? (I guess you'd need to fiddle
>>> with the kvm_device_access() code to make it assert rather
>>> than passing back the error).
>>
>> OK. I will try to do so. As I could have expected, I cannot reproduce on
>> a standalone qemu command line. The problem observed above is seen with
>> libvirt launch which may be doing some other QMP stuff concurrently?
> 
> Maybe not concurrently inside libvirt, but after the patches AFAIK the
> QMP part can be concurrent with something else or break some timing.
> 
> Anyway, sorry for that!  I'll see what I can do to help.

No worries

Thanks

Eric
> 

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Peter Xu]

On Fri, Mar 23, 2018 at 01:36:36PM +0100, Auger Eric wrote:
> Hi,
> 
> On 23/03/18 13:11, Peter Maydell wrote:
> > On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
> >> Hi,
> >>
> >> On 23/03/18 11:26, Peter Maydell wrote:
> >>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
> >>>> Hi,
> >>>>
> >>>> I observe a regression on KVM accelerated qemu-system-aarch64:
> >>>>
> >>>> Unexpected error in kvm_device_access() at
> >>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
> >>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
> >>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
> >>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
> >>>
> >>> Can you get a backtrace for this? (I guess you'd need to fiddle
> >>> with the kvm_device_access() code to make it assert rather
> >>> than passing back the error).
> >>
> >> OK. I will try to do so. As I could have expected, I cannot reproduce on
> >> a standalone qemu command line. The problem observed above is seen with
> >> libvirt launch which may be doing some other QMP stuff concurrently?
> > 
> > Hmm, that could be a bit painful to debug. I dunno if libvirt
> > has a "launch QEMU under gdb" option. If not, you could try
> > something like:
> >    if (condition we want to get a backtrace on) {
> >        printf("hit condition, attach gdb to process %d\n", (int)getpid());
> >        for (;;) { }
> >    }
> 
> Thanks for the hint. Here is the stack I get.
> 
> #0  kvm_device_access (fd=31, group=6, attr=50788, val=0x5937c88, write=false, errp=0x16984a8 <error_abort>) at /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164
> #1  0x00000000004f8ce4 in arm_gicv3_icc_reset (env=0xffffa1fc8330, ri=0x597f910) at /home/augere/UPSTREAM/qemu/hw/intc/arm_gicv3_kvm.c:632
> #2  0x00000000006351ac in cp_reg_reset (key=0x597f730, value=0x597f910, opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:78
> #3  0x0000ffffa47edce4 in g_hash_table_foreach () from /lib64/libglib-2.0.so.0
> #4  0x0000000000635394 in arm_cpu_reset (s=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:130
> #5  0x000000000090c888 in cpu_reset (cpu=0xffffa1fc0010) at qom/cpu.c:249
> #6  0x00000000005793d8 in do_cpu_reset (opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/hw/arm/boot.c:665
> #7  0x000000000073095c in qemu_devices_reset () at hw/core/reset.c:69
> #8  0x00000000006976e0 in qemu_system_reset (reason=SHUTDOWN_CAUSE_NONE) at vl.c:1731
> #9  0x000000000069fd60 in main (argc=69, argv=0xffffe877d1a8, envp=0xffffe877d3d8) at vl.c:4697

I'm not sure, but I suspect libvirt has already sent something to QEMU
before this point, which breaks the timing of the old QMP code (the
old QMP won't do anything until main loop).

I'm thinking maybe I should postpone the monitors at least until main
loop so that we can still keep that assumption.  But I'll see what do
others think of it first.

Thanks,

-- 
Peter Xu

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Peter Xu]

On Fri, Mar 23, 2018 at 01:36:36PM +0100, Auger Eric wrote:
> Hi,
> 
> On 23/03/18 13:11, Peter Maydell wrote:
> > On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
> >> Hi,
> >>
> >> On 23/03/18 11:26, Peter Maydell wrote:
> >>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
> >>>> Hi,
> >>>>
> >>>> I observe a regression on KVM accelerated qemu-system-aarch64:
> >>>>
> >>>> Unexpected error in kvm_device_access() at
> >>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
> >>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
> >>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
> >>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
> >>>
> >>> Can you get a backtrace for this? (I guess you'd need to fiddle
> >>> with the kvm_device_access() code to make it assert rather
> >>> than passing back the error).
> >>
> >> OK. I will try to do so. As I could have expected, I cannot reproduce on
> >> a standalone qemu command line. The problem observed above is seen with
> >> libvirt launch which may be doing some other QMP stuff concurrently?
> > 
> > Hmm, that could be a bit painful to debug. I dunno if libvirt
> > has a "launch QEMU under gdb" option. If not, you could try
> > something like:
> >    if (condition we want to get a backtrace on) {
> >        printf("hit condition, attach gdb to process %d\n", (int)getpid());
> >        for (;;) { }
> >    }
> 
> Thanks for the hint. Here is the stack I get.
> 
> #0  kvm_device_access (fd=31, group=6, attr=50788, val=0x5937c88, write=false, errp=0x16984a8 <error_abort>) at /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164
> #1  0x00000000004f8ce4 in arm_gicv3_icc_reset (env=0xffffa1fc8330, ri=0x597f910) at /home/augere/UPSTREAM/qemu/hw/intc/arm_gicv3_kvm.c:632
> #2  0x00000000006351ac in cp_reg_reset (key=0x597f730, value=0x597f910, opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:78
> #3  0x0000ffffa47edce4 in g_hash_table_foreach () from /lib64/libglib-2.0.so.0
> #4  0x0000000000635394 in arm_cpu_reset (s=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:130
> #5  0x000000000090c888 in cpu_reset (cpu=0xffffa1fc0010) at qom/cpu.c:249
> #6  0x00000000005793d8 in do_cpu_reset (opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/hw/arm/boot.c:665
> #7  0x000000000073095c in qemu_devices_reset () at hw/core/reset.c:69
> #8  0x00000000006976e0 in qemu_system_reset (reason=SHUTDOWN_CAUSE_NONE) at vl.c:1731
> #9  0x000000000069fd60 in main (argc=69, argv=0xffffe877d1a8, envp=0xffffe877d3d8) at vl.c:4697

I think current master should work fine with ARM KVM now since OOB is
now off by default. But does ARM use postcopy, and will ARM need the
coming network failure recovery feature?

If so, maybe we'll still need to have a look on this single problem
(this is the only non-testcase issue I know now with Out-Of-Band).

Thanks,

-- 
Peter Xu

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Auger Eric]

Hi Peter,

On 28/03/18 04:03, Peter Xu wrote:
> On Fri, Mar 23, 2018 at 01:36:36PM +0100, Auger Eric wrote:
>> Hi,
>>
>> On 23/03/18 13:11, Peter Maydell wrote:
>>> On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
>>>> Hi,
>>>>
>>>> On 23/03/18 11:26, Peter Maydell wrote:
>>>>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
>>>>>> Hi,
>>>>>>
>>>>>> I observe a regression on KVM accelerated qemu-system-aarch64:
>>>>>>
>>>>>> Unexpected error in kvm_device_access() at
>>>>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
>>>>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
>>>>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
>>>>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
>>>>>
>>>>> Can you get a backtrace for this? (I guess you'd need to fiddle
>>>>> with the kvm_device_access() code to make it assert rather
>>>>> than passing back the error).
>>>>
>>>> OK. I will try to do so. As I could have expected, I cannot reproduce on
>>>> a standalone qemu command line. The problem observed above is seen with
>>>> libvirt launch which may be doing some other QMP stuff concurrently?
>>>
>>> Hmm, that could be a bit painful to debug. I dunno if libvirt
>>> has a "launch QEMU under gdb" option. If not, you could try
>>> something like:
>>>    if (condition we want to get a backtrace on) {
>>>        printf("hit condition, attach gdb to process %d\n", (int)getpid());
>>>        for (;;) { }
>>>    }
>>
>> Thanks for the hint. Here is the stack I get.
>>
>> #0  kvm_device_access (fd=31, group=6, attr=50788, val=0x5937c88, write=false, errp=0x16984a8 <error_abort>) at /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164
>> #1  0x00000000004f8ce4 in arm_gicv3_icc_reset (env=0xffffa1fc8330, ri=0x597f910) at /home/augere/UPSTREAM/qemu/hw/intc/arm_gicv3_kvm.c:632
>> #2  0x00000000006351ac in cp_reg_reset (key=0x597f730, value=0x597f910, opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:78
>> #3  0x0000ffffa47edce4 in g_hash_table_foreach () from /lib64/libglib-2.0.so.0
>> #4  0x0000000000635394 in arm_cpu_reset (s=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:130
>> #5  0x000000000090c888 in cpu_reset (cpu=0xffffa1fc0010) at qom/cpu.c:249
>> #6  0x00000000005793d8 in do_cpu_reset (opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/hw/arm/boot.c:665
>> #7  0x000000000073095c in qemu_devices_reset () at hw/core/reset.c:69
>> #8  0x00000000006976e0 in qemu_system_reset (reason=SHUTDOWN_CAUSE_NONE) at vl.c:1731
>> #9  0x000000000069fd60 in main (argc=69, argv=0xffffe877d1a8, envp=0xffffe877d3d8) at vl.c:4697
> 
> I think current master should work fine with ARM KVM now since OOB is
> now off by default.

Yes it works for me with the reverts.

 But does ARM use postcopy, and will ARM need the
> coming network failure recovery feature?

I assume it does
> 
> If so, maybe we'll still need to have a look on this single problem
> (this is the only non-testcase issue I know now with Out-Of-Band).

OK. I need to have a look at your series to better understand what it does.

Thanks

Eric
> 
> Thanks,
> 

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Peter Xu]

On Wed, Mar 28, 2018 at 08:49:59AM +0200, Auger Eric wrote:
> Hi Peter,
> 
> On 28/03/18 04:03, Peter Xu wrote:
> > On Fri, Mar 23, 2018 at 01:36:36PM +0100, Auger Eric wrote:
> >> Hi,
> >>
> >> On 23/03/18 13:11, Peter Maydell wrote:
> >>> On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
> >>>> Hi,
> >>>>
> >>>> On 23/03/18 11:26, Peter Maydell wrote:
> >>>>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
> >>>>>> Hi,
> >>>>>>
> >>>>>> I observe a regression on KVM accelerated qemu-system-aarch64:
> >>>>>>
> >>>>>> Unexpected error in kvm_device_access() at
> >>>>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
> >>>>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
> >>>>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
> >>>>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
> >>>>>
> >>>>> Can you get a backtrace for this? (I guess you'd need to fiddle
> >>>>> with the kvm_device_access() code to make it assert rather
> >>>>> than passing back the error).
> >>>>
> >>>> OK. I will try to do so. As I could have expected, I cannot reproduce on
> >>>> a standalone qemu command line. The problem observed above is seen with
> >>>> libvirt launch which may be doing some other QMP stuff concurrently?
> >>>
> >>> Hmm, that could be a bit painful to debug. I dunno if libvirt
> >>> has a "launch QEMU under gdb" option. If not, you could try
> >>> something like:
> >>>    if (condition we want to get a backtrace on) {
> >>>        printf("hit condition, attach gdb to process %d\n", (int)getpid());
> >>>        for (;;) { }
> >>>    }
> >>
> >> Thanks for the hint. Here is the stack I get.
> >>
> >> #0  kvm_device_access (fd=31, group=6, attr=50788, val=0x5937c88, write=false, errp=0x16984a8 <error_abort>) at /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164
> >> #1  0x00000000004f8ce4 in arm_gicv3_icc_reset (env=0xffffa1fc8330, ri=0x597f910) at /home/augere/UPSTREAM/qemu/hw/intc/arm_gicv3_kvm.c:632
> >> #2  0x00000000006351ac in cp_reg_reset (key=0x597f730, value=0x597f910, opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:78
> >> #3  0x0000ffffa47edce4 in g_hash_table_foreach () from /lib64/libglib-2.0.so.0
> >> #4  0x0000000000635394 in arm_cpu_reset (s=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:130
> >> #5  0x000000000090c888 in cpu_reset (cpu=0xffffa1fc0010) at qom/cpu.c:249
> >> #6  0x00000000005793d8 in do_cpu_reset (opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/hw/arm/boot.c:665
> >> #7  0x000000000073095c in qemu_devices_reset () at hw/core/reset.c:69
> >> #8  0x00000000006976e0 in qemu_system_reset (reason=SHUTDOWN_CAUSE_NONE) at vl.c:1731
> >> #9  0x000000000069fd60 in main (argc=69, argv=0xffffe877d1a8, envp=0xffffe877d3d8) at vl.c:4697
> > 
> > I think current master should work fine with ARM KVM now since OOB is
> > now off by default.
> 
> Yes it works for me with the reverts.
> 
>  But does ARM use postcopy, and will ARM need the
> > coming network failure recovery feature?
> 
> I assume it does
> > 
> > If so, maybe we'll still need to have a look on this single problem
> > (this is the only non-testcase issue I know now with Out-Of-Band).
> 
> OK. I need to have a look at your series to better understand what it does.

It introduced a dedicated iothread to run IO part of the monitor code
(e.g., parsing of QMP input, and reply of the responses).  So now the
parsing could start earlier, before the main loop (that's what I
suspect the problem before), and meanwhile QMP IOs can happen in
parallel now with main thread, which it never can before (since all
QMP logic will be in main thread).

I would be curious about what commands have been sent by libvirt to
QEMU-arm when reach this point.  Please feel free to let me know if I
can help in any form.  For example, if there is an ARM server that I
can login and run both libvirt and QEMU, I'd be glad to play with it
too.

Thanks,

-- 
Peter Xu

Re: [Qemu-devel] Regression on KVM qemu-system-aarch64 since "monitor: enable IO thread for (qmp & !mux) typed"

[Auger Eric]

Hi Peter,

On 28/03/18 09:21, Peter Xu wrote:
> On Wed, Mar 28, 2018 at 08:49:59AM +0200, Auger Eric wrote:
>> Hi Peter,
>>
>> On 28/03/18 04:03, Peter Xu wrote:
>>> On Fri, Mar 23, 2018 at 01:36:36PM +0100, Auger Eric wrote:
>>>> Hi,
>>>>
>>>> On 23/03/18 13:11, Peter Maydell wrote:
>>>>> On 23 March 2018 at 12:01, Auger Eric <eric.auger@redhat.com> wrote:
>>>>>> Hi,
>>>>>>
>>>>>> On 23/03/18 11:26, Peter Maydell wrote:
>>>>>>> On 23 March 2018 at 10:24, Auger Eric <eric.auger@redhat.com> wrote:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> I observe a regression on KVM accelerated qemu-system-aarch64:
>>>>>>>>
>>>>>>>> Unexpected error in kvm_device_access() at
>>>>>>>> /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164:
>>>>>>>> 2018-03-23T09:59:59.629439Z qemu-system-aarch64: KVM_GET_DEVICE_ATTR
>>>>>>>> failed: Group 6 attr 0x000000000000c664: Device or resource busy
>>>>>>>> 2018-03-23 10:00:00.085+0000: shutting down, reason=crashed
>>>>>>>
>>>>>>> Can you get a backtrace for this? (I guess you'd need to fiddle
>>>>>>> with the kvm_device_access() code to make it assert rather
>>>>>>> than passing back the error).
>>>>>>
>>>>>> OK. I will try to do so. As I could have expected, I cannot reproduce on
>>>>>> a standalone qemu command line. The problem observed above is seen with
>>>>>> libvirt launch which may be doing some other QMP stuff concurrently?
>>>>>
>>>>> Hmm, that could be a bit painful to debug. I dunno if libvirt
>>>>> has a "launch QEMU under gdb" option. If not, you could try
>>>>> something like:
>>>>>    if (condition we want to get a backtrace on) {
>>>>>        printf("hit condition, attach gdb to process %d\n", (int)getpid());
>>>>>        for (;;) { }
>>>>>    }
>>>>
>>>> Thanks for the hint. Here is the stack I get.
>>>>
>>>> #0  kvm_device_access (fd=31, group=6, attr=50788, val=0x5937c88, write=false, errp=0x16984a8 <error_abort>) at /home/augere/UPSTREAM/qemu/accel/kvm/kvm-all.c:2164
>>>> #1  0x00000000004f8ce4 in arm_gicv3_icc_reset (env=0xffffa1fc8330, ri=0x597f910) at /home/augere/UPSTREAM/qemu/hw/intc/arm_gicv3_kvm.c:632
>>>> #2  0x00000000006351ac in cp_reg_reset (key=0x597f730, value=0x597f910, opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:78
>>>> #3  0x0000ffffa47edce4 in g_hash_table_foreach () from /lib64/libglib-2.0.so.0
>>>> #4  0x0000000000635394 in arm_cpu_reset (s=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/target/arm/cpu.c:130
>>>> #5  0x000000000090c888 in cpu_reset (cpu=0xffffa1fc0010) at qom/cpu.c:249
>>>> #6  0x00000000005793d8 in do_cpu_reset (opaque=0xffffa1fc0010) at /home/augere/UPSTREAM/qemu/hw/arm/boot.c:665
>>>> #7  0x000000000073095c in qemu_devices_reset () at hw/core/reset.c:69
>>>> #8  0x00000000006976e0 in qemu_system_reset (reason=SHUTDOWN_CAUSE_NONE) at vl.c:1731
>>>> #9  0x000000000069fd60 in main (argc=69, argv=0xffffe877d1a8, envp=0xffffe877d3d8) at vl.c:4697
>>>
>>> I think current master should work fine with ARM KVM now since OOB is
>>> now off by default.
>>
>> Yes it works for me with the reverts.
>>
>>  But does ARM use postcopy, and will ARM need the
>>> coming network failure recovery feature?
>>
>> I assume it does
>>>
>>> If so, maybe we'll still need to have a look on this single problem
>>> (this is the only non-testcase issue I know now with Out-Of-Band).
>>
>> OK. I need to have a look at your series to better understand what it does.
> 
> It introduced a dedicated iothread to run IO part of the monitor code
> (e.g., parsing of QMP input, and reply of the responses).  So now the
> parsing could start earlier, before the main loop (that's what I
> suspect the problem before), and meanwhile QMP IOs can happen in
> parallel now with main thread, which it never can before (since all
> QMP logic will be in main thread).
> 
> I would be curious about what commands have been sent by libvirt to
> QEMU-arm when reach this point.  Please feel free to let me know if I
> can help in any form.  For example, if there is an ARM server that I
> can login and run both libvirt and QEMU, I'd be glad to play with it
> too.
Yes, I will send you the data and will my utmost to help in the debugging.

Thanks

Eric
> 
> Thanks,
>