Bug 2165278

Summary: [RHEL9.2] virsh start guest hanged and virsh console can not login
Product: Red Hat Enterprise Linux 9 Reporter: Hekai Wang <hewang>
Component: qemu-kvmAssignee: Laurent Vivier <lvivier>
qemu-kvm sub component: Networking QA Contact: Yiqian Wei <yiwei>
Status: CLOSED DUPLICATE Docs Contact:
Severity: unspecified    
Priority: unspecified CC: coli, jinzhao, jsuchane, juzhang, lvivier, mprivozn, peterx, virt-maint, yiwei, ymankad
Version: 9.2Keywords: Regression, Triaged
Target Milestone: rcFlags: jinzhao: needinfo-
pm-rhel: mirror+
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-02-21 06:13:00 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Hekai Wang 2023-01-29 02:42:55 UTC
Description of problem:
[RHEL9.2] virsh start guest hanged and virsh console can not login 


Version-Release number of selected component (if applicable):

[root@dell-per730-54 ~]# rpm -qa | grep qemu-kvm
qemu-kvm-tools-7.2.0-3.el9.x86_64
qemu-kvm-docs-7.2.0-3.el9.x86_64
qemu-kvm-common-7.2.0-3.el9.x86_64
qemu-kvm-device-display-virtio-gpu-7.2.0-3.el9.x86_64
qemu-kvm-ui-opengl-7.2.0-3.el9.x86_64
qemu-kvm-ui-egl-headless-7.2.0-3.el9.x86_64
qemu-kvm-device-display-virtio-gpu-pci-7.2.0-3.el9.x86_64
qemu-kvm-device-display-virtio-vga-7.2.0-3.el9.x86_64
qemu-kvm-device-usb-host-7.2.0-3.el9.x86_64
qemu-kvm-device-usb-redirect-7.2.0-3.el9.x86_64
qemu-kvm-audio-pa-7.2.0-3.el9.x86_64
qemu-kvm-core-7.2.0-3.el9.x86_64
qemu-kvm-block-rbd-7.2.0-3.el9.x86_64
qemu-kvm-7.2.0-3.el9.x86_64


[root@dell-per730-54 ~]# rpm -qa | grep libvirt
libvirt-libs-8.10.0-2.el9.x86_64
libvirt-devel-8.10.0-2.el9.x86_64
libvirt-client-8.10.0-2.el9.x86_64
libvirt-daemon-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-core-8.10.0-2.el9.x86_64
libvirt-daemon-driver-nwfilter-8.10.0-2.el9.x86_64
libvirt-daemon-config-nwfilter-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-disk-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-iscsi-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-logical-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-mpath-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-rbd-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-scsi-8.10.0-2.el9.x86_64
libvirt-daemon-driver-storage-8.10.0-2.el9.x86_64
libvirt-daemon-driver-interface-8.10.0-2.el9.x86_64
libvirt-daemon-driver-secret-8.10.0-2.el9.x86_64
libvirt-daemon-driver-qemu-8.10.0-2.el9.x86_64
libvirt-daemon-driver-nodedev-8.10.0-2.el9.x86_64
libvirt-daemon-driver-network-8.10.0-2.el9.x86_64
libvirt-daemon-config-network-8.10.0-2.el9.x86_64
libvirt-8.10.0-2.el9.x86_64
python3-libvirt-8.10.0-1.el9.x86_64
libvisual-0.4.0-34.el9.x86_64
libvirt-glib-4.0.0-3.el9.x86_64
libvirt-daemon-kvm-8.10.0-2.el9.x86_64


[root@dell-per730-54 ~]# getenforce 
Enforcing

