vmx_host_state_area / vmx_intr_window_test / vmx_nmi_window_test / vmx_hlt_with_rvi_test fails with timeout on Bionic

[Kelsey Steele]

vmx_host_state_area / vmx_intr_window_test / vmx_nmi_window_test fails with timeout on Bionic 4.15.0-141.145 host rizzo

this failed on the previous version of bionic 4.15.0-140.144 as well, so not a regression.

vmx_host_state_area has an error before giving timeout:

04/10 01:29:18 DEBUG| utils:0153| [stderr] KVM: entry failed, hardware error 0x80000021
04/10 01:29:18 DEBUG| utils:0153| [stderr]
04/10 01:29:18 DEBUG| utils:0153| [stderr] If you're running a guest on an Intel machine without unrestricted mode
04/10 01:29:18 DEBUG| utils:0153| [stderr] support, the failure can be most likely due to the guest entering an invalid
04/10 01:29:18 DEBUG| utils:0153| [stderr] state for Intel VT. For example, the guest maybe running in big real mode
04/10 01:29:18 DEBUG| utils:0153| [stderr] which is not supported on less recent Intel processors.
04/10 01:29:18 DEBUG| utils:0153| [stderr]

....

04/10 01:29:47 DEBUG| utils:0153| [stderr] qemu-system-x86_64: terminating on signal 15 from pid 21956 (timeout)
04/10 01:29:47 DEBUG| utils:0153| [stdout] FAIL vmx_host_state_area (timeout; duration=30)

 vmx_intr_window_test / vmx_nmi_window_test shows passing until the timeout:

28. 04/10 01:29:49 DEBUG| utils:0153| [stdout] PASS: interrupt-window: active, RFLAGS.IF = 0: Activity state (0) is 'ACTIVE'
29. 04/10 01:30:19 DEBUG| utils:0153| [stderr] qemu-system-x86_64: terminating on signal 15 from pid 22161 (timeout)
30. 04/10 01:30:19 DEBUG| utils:0153| [stdout] FAIL vmx_intr_window_test (timeout; duration=30)
31. 04/10 01:30:19 ERROR| test:0414| Exception escaping from test:

------

26. 04/10 01:30:24 DEBUG| utils:0153| [stdout] PASS: NMI-window: active, blocking by NMI: #UD handler executed once (actual 1 times)
27. 04/10 01:30:53 DEBUG| utils:0153| [stderr] qemu-system-x86_64: terminating on signal 15 from pid 22570 (timeout)
28. 04/10 01:30:53 DEBUG| utils:0153| [stdout] FAIL vmx_nmi_window_test (timeout; duration=30)

[Kleber Sacilotto de Souza (kleber-souza)]

Issue also found with xenial/linux-kvm 4.4.0-1094.103.

[Guilherme G. Piccoli (gpiccoli)]

Found on B/kvm, cycle sru-20210412:

12:32:07 DEBUG| [stdout] timeout -k 1s --foreground 10 /usr/bin/qemu-system-x86_64 -nodefaults -device pc-testdev -device isa-debug-exit,iobase=0xf4,iosize=0x4 -vnc none -serial stdio -device pci-testdev -machine accel=kvm -kernel /tmp/tmp.koOEqf3dQU -smp 1 -cpu host,+vmx -append vmx_hlt_with_rvi_test # -initrd /tmp/tmp.6W3EtlGxIG
12:32:07 DEBUG| [stdout] enabling apic^M
12:32:08 DEBUG| [stdout] paging enabled^M
12:32:08 DEBUG| [stdout] cr0 = 80010011^M
12:32:08 DEBUG| [stdout] cr3 = 477000^M
12:32:08 DEBUG| [stdout] cr4 = 20^M
12:32:08 DEBUG| [stdout] ^M
12:32:08 DEBUG| [stdout] Test suite: vmx_hlt_with_rvi_test^M
12:32:17 DEBUG| [stderr] qemu-system-x86_64: terminating on signal 15 from pid 20961 (timeout)
12:32:17 DEBUG| [stdout] FAIL vmx_hlt_with_rvi_test (timeout; duration=10)

[Guilherme G. Piccoli (gpiccoli)]

Also for B/kvm, cycle sru-20210412:

12:32:49 DEBUG| [stderr] qemu-system-x86_64: terminating on signal 15 from pid 21162 (timeout)
12:32:49 DEBUG| [stdout] FAIL vmx_host_state_area (timeout; duration=30)

12:33:21 DEBUG| [stderr] qemu-system-x86_64: terminating on signal 15 from pid 21363 (timeout)
12:33:21 DEBUG| [stdout] FAIL vmx_intr_window_test (timeout; duration=30)

[Guilherme G. Piccoli (gpiccoli)]

Issue observed in B/KVM, cycle sru-20210510.

[Guilherme G. Piccoli (gpiccoli)]

Issue observed in B/KVM, cycle sru-20210531.

[Guilherme G. Piccoli (gpiccoli)]

