[Bug 1888601] Re: QEMU v5.1.0-rc0/rc1 hang with nested virtualization

[Simon Kaegi]

Here's what I get with 5.1.0-rc2

```
(gdb) thread apply all bt

Thread 5 (LWP 23730):
#0  0x00007f9ae6040ebb in ioctl ()
#1  0x00007f9ae57cf98b in kvm_vcpu_ioctl (cpu=cpu@entry=0x555557539ea0, 
type=type@entry=44672) at /root/qemu/accel/kvm/kvm-all.c:2631
#2  0x00007f9ae57cfac5 in kvm_cpu_exec (cpu=cpu@entry=0x555557539ea0) at 
/root/qemu/accel/kvm/kvm-all.c:2468
#3  0x00007f9ae586703c in qemu_kvm_cpu_thread_fn (arg=0x555557539ea0) at 
/root/qemu/softmmu/cpus.c:1188
#4  qemu_kvm_cpu_thread_fn (arg=arg@entry=0x555557539ea0) at 
/root/qemu/softmmu/cpus.c:1160
#5  0x00007f9ae5bd2f13 in qemu_thread_start (args=<optimized out>) at 
util/qemu-thread-posix.c:521
#6  0x00007f9ae5f97109 in start_thread (arg=<optimized out>) at 
pthread_create.c:477
#7  0x00007f9ae6045353 in clone ()

Thread 4 (LWP 23729):
#0  0x00007f9ae5fed337 in __strcmp_sse2 ()
#1  0x00007f9ae5d9a8ad in g_str_equal () at pthread_create.c:679
#2  0x00007f9ae5d99a9d in g_hash_table_lookup () at pthread_create.c:679
#3  0x00007f9ae5ac728f in type_table_lookup (name=0x7f9ae609c9dd "virtio-bus") 
at qom/object.c:84
#4  type_get_by_name (name=0x7f9ae609c9dd "virtio-bus") at qom/object.c:171
#5  object_class_dynamic_cast (class=class@entry=0x5555572d1ac0, 
typename=typename@entry=0x7f9ae609c9dd "virtio-bus") at qom/object.c:879
#6  0x00007f9ae5ac75b5 in object_class_dynamic_cast_assert 
(class=0x5555572d1ac0, typename=typename@entry=0x7f9ae609c9dd "virtio-bus", 
file=file@entry=0x7f9ae60a80b8 "/root/qemu/hw/virtio/virtio.c", 
line=line@entry=3290, 
    func=func@entry=0x7f9ae60a8c30 <__func__.31954> "virtio_queue_enabled") at 
qom/object.c:935
#7  0x00007f9ae5817842 in virtio_queue_enabled (vdev=0x555558418be0, n=0) at 
/root/qemu/hw/virtio/virtio.c:3290
#8  0x00007f9ae59c2837 in vhost_net_start_one (dev=0x555558418be0, 
net=0x5555574d8ca0) at hw/net/vhost_net.c:259
#9  vhost_net_start (dev=dev@entry=0x555558418be0, ncs=0x55555842e030, 
total_queues=total_queues@entry=2) at hw/net/vhost_net.c:351
#10 0x00007f9ae57f4d98 in virtio_net_vhost_status (status=<optimized out>, 
n=0x555558418be0) at /root/qemu/hw/net/virtio-net.c:268
#11 virtio_net_set_status (vdev=0x555558418be0, status=<optimized out>) at 
/root/qemu/hw/net/virtio-net.c:349
#12 0x00007f9ae5815bdb in virtio_set_status (vdev=vdev@entry=0x555558418be0, 
val=val@entry=7 '\a') at /root/qemu/hw/virtio/virtio.c:1956
#13 0x00007f9ae5a5ddf0 in virtio_ioport_write (val=7, addr=18, 
opaque=0x555558410a50) at hw/virtio/virtio-pci.c:331
#14 virtio_pci_config_write (opaque=0x555558410a50, addr=18, val=<optimized 
out>, size=<optimized out>) at hw/virtio/virtio-pci.c:455
#15 0x00007f9ae5870b2a in memory_region_write_accessor (attrs=..., mask=255, 
shift=<optimized out>, size=1, value=0x7f99dfffd5f8, addr=<optimized out>, 
mr=0x555558411340) at /root/qemu/softmmu/memory.c:483
#16 access_with_adjusted_size (attrs=..., mr=0x555558411340, 
access_fn=<optimized out>, access_size_max=<optimized out>, 
access_size_min=<optimized out>, size=1, value=0x7f99dfffd5f8, addr=18)
    at /root/qemu/softmmu/memory.c:544
#17 memory_region_dispatch_write (mr=mr@entry=0x555558411340, addr=<optimized 
out>, data=<optimized out>, op=<optimized out>, attrs=..., attrs@entry=...) at 
/root/qemu/softmmu/memory.c:1465
#18 0x00007f9ae57ab4b2 in flatview_write_continue (fv=0x7f99d007ef80, 
addr=addr@entry=53394, attrs=..., attrs@entry=..., 
ptr=ptr@entry=0x7f9ae43f1000, len=len@entry=1, addr1=<optimized out>, 
l=<optimized out>, 
    mr=0x555558411340) at /root/qemu/include/qemu/host-utils.h:164
#19 0x00007f9ae57afc4d in flatview_write (len=1, buf=0x7f9ae43f1000, attrs=..., 
addr=53394, fv=<optimized out>) at /root/qemu/exec.c:3216
#20 address_space_write (len=1, buf=0x7f9ae43f1000, attrs=..., addr=53394, 
as=0x7f9ae43f1000) at /root/qemu/exec.c:3307
#21 address_space_rw (as=as@entry=0x7f9ae6846d60 <address_space_io>, 
addr=addr@entry=53394, attrs=attrs@entry=..., buf=0x7f9ae43f1000, 
len=len@entry=1, is_write=is_write@entry=true) at /root/qemu/exec.c:3317
#22 0x00007f9ae57cfd5f in kvm_handle_io (count=1, size=1, direction=<optimized 
out>, data=<optimized out>, attrs=..., port=53394) at 
/root/qemu/accel/kvm/kvm-all.c:2262
#23 kvm_cpu_exec (cpu=cpu@entry=0x5555574f3ac0) at 
/root/qemu/accel/kvm/kvm-all.c:2508
#24 0x00007f9ae586703c in qemu_kvm_cpu_thread_fn (arg=0x5555574f3ac0) at 
/root/qemu/softmmu/cpus.c:1188
#25 qemu_kvm_cpu_thread_fn (arg=arg@entry=0x5555574f3ac0) at 
/root/qemu/softmmu/cpus.c:1160
#26 0x00007f9ae5bd2f13 in qemu_thread_start (args=<optimized out>) at 
util/qemu-thread-posix.c:521
#27 0x00007f9ae5f97109 in start_thread (arg=<optimized out>) at 
pthread_create.c:477
#28 0x00007f9ae6045353 in clone ()

Thread 3 (LWP 23728):
#0  0x00007f9ae603fd0f in poll ()
#1  0x00007f9ae5dac5de in g_main_context_iterate.isra () at pthread_create.c:679
#2  0x00007f9ae5dac963 in g_main_loop_run () at pthread_create.c:679
#3  0x00007f9ae58a7b71 in iothread_run (opaque=opaque@entry=0x55555734b800) at 
iothread.c:82
#4  0x00007f9ae5bd2f13 in qemu_thread_start (args=<optimized out>) at 
util/qemu-thread-posix.c:521
#5  0x00007f9ae5f97109 in start_thread (arg=<optimized out>) at 
pthread_create.c:477
#6  0x00007f9ae6045353 in clone ()

Thread 2 (LWP 23723):
#0  0x00007f9ae604207d in syscall ()
#1  0x00007f9ae5bd3e32 in qemu_futex_wait (val=<optimized out>, f=<optimized 
out>) at /root/qemu/include/qemu/futex.h:29
#2  qemu_event_wait () at util/qemu-thread-posix.c:460
#3  0x00007f9ae5bde0f2 in call_rcu_thread () at util/rcu.c:258
#4  0x00007f9ae5bd2f13 in qemu_thread_start (args=<optimized out>) at 
util/qemu-thread-posix.c:521
#5  0x00007f9ae5f97109 in start_thread (arg=<optimized out>) at 
pthread_create.c:477
#6  0x00007f9ae6045353 in clone ()
---Type <return> to continue, or q <return> to quit---

Thread 1 (LWP 23722):
#0  __lll_lock_wait (futex=futex@entry=0x7f9ae6849980 <qemu_global_mutex>, 
private=0) at lowlevellock.c:52
#1  0x00007f9ae5f99263 in __pthread_mutex_lock 
(mutex=mutex@entry=0x7f9ae6849980 <qemu_global_mutex>) at 
../nptl/pthread_mutex_lock.c:80
#2  0x00007f9ae5bd3087 in qemu_mutex_lock_impl (mutex=0x7f9ae6849980 
<qemu_global_mutex>, file=0x7f9ae61d11e3 "util/main-loop.c", line=238) at 
util/qemu-thread-posix.c:79
#3  0x00007f9ae5868f8e in qemu_mutex_lock_iothread_impl 
(file=file@entry=0x7f9ae61d11e3 "util/main-loop.c", line=line@entry=238) at 
/root/qemu/softmmu/cpus.c:1782
#4  0x00007f9ae5beb09d in os_host_main_loop_wait (timeout=940584562) at 
util/main-loop.c:238
#5  main_loop_wait (nonblocking=nonblocking@entry=0) at util/main-loop.c:516
#6  0x00007f9ae587a76e in qemu_main_loop () at /root/qemu/softmmu/vl.c:1676
#7  0x00007f9ae57a7b52 in main (argc=<optimized out>, argv=<optimized out>, 
envp=<optimized out>) at /root/qemu/softmmu/main.c:49
```

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1888601