[root@dell-per730-54 ~]# virsh dumpxml gg
<domain type='kvm' id='1'>
  <name>gg</name>
  <uuid>37425e76-af6a-44a6-aba0-73434afe34c0</uuid>
  <memory unit='KiB'>8388608</memory>
  <currentMemory unit='KiB'>8388608</currentMemory>
  <memoryBacking>
    <hugepages>
      <page size='1048576' unit='KiB'/>
    </hugepages>
    <access mode='shared'/>
  </memoryBacking>
  <vcpu placement='static'>3</vcpu>
  <cputune>
    <vcpupin vcpu='0' cpuset='7'/>
    <vcpupin vcpu='1' cpuset='5'/>
    <vcpupin vcpu='2' cpuset='29'/>
  </cputune>
  <numatune>
    <memory mode='strict' nodeset='1'/>
  </numatune>
  <resource>
    <partition>/machine</partition>
  </resource>
  <os>
    <type arch='x86_64' machine='pc-q35-rhel9.2.0'>hvm</type>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pmu state='off'/>
    <vmport state='off'/>
    <ioapic driver='qemu'/>
  </features>
  <cpu mode='host-passthrough' check='none' migratable='on'>
    <feature policy='require' name='tsc-deadline'/>
    <numa>
      <cell id='0' cpus='0-2' memory='8388608' unit='KiB' memAccess='shared'/>
    </numa>
  </cpu>
  <clock offset='utc'>
    <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>
  <pm>
    <suspend-to-mem enabled='no'/>
    <suspend-to-disk enabled='no'/>
  </pm>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2'/>
      <source file='/tmp//gg.qcow2' index='1'/>
      <backingStore/>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x01' slot='0x00' function='0x0'/>
    </disk>
    <controller type='usb' index='0' model='none'>
      <alias name='usb'/>
    </controller>
    <controller type='pci' index='0' model='pcie-root'>
      <alias name='pcie.0'/>
    </controller>
    <controller type='pci' index='1' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='1' port='0x10'/>
      <alias name='pci.1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </controller>
    <controller type='pci' index='2' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='2' port='0x11'/>
      <alias name='pci.2'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </controller>
    <controller type='pci' index='3' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='3' port='0x8'/>
      <alias name='pci.3'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </controller>
    <controller type='pci' index='4' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='4' port='0x9'/>
      <alias name='pci.4'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </controller>
    <controller type='pci' index='5' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='5' port='0xa'/>
      <alias name='pci.5'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>
    </controller>
    <controller type='pci' index='6' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='6' port='0xb'/>
      <alias name='pci.6'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x07' function='0x0'/>
    </controller>
    <controller type='sata' index='0'>
      <alias name='ide'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x1f' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='52:54:00:bb:63:7b'/>
      <source bridge='virbr0'/>
      <target dev='vnet0'/>
      <model type='virtio'/>
      <alias name='net0'/>
      <address type='pci' domain='0x0000' bus='0x02' slot='0x00' function='0x0'/>
    </interface>
    <interface type='vhostuser'>
      <mac address='52:54:00:11:8f:ea'/>
      <source type='unix' path='/tmp/vhost0' mode='server'/>
      <target dev='vhost0'/>
      <model type='virtio'/>
      <driver name='vhost' rx_queue_size='1024' tx_queue_size='1024' iommu='on' ats='on'/>
      <alias name='net1'/>
      <address type='pci' domain='0x0000' bus='0x03' slot='0x00' function='0x0'/>
    </interface>
    <interface type='vhostuser'>
      <mac address='52:54:00:11:8f:eb'/>
      <source type='unix' path='/tmp/vhost1' mode='server'/>
      <target dev='vhost1'/>
      <model type='virtio'/>
      <driver name='vhost' rx_queue_size='1024' tx_queue_size='1024' iommu='on' ats='on'/>
      <alias name='net2'/>
      <address type='pci' domain='0x0000' bus='0x04' slot='0x00' function='0x0'/>
    </interface>
    <serial type='pty'>
      <source path='/dev/pts/0'/>
      <target type='isa-serial' port='0'>
        <model name='isa-serial'/>
      </target>
      <alias name='serial0'/>
    </serial>
    <console type='pty' tty='/dev/pts/0'>
      <source path='/dev/pts/0'/>
      <target type='serial' port='0'/>
      <alias name='serial0'/>
    </console>
    <input type='mouse' bus='ps2'>
      <alias name='input0'/>
    </input>
    <input type='keyboard' bus='ps2'>
      <alias name='input1'/>
    </input>
    <graphics type='vnc' port='5900' autoport='yes' listen='0.0.0.0'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <audio id='1' type='none'/>
    <video>
      <model type='cirrus' vram='16384' heads='1' primary='yes'/>
      <alias name='video0'/>
      <address type='pci' domain='0x0000' bus='0x05' slot='0x00' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <alias name='balloon0'/>
      <address type='pci' domain='0x0000' bus='0x06' slot='0x00' function='0x0'/>
    </memballoon>
    <iommu model='intel'>
      <driver intremap='on' caching_mode='on' iotlb='on'/>
      <alias name='iommu0'/>
    </iommu>
  </devices>
  <seclabel type='dynamic' model='selinux' relabel='yes'>
    <label>system_u:system_r:svirt_t:s0:c392,c809</label>
    <imagelabel>system_u:object_r:svirt_image_t:s0:c392,c809</imagelabel>
  </seclabel>
  <seclabel type='dynamic' model='dac' relabel='yes'>
    <label>+107:+1001</label>
    <imagelabel>+107:+1001</imagelabel>
  </seclabel>
