Re: [RESEND][BUG FIX HELP] QEMU main thread endlessly hangs in __ppoll()

[Like Xu]

Hi John,

Thanks for your comment.

On 2021/3/5 7:53, John Snow wrote:
> On 2/28/21 9:39 PM, Like Xu wrote:
> > Hi Genius,
> >
> > I am a user of QEMU v4.2.0 and stuck in an interesting bug, which may 
> > still exist in the mainline.
> > Thanks in advance to heroes who can take a look and share understanding.
>
> Do you have a test case that reproduces on 5.2? It'd be nice to know if it 
> was still a problem in the latest source tree or not.

We narrowed down the source of the bug, which basically came from
the following qmp usage:

{'execute': 'human-monitor-command', 'arguments':{ 'command-line': 
'drive_del replication0' } }

One of the test cases is the COLO usage (docs/colo-proxy.txt).

This issue is sporadic,the probability may be 1/15 for a io-heavy guest.

I believe it's reproducible on 5.2 and the latest tree.

> --js
>
> > The qemu main thread endlessly hangs in the handle of the qmp statement:
> > {'execute': 'human-monitor-command', 'arguments':{ 'command-line': 
> > 'drive_del replication0' } }
> > and we have the call trace looks like:
> >
> > #0 0x00007f3c22045bf6 in __ppoll (fds=0x555611328410, nfds=1, 
> > timeout=<optimized out>, timeout@entry=0x7ffc56c66db0,
> > sigmask=sigmask@entry=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:44
> > #1 0x000055561021f415 in ppoll (__ss=0x0, __timeout=0x7ffc56c66db0, 
> > __nfds=<optimized out>, __fds=<optimized out>)
> > at /usr/include/x86_64-linux-gnu/bits/poll2.h:77
> > #2 qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>, 
> > timeout=<optimized out>) at util/qemu-timer.c:348
> > #3 0x0000555610221430 in aio_poll (ctx=ctx@entry=0x5556113010f0, 
> > blocking=blocking@entry=true) at util/aio-posix.c:669
> > #4 0x000055561019268d in bdrv_do_drained_begin (poll=true, 
> > ignore_bds_parents=false, parent=0x0, recursive=false,
> > bs=0x55561138b0a0) at block/io.c:430
> > #5 bdrv_do_drained_begin (bs=0x55561138b0a0, recursive=<optimized out>, 
> > parent=0x0, ignore_bds_parents=<optimized out>,
> > poll=<optimized out>) at block/io.c:396
> > #6 0x000055561017b60b in quorum_del_child (bs=0x55561138b0a0, 
> > child=0x7f36dc0ce380, errp=<optimized out>)
> > at block/quorum.c:1063
> > #7 0x000055560ff5836b in qmp_x_blockdev_change (parent=0x555612373120 
> > "colo-disk0", has_child=<optimized out>,
> > child=0x5556112df3e0 "children.1", has_node=<optimized out>, node=0x0, 
> > errp=0x7ffc56c66f98) at blockdev.c:4494
> > #8 0x00005556100f8f57 in qmp_marshal_x_blockdev_change (args=<optimized 
> > out>, ret=<optimized out>, errp=0x7ffc56c67018)
> > at qapi/qapi-commands-block-core.c:1538
> > #9 0x00005556101d8290 in do_qmp_dispatch (errp=0x7ffc56c67010, 
> > allow_oob=<optimized out>, request=<optimized out>,
> > cmds=0x5556109c69a0 <qmp_commands>) at qapi/qmp-dispatch.c:132
> > #10 qmp_dispatch (cmds=0x5556109c69a0 <qmp_commands>, request=<optimized 
> > out>, allow_oob=<optimized out>)
> > at qapi/qmp-dispatch.c:175
> > #11 0x00005556100d4c4d in monitor_qmp_dispatch (mon=0x5556113a6f40, 
> > req=<optimized out>) at monitor/qmp.c:145
> > #12 0x00005556100d5437 in monitor_qmp_bh_dispatcher (data=<optimized 
> > out>) at monitor/qmp.c:234
> > #13 0x000055561021dbec in aio_bh_call (bh=0x5556112164bGrateful0) at 
> > util/async.c:117
> > #14 aio_bh_poll (ctx=ctx@entry=0x5556112151b0) at util/async.c:117
> > #15 0x00005556102212c4 in aio_dispatch (ctx=0x5556112151b0) at 
> > util/aio-posix.c:459
> > #16 0x000055561021dab2 in aio_ctx_dispatch (source=<optimized out>, 
> > callback=<optimized out>, user_data=<optimized out>)
> > at util/async.c:260
> > #17 0x00007f3c22302fbd in g_main_context_dispatch () from 
> > /lib/x86_64-linux-gnu/libglib-2.0.so.0
> > #18 0x0000555610220358 in glib_pollfds_poll () at util/main-loop.c:219
> > #19 os_host_main_loop_wait (timeout=<optimized out>) at util/main-loop.c:242
> > #20 main_loop_wait (nonblocking=<optimized out>) at util/main-loop.c:518
> > #21 0x000055560ff600fe in main_loop () at vl.c:1814
> > #22 0x000055560fddbce9 in main (argc=<optimized out>, argv=<optimized 
> > out>, envp=<optimized out>) at vl.c:4503
> >
> > We found that we're doing endless check in the line of 
> > block/io.c:bdrv_do_drained_begin():
> >      BDRV_POLL_WHILE(bs, bdrv_drain_poll_top_level(bs, recursive, parent));
> > and it turns out that the bdrv_drain_poll() always get true from:
> > - bdrv_parent_drained_poll(bs, ignore_parent, ignore_bds_parents)
> > - AND atomic_read(&bs->in_flight)
> >
> > I personally think this is a deadlock issue in the a QEMU block layer
> > (as we know, we have some #FIXME comments in related codes, such as block 
> > permisson update).
> > Any comments are welcome and appreciated.
> >
> > ---
> > thx,likexu