Created attachment 257135 [details] dmesg Hey, I've been getting system freezes from time to time but I wasn't sure what caused them because there were no logs or anything. A hard reboot was required then. Today I've actually found a way to reproduce this freeze and I was lucky enough that I was able to get some logs about this freezes through a remote ssh session which was very slow (you will see why.) First of all my system: uname -a: Linux 4.11.6-1-ck #1 SMP PREEMPT Thu Jun 22 02:06:23 CEST 2017 x86_64 GNU/Linux CPU: Intel i7 6700k RAM: 4 x 8GB DDR4 @ 2400MHz GPU: NVIDIA GTX 1060 with NVIDIA's latest proprietary drivers MB: Asus Z170-A with the latest BIOS Note this this also happens with the vanilla kernel as I am also using a kernel with the muqss scheduler (ck-patchset). I can reproduce this issue by doing the following: 1.) Start applications like (chromium/pidgin/spotify) 2.) Start a windows 7 vm (libvirt/kvm/virt-manager) (the vm image is on an ssd) 3.) Start a windows 10 vm (the vm image is on an hdd) This isn't a scientific reproduction and I am not even sure how exactly but this worked every time I tried it. I have observed the following: - The system freezes / It's actually more like everything is going slow (The audio was looping). Usually everything freezes and only a hard reboot was possible. But I had luck that somehow it froze (audio was in a loop, everything desktop wise was unresponsive) but I could actually move the mouse, so I quickly changed to a different tty session and could login again but again everything was very slow I couldn't even run a proper command. But I guess this was helpful because I actually saw some proper kernel warnings: NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [CPU 1/KVM:2411] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 22s! [CPU 1/KVM:2629] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [CPU 1/KVM:2411] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 22s! [CPU 1/KVM:2629] INFO: rcu_preempt self-detected stall on CPU INFO: rcu_preempt self-detected stall on CPU ... More warning which contains lots of stuff so I've simply taken a picture and attached it here. Finally I've added the dmesg from the ssh session, it is probably incomplete as after some minutes it completely froze and the connection was broken. The crash happens after the "kvm_get_msr_common: 6 callbacks suppressed" lines. It basically starts with the messages about NVRM and followed by some ata4 error messages and more. I've also included this in the attachments.
Created attachment 257137 [details] image freezes kernel messages
I was lucky a second time and was able to recover the follwing kernel log: [ +9.397431] NVRM: GPU at PCI:0000:01:00: GPU-6bc6eebc-c700-43b5-d252-2d51c49afbd9 [ +0.000004] NVRM: GPU Board Serial Number: [ +0.000002] NVRM: Xid (PCI:0000:01:00): 16, Head 00000000 Count 0000b24a [ +3.110024] NVRM: Xid (PCI:0000:01:00): 8, Channel 00000010 [Jun22 23:49] NMI watchdog: Watchdog detected hard LOCKUP on cpu 5 [ +0.000001] Modules linked in: vhost_net vhost tap fuse ctr ccm xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack libcrc32c crc32c_generic ipt_REJECT nf_reject_ipv4 xt_tcpudp tun bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic arc4 nls_iso8859_1 nls_cp437 vfat fat intel_rapl x86_pkg_temp_thermal iwlmvm intel_powerclamp coretemp kvm_intel iTCO_wdt iTCO_vendor_support eeepc_wmi kvm asus_wmi mac80211 sparse_keymap irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel pcbc iwlwifi nouveau aesni_intel aes_x86_64 crypto_simd cryptd snd_hda_intel evdev glue_helper joydev input_leds mousedev [ +0.000007] snd_hda_codec intel_cstate e1000e mac_hid intel_rapl_perf cfg80211 snd_hwdep snd_hda_core psmouse ptp hci_uart snd_pcm pps_core led_class btbcm pcspkr mxm_wmi snd_timer btqca i2c_i801 mei_me btintel ttm mei snd i2c_algo_bit soundcore bluetooth battery video rfkill i2c_hid intel_lpss_acpi intel_lpss shpchp wmi acpi_als tpm_tis kfifo_buf tpm_tis_core industrialio acpi_pad tpm button sch_fq_codel sg ip_tables x_tables ext4 crc16 jbd2 fscrypto mbcache hid_generic usbhid hid sd_mod serio_raw atkbd libps2 ahci xhci_pci libahci xhci_hcd libata usbcore scsi_mod usb_common i8042 serio nvidia_drm(PO) drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm nvidia_uvm(PO) nvidia_modeset(PO) nvidia(PO) [ +0.000009] CPU: 5 PID: 3041 Comm: CPU 1/KVM Tainted: P O 4.11.6-1-ck #1 [ +0.000000] Hardware name: System manufacturer System Product Name/Z170-A, BIOS 3401 01/25/2017 [ +0.000000] task: ffff88065aa98cc0 task.stack: ffffc9000658c000 [ +0.000000] RIP: 0010:vmx_complete_atomic_exit+0x5d/0x90 [kvm_intel] [ +0.000001] RSP: 0018:ffffc9000658fcc8 EFLAGS: 00000046 [ +0.000000] RAX: 0000000080000200 RBX: ffff880651a78000 RCX: ffff880651a78000 [ +0.000000] RDX: 0000000080000202 RSI: ffff9b01b85eeb80 RDI: ffff880651a78000 [ +0.000001] RBP: ffffc9000658fcd8 R08: ffff9b01b8727630 R09: ffff9b01b8727610 [ +0.000000] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000002 [ +0.000000] R13: 0000000000000000 R14: fffff803fc289180 R15: fffff803fcc89000 [ +0.000000] FS: 00007f93037ff700(0000) GS:ffff88086ed40000(0000) knlGS:000000af3a776000 [ +0.000001] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ +0.000000] CR2: 00007ffc841a5550 CR3: 00000007aa589000 CR4: 00000000003426e0 [ +0.000000] Call Trace: [ +0.000000] vmx_vcpu_run+0x31a/0x430 [kvm_intel] [ +0.000000] kvm_arch_vcpu_ioctl_run+0xb83/0x16a0 [kvm] [ +0.000000] kvm_vcpu_ioctl+0x2a6/0x640 [kvm] [ +0.000001] ? kvm_vcpu_ioctl+0x2a6/0x640 [kvm] [ +0.000000] ? __vfs_write+0x37/0x140 [ +0.000000] do_vfs_ioctl+0xa5/0x600 [ +0.000000] ? __fget+0x77/0xb0 [ +0.000000] SyS_ioctl+0x79/0x90 [ +0.000000] entry_SYSCALL_64_fastpath+0x1a/0xa9 [ +0.000001] RIP: 0033:0x7f931336bcb7
The thing I don't understand is that this freeze wasn't occurring very often but now I am literally unable to start the windows 10 vm. By simply starting the windows 10 vm I am getting the freeze. The dmesg log shows ata4 error messages, could this be that this is related to the hdd? (The win10 vm image is on the hdd but not the win7 image, the latter is stored on the ssd.)
I've also tested this with linux 4.12-rc6 and it also freezes here.
I might have found the indirect cause for this. Since I am using libvirt, I somehow forgot that I've had this node in the xml config: 1 <cpu mode='host-passthrough' check='none'> 2 <feature policy='disable' name='hypervisor'/> 3 </cpu> It seems that line 2 is actually causing this because the vm booted fine without that addition. This is somewhat strange as I've tested it before and it worked fine. I've also attached the win10 xml config just in case. How can this actually freeze the whole system?
Created attachment 257147 [details] win10 xml
It seems that there are other similar reports which also have similar call traces: https://bugzilla.kernel.org/show_bug.cgi?id=196143 - NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [libvirtd:923] https://bugzilla.kernel.org/show_bug.cgi?id=196149 - QEMU causes a host hang / reset on PPC64EL when used in KVM + HV mode (kvm_hv module)
I actually remember now what I did with the vm and this might be the trigger for the windows 10 vm. I remember that I've installed avast free antivirus and then restarted the vm and then it froze. I am pretty sure that avast has windows kernel modules which are using virtualization features and well, it's disabled by libvirt but when I enable it, windows booted fine without any host freezes. I assume this might have to do with the vm accessing cpu which aren't enabled somehow? But again, how can this cause the host to hang/freeze?
Ping.
Ping. This is still occurring with mainline kernel.
1) Can you include the output of "grep . /sys/module/kvm_intel/parameters" on a system where you experience freezes? 2) Can you reproduce it without the nvidia drivers? 2 is more important but 1 is easier to get.
Actually I am not using the NVIDIA driver anymore, I needed GBM so I just went with the integrated Intel HD Driver. I am currently using i915 and nvidia is uninstalled. I think you meant this command: "grep . /sys/module/kvm_intel/parameters/*", right? The grep command prints the follwing: /sys/module/kvm_intel/parameters/emulate_invalid_guest_state:Y /sys/module/kvm_intel/parameters/enable_apicv:N /sys/module/kvm_intel/parameters/enable_shadow_vmcs:Y /sys/module/kvm_intel/parameters/ept:Y /sys/module/kvm_intel/parameters/eptad:Y /sys/module/kvm_intel/parameters/fasteoi:Y /sys/module/kvm_intel/parameters/flexpriority:Y /sys/module/kvm_intel/parameters/nested:Y /sys/module/kvm_intel/parameters/ple_gap:128 /sys/module/kvm_intel/parameters/ple_window:4096 /sys/module/kvm_intel/parameters/ple_window_grow:2 /sys/module/kvm_intel/parameters/ple_window_max:1073741823 /sys/module/kvm_intel/parameters/ple_window_shrink:0 /sys/module/kvm_intel/parameters/pml:Y /sys/module/kvm_intel/parameters/preemption_timer:Y /sys/module/kvm_intel/parameters/unrestricted_guest:Y /sys/module/kvm_intel/parameters/vpid:Y I was lucky again and was able to catch the dmesg output through an ssh session. I've attached the output.
Created attachment 257733 [details] new dmesg output
Sorry, I've attached an old file. I will upload the new one shortly.
Comment on attachment 257733 [details] new dmesg output Ignore this file. This is old.
Created attachment 257735 [details] fresh dmesg output
The soft lock/freeze starts at line 873.
Can you attach your kvm_intel.ko file?
Also, please try to reproduce with nested=0.
Created attachment 257737 [details] kvm-intel
It seems that the soft lock is gone with nested=0. Do you already have a hunch/explanation what might be wrong? (I assume something with nested virtualization.)
No, unfortunately not, but I guess it's now linked to nested virtualization and an "uncommon" hypervisor (AVAST) makes the bug more interesting. I'll think of something for you to test. Can you build your own kernel too?
Yup. I can build my own kernels, no problem ;)
I seriously have no clue at all but today somehow I've managed to trigger this bug on a windows 7 vm (which doesn't use the AVAST hypervisor). I couldn't reproduce this after a forced system reset. Note: I'v re-enabled nested virtualization because my work requires it ;)
Well, it just happened again with the win 7 vm (with no avast hypervisor or anything + nested virt). The whole system freezes and I couldn't recover any logs. @Paolo Bonzini This is really frustrating. Is there any progress finding the cause of this bug?
No, I cannot reproduce it. From the logs, it seems to be a deadlock between two callers of smp_call_function, KVM and seccomp, but it's not clear what the two are waiting (interrupts are enabled). It's possible that a workaround is to pin QEMU's VCPU thread to one host VCPU. If you're using libvirt, this is easily done by modifying the virtual machine's XML.
Did you reproduce this issues with the hypervisor option disable in libvirt? AFAIK, I can only 100% reproduce this with this option in the libvirt conf: 1 <cpu mode='host-passthrough' check='none'> 2 <feature policy='disable' name='hypervisor'/> 3 </cpu> I will try that cpu pinning workaround.
I've tried the following: Limiting the vm to one vcpu and pinning it to core #0. Unfortunately the freeze still happens but I could still move the mouse but all the applications were frozen. I guess it's because of the cpu pinning. Could you reproduce this issue with the hypervisor feature disabled?
Ping. (I can still reproduce this on v4.12.8).
It seems that linux 4.13 has been released. I will try if I can still reproduce this bug with v4.13.
I can confirm that this is still reproducible with 4.13.
I can confirm that this has been fixed with 4.13.5.