</domain>



[root@dell-per730-54 ~]# ovs-vsctl show
a2fec61a-fa3e-46c6-8653-26cd0d17bb44
    Bridge ovsbr0
        datapath_type: netdev
        Port vhost0
            Interface vhost0
                type: dpdkvhostuserclient
                options: {vhost-server-path="/tmp/vhost0"}
        Port vhost1
            Interface vhost1
                type: dpdkvhostuserclient
                options: {vhost-server-path="/tmp/vhost1"}
        Port dpdk0
            Interface dpdk0
                type: dpdk
                options: {dpdk-devargs="0000:84:00.0", n_rxq="1"}
        Port dpdk1
            Interface dpdk1
                type: dpdk
                options: {dpdk-devargs="0000:84:00.1", n_rxq="1"}
        Port ovsbr0
            Interface ovsbr0
                type: internal
    ovs_version: "2.17.6"
[root@dell-per730-54 ~]# ll /tmp/
total 6852284
-rw-r--r--. 1 root root           22020 Jan 28 21:08 all_cmd_file
-rw-r--r--. 1 qemu hugetlbfs 3516334080 Jan 28 21:07 gg.qcow2
-rw-r--r--. 1 root root             126 Jan 28 21:01 lib_nc_sync.log
-rw-r--r--. 1 root root      3500343296 Nov 29 08:33 rhel9.2-vsperf-1Q-viommu.qcow2
srwxr-xr-x. 1 root root               0 Jan 28 20:58 rstrntsync.sock
drwx------. 3 root root              17 Jan 28 20:57 systemd-private-8ff4e98348f6414cb6946efb41ad678a-chronyd.service-YlyeHU
drwx------. 3 root root              17 Jan 28 20:57 systemd-private-8ff4e98348f6414cb6946efb41ad678a-dbus-broker.service-RauBDJ
drwx------. 3 root root              17 Jan 28 20:57 systemd-private-8ff4e98348f6414cb6946efb41ad678a-systemd-logind.service-1slFww
srwxrwxr-x. 1 qemu hugetlbfs          0 Jan 28 21:07 vhost0
srwxrwxr-x. 1 qemu hugetlbfs          0 Jan 28 21:07 vhost1


[root@dell-per730-54 ~]# rpm -qa | grep openv
kernel-kernel-networking-openvswitch-common-2.0-290.noarch
openvswitch-selinux-extra-policy-1.0-31.el9fdp.noarch
openvswitch2.17-2.17.0-62.el9fdp.x86_64

How reproducible:
Always

Steps to Reproduce:
config vm with two vhostuserclient interface
virsh start vm 
vm hanged 