Title:
  QEMU v5.1.0-rc0/rc1 hang with nested virtualization

Status in QEMU:
  New

Bug description:
  We're running Kata Containers using QEMU and with v5.1.0rc0 and rc1
  have noticed a problem at startup where QEMu appears to hang. We are
  not seeing this problem on our bare metal nodes and only on a VSI that
  supports nested virtualization.

  We unfortunately see nothing at all in the QEMU logs to help
  understand the problem and a hung process is just a guess at this
  point.

  Using git bisect we first see the problem with...

  ---

  f19bcdfedd53ee93412d535a842a89fa27cae7f2 is the first bad commit
  commit f19bcdfedd53ee93412d535a842a89fa27cae7f2
  Author: Jason Wang <jasowang@redhat.com>
  Date:   Wed Jul 1 22:55:28 2020 +0800

      virtio-pci: implement queue_enabled method

      With version 1, we can detect whether a queue is enabled via
      queue_enabled.

      Signed-off-by: Jason Wang <jasowang@redhat.com>
      Signed-off-by: Cindy Lu <lulu@redhat.com>
      Message-Id: <20200701145538.22333-5-lulu@redhat.com>
      Reviewed-by: Michael S. Tsirkin <mst@redhat.com>
      Signed-off-by: Michael S. Tsirkin <mst@redhat.com>
      Acked-by: Jason Wang <jasowang@redhat.com>

   hw/virtio/virtio-pci.c | 13 +++++++++++++
   1 file changed, 13 insertions(+)

  ---

  Reverting this commit (on top of 5.1.0-rc1) seems to work and prevent
  the hanging.

  ---

  Here's how kata ends up launching qemu in our environment --
  /opt/kata/bin/qemu-system-x86_64 -name 