Observed in B/aws (kernel 4.15), cycle sru-20210621.

[Guilherme G. Piccoli (gpiccoli)]

Observed in B/oracle (kernel 4.15), cycle sru-20210621.

[Guilherme G. Piccoli (gpiccoli)]

Observed in B/aws-fips (kernel 4.15), cycle sru-20210621.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Po-Hsu Lin (cypressyew)]

With test suite updated to d8a4f9e5e8 ci: Update the list of tests that we run in the Fedora Cirrus-CI

This issue still exist on Bionic, even with 10 mins timeout on these 4 tests.

It's worth noting that the vmx_host_state_area test will generate these messages in dmesg:
[ 4219.010606] kvm [17175]: vcpu0, guest rIP: 0x4085e4 kvm_set_msr_common: MSR_IA32_DEBUGCTLMSR 0x1, nop
[ 4219.059166] kvm [17175]: vcpu0, guest rIP: 0x40b099 kvm_set_msr_common: MSR_IA32_DEBUGCTLMSR 0x3, nop
[ 4219.109307] kvm [17175]: vcpu0, guest rIP: 0x410453 kvm_set_msr_common: MSR_IA32_DEBUGCTLMSR 0x1, nop
[ 4219.153933] kvm [17175]: vcpu0, guest rIP: 0x40b13a kvm_set_msr_common: MSR_IA32_DEBUGCTLMSR 0x3, nop
[ 5014.736843] *** Guest State ***
[ 5014.753543] CR0: actual=0x0000000080010031, shadow=0x0000000080010031, gh_mask=fffffffffffffff7
[ 5014.798851] CR4: actual=0x0000000000002060, shadow=0x0000000000002020, gh_mask=ffffffffffffe871
[ 5014.839351] CR3 = 0x0000000001007000
[ 5014.856094] RSP = 0x000000000053a2f8 RIP = 0x00000000004079a5
[ 5014.883133] RFLAGS=0x00000002 DR7 = 0x0000000000000400
[ 5014.910111] Sysenter RSP=aaaaaaaaaaaaaaaa CS:RIP=0008:00000000004001e4
[ 5014.940072] CS: sel=0x0008, attr=0x0a09b, limit=0xffffffff, base=0x0000000000000000
[ 5014.977109] DS: sel=0x0010, attr=0x0c093, limit=0xffffffff, base=0x0000000000000000
[ 5015.012935] SS: sel=0x0010, attr=0x0c093, limit=0xffffffff, base=0x0000000000000000
[ 5015.048569] ES: sel=0x0010, attr=0x0c093, limit=0xffffffff, base=0x0000000000000000
[ 5015.084293] FS: sel=0x0010, attr=0x0c093, limit=0xffffffff, base=0x0000000000000000
[ 5015.120186] GS: sel=0x0010, attr=0x0c093, limit=0xffffffff, base=0x0000000000539590
[ 5015.155731] GDTR: limit=0x0000ffff, base=0x000000000042af80
[ 5015.191524] LDTR: sel=0x0000, attr=0x10000, limit=0x00000000, base=0x0000000000000000
[ 5015.227181] IDTR: limit=0x0000ffff, base=0x000000000054af00
[ 5015.263048] TR: sel=0x0080, attr=0x0008b, limit=0x00000067, base=0x0000000000544760
[ 5015.303739] EFER = 0x0000000000000500 PAT = 0x0007040600070406
[ 5015.332411] DebugCtl = 0x0000000000000000 DebugExceptions = 0x0000000000000000
[ 5015.366642] Interruptibility = 00000000 ActivityState = 00000000
[ 5015.394930] InterruptStatus = 0000
[ 5015.410633] *** Host State ***
[ 5015.424791] RIP = 0xffffffffc07b454c RSP = 0xffffbfc98a3c7c98
[ 5015.451433] CS=0010 SS=0018 DS=0000 ES=0000 FS=0000 GS=0000 TR=0040
[ 5015.480408] FSBase=00007f571eaa4700 GSBase=ffff9c02df480000 TRBase=fffffe00001ed000
[ 5015.515285] GDTBase=fffffe00001eb000 IDTBase=fffffe0000000000
[ 5015.541569] CR0=0000000080050033 CR3=000000084e7d2002 CR4=00000000003626e0
[ 5015.572969] Sysenter RSP=fffffe00001ed000 CS:RIP=0010:ffffffffb9a01b00
[ 5015.602954] EFER = 0x0000000000000d01 PAT = 0x0407050600070106
[ 5015.630027] *** Control State ***
[ 5015.645470] PinBased=000000bf CPUBased=96a069fe SecondaryExec=000277eb
[ 5015.675481] EntryControls=0000d3ff ExitControls=002fefff
[ 5015.699919] ExceptionBitmap=00060042 PFECmask=00000000 PFECmatch=00000000
[ 5015.731131] VMEntry: intr_info=00000000 errcode=00000000 ilen=00000000
[ 5015.76125...