Jan 28 21:03:11 dell-per730-54 systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Jan 28 21:03:41 dell-per730-54 systemd[1]: Stopping Virtualization daemon...
Jan 28 21:03:41 dell-per730-54 systemd[1]: Starting Virtualization qemu daemon...
Jan 28 21:03:41 dell-per730-54 systemd[1]: Started Virtualization qemu daemon.
Jan 28 21:03:41 dell-per730-54 systemd[1]: libvirtd.service: Deactivated successfully.
Jan 28 21:03:41 dell-per730-54 systemd[1]: libvirtd.service: Unit process 19328 (dnsmasq) remains running after unit stopped.
Jan 28 21:03:41 dell-per730-54 systemd[1]: libvirtd.service: Unit process 19329 (dnsmasq) remains running after unit stopped.
Jan 28 21:03:41 dell-per730-54 systemd[1]: Stopped Virtualization daemon.
Jan 28 21:03:42 dell-per730-54 kernel: L1TF CPU bug present and SMT on, data leak possible. See CVE-2018-3646 and https://www.kernel.org/doc/html/latest/admin-guide/hw-vuln/l1tf.html for details.
Jan 28 21:03:52 dell-per730-54 systemd[1]: Listening on Virtual machine log manager socket.
Jan 28 21:03:52 dell-per730-54 systemd[1]: Started Virtual machine log manager.
Jan 28 21:03:52 dell-per730-54 virtlogd[19846]: libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:03:52 dell-per730-54 virtlogd[19846]: hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:03:52 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:03:52 dell-per730-54 virtqemud[19644]: libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:03:52 dell-per730-54 virtqemud[19644]: hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:03:52 dell-per730-54 virtqemud[19644]: Domain id=1 name='guestfs-6z3u0p60zfkckt82' uuid=5821af66-b030-4547-aec1-82a49d6e2446 is tainted: deprecated-config (machine type 'pc-i440fx-rhel7.6.0')
Jan 28 21:03:52 dell-per730-54 systemd-machined[1400]: New machine qemu-1-guestfs-6z3u0p60zfkckt82.
Jan 28 21:03:52 dell-per730-54 systemd[1]: Started Virtual Machine qemu-1-guestfs-6z3u0p60zfkckt82.
Jan 28 21:03:57 dell-per730-54 restraintd[1729]: *** Current Time: Sat Jan 28 21:03:57 2023  Localwatchdog at: Sun Jan 29 08:49:57 2023
Jan 28 21:03:57 dell-per730-54 systemd[1]: machine-qemu\x2d1\x2dguestfs\x2d6z3u0p60zfkckt82.scope: Deactivated successfully.
Jan 28 21:03:57 dell-per730-54 systemd[1]: machine-qemu\x2d1\x2dguestfs\x2d6z3u0p60zfkckt82.scope: Consumed 4.290s CPU time.
Jan 28 21:03:57 dell-per730-54 systemd-machined[1400]: Machine qemu-1-guestfs-6z3u0p60zfkckt82 terminated.
Jan 28 21:03:57 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:03:57 dell-per730-54 virtqemud[19884]: 2023-01-29 02:03:57.659+0000: 19884: info : libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:03:57 dell-per730-54 virtqemud[19884]: 2023-01-29 02:03:57.659+0000: 19884: info : hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:03:57 dell-per730-54 virtqemud[19884]: 2023-01-29 02:03:57.659+0000: 19884: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsIZA8nC/console.sock
Jan 28 21:03:57 dell-per730-54 virtqemud[19884]: 2023-01-29 02:03:57.660+0000: 19884: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsIZA8nC/guestfsd.sock
Jan 28 21:04:00 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:04:00 dell-per730-54 virtqemud[19644]: Domain id=2 name='guestfs-kxsin23sxbmovuwz' uuid=fd775608-630f-4a35-8e31-385c4048ff6d is tainted: deprecated-config (machine type 'pc-i440fx-rhel7.6.0')
Jan 28 21:04:00 dell-per730-54 systemd-machined[1400]: New machine qemu-2-guestfs-kxsin23sxbmovuwz.
Jan 28 21:04:00 dell-per730-54 systemd[1]: Started Virtual Machine qemu-2-guestfs-kxsin23sxbmovuwz.
Jan 28 21:04:04 dell-per730-54 systemd[1]: machine-qemu\x2d2\x2dguestfs\x2dkxsin23sxbmovuwz.scope: Deactivated successfully.
Jan 28 21:04:04 dell-per730-54 systemd[1]: machine-qemu\x2d2\x2dguestfs\x2dkxsin23sxbmovuwz.scope: Consumed 4.304s CPU time.
Jan 28 21:04:04 dell-per730-54 systemd-machined[1400]: Machine qemu-2-guestfs-kxsin23sxbmovuwz terminated.
Jan 28 21:04:04 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:04:04 dell-per730-54 virtqemud[20116]: 2023-01-29 02:04:04.663+0000: 20116: info : libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:04:04 dell-per730-54 virtqemud[20116]: 2023-01-29 02:04:04.663+0000: 20116: info : hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:04:04 dell-per730-54 virtqemud[20116]: 2023-01-29 02:04:04.663+0000: 20116: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfs7HEehR/console.sock
Jan 28 21:04:04 dell-per730-54 virtqemud[20116]: 2023-01-29 02:04:04.664+0000: 20116: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfs7HEehR/guestfsd.sock
Jan 28 21:04:41 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:04:41 dell-per730-54 virtqemud[19644]: Domain id=3 name='guestfs-534ev2d9rqzmvkk6' uuid=4f478221-5ca2-4650-8082-fa92b01447e4 is tainted: deprecated-config (machine type 'pc-i440fx-rhel7.6.0')
Jan 28 21:04:41 dell-per730-54 systemd-machined[1400]: New machine qemu-3-guestfs-534ev2d9rqzmvkk6.
Jan 28 21:04:41 dell-per730-54 systemd[1]: Started Virtual Machine qemu-3-guestfs-534ev2d9rqzmvkk6.
Jan 28 21:04:45 dell-per730-54 systemd[1]: machine-qemu\x2d3\x2dguestfs\x2d534ev2d9rqzmvkk6.scope: Deactivated successfully.
Jan 28 21:04:45 dell-per730-54 systemd[1]: machine-qemu\x2d3\x2dguestfs\x2d534ev2d9rqzmvkk6.scope: Consumed 4.309s CPU time.
Jan 28 21:04:45 dell-per730-54 systemd-machined[1400]: Machine qemu-3-guestfs-534ev2d9rqzmvkk6 terminated.
Jan 28 21:04:45 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:04:45 dell-per730-54 virtqemud[20423]: 2023-01-29 02:04:45.827+0000: 20423: info : libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:04:45 dell-per730-54 virtqemud[20423]: 2023-01-29 02:04:45.827+0000: 20423: info : hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:04:45 dell-per730-54 virtqemud[20423]: 2023-01-29 02:04:45.827+0000: 20423: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfs3vnfBo/console.sock
Jan 28 21:04:45 dell-per730-54 virtqemud[20423]: 2023-01-29 02:04:45.827+0000: 20423: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfs3vnfBo/guestfsd.sock
Jan 28 21:04:57 dell-per730-54 restraintd[1729]: *** Current Time: Sat Jan 28 21:04:57 2023  Localwatchdog at: Sun Jan 29 08:49:57 2023
Jan 28 21:05:16 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:05:16 dell-per730-54 virtqemud[19644]: Domain id=4 name='guestfs-m7n5b45n700amupx' uuid=7d211bbf-1721-4401-b125-d26d08b17917 is tainted: deprecated-config (machine type 'pc-i440fx-rhel7.6.0')
Jan 28 21:05:16 dell-per730-54 systemd-machined[1400]: New machine qemu-4-guestfs-m7n5b45n700amupx.
Jan 28 21:05:16 dell-per730-54 systemd[1]: Started Virtual Machine qemu-4-guestfs-m7n5b45n700amupx.
Jan 28 21:05:57 dell-per730-54 restraintd[1729]: *** Current Time: Sat Jan 28 21:05:57 2023  Localwatchdog at: Sun Jan 29 08:49:57 2023
Jan 28 21:06:00 dell-per730-54 systemd[1]: machine-qemu\x2d4\x2dguestfs\x2dm7n5b45n700amupx.scope: Deactivated successfully.
Jan 28 21:06:00 dell-per730-54 systemd[1]: machine-qemu\x2d4\x2dguestfs\x2dm7n5b45n700amupx.scope: Consumed 38.039s CPU time.
Jan 28 21:06:00 dell-per730-54 systemd-machined[1400]: Machine qemu-4-guestfs-m7n5b45n700amupx terminated.
Jan 28 21:06:00 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:06:00 dell-per730-54 virtqemud[20580]: 2023-01-29 02:06:00.772+0000: 20580: info : libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:06:00 dell-per730-54 virtqemud[20580]: 2023-01-29 02:06:00.772+0000: 20580: info : hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:06:00 dell-per730-54 virtqemud[20580]: 2023-01-29 02:06:00.772+0000: 20580: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfs9nqfob/console.sock
Jan 28 21:06:00 dell-per730-54 virtqemud[20580]: 2023-01-29 02:06:00.772+0000: 20580: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfs9nqfob/guestfsd.sock
Jan 28 21:06:01 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:06:01 dell-per730-54 virtqemud[19644]: Domain id=5 name='guestfs-uflryhqlah8t799j' uuid=40525343-8dd2-4716-a993-5abaf406585c is tainted: deprecated-config (machine type 'pc-i440fx-rhel7.6.0')
Jan 28 21:06:01 dell-per730-54 systemd-machined[1400]: New machine qemu-5-guestfs-uflryhqlah8t799j.
Jan 28 21:06:01 dell-per730-54 systemd[1]: Started Virtual Machine qemu-5-guestfs-uflryhqlah8t799j.
Jan 28 21:06:40 dell-per730-54 systemd[1]: machine-qemu\x2d5\x2dguestfs\x2duflryhqlah8t799j.scope: Deactivated successfully.
Jan 28 21:06:40 dell-per730-54 systemd[1]: machine-qemu\x2d5\x2dguestfs\x2duflryhqlah8t799j.scope: Consumed 37.366s CPU time.
Jan 28 21:06:40 dell-per730-54 systemd-machined[1400]: Machine qemu-5-guestfs-uflryhqlah8t799j terminated.
Jan 28 21:06:40 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:06:40 dell-per730-54 virtqemud[20678]: 2023-01-29 02:06:40.525+0000: 20678: info : libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:06:40 dell-per730-54 virtqemud[20678]: 2023-01-29 02:06:40.525+0000: 20678: info : hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:06:40 dell-per730-54 virtqemud[20678]: 2023-01-29 02:06:40.525+0000: 20678: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsRyCZBS/console.sock
Jan 28 21:06:40 dell-per730-54 virtqemud[20678]: 2023-01-29 02:06:40.525+0000: 20678: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsRyCZBS/guestfsd.sock
Jan 28 21:06:41 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:06:41 dell-per730-54 virtqemud[19644]: Domain id=6 name='guestfs-wcyqxpcos8rsoyep' uuid=61de6d19-869c-4fd3-a45f-363e7565bc64 is tainted: deprecated-config (machine type 'pc-i440fx-rhel7.6.0')
Jan 28 21:06:41 dell-per730-54 systemd-machined[1400]: New machine qemu-6-guestfs-wcyqxpcos8rsoyep.
Jan 28 21:06:41 dell-per730-54 systemd[1]: Started Virtual Machine qemu-6-guestfs-wcyqxpcos8rsoyep.
Jan 28 21:06:45 dell-per730-54 systemd[1]: machine-qemu\x2d6\x2dguestfs\x2dwcyqxpcos8rsoyep.scope: Deactivated successfully.
Jan 28 21:06:45 dell-per730-54 systemd[1]: machine-qemu\x2d6\x2dguestfs\x2dwcyqxpcos8rsoyep.scope: Consumed 4.295s CPU time.
Jan 28 21:06:45 dell-per730-54 systemd-machined[1400]: Machine qemu-6-guestfs-wcyqxpcos8rsoyep terminated.
Jan 28 21:06:45 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:06:45 dell-per730-54 virtqemud[20804]: 2023-01-29 02:06:45.492+0000: 20804: info : libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:06:45 dell-per730-54 virtqemud[20804]: 2023-01-29 02:06:45.492+0000: 20804: info : hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:06:45 dell-per730-54 virtqemud[20804]: 2023-01-29 02:06:45.492+0000: 20804: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsxRwGph/console.sock
Jan 28 21:06:45 dell-per730-54 virtqemud[20804]: 2023-01-29 02:06:45.492+0000: 20804: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsxRwGph/guestfsd.sock
Jan 28 21:06:47 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:06:47 dell-per730-54 virtqemud[19644]: Domain id=7 name='guestfs-ny4pdb9gb5v61036' uuid=e6568168-4f9b-4012-b93a-539a2ea1a8ea is tainted: deprecated-config (machine type 'pc-i440fx-rhel7.6.0')
Jan 28 21:06:47 dell-per730-54 systemd-machined[1400]: New machine qemu-7-guestfs-ny4pdb9gb5v61036.
Jan 28 21:06:47 dell-per730-54 systemd[1]: Started Virtual Machine qemu-7-guestfs-ny4pdb9gb5v61036.
Jan 28 21:06:57 dell-per730-54 restraintd[1729]: *** Current Time: Sat Jan 28 21:06:57 2023  Localwatchdog at: Sun Jan 29 08:49:57 2023
Jan 28 21:07:28 dell-per730-54 systemd[1]: machine-qemu\x2d7\x2dguestfs\x2dny4pdb9gb5v61036.scope: Deactivated successfully.
Jan 28 21:07:28 dell-per730-54 systemd[1]: machine-qemu\x2d7\x2dguestfs\x2dny4pdb9gb5v61036.scope: Consumed 39.090s CPU time.
Jan 28 21:07:28 dell-per730-54 systemd-machined[1400]: Machine qemu-7-guestfs-ny4pdb9gb5v61036 terminated.
Jan 28 21:07:28 dell-per730-54 virtlogd[19846]: Client hit max requests limit 1. This may result in keep-alive timeouts. Consider tuning the max_client_requests server parameter
Jan 28 21:07:28 dell-per730-54 virtqemud[21058]: 2023-01-29 02:07:28.489+0000: 21058: info : libvirt version: 8.10.0, package: 2.el9 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2022-12-06-04:27:41, )
Jan 28 21:07:28 dell-per730-54 virtqemud[21058]: 2023-01-29 02:07:28.489+0000: 21058: info : hostname: dell-per730-54.rhts.eng.pek2.redhat.com
Jan 28 21:07:28 dell-per730-54 virtqemud[21058]: 2023-01-29 02:07:28.489+0000: 21058: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsVYm8an/console.sock
Jan 28 21:07:28 dell-per730-54 virtqemud[21058]: 2023-01-29 02:07:28.489+0000: 21058: warning : virSecuritySELinuxRestoreFileLabel:1485 : cannot lookup default selinux label for /tmp/libguestfsVYm8an/guestfsd.sock
Jan 28 21:07:28 dell-per730-54 systemd[1]: Starting Virtualization daemon...
Jan 28 21:07:28 dell-per730-54 systemd[1]: Stopping Virtualization qemu daemon...
Jan 28 21:07:28 dell-per730-54 systemd[1]: virtqemud.service: Deactivated successfully.
Jan 28 21:07:28 dell-per730-54 systemd[1]: Stopped Virtualization qemu daemon.
Jan 28 21:07:28 dell-per730-54 systemd[1]: virtqemud.service: Consumed 1.214s CPU time.






