Re: [Qemu-devel] [PATCH 0/4] Tweaks around virtio-blk start/stop

[Christian Borntraeger <borntraeger@de.ibm.com>]

On 03/21/2016 10:42 AM, Fam Zheng wrote:
> On Fri, 03/18 16:03, Paolo Bonzini wrote:
>>
>>
>> On 17/03/2016 17:08, Christian Borntraeger wrote:
>>> Good (or bad?) news is the assert also triggers on F23, it just seems
>>> to take longer.
>>
>> I guess good news, because we can rule out the kernel (not that I
>> believed it was a kernel problem, but the thought is always there in
>> the background...).
>>
>> The interaction between ioeventfd and dataplane is too complicated.  I
>> think if we get rid of the start/stop ioeventfd calls (just set up the
>> ioeventfd as soon as possible and then only set/clear the handlers)
>> things would be much simpler.
>>
>> I'll see if I can produce something based on Conny's patches, which are
>> already a start.  Today I had a short day so I couldn't play with the
>> bug; out of curiosity, does the bug reproduce with her work + patch 4
>> from this series + the reentrancy assertion?
> 
> The other half of the race condition is from ioport write in the vcpu thread. I
> hit this by adding an extra assert(is_in_iothread()) in
> virtio_blk_handle_request(), at the same place with Paolo's atomic read of
> variable "test".

Thats good, that you can reproduce on x86.
the ioport write in the vcpu thread, is the equivalent of s390_virtio_hypercall on
s390 - a virtio kick that is usually handled by eventfd but here we  have a case
where we go the slow path. So the good thing is that this is not s390 specific,
which might help to find the issue more quickly.



