Re: [Qemu-devel] [PATCH v2 0/9] virtio: aio handler API

[Michael S. Tsirkin]

On Fri, Apr 01, 2016 at 05:16:06PM +0200, Christian Borntraeger wrote:
> Now with enable-debug and better call traces
> 
> (gdb) 
> (gdb) thread apply all bt
> 
> Thread 5 (Thread 0x3ffa0e7f910 (LWP 29839)):
> #0  0x000003ffa530334a in ioctl () at /lib64/libc.so.6
> #1  0x0000000080081c84 in kvm_vcpu_ioctl (cpu=0x80e8c170, type=44672) at 
> /home/cborntra/REPOS/qemu/kvm-all.c:1984
> #2  0x000000008008154c in kvm_cpu_exec (cpu=0x80e8c170) at 
> /home/cborntra/REPOS/qemu/kvm-all.c:1834
> #3  0x000000008006075c in qemu_kvm_cpu_thread_fn (arg=0x80e8c170) at 
> /home/cborntra/REPOS/qemu/cpus.c:1056
> #4  0x000003ffa5407c2c in start_thread () at /lib64/libpthread.so.0
> #5  0x000003ffa530ec9a in thread_start () at /lib64/libc.so.6
> 
> Thread 4 (Thread 0x3ffa3c7f910 (LWP 29830)):
> #0  0x000003ffa530841e in syscall () at /lib64/libc.so.6
> #1  0x00000000803e83fe in futex_wait (ev=0x80a65bd4 <rcu_call_ready_event>, 
> val=4294967295) at /home/cborntra/REPOS/qemu/util/qemu-thread-posix.c:292
> #2  0x00000000803e868e in qemu_event_wait (ev=0x80a65bd4 
> <rcu_call_ready_event>) at 
> /home/cborntra/REPOS/qemu/util/qemu-thread-posix.c:399
> #3  0x0000000080405dcc in call_rcu_thread (opaque=0x0) at 
> /home/cborntra/REPOS/qemu/util/rcu.c:250
> #4  0x000003ffa5407c2c in start_thread () at /lib64/libpthread.so.0
> #5  0x000003ffa530ec9a in thread_start () at /lib64/libc.so.6
> 
> Thread 3 (Thread 0x3ffa16c3910 (LWP 29838)):
> #0  0x000003ffa5410cd4 in __lll_lock_wait () at /lib64/libpthread.so.0
> #1  0x000003ffa5413ed4 in __lll_lock_elision () at /lib64/libpthread.so.0
> #2  0x00000000803e7ace in qemu_mutex_lock (mutex=0x8063ad08 
> <qemu_global_mutex>) at /home/cborntra/REPOS/qemu/util/qemu-thread-posix.c:64
> #3  0x0000000080060f04 in qemu_mutex_lock_iothread () at 
> /home/cborntra/REPOS/qemu/cpus.c:1232
> #4  0x0000000080158866 in kvm_arch_handle_exit (cs=0x80e4d2b0, 
> run=0x3ffa0e80000) at /home/cborntra/REPOS/qemu/target-s390x/kvm.c:2024
> #5  0x000000008008181e in kvm_cpu_exec (cpu=0x80e4d2b0) at 
> /home/cborntra/REPOS/qemu/kvm-all.c:1921
> #6  0x000000008006075c in qemu_kvm_cpu_thread_fn (arg=0x80e4d2b0) at 
> /home/cborntra/REPOS/qemu/cpus.c:1056
> #7  0x000003ffa5407c2c in start_thread () at /lib64/libpthread.so.0
> #8  0x000003ffa530ec9a in thread_start () at /lib64/libc.so.6
> 
> Thread 2 (Thread 0x3ffa6edbb90 (LWP 29795)):
> #0  0x000003ffa540d68a in pthread_cond_wait@@GLIBC_2.3.2 () at 
> /lib64/libpthread.so.0
> #1  0x00000000803e7d66 in qemu_cond_wait (cond=0x80acd660, mutex=0x80acd630) 
> at /home/cborntra/REPOS/qemu/util/qemu-thread-posix.c:123
> #2  0x0000000080405618 in rfifolock_lock (r=0x80acd630) at 
> /home/cborntra/REPOS/qemu/util/rfifolock.c:59
> #3  0x00000000802dfafa in aio_context_acquire (ctx=0x80acd5d0) at 
> /home/cborntra/REPOS/qemu/async.c:373
> #4  0x00000000802eb7e0 in bdrv_set_aio_context (bs=0x80b00d30, 
> new_context=0x80acd5d0) at /home/cborntra/REPOS/qemu/block.c:3682
> #5  0x000000008034834e in blk_set_aio_context (blk=0x80af81f0, 
> new_context=0x80acd5d0) at 
> /home/cborntra/REPOS/qemu/block/block-backend.c:1371
> #6  0x00000000800b7b08 in virtio_blk_data_plane_start (s=0x80f39530) at 
> /home/cborntra/REPOS/qemu/hw/block/dataplane/virtio-blk.c:228


So we are in virtio_blk_data_plane_start, but before we set aio handler.

