From: "Michael S. Tsirkin" <mst@redhat.com>
To: Peter Maydell <peter.maydell@linaro.org>
Cc: Kevin Wolf <kwolf@redhat.com>,
QEMU Developers <qemu-devel@nongnu.org>,
Raphael Norwitz <raphael.norwitz@nutanix.com>,
Stefan Hajnoczi <stefanha@redhat.com>,
Paolo Bonzini <pbonzini@redhat.com>,
Max Reitz <mreitz@redhat.com>, Eric Blake <eblake@redhat.com>,
Stefano Garzarella <sgarzare@redhat.com>
Subject: Re: intermittent failure, s390 host, x86-64 guest, vhost-user-blk test
Date: Wed, 4 Aug 2021 09:43:25 -0400 [thread overview]
Message-ID: <20210804094231-mutt-send-email-mst@kernel.org> (raw)
In-Reply-To: <CAFEAcA-QcwjGtgzqkLshyU4NCq2ZhhdvJN3V_7rTCA4nUavhaQ@mail.gmail.com>
On Wed, Aug 04, 2021 at 01:40:37PM +0100, Peter Maydell wrote:
> Saw this intermittent as part of my ad-hoc CI test setup.
> The backtrace says that the QEMU process has somehow hung
> during 'realize' of the vhost-user device...
Hmm seems to have to do with the daemon not responding ...
Cc a bunch more people ...
> Process tree:
>
> ubuntu 59552 0.0 0.0 5460 3120 ? S 06:51 0:00
> \_ bash -o pipefail -c echo
> 'MALLOC_PERTURB_=${MALLOC_PERTURB_:-$(( ${RANDOM:-0} % 255 + 1))}
> QTEST_QEMU_IMG=./qemu-img
> G_TEST_DBUS_DAEMON=/home/ubuntu/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' &&
> MALLOC_PERTURB_=${MALLOC_PERTURB_:-$(( ${RANDOM:-0} % 255 + 1))}
> QTEST_QEMU_IMG=./qemu-img
> G_TEST_DBUS_DAEMON=/home/ubuntu/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"
> ubuntu 59553 0.0 0.2 88008 8332 ? Sl 06:51 0:00
> \_ tests/qtest/qos-test --tap -k -m quick
> ubuntu 60122 0.0 0.5 254432 21516 ? Sl 06:51 0:00
> | \_ ./storage-daemon/qemu-storage-daemon --blockdev
> driver=file,node-name=disk0,filename=qtest.trJnuR --export
> type=vhost-user-blk,id=disk0,addr.type=unix,addr.path=/tmp/qtest-59553-sock.iRt6WL,node-name=disk0,writable=on,num-queues=1
> ubuntu 60123 0.0 1.6 747952 62732 ? Sl 06:51 0:00
> | \_ ./qemu-system-x86_64 -qtest
> unix:/tmp/qtest-59553.sock -qtest-log /dev/null -chardev
> socket,path=/tmp/qtest-59553.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-59553-sock.iRt6WL
> -accel qtest
> ubuntu 59554 0.0 0.2 14116 11204 ? S 06:51 0:00
> \_ perl ./scripts/tap-driver.pl
> --test-name=qtest-x86_64/qos-test
>
> Backtrace, qemu process:
>
> Thread 4 (Thread 0x3ff5be1d910 (LWP 60131)):
> #0 0x000003ff7e2bed6a in __GI___sigtimedwait (set=<optimized out>,
> set@entry=0x3ff5be1a098, info=info@entry=0x3ff5be19f68,
> timeout=timeout@entry=0x0)
> at ../sysdeps/unix/sysv/linux/sigtimedwait.c:42
> #1 0x000003ff7e492ca8 in __sigwait (set=set@entry=0x3ff5be1a098,
> sig=sig@entry=0x3ff5be1a094)
> at ../sysdeps/unix/sysv/linux/sigwait.c:28
> #2 0x000002aa16891ab2 in dummy_cpu_thread_fn
> (arg=arg@entry=0x2aa182103e0) at ../../accel/dummy-cpus.c:46
> #3 0x000002aa16b22f5a in qemu_thread_start (args=<optimized out>) at
> ../../util/qemu-thread-posix.c:541
> #4 0x000003ff7e487aa8 in start_thread (arg=0x3ff5be1d910) at
> pthread_create.c:463
> #5 0x000003ff7e37a11e in thread_start () at
> ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
>
> Thread 3 (Thread 0x3ff608b4910 (LWP 60130)):
> #0 0x000003ff7e36f1b0 in __GI___poll (fds=0x3ff540031f0, nfds=3,
> timeout=<optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:29
> #1 0x000003ff7f9d2624 in () at /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #2 0x000003ff7f9d2aa8 in g_main_loop_run () at
> /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #3 0x000002aa1695ad26 in iothread_run
> (opaque=opaque@entry=0x2aa17ea2b80) at ../../iothread.c:73
> #4 0x000002aa16b22f5a in qemu_thread_start (args=<optimized out>) at
> ../../util/qemu-thread-posix.c:541
> #5 0x000003ff7e487aa8 in start_thread (arg=0x3ff608b4910) at
> pthread_create.c:463
> #6 0x000003ff7e37a11e in thread_start () at
> ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
>
> Thread 2 (Thread 0x3ff711b7910 (LWP 60129)):
> #0 0x000003ff7e4911f6 in __lll_lock_wait
> (futex=futex@entry=0x2aa17466bb8 <qemu_global_mutex>,
> private=<optimized out>)
> at lowlevellock.c:46
> #1 0x000003ff7e48a204 in __GI___pthread_mutex_lock
> (mutex=mutex@entry=0x2aa17466bb8 <qemu_global_mutex>)
> at ../nptl/pthread_mutex_lock.c:80
> #2 0x000002aa16b23116 in qemu_mutex_lock_impl (mutex=0x2aa17466bb8
> <qemu_global_mutex>, file=0x2aa170a07d8 "../../util/rcu.c",
> line=<optimized out>) at ../../util/qemu-thread-posix.c:79
> #3 0x000002aa168221c0 in qemu_mutex_lock_iothread_impl
> (file=file@entry=0x2aa170a07d8 "../../util/rcu.c",
> line=line@entry=266)
> at ../../softmmu/cpus.c:493
> #4 0x000002aa16b4c8aa in call_rcu_thread (opaque=opaque@entry=0x0) at
> ../../util/rcu.c:266
> #5 0x000002aa16b22f5a in qemu_thread_start (args=<optimized out>) at
> ../../util/qemu-thread-posix.c:541
> #6 0x000003ff7e487aa8 in start_thread (arg=0x3ff711b7910) at
> pthread_create.c:463
> #7 0x000003ff7e37a11e in thread_start () at
> ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
>
> Thread 1 (Thread 0x3ff81035470 (LWP 60123)):
> #0 0x000003ff7e36f1b0 in __GI___poll (fds=0x2aa18147da0, nfds=2,
> timeout=<optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:29
> #1 0x000003ff7f9d2624 in () at /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #2 0x000003ff7f9d2aa8 in g_main_loop_run () at
> /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #3 0x000002aa169104de in vhost_user_read
> (dev=dev@entry=0x2aa18f7afc8, msg=msg@entry=0x3ffc167ddfc)
> at ../../hw/virtio/vhost-user.c:402
> #4 0x000002aa1691186e in vhost_user_get_u64
> (dev=dev@entry=0x2aa18f7afc8, request=request@entry=1,
> u64=u64@entry=0x3ffc167e138)
> at ../../hw/virtio/vhost-user.c:1334
> #5 0x000002aa16913388 in vhost_user_get_features
> (features=0x3ffc167e138, dev=0x2aa18f7afc8) at
> ../../hw/virtio/vhost-user.c:1356
> #6 0x000002aa16913388 in vhost_user_backend_init (dev=0x2aa18f7afc8,
> opaque=0x2aa18f7b240, errp=0x3ffc167e470)
> at ../../hw/virtio/vhost-user.c:1877
> #7 0x000002aa1684030c in vhost_dev_init
> (hdev=hdev@entry=0x2aa18f7afc8, opaque=opaque@entry=0x2aa18f7b240,
> backend_type=backend_type@entry=VHOST_BACKEND_TYPE_USER,
> busyloop_timeout=busyloop_timeout@entry=0,
> errp=errp@entry=0x3ffc167e470)
> at ../../hw/virtio/vhost.c:1302
> #8 0x000002aa168be742 in vhost_user_blk_connect
> (dev=dev@entry=0x2aa18f7ad78, errp=errp@entry=0x3ffc167e470)
> at ../../hw/block/vhost-user-blk.c:339
> #9 0x000002aa168bec44 in vhost_user_blk_realize_connect
> (errp=0x3ffc167e470, s=0x2aa18f7ad78) at
> ../../hw/block/vhost-user-blk.c:440
> #10 0x000002aa168bec44 in vhost_user_blk_device_realize
> (dev=0x2aa18f7ad78, errp=0x3ffc167e470)
> at ../../hw/block/vhost-user-blk.c:513
> #11 0x000002aa16819e78 in virtio_device_realize (dev=0x2aa18f7ad78,
> errp=0x3ffc167e530) at ../../hw/virtio/virtio.c:3659
> #12 0x000002aa169fcc50 in device_set_realized (obj=<optimized out>,
> value=<optimized out>, errp=0x3ffc167e690)
> at ../../hw/core/qdev.c:761
> #13 0x000002aa169229ba in property_set_bool
> (obj=obj@entry=0x2aa18f7ad78, v=v@entry=
> 0x2aa18fc41e0, name=name@entry=0x2aa16ccfd74 "realized",
> opaque=0x2aa17f2a7a0, errp=errp@entry=0x3ffc167e690)
> at ../../qom/object.c:2258
> #14 0x000002aa16925534 in object_property_set
> (obj=obj@entry=0x2aa18f7ad78, name=name@entry=0x2aa16ccfd74
> "realized", v=v@entry=
> 0x2aa18fc41e0, errp=errp@entry=0x3ffc167e980) at ../../qom/object.c:1403
> #15 0x000002aa1692229c in object_property_set_qobject
> (obj=obj@entry=0x2aa18f7ad78, name=name@entry=0x2aa16ccfd74
> "realized", value=value@entry=0x2aa18fc4120,
> errp=errp@entry=0x3ffc167e980) at ../../qom/qom-qobject.c:28
> #16 0x000002aa169257e2 in object_property_set_bool (obj=0x2aa18f7ad78,
> name=0x2aa16ccfd74 "realized", value=<optimized out>,
> errp=0x3ffc167e980) at ../../qom/object.c:1473
> #17 0x000002aa1677e9c2 in virtio_pci_realize (pci_dev=0x2aa18f72b80,
> errp=0x3ffc167e980) at ../../hw/virtio/virtio-pci.c:1907
> #18 0x000002aa165dfc48 in pci_qdev_realize (qdev=0x2aa18f72b80,
> errp=<optimized out>) at ../../hw/pci/pci.c:2148
> #19 0x000002aa169fcc50 in device_set_realized (obj=<optimized out>,
> value=<optimized out>, errp=0x3ffc167ebe8)
> at ../../hw/core/qdev.c:761
> #20 0x000002aa169229ba in property_set_bool
> (obj=obj@entry=0x2aa18f72b80, v=v@entry=
> 0x2aa18fbe450, name=name@entry=0x2aa16ccfd74 "realized",
> opaque=0x2aa17f2a7a0, errp=errp@entry=0x3ffc167ebe8)
> at ../../qom/object.c:2258
> #21 0x000002aa16925534 in object_property_set
> (obj=obj@entry=0x2aa18f72b80, name=name@entry=0x2aa16ccfd74
> "realized", v=v@entry=
> 0x2aa18fbe450, errp=errp@entry=0x2aa17484fe0 <error_fatal>) at
> ../../qom/object.c:1403
> #22 0x000002aa1692229c in object_property_set_qobject
> (obj=obj@entry=0x2aa18f72b80, name=name@entry=0x2aa16ccfd74
> "realized", value=value@entry=0x2aa18fbe580,
> errp=errp@entry=0x2aa17484fe0 <error_fatal>) at
> ../../qom/qom-qobject.c:28
> #23 0x000002aa169257e2 in object_property_set_bool (obj=0x2aa18f72b80,
> name=name@entry=0x2aa16ccfd74 "realized", value=value@entry=true,
> errp=0x2aa17484fe0 <error_fatal>, errp@entry=<error reading variable:
> value has been optimized out>) at ../../qom/object.c:1473
> #24 0x000002aa169fb87e in qdev_realize (dev=<optimized out>,
> bus=bus@entry=0x2aa18384200, errp=<error reading variable: value has
> been optimized out>) at ../../hw/core/qdev.c:389
> #25 0x000002aa165f1c6c in qdev_device_add (opts=<optimized out>,
> errp=<optimized out>, errp@entry=0x2aa17484fe0 <error_fatal>)
> at ../../softmmu/qdev-monitor.c:673
> #26 0x000002aa168b2086 in device_init_func (opaque=<optimized out>,
> opts=<optimized out>, errp=0x2aa17484fe0 <error_fatal>)
> at ../../softmmu/vl.c:1187
> #27 0x000002aa16b2b906 in qemu_opts_foreach (list=<optimized out>,
> func=func@entry=0x2aa168b2068 <device_init_func>,
> opaque=opaque@entry=0x0, errp=0x2aa17484fe0 <error_fatal>) at
> ../../util/qemu-option.c:1135
> #28 0x000002aa168b5046 in qemu_create_cli_devices () at ../../softmmu/vl.c:2645
> #29 0x000002aa168b5046 in qmp_x_exit_preconfig (errp=<optimized out>)
> at ../../softmmu/vl.c:2693
> #30 0x000002aa168b83ce in qemu_init (argc=<optimized out>,
> argv=<optimized out>, envp=<optimized out>) at ../../softmmu/vl.c:3713
> #31 0x000002aa1654f6da in main (argc=<optimized out>, argv=<optimized
> out>, envp=<optimized out>) at ../../softmmu/main.c:49
>
>
> Backtrace, qos-test:
>
> Thread 2 (Thread 0x3ff9de7f910 (LWP 59555)):
> #0 syscall () at ../sysdeps/unix/sysv/linux/s390/s390-64/syscall.S:53
> #1 0x000002aa20c36a54 in qemu_futex_wait (val=<optimized out>,
> f=<optimized out>) at /home/ubuntu/qemu/include/qemu/futex.h:29
> #2 qemu_event_wait (ev=ev@entry=0x2aa20cdc3a0 <rcu_call_ready_event>)
> at ../../util/qemu-thread-posix.c:480
> #3 0x000002aa20c4efa4 in call_rcu_thread (opaque=opaque@entry=0x0) at
> ../../util/rcu.c:258
> #4 0x000002aa20c35a6a in qemu_thread_start (args=<optimized out>) at
> ../../util/qemu-thread-posix.c:541
> #5 0x000003ff9e887aa8 in start_thread (arg=0x3ff9de7f910) at
> pthread_create.c:463
> #6 0x000003ff9e77a11e in thread_start () at
> ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
>
> Thread 1 (Thread 0x3ff9eef0940 (LWP 59553)):
> #0 0x000003ff9e89165a in __libc_read (fd=<optimized out>,
> buf=buf@entry=0x3ffc10fd3e0, nbytes=nbytes@entry=1024)
> at ../sysdeps/unix/sysv/linux/read.c:27
> #1 0x000002aa20bdee7a in read (__nbytes=1024, __buf=0x3ffc10fd3e0,
> __fd=<optimized out>)
> at /usr/include/s390x-linux-gnu/bits/unistd.h:44
> #2 qtest_client_socket_recv_line (s=0x2aa22379fc0) at
> ../../tests/qtest/libqtest.c:494
> #3 0x000002aa20bdf032 in qtest_rsp_args (s=s@entry=0x2aa22379fc0,
> expected_args=expected_args@entry=1)
> at ../../tests/qtest/libqtest.c:521
> #4 0x000002aa20bdf6f2 in qtest_query_target_endianness
> (s=0x2aa22379fc0) at ../../tests/qtest/libqtest.c:570
> #5 0x000002aa20be0312 in qtest_init_without_qmp_handshake
> (extra_args=<optimized out>) at ../../tests/qtest/libqtest.c:332
> #6 0x000002aa20be09e2 in qtest_init (extra_args=<optimized out>) at
> ../../tests/qtest/libqtest.c:339
> #7 0x000002aa20bc7b76 in qtest_start (
> args=0x2aa22389ef0 "-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-59553-so"...)
> at ../../tests/qtest/libqtest-single.h:29
> #8 restart_qemu_or_continue (
> path=0x2aa22389ef0 "-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-59553-so"...) at
> ../../tests/qtest/qos-test.c:105
> #9 run_one_test (arg=<optimized out>) at ../../tests/qtest/qos-test.c:178
> #10 0x000003ff9eb7c70c in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #11 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #12 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #13 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #14 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #15 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #16 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #17 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #18 0x000003ff9eb7c648 in ?? () from /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #19 0x000003ff9eb7c8ee in g_test_run_suite () from
> /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #20 0x000003ff9eb7c928 in g_test_run () from
> /usr/lib/s390x-linux-gnu/libglib-2.0.so.0
> #21 0x000002aa20bc6c9a in main (argc=<optimized out>, argv=<optimized
> out>, envp=<optimized out>) at ../../tests/qtest/qos-test.c:338
>
> Backtrace, qemu-storage-daemon:
>
> Thread 2 (Thread 0x3ff951b7910 (LWP 60132)):
> #0 syscall () at ../sysdeps/unix/sysv/linux/s390/s390-64/syscall.S:53
> #1 0x000002aa0184fa6c in qemu_futex_wait (val=<optimized out>,
> f=<optimized out>) at /home/ubuntu/qemu/include/qemu/futex.h:29
> #2 qemu_event_wait (ev=ev@entry=0x2aa01971158 <rcu_call_ready_event>)
> at ../../util/qemu-thread-posix.c:480
> #3 0x000002aa0187498c in call_rcu_thread (opaque=opaque@entry=0x0) at
> ../../util/rcu.c:258
> #4 0x000002aa0184ea82 in qemu_thread_start (args=<optimized out>) at
> ../../util/qemu-thread-posix.c:541
> #5 0x000003ffa0507aa8 in start_thread (arg=0x3ff951b7910) at
> pthread_create.c:463
> #6 0x000003ffa03fa11e in thread_start () at
> ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
>
> Thread 1 (Thread 0x3ffa14590e0 (LWP 60122)):
> #0 0x000003ffa03ef302 in __GI_ppoll (fds=0x2aa0332b3d0, nfds=5,
> timeout=<optimized out>, timeout@entry=0x0,
> sigmask=sigmask@entry=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:39
> #1 0x000002aa0185b054 in ppoll (__ss=0x0, __timeout=0x0,
> __nfds=<optimized out>, __fds=<optimized out>)
> at /usr/include/s390x-linux-gnu/bits/poll2.h:77
> #2 qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>,
> timeout=timeout@entry=-1) at ../../util/qemu-timer.c:336
> #3 0x000002aa01851e48 in os_host_main_loop_wait (timeout=-1) at
> ../../util/main-loop.c:250
> #4 main_loop_wait (nonblocking=<optimized out>) at ../../util/main-loop.c:531
> #5 0x000002aa01738dda in main (argc=<optimized out>,
> argv=0x3ffd28feba8) at ../../storage-daemon/qemu-storage-daemon.c:345
>
>
> thanks
> -- PMM
next prev parent reply other threads:[~2021-08-04 13:44 UTC|newest]
Thread overview: 6+ messages / expand[flat|nested] mbox.gz Atom feed top
2021-08-04 12:40 intermittent failure, s390 host, x86-64 guest, vhost-user-blk test Peter Maydell
2021-08-04 13:43 ` Michael S. Tsirkin [this message]
2021-08-04 14:33 ` Peter Maydell
2021-08-05 17:39 ` Peter Maydell
2021-08-06 10:36 ` Peter Maydell
2021-08-27 16:53 ` Raphael Norwitz
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20210804094231-mutt-send-email-mst@kernel.org \
--to=mst@redhat.com \
--cc=eblake@redhat.com \
--cc=kwolf@redhat.com \
--cc=mreitz@redhat.com \
--cc=pbonzini@redhat.com \
--cc=peter.maydell@linaro.org \
--cc=qemu-devel@nongnu.org \
--cc=raphael.norwitz@nutanix.com \
--cc=sgarzare@redhat.com \
--cc=stefanha@redhat.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.