> 
> I haven't tried to find where this ioport write is from, but that is indeed an
> issue in virtio-pci.
> 
> (gdb) thread apply all bt
> 
> <...>
> 
> Thread 3 (Thread 0x7f9e8928b700 (LWP 30671)):
> #0  0x00007f9e8bac65d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
> #1  0x00007f9e8bac7cc8 in __GI_abort () at abort.c:90
> #2  0x00007f9e8babf546 in __assert_fail_base (fmt=0x7f9e8bc0f128 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f9e8e04e9d1 "is_in_iothread()",
>     file=file@entry=0x7f9e8e04e8e0 "/home/fam/work/qemu/hw/block/virtio-blk.c", line=line@entry=597,
>     function=function@entry=0x7f9e8e04ec30 <__PRETTY_FUNCTION__.37148> "virtio_blk_handle_output") at assert.c:92
> #3  0x00007f9e8babf5f2 in __GI___assert_fail (assertion=0x7f9e8e04e9d1 "is_in_iothread()", file=0x7f9e8e04e8e0 "/home/fam/work/qemu/hw/block/virtio-blk.c", line=597,
>     function=0x7f9e8e04ec30 <__PRETTY_FUNCTION__.37148> "virtio_blk_handle_output") at assert.c:101
> #4  0x00007f9e8dc9f414 in virtio_blk_handle_output (vdev=0x7f9e929d7b68, vq=0x7f9e92a762f0) at /home/fam/work/qemu/hw/block/virtio-blk.c:597
> #5  0x00007f9e8dcd6f53 in virtio_queue_notify_vq (vq=0x7f9e92a762f0) at /home/fam/work/qemu/hw/virtio/virtio.c:1095
> #6  0x00007f9e8dcd6f91 in virtio_queue_notify (vdev=0x7f9e929d7b68, n=0) at /home/fam/work/qemu/hw/virtio/virtio.c:1101
> #7  0x00007f9e8df03d2f in virtio_ioport_write (opaque=0x7f9e929cf840, addr=16, val=0) at /home/fam/work/qemu/hw/virtio/virtio-pci.c:419
> #8  0x00007f9e8df041be in virtio_pci_config_write (opaque=0x7f9e929cf840, addr=16, val=0, size=2) at /home/fam/work/qemu/hw/virtio/virtio-pci.c:552
> #9  0x00007f9e8dc7c8c9 in memory_region_write_accessor (mr=0x7f9e929d00c0, addr=16, value=0x7f9e8928a988, size=2, shift=0, mask=65535, attrs=...)
>     at /home/fam/work/qemu/memory.c:524
> #10 0x00007f9e8dc7cad4 in access_with_adjusted_size (addr=16, value=0x7f9e8928a988, size=2, access_size_min=1, access_size_max=4, access=
>     0x7f9e8dc7c7e8 <memory_region_write_accessor>, mr=0x7f9e929d00c0, attrs=...) at /home/fam/work/qemu/memory.c:590
> #11 0x00007f9e8dc7f71b in memory_region_dispatch_write (mr=0x7f9e929d00c0, addr=16, data=0, size=2, attrs=...) at /home/fam/work/qemu/memory.c:1272
> #12 0x00007f9e8dc32815 in address_space_write_continue (as=0x7f9e8e5834a0 <address_space_io>, addr=49232, attrs=..., buf=0x7f9e8daa9000 <Address 0x7f9e8daa9000 out of bounds>,
>     len=2, addr1=16, l=2, mr=0x7f9e929d00c0) at /home/fam/work/qemu/exec.c:2607
> #13 0x00007f9e8dc329c1 in address_space_write (as=0x7f9e8e5834a0 <address_space_io>, addr=49232, attrs=..., buf=0x7f9e8daa9000 <Address 0x7f9e8daa9000 out of bounds>, len=2)
>     at /home/fam/work/qemu/exec.c:2659
> #14 0x00007f9e8dc32d78 in address_space_rw (as=0x7f9e8e5834a0 <address_space_io>, addr=49232, attrs=..., buf=0x7f9e8daa9000 <Address 0x7f9e8daa9000 out of bounds>, len=2,
>     is_write=true) at /home/fam/work/qemu/exec.c:2762
> #15 0x00007f9e8dc79358 in kvm_handle_io (port=49232, attrs=..., data=0x7f9e8daa9000, direction=1, size=2, count=1) at /home/fam/work/qemu/kvm-all.c:1699
> #16 0x00007f9e8dc79858 in kvm_cpu_exec (cpu=0x7f9e905a5250) at /home/fam/work/qemu/kvm-all.c:1863
> #17 0x00007f9e8dc619a3 in qemu_kvm_cpu_thread_fn (arg=0x7f9e905a5250) at /home/fam/work/qemu/cpus.c:1056
> #18 0x00007f9e8be59df5 in start_thread (arg=0x7f9e8928b700) at pthread_create.c:308
> #19 0x00007f9e8bb871ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113
> 
> <...>
> 
> Thread 1 (Thread 0x7f9e8b28f700 (LWP 30667)):
> #0  0x00007f9e8bac65d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
> #1  0x00007f9e8bac7cc8 in __GI_abort () at abort.c:90
> #2  0x00007f9e8babf546 in __assert_fail_base (fmt=0x7f9e8bc0f128 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f9e8e04e9e2 "x == 0",
>     file=file@entry=0x7f9e8e04e8e0 "/home/fam/work/qemu/hw/block/virtio-blk.c", line=line@entry=598,
>     function=function@entry=0x7f9e8e04ec30 <__PRETTY_FUNCTION__.37148> "virtio_blk_handle_output") at assert.c:92
> #3  0x00007f9e8babf5f2 in __GI___assert_fail (assertion=0x7f9e8e04e9e2 "x == 0", file=0x7f9e8e04e8e0 "/home/fam/work/qemu/hw/block/virtio-blk.c", line=598,
>     function=0x7f9e8e04ec30 <__PRETTY_FUNCTION__.37148> "virtio_blk_handle_output") at assert.c:101
> #4  0x00007f9e8dc9f43c in virtio_blk_handle_output (vdev=0x7f9e929d7b68, vq=0x7f9e92a762f0) at /home/fam/work/qemu/hw/block/virtio-blk.c:598
> #5  0x00007f9e8dcd6f53 in virtio_queue_notify_vq (vq=0x7f9e92a762f0) at /home/fam/work/qemu/hw/virtio/virtio.c:1095
> #6  0x00007f9e8dcd8dfd in virtio_queue_host_notifier_read (n=0x7f9e92a76348) at /home/fam/work/qemu/hw/virtio/virtio.c:1785
> #7  0x00007f9e8df76b40 in aio_dispatch (ctx=0x7f9e90540a50) at /home/fam/work/qemu/aio-posix.c:327
> #8  0x00007f9e8df770f8 in aio_poll (ctx=0x7f9e90540a50, blocking=true) at /home/fam/work/qemu/aio-posix.c:475
> #9  0x00007f9e8dd7b5c4 in iothread_run (opaque=0x7f9e905404d0) at /home/fam/work/qemu/iothread.c:55
> #10 0x00007f9e8be59df5 in start_thread (arg=0x7f9e8b28f700) at pthread_create.c:308
> #11 0x00007f9e8bb871ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113
>