sandbox-849df14c6065931adedb9d18bc9260a6d896f1814a8c5cfa239865772f1b7a5f -uuid 
6bec458e-1da7-4847-a5d7-5ab31d4d2465 -machine pc,accel=kvm,kernel_irqchip -cpu 
host,pmu=off -qmp 
unix:/run/vc/vm/849df14c6065931adedb9d18bc9260a6d896f1814a8c5cfa239865772f1b7a5f/qmp.sock,server,nowait
 -m 4096M,slots=10,maxmem=30978M -device 
pci-bridge,bus=pci.0,id=pci-bridge-0,chassis_nr=1,shpc=on,addr=2,romfile= 
-device virtio-serial-pci,disable-modern=true,id=serial0,romfile= -device 
virtconsole,chardev=charconsole0,id=console0 -chardev 
socket,id=charconsole0,path=/run/vc/vm/849df14c6065931adedb9d18bc9260a6d896f1814a8c5cfa239865772f1b7a5f/console.sock,server,nowait
 -device virtio-scsi-pci,id=scsi0,disable-modern=true,romfile= -object 
rng-random,id=rng0,filename=/dev/urandom -device 
virtio-rng-pci,rng=rng0,romfile= -device 
virtserialport,chardev=charch0,id=channel0,name=agent.channel.0 -chardev 
socket,id=charch0,path=/run/vc/vm/849df14c6065931adedb9d18bc9260a6d896f1814a8c5cfa239865772f1b7a5f/kata.sock,server,nowait
 -chardev 
socket,id=char-396c5c3e19e29353,path=/run/vc/vm/849df14c6065931adedb9d18bc9260a6d896f1814a8c5cfa239865772f1b7a5f/vhost-fs.sock
 -device 
vhost-user-fs-pci,chardev=char-396c5c3e19e29353,tag=kataShared,romfile= -netdev 
tap,id=network-0,vhost=on,vhostfds=3:4,fds=5:6 -device 
driver=virtio-net-pci,netdev=network-0,mac=52:ac:2d:02:1f:6f,disable-modern=true,mq=on,vectors=6,romfile=
 -global kvm-pit.lost_tick_policy=discard -vga none -no-user-config -nodefaults 
-nographic -daemonize -object 
memory-backend-file,id=dimm1,size=4096M,mem-path=/dev/shm,share=on -numa 
node,memdev=dimm1 -kernel /opt/kata/share/kata-containers/vmlinuz-5.7.9-74 
-initrd 
/opt/kata/share/kata-containers/kata-containers-initrd_alpine_1.11.2-6_agent.initrd
 -append tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 
i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 
console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 debug 
panic=1 nr_cpus=4 agent.use_vsock=false scsi_mod.scan=none 
init=/usr/bin/kata-agent -pidfile 
/run/vc/vm/849df14c6065931adedb9d18bc9260a6d896f1814a8c5cfa239865772f1b7a5f/pid 
-D 
/run/vc/vm/849df14c6065931adedb9d18bc9260a6d896f1814a8c5cfa239865772f1b7a5f/qemu.log
 -smp 2,cores=1,threads=1,sockets=4,maxcpus=4

  ---

To manage notifications about this bug go to:
https://bugs.launchpad.net/qemu/+bug/1888601/+subscriptions