kvm_irqchip_commit_routes: Assertion `ret == 0' failed.

[Alex Williamson]

During win8.1 boot on qemu.git eba05e922e8e7f307bc5d4104a78797e55124e97, kernel 4.1-rc4, I get the following assert:

qemu-system-x86_64: /net/gimli/home/alwillia/Work/qemu.git/kvm-all.c:1033: kvm_irqchip_commit_routes: Assertion `ret == 0' failed.

Bisected to:

commit 851c2a75a6e80c8aa5e713864d98cfb512e7229b
Author: Jason Wang <email address hidden>
Date: Thu Apr 23 14:21:47 2015 +0800

    virtio-pci: speedup MSI-X masking and unmasking

    This patch tries to speed up the MSI-X masking and unmasking through
    the mapping between vector and queues. With this patch it will there's
    no need to go through all possible virtqueues, which may help to
    reduce the time spent when doing MSI-X masking/unmasking a single
    vector when more than hundreds or even thousands of virtqueues were
    supported.

    Tested with 80 queue pairs virito-net-pci by changing the smp affinity
    in the background and doing netperf in the same time:

    Before the patch:
    5711.70 Gbits/sec
    After the patch:
    6830.98 Gbits/sec

    About 19.6% improvements in throughput.

    Cc: Michael S. Tsirkin <email address hidden>
    Signed-off-by: Jason Wang <email address hidden>
    Reviewed-by: Michael S. Tsirkin <email address hidden>
    Signed-off-by: Michael S. Tsirkin <email address hidden>

Backtrace:

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7f32fffff700 (LWP 23059)]
0x00007f33187438d7 in raise () from /lib64/libc.so.6
(gdb) bt
#0 0x00007f33187438d7 in raise () at /lib64/libc.so.6
#1 0x00007f331874553a in abort () at /lib64/libc.so.6
#2 0x00007f331873c47d in __assert_fail_base () at /lib64/libc.so.6
#3 0x00007f331873c532 in () at /lib64/libc.so.6
#4 0x000055e0252fed5b in kvm_irqchip_commit_routes (s=0x55e027ce17e0)
    at /net/gimli/home/alwillia/Work/qemu.git/kvm-all.c:1033
#5 0x000055e0252fef46 in kvm_update_routing_entry (s=0x55e027ce17e0, new_entry=0x7f32ffffe4a0) at /net/gimli/home/alwillia/Work/qemu.git/kvm-all.c:1078
#6 0x000055e0252ff78e in kvm_irqchip_update_msi_route (s=0x55e027ce17e0, virq=0, msg=...) at /net/gimli/home/alwillia/Work/qemu.git/kvm-all.c:1282
#7 0x000055e0255899a0 in virtio_pci_vq_vector_unmask (proxy=0x55e02a0ee580, queue_no=2, vector=2, msg=...) at hw/virtio/virtio-pci.c:588
#8 0x000055e025589b76 in virtio_pci_vector_unmask (dev=0x55e02a0ee580, vector=2, msg=...) at hw/virtio/virtio-pci.c:641
#9 0x000055e0255186f0 in msix_set_notifier_for_vector (dev=0x55e02a0ee580, vector=2) at hw/pci/msix.c:513
#10 0x000055e0255187ee in msix_set_vector_notifiers (dev=0x55e02a0ee580, use_notifier=0x55e025589ad2 <virtio_pci_vector_unmask>, release_notifier=0x55e025589c0c <virtio_pci_vector_mask>, poll_notifier=0x55e025589cb1 <virtio_pci_vector_poll>) at hw/pci/msix.c:540
#11 0x000055e02558a1f0 in virtio_pci_set_guest_notifiers (d=0x55e02a0ee580, nvqs=2, assign=true) at hw/virtio/virtio-pci.c:794
#12 0x000055e02533c2bc in vhost_net_start (dev=0x55e02a0eef90, ncs=0x55e02a866ac0, total_queues=1)
    at /net/gimli/home/alwillia/Work/qemu.git/hw/net/vhost_net.c:318
#13 0x000055e025336dce in virtio_net_vhost_status (n=0x55e02a0eef90, status=7 '\a') at /net/gimli/home/alwillia/Work/qemu.git/hw/net/virtio-net.c:146
#14 0x000055e025336e78 in virtio_net_set_status (vdev=0x55e02a0eef90, status=7 '\a') at /net/gimli/home/alwillia/Work/qemu.git/hw/net/virtio-net.c:165
#15 0x000055e0253504c6 in virtio_set_status (vdev=0x55e02a0eef90, val=7 '\a')
    at /net/gimli/home/alwillia/Work/qemu.git/hw/virtio/virtio.c:551