Actual results:
vm hanged 

Expected results:
It works fine 

Additional info:

Comment 2 jingzhao 2023-01-29 02:49:47 UTC
Hello Yiwei

Could you reproduce it on qemu side?

Thanks
Jing

Comment 3 Hekai Wang 2023-01-29 02:51:03 UTC
Here is the job link https://bugzilla.redhat.com/show_bug.cgi?id=2165278

Comment 4 Peter Xu 2023-02-01 15:32:37 UTC
(In reply to Hekai Wang from comment #3)
> Here is the job link https://bugzilla.redhat.com/show_bug.cgi?id=2165278

The link seems wrong.

Besides what Jing suggested, one can gdb attach to the QEMU process and dump the user stacks.

gdb -p $QEMU_PID
(gdb) thread apply all bt

Comment 5 Hekai Wang 2023-02-02 02:14:42 UTC
(In reply to Peter Xu from comment #4)
> (In reply to Hekai Wang from comment #3)
> > Here is the job link https://bugzilla.redhat.com/show_bug.cgi?id=2165278
> 
> The link seems wrong.
> 
> Besides what Jing suggested, one can gdb attach to the QEMU process and dump
> the user stacks.
> 
> gdb -p $QEMU_PID
> (gdb) thread apply all bt

Sorry for the wrong link 
Here is the correct job link https://beaker.engineering.redhat.com/jobs/7476822

I will try to debug it and paste the bt stack

Comment 6 Laurent Vivier 2023-02-14 11:16:23 UTC
Could you provide the qemu logs from libvirtd?
Could you provide the qemu command line?

What is the version of the guest OS?

With RHEL 7.9 guest has a known bug, see BZ 2156876

Could you provide the QEMU backtrace?

Comment 9 Laurent Vivier 2023-02-15 07:56:05 UTC
Jarda,

it seems there are some warnings related to virtqemud and SELinux in the logs: could someone from libvirt have a look?

Thanks

Comment 12 Jaroslav Suchanek 2023-02-16 12:25:35 UTC
I haven't found libvirt debug logs in the attached sos report. We will need one. The log from comment 0 is not log from the domain named 'gg', which is being reported as stuck.

There is the gg domain log though containing following errors.

2023-01-29T02:07:32.493604Z qemu-kvm: -chardev socket,id=charnet1,path=/tmp/vhost0,server=on: info: QEMU waiting for connection on: disconnected:unix:/tmp/vhost0,server=on
2023-01-29T02:07:33.212264Z qemu-kvm: -chardev socket,id=charnet2,path=/tmp/vhost1,server=on: info: QEMU waiting for connection on: disconnected:unix:/tmp/vhost1,server=on
char device redirected to /dev/pts/0 (label charserial0)
2023-01-29T02:07:34.653884Z qemu-kvm: -device {"driver":"cirrus-vga","id":"video0","bus":"pci.5","addr":"0x0"}: warning: 'cirrus-vga' is deprecated, please use a different VGA card instead
2023-01-29T02:07:44.599070Z qemu-kvm: Received unexpected msg type. Expected 22 received 40
2023-01-29T02:07:44.599114Z qemu-kvm: Fail to update device iotlb
2023-01-29T02:07:44.599185Z qemu-kvm: Received unexpected msg type. Expected 40 received 22
2023-01-29T02:07:44.608331Z qemu-kvm: Received unexpected msg type. Expected 22 received 11
2023-01-29T02:07:44.608349Z qemu-kvm: Fail to update device iotlb
2023-01-29T02:07:44.608583Z qemu-kvm: Received unexpected msg type. Expected 11 received 22
2023-01-29T02:07:44.608597Z qemu-kvm: vhost VQ 1 ring restore failed: -71: Protocol error (71)
2023-01-29T02:07:44.608968Z qemu-kvm: Received unexpected msg type. Expected 22 received 11
2023-01-29T02:07:44.608979Z qemu-kvm: Fail to update device iotlb
2023-01-29T02:07:44.609335Z qemu-kvm: Received unexpected msg type. Expected 11 received 22
2023-01-29T02:07:44.609347Z qemu-kvm: vhost VQ 0 ring restore failed: -71: Protocol error (71)
2023-01-29T02:07:44.613280Z qemu-kvm: unable to start vhost net: 71: falling back on userspace virtio
2023-01-29T02:07:44.616568Z qemu-kvm: Received unexpected msg type. Expected 22 received 40

Just a speculation, placing openvswitch sockets to /tmp might not be the best idea, as the labeling might not succeed. I'm adding Michal to the loop.

Comment 13 Laurent Vivier 2023-02-16 13:20:17 UTC
(In reply to Jaroslav Suchanek from comment #12)
> I haven't found libvirt debug logs in the attached sos report. We will need
> one. The log from comment 0 is not log from the domain named 'gg', which is
> being reported as stuck.
> 
> There is the gg domain log though containing following errors.
> 
> 2023-01-29T02:07:32.493604Z qemu-kvm: -chardev
> socket,id=charnet1,path=/tmp/vhost0,server=on: info: QEMU waiting for
> connection on: disconnected:unix:/tmp/vhost0,server=on
> 2023-01-29T02:07:33.212264Z qemu-kvm: -chardev
> socket,id=charnet2,path=/tmp/vhost1,server=on: info: QEMU waiting for
> connection on: disconnected:unix:/tmp/vhost1,server=on
> char device redirected to /dev/pts/0 (label charserial0)
> 2023-01-29T02:07:34.653884Z qemu-kvm: -device
> {"driver":"cirrus-vga","id":"video0","bus":"pci.5","addr":"0x0"}: warning:
> 'cirrus-vga' is deprecated, please use a different VGA card instead
> 2023-01-29T02:07:44.599070Z qemu-kvm: Received unexpected msg type. Expected
> 22 received 40
> 2023-01-29T02:07:44.599114Z qemu-kvm: Fail to update device iotlb
> 2023-01-29T02:07:44.599185Z qemu-kvm: Received unexpected msg type. Expected
> 40 received 22
> 2023-01-29T02:07:44.608331Z qemu-kvm: Received unexpected msg type. Expected
> 22 received 11
> 2023-01-29T02:07:44.608349Z qemu-kvm: Fail to update device iotlb
> 2023-01-29T02:07:44.608583Z qemu-kvm: Received unexpected msg type. Expected
> 11 received 22
> 2023-01-29T02:07:44.608597Z qemu-kvm: vhost VQ 1 ring restore failed: -71:
> Protocol error (71)
> 2023-01-29T02:07:44.608968Z qemu-kvm: Received unexpected msg type. Expected
> 22 received 11
> 2023-01-29T02:07:44.608979Z qemu-kvm: Fail to update device iotlb
> 2023-01-29T02:07:44.609335Z qemu-kvm: Received unexpected msg type. Expected
> 11 received 22
> 2023-01-29T02:07:44.609347Z qemu-kvm: vhost VQ 0 ring restore failed: -71:
> Protocol error (71)
> 2023-01-29T02:07:44.613280Z qemu-kvm: unable to start vhost net: 71: falling
> back on userspace virtio
> 2023-01-29T02:07:44.616568Z qemu-kvm: Received unexpected msg type. Expected
> 22 received 40


Thank you Jarda.

This is a know bug fixed in qemu-kvm-7.2.0-8.el9

See BZ 2155173.

Heka, could you test with qemu-kvm-7.2.0-8.el9?