> #7  0x00000000800b57ba in virtio_blk_handle_output (vdev=0x80f18008, 
> vq=0x80fa25d0) at /home/cborntra/REPOS/qemu/hw/block/virtio-blk.c:607
> #8  0x00000000800f0c7c in virtio_queue_notify_vq (vq=0x80fa25d0) at 
> /home/cborntra/REPOS/qemu/hw/virtio/virtio.c:1108
> #9  0x00000000800f3674 in virtio_queue_host_notifier_read (n=0x80fa2630) at 
> /home/cborntra/REPOS/qemu/hw/virtio/virtio.c:1820
> #10 0x00000000802f1914 in aio_dispatch (ctx=0x80abae30) at 
> /home/cborntra/REPOS/qemu/aio-posix.c:327
> #11 0x00000000802df3dc in aio_ctx_dispatch (source=0x80abae30, callback=0x0, 
> user_data=0x0) at /home/cborntra/REPOS/qemu/async.c:233
> #12 0x000003ffa5c51c0a in g_main_context_dispatch () at 
> /lib64/libglib-2.0.so.0
> #13 0x00000000802ee616 in glib_pollfds_poll () at 
> /home/cborntra/REPOS/qemu/main-loop.c:213
> #14 0x00000000802ee752 in os_host_main_loop_wait (timeout=1328000000) at 
> /home/cborntra/REPOS/qemu/main-loop.c:258
> #15 0x00000000802ee85e in main_loop_wait (nonblocking=0) at 
> /home/cborntra/REPOS/qemu/main-loop.c:506
> #16 0x000000008017db14 in main_loop () at /home/cborntra/REPOS/qemu/vl.c:1934
> #17 0x0000000080185fe8 in main (argc=72, argv=0x3ffd157ea28, 
> envp=0x3ffd157ec70) at /home/cborntra/REPOS/qemu/vl.c:4652
> 
> Thread 1 (Thread 0x3ffa347f910 (LWP 29831)):
> #0  0x000003ffa540a178 in pthread_mutex_lock () at /lib64/libpthread.so.0
> #1  0x00000000803e7ace in qemu_mutex_lock (mutex=0xf0) at 
> /home/cborntra/REPOS/qemu/util/qemu-thread-posix.c:64
> #2  0x00000000802deba8 in aio_bh_new (ctx=0x0, cb=0x80346910 
> <blk_aio_complete_bh>, opaque=0x3ff9c000a50) at 
> /home/cborntra/REPOS/qemu/async.c:55
> #3  0x0000000080346a6e in blk_aio_prwv (blk=0x80af81f0, offset=4096, 
> qiov=0x3ff9c0021c8, co_entry=0x80346aa8 <blk_aio_read_entry>, flags=(unknown: 
> 0), cb=0x800b3be8 <virtio_blk_rw_complete>, opaque=0x3ff9c002170) at 
> /home/cborntra/REPOS/qemu/block/block-backend.c:904
> #4  0x0000000080347030 in blk_aio_readv (blk=0x80af81f0, sector_num=8, 
> iov=0x3ff9c0021c8, nb_sectors=8, cb=0x800b3be8 <virtio_blk_rw_complete>, 
> opaque=0x3ff9c002170) at /home/cborntra/REPOS/qemu/block/block-backend.c:997
> #5  0x00000000800b492c in submit_requests (blk=0x80af81f0, mrb=0x3ffa347e5c0, 
> start=0, num_reqs=1, niov=-1) at 
> /home/cborntra/REPOS/qemu/hw/block/virtio-blk.c:361
> #6  0x00000000800b4a5e in virtio_blk_submit_multireq (blk=0x80af81f0, 
> mrb=0x3ffa347e5c0) at /home/cborntra/REPOS/qemu/hw/block/virtio-blk.c:391
> #7  0x00000000800b571e in virtio_blk_handle_vq (s=0x80f18008, vq=0x80fa25d0) 
> at /home/cborntra/REPOS/qemu/hw/block/virtio-blk.c:593
> #8  0x00000000800b78a2 in virtio_blk_data_plane_handle_output 
> (vdev=0x80f18008, vq=0x80fa25d0) at 
> /home/cborntra/REPOS/qemu/hw/block/dataplane/virtio-blk.c:192


but here, are are in the aio handler already. how come?

is it possible that data plane stop does not shut down
running aio properly?

> #9  0x00000000800f0bbc in virtio_queue_notify_aio_vq (vq=0x80fa25d0) at 
> /home/cborntra/REPOS/qemu/hw/virtio/virtio.c:1098
> #10 0x00000000800f356c in virtio_queue_host_notifier_aio_read (n=0x80fa2630) 
> at /home/cborntra/REPOS/qemu/hw/virtio/virtio.c:1799
> #11 0x00000000802f1914 in aio_dispatch (ctx=0x80acd5d0) at 
> /home/cborntra/REPOS/qemu/aio-posix.c:327
> #12 0x00000000802f229a in aio_poll (ctx=0x80acd5d0, blocking=true) at 
> /home/cborntra/REPOS/qemu/aio-posix.c:475
> #13 0x0000000080165812 in iothread_run (opaque=0x80acd090) at 
> /home/cborntra/REPOS/qemu/iothread.c:46
> #14 0x000003ffa5407c2c in start_thread () at /lib64/libpthread.so.0
> #15 0x000003ffa530ec9a in thread_start () at /lib64/libc.so.6