On 7/22/21 10:12 AM, Philippe Mathieu-Daudé wrote:
> On 7/22/21 9:49 AM, Claudio Fontana wrote:
>> Hi all,
>>
>> I see a strange effect on master, with
>>
>> cd build
>> ../configure --enable-kvm --enable-debug --enable-tcg
>> --target-list=x86_64-softmmu
>> make -j
>>
>> make -j check
>> ...
>>
>> Not run: 220 287
>> Passed all 121 iotests
>> [buzzes here]
>>
>>
>> ps -a
>> PID TTY TIME CMD
>> 3609 pts/0 00:00:00 make
>> 4196 pts/0 00:00:00 bash
>> 4212 pts/0 00:00:00 qos-test
>> 4215 pts/0 00:00:00 perl
>> 9025 pts/0 00:00:00 qemu-storage-da
>> 9027 pts/0 00:00:00 qemu-system-x86
>> 11293 pts/3 00:00:00 ps
>>
>> /proc/4196/cmdline:
>> bash -o pipefail -c echo 'Running test qtest-x86_64/qos-test' &&
>> MALLOC_PERTURB_=${MALLOC_PERTURB_:-$(( ${RANDOM:-0} % 255 + 1))}
>> QTEST_QEMU_IMG=./qemu-img
>> G_TEST_DBUS_DAEMON=/home/claudio/git/qemu-pristine/qemu/tests/dbus-vmstate-daemon.sh
>> QTEST_QEMU_BINARY=./qemu-system-x86_64
>> QTEST_QEMU_STORAGE_DAEMON_BINARY=./storage-daemon/qemu-storage-daemon
>> tests/qtest/qos-test --tap -k -m quick < /dev/null | ./scripts/tap-driver.pl
>> --test-name="qtest-x86_64/qos-test" --show-failures-only
>> gstack 4196
>> #0 0x00007f66624e32ba in waitpid () from /lib64/libc.so.6
>> #1 0x000056036f401bd6 in ?? ()
>> #2 0x000056036f404416 in wait_for ()
>> #3 0x000056036f3c8cf3 in execute_command_internal ()
>> #4 0x000056036f3cb108 in ?? ()
>> #5 0x000056036f375a83 in ?? ()
>> #6 0x000056036f3c95a1 in execute_command ()
>> #7 0x000056036f376484 in ?? ()
>> #8 0x000056036f3ee706 in parse_and_execute ()
>> #9 0x000056036f3f86f5 in ?? ()
>> #10 0x000056036f3bd696 in main ()
>>
>> /proc/4212/cmdline:
>> tests/qtest/qos-test --tap -k -m quick
>> gstack 4212
>>
>> Thread 2 (Thread 0x7f247fe03700 (LWP 4886)):
>> #0 0x00007f24818cf839 in syscall () from /lib64/libc.so.6
>> #1 0x00005617895e6c85 in qemu_futex_wait (f=0x561789663398
>> <rcu_call_ready_event>, val=4294967295) at
>> /home/claudio/git/qemu-pristine/qemu/include/qemu/futex.h:29
>> #2 0x00005617895e6e4c in qemu_event_wait (ev=0x561789663398
>> <rcu_call_ready_event>) at ../util/qemu-thread-posix.c:480
>> #3 0x00005617895c3824 in call_rcu_thread (opaque=0x0) at ../util/rcu.c:258
>> #4 0x00005617895e7006 in qemu_thread_start (args=0x56178a168420) at
>> ../util/qemu-thread-posix.c:541
>> #5 0x00007f2481b9c4f9 in start_thread () from /lib64/libpthread.so.0
>> #6 0x00007f24818d4fbf in clone () from /lib64/libc.so.6
>> Thread 1 (Thread 0x7f24830ddf40 (LWP 4212)):
>> #0 0x00007f2481ba5e88 in read () from /lib64/libpthread.so.0
>> #1 0x00005617895494e8 in qtest_client_socket_recv_line (s=0x56178a1cde00)
>> at ../tests/qtest/libqtest.c:494
>> #2 0x0000561789549664 in qtest_rsp_args (s=0x56178a1cde00, expected_args=1)
>> at ../tests/qtest/libqtest.c:521
>> #3 0x00005617895499f4 in qtest_query_target_endianness (s=0x56178a1cde00)
>> at ../tests/qtest/libqtest.c:570
>> #4 0x0000561789548b72 in qtest_init_without_qmp_handshake
>> (extra_args=0x56178a19e2f0 "-M pc -device
>> vhost-user-blk-pci,id=drv0,chardev=char1,addr=4.0 -object
>> memory-backend-memfd,id=mem,size=256M,share=on -M memory-backend=mem -m
>> 256M -chardev socket,id=char1,path=/tmp/qtest-4212-soc"...) at
>> ../tests/qtest/libqtest.c:332
>> #5 0x0000561789548ba1 in qtest_init (extra_args=0x56178a19e2f0 "-M pc
>> -device vhost-user-blk-pci,id=drv0,chardev=char1,addr=4.0 -object
>> memory-backend-memfd,id=mem,size=256M,share=on -M memory-backend=mem -m
>> 256M -chardev socket,id=char1,path=/tmp/qtest-4212-soc"...) at
>> ../tests/qtest/libqtest.c:339
>> #6 0x000056178952afb8 in qtest_start (args=0x56178a19e2f0 "-M pc -device
>> vhost-user-blk-pci,id=drv0,chardev=char1,addr=4.0 -object
>> memory-backend-memfd,id=mem,size=256M,share=on -M memory-backend=mem -m
>> 256M -chardev socket,id=char1,path=/tmp/qtest-4212-soc"...) at
>> ../tests/qtest/libqtest-single.h:29
>> #7 0x000056178952b33c in restart_qemu_or_continue (path=0x56178a19e2f0 "-M
>> pc -device vhost-user-blk-pci,id=drv0,chardev=char1,addr=4.0 -object
>> memory-backend-memfd,id=mem,size=256M,share=on -M memory-backend=mem -m
>> 256M -chardev socket,id=char1,path=/tmp/qtest-4212-soc"...) at
>> ../tests/qtest/qos-test.c:105
>> #8 0x000056178952b4a1 in run_one_test (arg=0x56178a1d7400) at
>> ../tests/qtest/qos-test.c:178
>> #9 0x00007f2482a3a826 in ?? () from /usr/lib64/libglib-2.0.so.0
>> #10 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #11 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #12 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #13 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #14 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #15 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #16 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #17 0x00007f2482a3a73b in ?? () from /usr/lib64/libglib-2.0.so.0
>> #18 0x00007f2482a3ace2 in g_test_run_suite () from
>> /usr/lib64/libglib-2.0.so.0
>> #19 0x00007f2482a3ad01 in g_test_run () from /usr/lib64/libglib-2.0.so.0
>> #20 0x000056178952b9cb in main (argc=1, argv=0x7ffed7147028,
>> envp=0x7ffed7147058) at ../tests/qtest/qos-test.c:338
>>
>> /proc/4215/cmdline:
>> perl ./scripts/tap-driver.pl --test-name=qtest-x86_64/qos-test
>> --show-failures-only
>> gstack 4215
>>
>> #0 0x00007f411d4c8e51 in read () from /lib64/libpthread.so.0
>> #1 0x000056173781a78d in PerlIOUnix_read ()
>> #2 0x000056173781dbc8 in PerlIOBuf_fill ()
>> #3 0x000056173781c2c8 in Perl_PerlIO_fill ()
>> #4 0x000056173781dac0 in PerlIOBase_read ()
>> #5 0x000056173781fa98 in PerlIO_getc ()
>> #6 0x00005617377b5575 in Perl_sv_gets ()
>> #7 0x00005617377929d8 in Perl_do_readline ()
>> #8 0x000056173778d8e6 in Perl_runops_standard ()
>> #9 0x000056173770e7d7 in perl_run ()
>> #10 0x00005617376e5ef2 in main ()
>>
>> /proc/9027/cmdline:
>> ./qemu-system-x86_64 -qtest unix:/tmp/qtest-4212.sock -qtest-log /dev/null
>> -chardev socket,path=/tmp/qtest-4212.qmp,id=char0 -mon
>> chardev=char0,mode=control -display none -M pc -device
>> vhost-user-blk-pci,id=drv0,chardev=char1,addr=4.0 -object
>> memory-backend-memfd,id=mem,size=256M,share=on -M memory-backend=mem -m 256M
>> -chardev socket,id=char1,path=/tmp/qtest-4212-sock.leKGw1 -accel qtest
>> gstack 9027
>>
>> Thread 4 (Thread 0x7fced5d8f700 (LWP 9055)):
>> #0 0x00007fceeef55dcf in do_sigwait () at /lib64/libpthread.so.0
>> #1 0x00007fceeef55e5d in sigwait () at /lib64/libpthread.so.0
>> #2 0x000055ba630ed5b7 in dummy_cpu_thread_fn (arg=0x55ba64830600) at
>> ../accel/dummy-cpus.c:46
>> #3 0x000055ba63333c1a in qemu_thread_start (args=0x55ba6483d7a0) at
>> ../util/qemu-thread-posix.c:541
>> #4 0x00007fceeef4b4f9 in start_thread () at /lib64/libpthread.so.0
>> #5 0x00007fceeec83fbf in clone () at /lib64/libc.so.6
>> Thread 3 (Thread 0x7fced6772700 (LWP 9052)):
>> #0 0x00007fceeec796db in poll () at /lib64/libc.so.6
>> #1 0x00007fcef5455779 in () at /usr/lib64/libglib-2.0.so.0
>> #2 0x00007fcef5455ac2 in g_main_loop_run () at /usr/lib64/libglib-2.0.so.0
>> #3 0x000055ba6319e03f in iothread_run (opaque=0x55ba64496be0) at
>> ../iothread.c:73
>> #4 0x000055ba63333c1a in qemu_thread_start (args=0x55ba6476f2f0) at
>> ../util/qemu-thread-posix.c:541
>> #5 0x00007fceeef4b4f9 in start_thread () at /lib64/libpthread.so.0
>> #6 0x00007fceeec83fbf in clone () at /lib64/libc.so.6
>> Thread 2 (Thread 0x7fced7074700 (LWP 9038)):
>> #0 0x00007fceeef54c3d in __lll_lock_wait () at /lib64/libpthread.so.0
>> #1 0x00007fceeef578a7 in __lll_lock_elision () at /lib64/libpthread.so.0
>> #2 0x000055ba63332ffb in qemu_mutex_lock_impl (mutex=0x55ba63bb6600
>> <qemu_global_mutex>, file=0x55ba63772a1b "../util/rcu.c", line=266) at
>> ../util/qemu-thread-posix.c:79
>> #3 0x000055ba631094f1 in qemu_mutex_lock_iothread_impl (file=0x55ba63772a1b
>> "../util/rcu.c", line=266) at ../softmmu/cpus.c:493
>> #4 0x000055ba63303c92 in call_rcu_thread (opaque=0x0) at ../util/rcu.c:266
>> #5 0x000055ba63333c1a in qemu_thread_start (args=0x55ba644ce520) at
>> ../util/qemu-thread-posix.c:541
>> #6 0x00007fceeef4b4f9 in start_thread () at /lib64/libpthread.so.0
>> #7 0x00007fceeec83fbf in clone () at /lib64/libc.so.6
>> Thread 1 (Thread 0x7fcef7bee140 (LWP 9027)):
>> #0 0x00007fceeec796db in poll () at /lib64/libc.so.6
>> #1 0x00007fcef5455779 in () at /usr/lib64/libglib-2.0.so.0
>> #2 0x00007fcef5455ac2 in g_main_loop_run () at /usr/lib64/libglib-2.0.so.0
>> #3 0x000055ba62fffe2f in vhost_user_read (dev=0x55ba655b3330,
>> msg=0x7fff63510230) at ../hw/virtio/vhost-user.c:402
>> #4 0x000055ba63002512 in vhost_user_get_u64 (dev=0x55ba655b3330, request=1,
>> u64=0x7fff63510518) at ../hw/virtio/vhost-user.c:1334
>> #5 0x000055ba630025c7 in vhost_user_get_features (dev=0x55ba655b3330,
>> features=0x7fff63510518) at ../hw/virtio/vhost-user.c:1356
>> #6 0x000055ba63003b48 in vhost_user_backend_init (dev=0x55ba655b3330,
>> opaque=0x55ba655b35b0, errp=0x7fff635106d0) at ../hw/virtio/vhost-user.c:1877
>> #7 0x000055ba63037c2e in vhost_dev_init (hdev=0x55ba655b3330,
>> opaque=0x55ba655b35b0, backend_type=VHOST_BACKEND_TYPE_USER,
>> busyloop_timeout=0, errp=0x7fff635106d0) at ../hw/virtio/vhost.c:1302
>> #8 0x000055ba630dca97 in vhost_user_blk_connect (dev=0x55ba655b30e0,
>> errp=0x7fff635106d0) at ../hw/block/vhost-user-blk.c:339
>> #9 0x000055ba630dcd86 in vhost_user_blk_realize_connect (s=0x55ba655b30e0,
>> errp=0x7fff635106d0) at ../hw/block/vhost-user-blk.c:440
>> #10 0x000055ba630dd195 in vhost_user_blk_device_realize (dev=0x55ba655b30e0,
>> errp=0x7fff635106d0) at ../hw/block/vhost-user-blk.c:513
>> #11 0x000055ba63026405 in virtio_device_realize (dev=0x55ba655b30e0,
>> errp=0x7fff63510730) at ../hw/virtio/virtio.c:3659
>> #12 0x000055ba631845f5 in device_set_realized (obj=0x55ba655b30e0,
>> value=true, errp=0x7fff63510838) at ../hw/core/qdev.c:761
>> #13 0x000055ba6316fed8 in property_set_bool (obj=0x55ba655b30e0,
>> v=0x55ba655fed80, name=0x55ba634f3051 "realized", opaque=0x55ba6453a7e0,
>> errp=0x7fff63510838) at ../qom/object.c:2257
>> #14 0x000055ba6316dfe7 in object_property_set (obj=0x55ba655b30e0,
>> name=0x55ba634f3051 "realized", v=0x55ba655fed80, errp=0x7fff635109b8) at
>> ../qom/object.c:1402
>> #15 0x000055ba6316ab20 in object_property_set_qobject (obj=0x55ba655b30e0,
>> name=0x55ba634f3051 "realized", value=0x55ba655fecc0, errp=0x7fff635109b8)
>> at ../qom/qom-qobject.c:28
>> #16 0x000055ba6316e34d in object_property_set_bool (obj=0x55ba655b30e0,
>> name=0x55ba634f3051 "realized", value=true, errp=0x7fff635109b8) at
>> ../qom/object.c:1472
>> #17 0x000055ba6318367b in qdev_realize (dev=0x55ba655b30e0,
>> bus=0x55ba655b3058, errp=0x7fff635109b8) at ../hw/core/qdev.c:389
>> #18 0x000055ba630332f7 in vhost_user_blk_pci_realize
>> (vpci_dev=0x55ba655aae60, errp=0x7fff635109b8) at
>> ../hw/virtio/vhost-user-blk-pci.c:66
>> #19 0x000055ba62e0f8a0 in virtio_pci_realize (pci_dev=0x55ba655aae60,
>> errp=0x7fff635109b8) at ../hw/virtio/virtio-pci.c:1907
>> #20 0x000055ba62dd16ec in pci_qdev_realize (qdev=0x55ba655aae60,
>> errp=0x7fff63510a70) at ../hw/pci/pci.c:2148
>> #21 0x000055ba62e0fc44 in virtio_pci_dc_realize (qdev=0x55ba655aae60,
>> errp=0x7fff63510a70) at ../hw/virtio/virtio-pci.c:1992
>> #22 0x000055ba631845f5 in device_set_realized (obj=0x55ba655aae60,
>> value=true, errp=0x7fff63510b78) at ../hw/core/qdev.c:761
>> #23 0x000055ba6316fed8 in property_set_bool (obj=0x55ba655aae60,
>> v=0x55ba655f86f0, name=0x55ba634f3051 "realized", opaque=0x55ba6453a7e0,
>> errp=0x7fff63510b78) at ../qom/object.c:2257
>> #24 0x000055ba6316dfe7 in object_property_set (obj=0x55ba655aae60,
>> name=0x55ba634f3051 "realized", v=0x55ba655f86f0, errp=0x55ba63bba880
>> <error_fatal>) at ../qom/object.c:1402
>> #25 0x000055ba6316ab20 in object_property_set_qobject (obj=0x55ba655aae60,
>> name=0x55ba634f3051 "realized", value=0x55ba655f86b0, errp=0x55ba63bba880
>> <error_fatal>) at ../qom/qom-qobject.c:28
>> #26 0x000055ba6316e34d in object_property_set_bool (obj=0x55ba655aae60,
>> name=0x55ba634f3051 "realized", value=true, errp=0x55ba63bba880
>> <error_fatal>) at ../qom/object.c:1472
>> #27 0x000055ba6318367b in qdev_realize (dev=0x55ba655aae60,
>> bus=0x55ba649a5000, errp=0x55ba63bba880 <error_fatal>) at
>> ../hw/core/qdev.c:389
>> #28 0x000055ba62f0353b in qdev_device_add (opts=0x55ba645370e0,
>> errp=0x55ba63bba880 <error_fatal>) at ../softmmu/qdev-monitor.c:673
>> #29 0x000055ba62fe4aa2 in device_init_func (opaque=0x0, opts=0x55ba645370e0,
>> errp=0x55ba63bba880 <error_fatal>) at ../softmmu/vl.c:1185
>> #30 0x000055ba63311904 in qemu_opts_foreach (list=0x55ba63ad6280
>> <qemu_device_opts>, func=0x55ba62fe4a7b <device_init_func>, opaque=0x0,
>> errp=0x55ba63bba880 <error_fatal>) at ../util/qemu-option.c:1135
>> #31 0x000055ba62fe82e2 in qemu_create_cli_devices () at ../softmmu/vl.c:2624
>> #32 0x000055ba62fe8406 in qmp_x_exit_preconfig (errp=0x55ba63bba880
>> <error_fatal>) at ../softmmu/vl.c:2672
>> #33 0x000055ba62feaa89 in qemu_init (argc=25, argv=0x7fff63511008,
>> envp=0x7fff635110d8) at ../softmmu/vl.c:3692
>> #34 0x000055ba62bf0ae2 in main (argc=25, argv=0x7fff63511008,
>> envp=0x7fff635110d8) at ../softmmu/main.c:49
>>
>>
>> /proc/9025/cmdline:
>> ./storage-daemon/qemu-storage-daemon --blockdev
>> driver=file,node-name=disk0,filename=qtest.X95rzW --export
>> type=vhost-user-blk,id=disk0,addr.type=unix,addr.path=/tmp/qtest-4212-sock.leKGw1,node-name=disk0,writable=on,num-queues=1
>> gstack 9025
>>
>> Thread 2 (Thread 0x7f1df77a5700 (LWP 9029)):
>> #0 0x00007f1e06d03839 in syscall () from /lib64/libc.so.6
>> #1 0x000055d5bd350f93 in qemu_futex_wait (f=0x55d5bd4737f8
>> <rcu_call_ready_event>, val=4294967295) at
>> /home/claudio/git/qemu-pristine/qemu/include/qemu/futex.h:29
>> #2 0x000055d5bd35115a in qemu_event_wait (ev=0x55d5bd4737f8
>> <rcu_call_ready_event>) at ../util/qemu-thread-posix.c:480
>> #3 0x000055d5bd325617 in call_rcu_thread (opaque=0x0) at ../util/rcu.c:258
>> #4 0x000055d5bd351314 in qemu_thread_start (args=0x55d5bf4a4270) at
>> ../util/qemu-thread-posix.c:541
>> #5 0x00007f1e06fd04f9 in start_thread () from /lib64/libpthread.so.0
>> #6 0x00007f1e06d08fbf in clone () from /lib64/libc.so.6
>> Thread 1 (Thread 0x7f1e0a367e80 (LWP 9025)):
>> #0 0x00007f1e06cfe7d6 in ppoll () from /lib64/libc.so.6
>> #1 0x000055d5bd33c593 in qemu_poll_ns (fds=0x55d5bf4aa6c0, nfds=5,
>> timeout=-1) at ../util/qemu-timer.c:336
>> #2 0x000055d5bd343abb in os_host_main_loop_wait (timeout=-1) at
>> ../util/main-loop.c:250
>> #3 0x000055d5bd343be1 in main_loop_wait (nonblocking=0) at
>> ../util/main-loop.c:531
>> #4 0x000055d5bd1bda5c in main (argc=5, argv=0x7ffcbaf84a28) at
>> ../storage-daemon/qemu-storage-daemon.c:345
>>
>> Any idea what could be up?
>
> Seems similar to this one:
> https://www.mail-archive.com/qemu-devel@nongnu.org/msg822994.html
>
Yes, seems very similar to me.
Will add a link to this in that thread, thanks!
Seems it reproduces easily for me..
Claudio
