[Qemu-devel] dataplane: latest rc with selected patches hangs very often

[Qemu-devel] dataplane: latest rc with selected patches hangs very often

[Andrey Korolyov]

Hello,

is it worthy to re-test dp until next tag point? I am checking aio
with -rc1 and following picked commits (sorry for patchwork
references):

stefanha:
368191 New          [v3,1/4] virtio-blk: avoid dataplane
VirtIOBlockReq early free
368787 New          [v3,2/4] dataplane: do not free VirtQueueElement
in vring_push()
368360 New          [v3,3/4] virtio-blk: avoid g_slice_new0() for
VirtIOBlockReq and VirtQueueElement
368863 New          [v3,4/4] virtio-blk: embed VirtQueueElement in
VirtIOBlockReq

pbonzini:
367551 New          [1/4] block: prefer aio_poll to qemu_aio_wait
367553 New          [2/4] block: drop aio functions that operate on
the main AioContext
367552 New          [3/4] test-aio: fix GSource-based timer test
367554 New          [4/4] AioContext: speed up aio_notify

Emulator itself stop responding in approximately ninety percent of
cases, e.g. it does not react to anything except SIGKILL. Windows VM
is able to read some bits before lockup happens because it draws an
initial logo.

hangs on vl.c:
(gdb) list
2890        g_free(dummy);
2891        if (err) {
2892            qerror_report_err(err);
2893            return -1;
2894        }
2895        return 0;
2896    }
2897
2898    int main(int argc, char **argv, char **envp)
2899    {
(gdb) next
Single stepping until exit from function __lll_lock_wait,
which has no line number information.

cmdline follows:
if=none,id=drive-virtio-disk0,format=raw,cache=writeback,aio=native
... -object iothread,id=blk0 -set device.virtio-disk0.config-wce=off
-set device.virtio-disk0.scsi=off -set
device.virtio-disk0.iothread=blk0

Re: [Qemu-devel] dataplane: latest rc with selected patches hangs very often

[Andrey Korolyov]

[-- Attachment #1: Type: text/plain, Size: 1863 bytes --]

On Fri, Jul 11, 2014 at 11:01 PM, Andrey Korolyov <andrey@xdel.ru> wrote:
> Hello,
>
> is it worthy to re-test dp until next tag point? I am checking aio
> with -rc1 and following picked commits (sorry for patchwork
> references):
>
> stefanha:
> 368191 New          [v3,1/4] virtio-blk: avoid dataplane
> VirtIOBlockReq early free
> 368787 New          [v3,2/4] dataplane: do not free VirtQueueElement
> in vring_push()
> 368360 New          [v3,3/4] virtio-blk: avoid g_slice_new0() for
> VirtIOBlockReq and VirtQueueElement
> 368863 New          [v3,4/4] virtio-blk: embed VirtQueueElement in
> VirtIOBlockReq
>
> pbonzini:
> 367551 New          [1/4] block: prefer aio_poll to qemu_aio_wait
> 367553 New          [2/4] block: drop aio functions that operate on
> the main AioContext
> 367552 New          [3/4] test-aio: fix GSource-based timer test
> 367554 New          [4/4] AioContext: speed up aio_notify
>
> Emulator itself stop responding in approximately ninety percent of
> cases, e.g. it does not react to anything except SIGKILL. Windows VM
> is able to read some bits before lockup happens because it draws an
> initial logo.
>
> hangs on vl.c:
> (gdb) list
> 2890        g_free(dummy);
> 2891        if (err) {
> 2892            qerror_report_err(err);
> 2893            return -1;
> 2894        }
> 2895        return 0;
> 2896    }
> 2897
> 2898    int main(int argc, char **argv, char **envp)
> 2899    {
> (gdb) next
> Single stepping until exit from function __lll_lock_wait,
> which has no line number information.
>
> cmdline follows:
> if=none,id=drive-virtio-disk0,format=raw,cache=writeback,aio=native
> ... -object iothread,id=blk0 -set device.virtio-disk0.config-wce=off
> -set device.virtio-disk0.scsi=off -set
> device.virtio-disk0.iothread=blk0

Forgot to attach backtrace, though the issue and bt itself can be
easily reproduced.

[-- Attachment #2: aio-dp-bt.txt --]
[-- Type: text/plain, Size: 5570 bytes --]

Thread 4 (Thread 0x7ff1239ff700 (LWP 11532)):
#0  0x00007ff12d4f8116 in ppoll () from /lib64/libc.so.6
#1  0x00007ff133aa543b in ppoll (__ss=0x0, __timeout=0x0, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/bits/poll2.h:77
#2  qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>, timeout=<optimized out>) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/qemu-timer.c:314
#3  0x00007ff133aa6750 in aio_poll (ctx=0x7ff13447d6e0, blocking=blocking@entry=true) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/aio-posix.c:250
#4  0x00007ff133919b17 in iothread_run (opaque=0x7ff13447d340) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/iothread.c:41
#5  0x00007ff12fffcf3a in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff12d501c3d in clone () from /lib64/libc.so.6

Thread 3 (Thread 0x7ff1229c4700 (LWP 11534)):
#0  0x00007ff130000d0c in pthread_cond_wait () from /lib64/libpthread.so.0
#1  0x00007ff133af3619 in qemu_cond_wait (cond=cond@entry=0x7ff13447d770, mutex=mutex@entry=0x7ff13447d740) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/util/qemu-thread-posix.c:135
#2  0x00007ff133b046aa in rfifolock_lock (r=0x7ff13447d740) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/util/rfifolock.c:59
#3  0x00007ff133a953e1 in aio_context_acquire (ctx=<optimized out>) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/async.c:312
#4  0x00007ff133865764 in virtio_blk_set_status (vdev=0x7ff134687938, status=<optimized out>) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/hw/block/virtio-blk.c:609
#5  0x00007ff133888627 in virtio_set_status (vdev=vdev@entry=0x7ff134687938, val=val@entry=5 '\005') at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/hw/virtio/virtio.c:550
#6  0x00007ff133a4cad0 in virtio_ioport_write (val=5, addr=<optimized out>, opaque=0x7ff134686f60) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/hw/virtio/virtio-pci.c:306
#7  virtio_pci_config_write (opaque=0x7ff134686f60, addr=<optimized out>, val=5, size=<optimized out>) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/hw/virtio/virtio-pci.c:430
#8  0x00007ff133856879 in access_with_adjusted_size (addr=addr@entry=18, value=value@entry=0x7ff1229c3bb0, size=size@entry=1, access_size_min=<optimized out>, access_size_max=<optimized out>,
    access=0x7ff133856f70 <memory_region_write_accessor>, mr=0x7ff1346877a8) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/memory.c:481
#9  0x00007ff13385c5bf in memory_region_dispatch_write (size=1, data=5, addr=18, mr=0x7ff1346877a8) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/memory.c:1143
#10 io_mem_write (mr=mr@entry=0x7ff1346877a8, addr=18, val=<optimized out>, size=1) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/memory.c:1976
#11 0x00007ff13381bfc3 in address_space_rw (as=0x7ff133f3e120 <address_space_io>, addr=<optimized out>, addr@entry=49170, buf=<optimized out>, len=len@entry=1, is_write=is_write@entry=true)
    at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/exec.c:2054
#12 0x00007ff13385593f in kvm_handle_io (count=1, size=1, direction=<optimized out>, data=<optimized out>, port=49170) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/kvm-all.c:1597
#13 kvm_cpu_exec (cpu=cpu@entry=0x7ff13449d8d0) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/kvm-all.c:1734
#14 0x00007ff133840e2c in qemu_kvm_cpu_thread_fn (arg=0x7ff13449d8d0) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/cpus.c:874
#15 0x00007ff12fffcf3a in start_thread () from /lib64/libpthread.so.0
#16 0x00007ff12d501c3d in clone () from /lib64/libc.so.6

Thread 2 (Thread 0x7ff1209ff700 (LWP 11537)):
#0  0x00007ff130000d0c in pthread_cond_wait () from /lib64/libpthread.so.0
#1  0x00007ff133af3619 in qemu_cond_wait (cond=cond@entry=0x7ff1344ec690, mutex=mutex@entry=0x7ff1344ec6c0) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/util/qemu-thread-posix.c:135
#2  0x00007ff133a902ab in vnc_worker_thread_loop (queue=queue@entry=0x7ff1344ec690) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/ui/vnc-jobs.c:222
#3  0x00007ff133a90680 in vnc_worker_thread (arg=0x7ff1344ec690) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/ui/vnc-jobs.c:323
#4  0x00007ff12fffcf3a in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff12d501c3d in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x7ff1336fa980 (LWP 11515)):
#0  0x00007ff1300037a4 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007ff12ffff19c in _L_lock_518 () from /lib64/libpthread.so.0
#2  0x00007ff12fffefeb in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00007ff133af33f9 in qemu_mutex_lock (mutex=mutex@entry=0x7ff133f9a3c0 <qemu_global_mutex>) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/util/qemu-thread-posix.c:76
#4  0x00007ff133842120 in qemu_mutex_lock_iothread () at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/cpus.c:1044
#5  0x00007ff133aa48db in os_host_main_loop_wait (timeout=15438744) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/main-loop.c:232
#6  main_loop_wait (nonblocking=<optimized out>) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/main-loop.c:484
#7  0x00007ff133811cd5 in main_loop () at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/vl.c:2010
#8  main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at /var/tmp/portage/app-emulation/qemu-2.1.0/work/qemu-2.1.0/vl.c:4524

Re: [Qemu-devel] dataplane: latest rc with selected patches hangs very often

[Paolo Bonzini]

Il 11/07/2014 21:18, Andrey Korolyov ha scritto:
> On Fri, Jul 11, 2014 at 11:01 PM, Andrey Korolyov <andrey@xdel.ru> wrote:
>> Hello,
>>
>> is it worthy to re-test dp until next tag point? I am checking aio
>> with -rc1 and following picked commits (sorry for patchwork
>> references):
>>
>> stefanha:
>> 368191 New          [v3,1/4] virtio-blk: avoid dataplane
>> VirtIOBlockReq early free
>> 368787 New          [v3,2/4] dataplane: do not free VirtQueueElement
>> in vring_push()
>> 368360 New          [v3,3/4] virtio-blk: avoid g_slice_new0() for
>> VirtIOBlockReq and VirtQueueElement
>> 368863 New          [v3,4/4] virtio-blk: embed VirtQueueElement in
>> VirtIOBlockReq
>>
>> pbonzini:
>> 367551 New          [1/4] block: prefer aio_poll to qemu_aio_wait
>> 367553 New          [2/4] block: drop aio functions that operate on
>> the main AioContext
>> 367552 New          [3/4] test-aio: fix GSource-based timer test
>> 367554 New          [4/4] AioContext: speed up aio_notify
>>
>> Emulator itself stop responding in approximately ninety percent of
>> cases, e.g. it does not react to anything except SIGKILL. Windows VM
>> is able to read some bits before lockup happens because it draws an
>> initial logo.

Please try this patch:

http://article.gmane.org/gmane.comp.emulators.qemu/285674/raw

Paolo

>> hangs on vl.c:
>> (gdb) list
>> 2890        g_free(dummy);
>> 2891        if (err) {
>> 2892            qerror_report_err(err);
>> 2893            return -1;
>> 2894        }
>> 2895        return 0;
>> 2896    }
>> 2897
>> 2898    int main(int argc, char **argv, char **envp)
>> 2899    {
>> (gdb) next
>> Single stepping until exit from function __lll_lock_wait,
>> which has no line number information.
>>
>> cmdline follows:
>> if=none,id=drive-virtio-disk0,format=raw,cache=writeback,aio=native
>> ... -object iothread,id=blk0 -set device.virtio-disk0.config-wce=off
>> -set device.virtio-disk0.scsi=off -set
>> device.virtio-disk0.iothread=blk0
>
> Forgot to attach backtrace, though the issue and bt itself can be
> easily reproduced.
>

Re: [Qemu-devel] dataplane: latest rc with selected patches hangs very often

[Andrey Korolyov]

On Sat, Jul 12, 2014 at 12:45 AM, Paolo Bonzini <pbonzini@redhat.com> wrote:
> Il 11/07/2014 21:18, Andrey Korolyov ha scritto:
>
>> On Fri, Jul 11, 2014 at 11:01 PM, Andrey Korolyov <andrey@xdel.ru> wrote:
>>>
>>> Hello,
>>>
>>> is it worthy to re-test dp until next tag point? I am checking aio
>>> with -rc1 and following picked commits (sorry for patchwork
>>> references):
>>>
>>> stefanha:
>>> 368191 New          [v3,1/4] virtio-blk: avoid dataplane
>>> VirtIOBlockReq early free
>>> 368787 New          [v3,2/4] dataplane: do not free VirtQueueElement
>>> in vring_push()
>>> 368360 New          [v3,3/4] virtio-blk: avoid g_slice_new0() for
>>> VirtIOBlockReq and VirtQueueElement
>>> 368863 New          [v3,4/4] virtio-blk: embed VirtQueueElement in
>>> VirtIOBlockReq
>>>
>>> pbonzini:
>>> 367551 New          [1/4] block: prefer aio_poll to qemu_aio_wait
>>> 367553 New          [2/4] block: drop aio functions that operate on
>>> the main AioContext
>>> 367552 New          [3/4] test-aio: fix GSource-based timer test
>>> 367554 New          [4/4] AioContext: speed up aio_notify
>>>
>>> Emulator itself stop responding in approximately ninety percent of
>>> cases, e.g. it does not react to anything except SIGKILL. Windows VM
>>> is able to read some bits before lockup happens because it draws an
>>> initial logo.
>
>
> Please try this patch:
>
> http://article.gmane.org/gmane.comp.emulators.qemu/285674/raw
>
> Paolo
>
>
>>> hangs on vl.c:
>>> (gdb) list
>>> 2890        g_free(dummy);
>>> 2891        if (err) {
>>> 2892            qerror_report_err(err);
>>> 2893            return -1;
>>> 2894        }
>>> 2895        return 0;
>>> 2896    }
>>> 2897
>>> 2898    int main(int argc, char **argv, char **envp)
>>> 2899    {
>>> (gdb) next
>>> Single stepping until exit from function __lll_lock_wait,
>>> which has no line number information.
>>>
>>> cmdline follows:
>>> if=none,id=drive-virtio-disk0,format=raw,cache=writeback,aio=native
>>> ... -object iothread,id=blk0 -set device.virtio-disk0.config-wce=off
>>> -set device.virtio-disk0.scsi=off -set
>>> device.virtio-disk0.iothread=blk0
>>
>>
>> Forgot to attach backtrace, though the issue and bt itself can be
>> easily reproduced.
>>
>

Thanks, issue fixed.