Re: [PATCH] monitor: Fix order in monitor_cleanup()

[Markus Armbruster <armbru@redhat.com>]

I ran into odd behavior the other day, and bisected it to this commit.

    $ qemu-system-x86_64 -display none -chardev socket,id=qmp,path=test-qmp,server=on,wait=off -mon mode=control,chardev=qmp

In another terminal, create a bunch of FIFOs, then use them to have some
in-band commands block, with out-of-band commands interleaved just
because:

    $ for ((i=0; i<20; i++)); do mkfifo fifo$i; done
    $ cat oob-test2
    {"execute": "qmp_capabilities", "arguments": {"enable": ["oob"]}}
    {"exec-oob": "migrate-pause", "id": 0}
    {"execute": "memsave", "id": 1, "arguments": {"val": 0, "size": 4096, "filename": "fifo1"}}
    {"exec-oob": "migrate-pause", "id": 2}
    {"execute": "memsave", "id": 3, "arguments": {"val": 0, "size": 4096, "filename": "fifo3"}}
    {"exec-oob": "migrate-pause", "id": 4}
    {"execute": "memsave", "id": 5, "arguments": {"val": 0, "size": 4096, "filename": "fifo5"}}
    {"exec-oob": "migrate-pause", "id": 6}
    {"execute": "memsave", "id": 7, "arguments": {"val": 0, "size": 4096, "filename": "fifo7"}}
    {"exec-oob": "migrate-pause", "id": 8}
    {"execute": "memsave", "id": 9, "arguments": {"val": 0, "size": 4096, "filename": "fifo9"}}
    {"exec-oob": "migrate-pause", "id": 10}
    {"execute": "memsave", "id": 11, "arguments": {"val": 0, "size": 4096, "filename": "fifo11"}}
    {"exec-oob": "migrate-pause", "id": 12}
    {"execute": "memsave", "id": 13, "arguments": {"val": 0, "size": 4096, "filename": "fifo13"}}
    {"exec-oob": "migrate-pause", "id": 14}
    {"execute": "memsave", "id": 15, "arguments": {"val": 0, "size": 4096, "filename": "fifo15"}}
    {"exec-oob": "migrate-pause", "id": 16}
    {"execute": "memsave", "id": 17, "arguments": {"val": 0, "size": 4096, "filename": "fifo17"}}
    {"exec-oob": "migrate-pause", "id": 18}
    {"execute": "memsave", "id": 19, "arguments": {"val": 0, "size": 4096, "filename": "fifo19"}}
    {"exec-oob": "migrate-pause", "id": 20}
    $ socat -t99999 STDIO UNIX-CONNECT:$HOME/work/images/test-qmp <oob-test2
    {"QMP": {"version": {"qemu": {"micro": 50, "minor": 1, "major": 5}, "package": "v5.1.0-2224-g8db1efd3f3"}, "capabilities": ["oob"]}}
    {"return": {}}
    {"id": 0, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 2, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 4, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 6, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 8, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 10, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 12, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 14, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}
    {"id": 16, "error": {"class": "GenericError", "desc": "migrate-pause is currently only supported during postcopy-active state"}}

Looking good: the out-of-band commands jump the queue until the queue is
too full for jumping.

Now go back to the first terminal, and hit C-c.

Before this commit, the second terminal shows the shutdown event

    {"timestamp": {"seconds": 1611923623, "microseconds": 528169}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-signal"}}

and the first terminal shows

    ^Cqemu-system-x86_64: terminating on signal 2

QEMU terminates with exit status 0.  Good (except for the exit status,
but let's ignore that).

After the commit, the second terminal additionally shows the error reply
for (in-band) command 1

    {"id": 1, "error": {"class": "GenericError", "desc": "Could not open 'fifo1': Interrupted system call"}}
    {"timestamp": {"seconds": 1611923812, "microseconds": 520891}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-signal"}}

and the first terminal still shows

    ^Cqemu-system-x86_64: terminating on signal 2

However, QEMU does *not* terminate.  When I hit C-c again, the second
terminal gives me the next in-band reply

    {"id": 3, "error": {"class": "GenericError", "desc": "Could not open 'fifo3': Interrupted system call"}}

and the first one another

    ^C

Hitting C-c some more gives me more in-band replies and more ^C.  The
ninth C-c gives me the error reply for (in-band) command 17, and a crash:

Terminal 1 now shows

    ^Cqemu-system-x86_64-qemu: terminating on signal 2
    ^C^C^C^C^C^C^C^Cqemu-system-x86_64-qemu: ../util/async.c:343: aio_ctx_finalize: Assertion `flags & BH_DELETED' failed.
    Aborted (core dumped)

Backtrace:

    #0  0x00007f14931929e5 in raise () at /lib64/libc.so.6
    #1  0x00007f149317b895 in abort () at /lib64/libc.so.6
    #2  0x00007f149317b769 in _nl_load_domain.cold () at /lib64/libc.so.6
    #3  0x00007f149318ae76 in annobin_assert.c_end () at /lib64/libc.so.6
    #4  0x000055b3de710846 in aio_ctx_finalize (source=0x55b3e02d86c0)
        at ../util/async.c:343
    #5  0x00007f1494604d46 in g_source_unref_internal () at /lib64/libglib-2.0.so.0
    #6  0x00007f1494606b92 in g_main_context_unref () at /lib64/libglib-2.0.so.0
    #7  0x00007f1494608d59 in g_main_loop_unref () at /lib64/libglib-2.0.so.0
    #8  0x000055b3de321d14 in iothread_instance_finalize (obj=0x55b3e003f170)
        at ../iothread.c:145
    #9  0x000055b3de57bc65 in object_deinit
        (obj=0x55b3e003f170, type=0x55b3e0081220) at ../qom/object.c:671
    #10 0x000055b3de57bcd7 in object_finalize (data=0x55b3e003f170)
        at ../qom/object.c:685
    #11 0x000055b3de57cc92 in object_unref (objptr=0x55b3e003f170)
        at ../qom/object.c:1183
    #12 0x000055b3de57e277 in object_finalize_child_property
        (obj=0x55b3e02cdad0, name=0x55b3e02d36b0 "mon_iothread", opaque=0x55b3e003f170) at ../qom/object.c:1723
    #13 0x000055b3de57bb59 in object_property_del_child
        (obj=0x55b3e02cdad0, child=0x55b3e003f170) at ../qom/object.c:645
    #14 0x000055b3de57bc34 in object_unparent (obj=0x55b3e003f170)
    --Type <RET> for more, q to quit, c to continue without paging--
        at ../qom/object.c:664
    #15 0x000055b3de32240f in iothread_destroy (iothread=0x55b3e003f170)
        at ../iothread.c:369
    #16 0x000055b3de564db5 in monitor_cleanup () at ../monitor/monitor.c:670
    #17 0x000055b3de5285cc in qemu_cleanup () at ../softmmu/vl.c:4554
    #18 0x000055b3de03b28b in main
        (argc=7, argv=0x7ffc4088d4a8, envp=0x7ffc4088d4e8) at ../softmmu/main.c:51

Any ideas?