#16 0x000055e025588d6d in virtio_ioport_write (opaque=0x55e02a0ee580, addr=18, val=7) at hw/virtio/virtio-pci.c:259
#17 0x000055e0255891d1 in virtio_pci_config_write (opaque=0x55e02a0ee580, addr=18, val=7, size=1) at hw/virtio/virtio-pci.c:385
#18 0x000055e025303155 in memory_region_write_accessor (mr=0x55e02a0eee00, addr=18, value=0x7f32ffffe908, size=1, shift=0, mask=255, attrs=...)
    at /net/gimli/home/alwillia/Work/qemu.git/memory.c:457
#19 0x000055e025303308 in access_with_adjusted_size (addr=18, value=0x7f32ffffe908, size=1, access_size_min=1, access_size_max=4, access=
    0x55e0253030d0 <memory_region_write_accessor>, mr=0x55e02a0eee00, attrs=...) at /net/gimli/home/alwillia/Work/qemu.git/memory.c:516
#20 0x000055e025305b15 in memory_region_dispatch_write (mr=0x55e02a0eee00, addr=18, data=7, size=1, attrs=...)
    at /net/gimli/home/alwillia/Work/qemu.git/memory.c:1166
#21 0x000055e0252b68eb in address_space_rw (as=0x55e025b71a80 <address_space_io>, addr=49458, attrs=..., buf=0x7f3322f48000 "\a", len=1, is_write=true)
    at /net/gimli/home/alwillia/Work/qemu.git/exec.c:2363
#22 0x000055e02530041e in kvm_handle_io (port=49458, attrs=..., data=0x7f3322f48000, direction=1, size=1, count=1)
    at /net/gimli/home/alwillia/Work/qemu.git/kvm-all.c:1679
#23 0x000055e025300914 in kvm_cpu_exec (cpu=0x55e02a1383a0)
---Type <return> to continue, or q <return> to quit---
    at /net/gimli/home/alwillia/Work/qemu.git/kvm-all.c:1839
#24 0x000055e0252e8062 in qemu_kvm_cpu_thread_fn (arg=0x55e02a1383a0)
    at /net/gimli/home/alwillia/Work/qemu.git/cpus.c:947
#25 0x00007f3321b2352a in start_thread () at /lib64/libpthread.so.0
#26 0x00007f331880f22d in clone () at /lib64/libc.so.6

VM XML (-snapshot added only for bisect):

<domain type='kvm' id='8' xmlns:qemu='http://libvirt.org/schemas/domain/qemu/1.0'>
  <name>Steam</name>
  <uuid>79f39860-d659-426b-89e8-90cb46ee57c6</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <memoryBacking>
    <hugepages/>
  </memoryBacking>
  <vcpu placement='static'>4</vcpu>
  <cputune>
    <vcpupin vcpu='0' cpuset='0'/>
    <vcpupin vcpu='1' cpuset='1'/>
    <vcpupin vcpu='2' cpuset='2'/>
    <vcpupin vcpu='3' cpuset='3'/>
  </cputune>
  <resource>
    <partition>/machine</partition>
  </resource>
  <os>
    <type arch='x86_64' machine='pc-i440fx-2.3'>hvm</type>
    <loader readonly='yes' type='pflash'>/usr/share/edk2.git/ovmf-x64/OVMF_CODE-pure-efi.fd</loader>
    <nvram template='/usr/share/edk2.git/ovmf-x64/OVMF_VARS-pure-efi.fd'>/var/lib/libvirt/qemu/nvram/Steam_VARS.fd</nvram>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
    <kvm>
      <hidden state='on'/>
    </kvm>
  </features>
  <cpu mode='host-passthrough'>
    <topology sockets='1' cores='4' threads='1'/>
  </cpu>
  <clock offset='localtime'>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='hpet' present='no'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <devices>
    <emulator>/usr/local/bin/qemu-system-x86_64</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none' io='native'/>
      <source file='/mnt/store/vm/Steam.qcow2'/>
      <backingStore type='file' index='1'>
        <format type='raw'/>
        <source file='/mnt/store/vm/Steam.img'/>
        <backingStore/>
      </backingStore>
      <target dev='sda' bus='scsi'/>
      <boot order='2'/>
      <alias name='scsi0-0-0-0'/>
      <address type='drive' controller='0' bus='0' target='0' unit='0'/>
    </disk>
    <controller type='scsi' index='0' model='virtio-scsi'>
      <alias name='scsi0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </controller>
    <controller type='usb' index='0' model='ich9-ehci1'>
      <alias name='usb0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x7'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci1'>
      <alias name='usb0'/>
      <master startport='0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0' multifunction='on'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci2'>
      <alias name='usb0'/>
      <master startport='2'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x1'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci3'>
      <alias name='usb0'/>
      <master startport='4'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x2'/>
    </controller>
    <controller type='pci' index='0' model='pci-root'>
      <alias name='pci.0'/>
    </controller>
    <interface type='bridge'>
      <mac address='52:54:00:60:ef:ac'/>
      <source bridge='br0'/>
      <target dev='vnet0'/>
      <model type='virtio'/>
      <alias name='net0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <hostdev mode='subsystem' type='pci' managed='yes'>
      <driver name='vfio'/>
      <source>
        <address domain='0x0000' bus='0x01' slot='0x00' function='0x0'/>
      </source>
      <alias name='hostdev0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </hostdev>
    <hostdev mode='subsystem' type='pci' managed='yes'>
      <driver name='vfio'/>
      <source>
        <address domain='0x0000' bus='0x01' slot='0x00' function='0x1'/>
      </source>
      <alias name='hostdev1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>
    </hostdev>
    <memballoon model='none'>
      <alias name='balloon0'/>
    </memballoon>
  </devices>
  <qemu:commandline>
    <qemu:arg value='-snapshot'/>
  </qemu:commandline>
