19.11.2020 23:31, Vladimir Sementsov-Ogievskiy wrote:
19.11.2020 22:31, Vladimir Sementsov-Ogievskiy wrote:
19.11.2020 22:30, Vladimir Sementsov-Ogievskiy wrote:
19.11.2020 19:11, Vladimir Sementsov-Ogievskiy wrote:
16.11.2020 20:59, Peter Maydell wrote:
On Mon, 16 Nov 2020 at 17:34, Alberto Garcia <berto@igalia.com>
wrote:
Do you know if there is a core dump or stack trace available ?
Nope, sorry. What you get is what the 'vm-build-netbsd' etc targets
produce, so if you want more diagnostics on failures you have to
arrange for the test harness to produce them...
thanks
-- PMM
Hi!
After some iterations I've reproduced on SIGABRT:
#0 0x00007feb701bae35 in raise () at /lib64/libc.so.6
#1 0x00007feb701a5895 in abort () at /lib64/libc.so.6
#2 0x00007feb701a5769 in _nl_load_domain.cold () at /lib64/libc.so.6
#3 0x00007feb701b3566 in annobin_assert.c_end () at /lib64/libc.so.6
#4 0x000055a93374f7d3 in bdrv_replace_child (child=0x55a9363a3a00,
new_bs=0x0) at ../block.c:2648
#5 0x000055a93374fd5a in bdrv_detach_child (child=0x55a9363a3a00)
at ../block.c:2777
#6 0x000055a93374fd9c in bdrv_root_unref_child
(child=0x55a9363a3a00) at ../block.c:2789
#7 0x000055a933722e8b in block_job_remove_all_bdrv
(job=0x55a935f4f4b0) at ../blockjob.c:191
#8 0x000055a933722bb2 in block_job_free (job=0x55a935f4f4b0) at
../blockjob.c:88
#9 0x000055a9337755fa in job_unref (job=0x55a935f4f4b0) at
../job.c:380
#10 0x000055a9337767a6 in job_exit (opaque=0x55a935f4f4b0) at
../job.c:894
#11 0x000055a93386037e in aio_bh_call (bh=0x55a9352e16b0) at
../util/async.c:136
#12 0x000055a933860488 in aio_bh_poll (ctx=0x55a9351366f0) at
../util/async.c:164
#13 0x000055a93383151e in aio_dispatch (ctx=0x55a9351366f0) at
../util/aio-posix.c:381
#14 0x000055a9338608b9 in aio_ctx_dispatch (source=0x55a9351366f0,
callback=0x0, user_data=0x0)
at ../util/async.c:306
#15 0x00007feb71349ecd in g_main_context_dispatch () at
/lib64/libglib-2.0.so.0
#16 0x000055a933840300 in glib_pollfds_poll () at
../util/main-loop.c:221
#17 0x000055a93384037a in os_host_main_loop_wait (timeout=0) at
../util/main-loop.c:244
#18 0x000055a933840482 in main_loop_wait (nonblocking=0) at
../util/main-loop.c:520
#19 0x000055a933603979 in qemu_main_loop () at ../softmmu/vl.c:1678
#20 0x000055a933190046 in main (argc=20, argv=0x7ffd48c31138,
envp=0x7ffd48c311e0)
(gdb) fr 4
#4 0x000055a93374f7d3 in bdrv_replace_child (child=0x55a9363a3a00,
new_bs=0x0) at ../block.c:2648
2648 assert(tighten_restrictions == false);
(gdb) list
2643 int ret;
2644
2645 bdrv_get_cumulative_perm(old_bs, &perm, &shared_perm);
2646 ret = bdrv_check_perm(old_bs, NULL, perm,
shared_perm, NULL,
2647 &tighten_restrictions, NULL);
2648 assert(tighten_restrictions == false);
2649 if (ret < 0) {
2650 /* We only tried to loosen restrictions, so
errors are not fatal */
2651 bdrv_abort_perm_update(old_bs);
2652 } else {
(gdb) p tighten_restrictions
$1 = true
I've modified code a bit, to crash when we actually want to set
tighten_restrictions to true, and get the following bt:
#0 0x00007f6dbb49ee35 in raise () at /lib64/libc.so.6
#1 0x00007f6dbb489895 in abort () at /lib64/libc.so.6
#2 0x000055b9174104d7 in bdrv_check_perm
(bs=0x55b918f09720, q=0x0, cumulative_perms=1,
cumulative_shared_perms=21, ignore_children=0x55b918a57b20 = {...},
tighten_restrictions=0x55b917b044f8 <abort_on_set_to_true>,
errp=0x0) at ../block.c:2009
#3 0x000055b917410ec0 in bdrv_check_update_perm
(bs=0x55b918f09720, q=0x0, new_used_perm=1, new_shared_perm=21,
ignore_children=0x55b918a57b20 = {...},
tighten_restrictions=0x55b917b044f8 <abort_on_set_to_true>,
errp=0x0) at ../block.c:2280
#4 0x000055b917410f38 in bdrv_child_check_perm
(c=0x55b91921fcf0, q=0x0, perm=1, shared=21,
ignore_children=0x55b918a57b20 = {...},
tighten_restrictions=0x55b917b044f8 <abort_on_set_to_true>,
errp=0x0) at ../block.c:2294
#5 0x000055b91741078c in bdrv_check_perm
(bs=0x55b918defd90, q=0x0, cumulative_perms=1,
cumulative_shared_perms=21, ignore_children=0x0,
tighten_restrictions=0x55b917b044f8 <abort_on_set_to_true>,
errp=0x0) at ../block.c:2076
#6 0x000055b91741194e in bdrv_replace_child (child=0x55b919cf6200,
new_bs=0x0) at ../block.c:2666
#7 0x000055b917411f1d in bdrv_detach_child (child=0x55b919cf6200)
at ../block.c:2798
#8 0x000055b917411f5f in bdrv_root_unref_child
(child=0x55b919cf6200) at ../block.c:2810
#9 0x000055b9173e4d88 in block_job_remove_all_bdrv
(job=0x55b918f06a60) at ../blockjob.c:191
#10 0x000055b9173e4aaf in block_job_free (job=0x55b918f06a60) at
../blockjob.c:88
#11 0x000055b917437aca in job_unref (job=0x55b918f06a60) at
../job.c:380
#12 0x000055b917438c76 in job_exit (opaque=0x55b918f06a60) at
../job.c:894
#13 0x000055b917522a57 in aio_bh_call (bh=0x55b919a2b3b0) at
../util/async.c:136
#14 0x000055b917522b61 in aio_bh_poll (ctx=0x55b918a866f0) at
../util/async.c:164
#15 0x000055b9174f3bf7 in aio_dispatch (ctx=0x55b918a866f0) at
../util/aio-posix.c:381
#16 0x000055b917522f92 in aio_ctx_dispatch (source=0x55b918a866f0,
callback=0x0, user_data=0x0)
at ../util/async.c:306
#17 0x00007f6dbc62decd in g_main_context_dispatch () at
/lib64/libglib-2.0.so.0
#18 0x000055b9175029d9 in glib_pollfds_poll () at
../util/main-loop.c:221
#19 0x000055b917502a53 in os_host_main_loop_wait (timeout=0) at
../util/main-loop.c:244
#20 0x000055b917502b5b in main_loop_wait (nonblocking=0) at
../util/main-loop.c:520
#21 0x000055b9172c5979 in qemu_main_loop () at ../softmmu/vl.c:1678
#22 0x000055b916e52046 in main (argc=20, argv=0x7fff7f81f208,
envp=0x7fff7f81f2b0)
and the picture taken at the moment of abort (and it is the same as
at the moment before bdrv_replace_child call) is attached. So, it
looks like graph is already corrupted (you see that backing
permissions are not propagated to node2-node0 child).
How graph was corrupted it's still the question..
additional info: it's all during test_stream_commit_1 in 30 iiotest
OK, after some debugging and looking at block-graph dumps I tend to
think that this a race between finish (.prepare) of mirror and
block-stream. They do graph updates. Nothing prevents interleaving of
graph-updating operations (note that bdrv_replace_child_noperm may do
aio_poll). And nothing protects two processes of graph-update from
intersection.
Any ideas?
Wow, I get the following:
#0 0x00007fa84bcf97b6 in ppoll () at /lib64/libc.so.6
#1 0x000055b33e46321b in qemu_poll_ns (fds=0x55b340d28b60, nfds=1,
timeout=600000000000) at ../util/qemu-timer.c:349
#2 0x000055b33e495c33 in fdmon_poll_wait (ctx=0x55b340d026f0,
ready_list=0x7ffcc0af5f30, timeout=600000000000) at ../util/fdmon-poll.c:80
#3 0x000055b33e4575b0 in aio_poll (ctx=0x55b340d026f0, blocking=true)
at ../util/aio-posix.c:607
#4 0x000055b33e302c41 in mirror_exit_common (job=0x55b341e94d20) at
../block/mirror.c:648
#5 0x000055b33e3031e3 in mirror_prepare (job=0x55b341e94d20) at
../block/mirror.c:776
#6 0x000055b33e39ba6b in job_prepare (job=0x55b341e94d20) at ../job.c:781
#7 0x000055b33e39a31f in job_txn_apply (job=0x55b341e94d20,
fn=0x55b33e39ba2e <job_prepare>) at ../job.c:158
#8 0x000055b33e39baf4 in job_do_finalize (job=0x55b341e94d20) at
../job.c:798
#9 0x000055b33e39bcbb in job_completed_txn_success (job=0x55b341e94d20)
at ../job.c:852
#10 0x000055b33e39bd5b in job_completed (job=0x55b341e94d20) at
../job.c:865
#11 0x000055b33e39bdae in job_exit (opaque=0x55b341e94d20) at ../job.c:885
#12 0x000055b33e485cfc in aio_bh_call (bh=0x7fa830004100) at
../util/async.c:136
#13 0x000055b33e485e06 in aio_bh_poll (ctx=0x55b340d026f0) at
../util/async.c:164
#14 0x000055b33e4577a3 in aio_poll (ctx=0x55b340d026f0, blocking=true)
at ../util/aio-posix.c:659
#15 0x000055b33e2fa4d9 in bdrv_poll_co (s=0x7ffcc0af62e0) at
/work/src/qemu/master/block/block-gen.h:44
#16 0x000055b33e2faff4 in bdrv_pwritev (child=0x55b340ed0f60, offset=0,
bytes=65536, qiov=0x7ffcc0af6370, flags=0) at block/block-gen.c:408
#17 0x000055b33e34be9b in bdrv_pwrite (child=0x55b340ed0f60, offset=0,
buf=0x55b341d10000, bytes=65536) at ../block/io.c:984
#18 0x000055b33e386c6f in qcow2_update_header (bs=0x55b341023020) at
../block/qcow2.c:3037
#19 0x000055b33e386e53 in qcow2_change_backing_file (bs=0x55b341023020,
backing_file=0x55b341bf3c80 "/ramdisk/xx/img-0.img",
backing_fmt=0x55b33e613afc "raw") at ../block/qcow2.c:3074
#20 0x000055b33e379908 in bdrv_change_backing_file (bs=0x55b341023020,
backing_file=0x55b341bf3c80 "/ramdisk/xx/img-0.img",
backing_fmt=0x55b33e613afc "raw", warn=false) at ../block.c:4768
#21 0x000055b33e3b2377 in stream_prepare (job=0x55b341030620) at
../block/stream.c:88
#22 0x000055b33e39ba6b in job_prepare (job=0x55b341030620) at ../job.c:781
#23 0x000055b33e39a31f in job_txn_apply (job=0x55b341030620,
fn=0x55b33e39ba2e <job_prepare>) at ../job.c:158
#24 0x000055b33e39baf4 in job_do_finalize (job=0x55b341030620) at
../job.c:798
#25 0x000055b33e39bcbb in job_completed_txn_success (job=0x55b341030620)
at ../job.c:852
#26 0x000055b33e39bd5b in job_completed (job=0x55b341030620) at
../job.c:865
#27 0x000055b33e39bdae in job_exit (opaque=0x55b341030620) at ../job.c:885
#28 0x000055b33e485cfc in aio_bh_call (bh=0x55b340ead840) at
../util/async.c:136
#29 0x000055b33e485e06 in aio_bh_poll (ctx=0x55b340d026f0) at
../util/async.c:164
#30 0x000055b33e456e9c in aio_dispatch (ctx=0x55b340d026f0) at
../util/aio-posix.c:381
#31 0x000055b33e486237 in aio_ctx_dispatch (source=0x55b340d026f0,
callback=0x0, user_data=0x0) at ../util/async.c:306
#32 0x00007fa84cdceecd in g_main_context_dispatch () at
/lib64/libglib-2.0.so.0
#33 0x000055b33e465c7e in glib_pollfds_poll () at ../util/main-loop.c:221
#34 0x000055b33e465cf8 in os_host_main_loop_wait (timeout=0) at
../util/main-loop.c:244
#35 0x000055b33e465e00 in main_loop_wait (nonblocking=0) at
../util/main-loop.c:520
#36 0x000055b33e228979 in qemu_main_loop () at ../softmmu/vl.c:1678
#37 0x000055b33ddb5046 in main (argc=20, argv=0x7ffcc0af6a88,
envp=0x7ffcc0af6b30) at ../softmmu/main.c:50
aio_poll at start of mirror_exit_common is my addition. But anyway the
problem is here: we do call mirror_prepare inside of stream_prepare!
----
Ok, moving further, I moved stream_clean, stream_prepare,
mirror_exit_common and mirror_complete into coroutine context and
protect them all by new global coroutine mutex. This helps, now the bug
doesn't reproduce.
Still, I'll try to finally understand, what's going on. But I think now
that:
- graph modification code (permissions, drains, child-replacements, etc)
are not safe to call in parallel, for example in different coroutines or
through nested aio_poll.
- but they all do different kinds of drains, io operations, etc, which
lead to nested aio polls and everything is broken