</domain>

[Jason Wang (jasowang)]

From the trace, looks like the driver is trying to assign config vq (2) an vector(2). This is interesting.

I try to reproduce but fail. (The only difference is my guest does not have any vfio and ovmf was not used).

Can you reproduce it without ovmf and vfio?

Thanks

[Alex Williamson (alex-l-williamson)]

The bug is unaffected, it still occurs, by removing the vfio devices from the config and replacing them with a standard spice/qxl graphics setup. I'm unable to reproduce the issue so far using a seabios-based win8.1 install.

[Alex Williamson (alex-l-williamson)]

Correction, I was using the stock distro qemu-kvm. Yes, the problem occurs on a stock seabios win8.1 VM without vfio:

<domain type='kvm'>
  <name>win8.1</name>
  <uuid>896cb319-c196-4b92-a7e2-2306b0eac769</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>2</vcpu>
  <os>
    <type arch='x86_64' machine='pc-i440fx-2.3'>hvm</type>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
    <hyperv>
      <relaxed state='on'/>
      <vapic state='on'/>
      <spinlocks state='on' retries='8191'/>
    </hyperv>
  </features>
  <cpu mode='custom' match='exact'>
    <model fallback='allow'>SandyBridge</model>
  </cpu>
  <clock offset='localtime'>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='hpet' present='no'/>
    <timer name='hypervclock' present='yes'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <pm>
    <suspend-to-mem enabled='no'/>
    <suspend-to-disk enabled='no'/>
  </pm>
  <devices>
    <emulator>/usr/local/bin/qemu-system-x86_64</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2'/>
      <source file='/mnt/store/vm/win8.1-seabios'/>
      <target dev='sda' bus='scsi'/>
      <boot order='2'/>
      <address type='drive' controller='0' bus='0' target='0' unit='0'/>
    </disk>
    <controller type='usb' index='0' model='ich9-ehci1'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x7'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci1'>
      <master startport='0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0' multifunction='on'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci2'>
      <master startport='2'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x1'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci3'>
      <master startport='4'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x2'/>
    </controller>
    <controller type='scsi' index='0' model='virtio-scsi'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </controller>
    <controller type='pci' index='0' model='pci-root'/>
    <interface type='bridge'>
      <mac address='52:54:00:c9:7b:49'/>
      <source bridge='br0'/>
      <model type='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <input type='keyboard' bus='ps2'/>
    <graphics type='spice' autoport='yes'>
      <image compression='off'/>
    </graphics>
    <video>
      <model type='qxl' ram='65536' vram='65536' vgamem='16384' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x08' function='0x0'/>
    </memballoon>
  </devices>
</domain>

[Jason Wang (jasowang)]

Using almost the same XML but still could not reproduce this by myself.

What's the version of guest driver inside? I'm using 12/19/2014 62.70.104.9800?

[Alex Williamson (alex-l-williamson)]

I'm using 62.72.104.10300. I started with the old virtio-win-0.1-100 ISO, but I couldn't figure out how to downgrade to the latest "stable" release, so instead I upgraded to the 103 release to see if it fixed anything. It does not.

[Thomas Huth (th-huth)]

Looking through old bug tickets... can you still reproduce this issue with the latest version of QEMU? Or could we close this ticket nowadays?

[Alex Williamson (alex-l-williamson)]

This appears to address it in QEMU v2.4:

commit 6652d0811c9463fbfb2d2d1cb2ec03f388145c5f
Author: Jason Wang <email address hidden>
Date: Wed May 27 16:26:07 2015 +0800

    virtio-pci: don't try to mask or unmask vqs without notifiers

    We should validate the vq index against nvqs_with_notifiers. Otherwise we may
    try to mask or unmask vector for vqs without notifiers (e.g control vq). This
    will lead qemu abort on kvm_irqchip_commit_routes() when trying to boot win8.1
    guest.

    Fixes 851c2a75a6e80c8aa5e713864d98cfb512e7229b ("virtio-pci: speedup MSI-X
    masking and unmasking")

    Reported-by: Alex Williamson <email address hidden>
    Signed-off-by: Jason Wang <email address hidden>
    Reviewed-by: Michael S. Tsirkin <email address hidden>
    Signed-off-by: Michael S. Tsirkin <email address hidden>