Dasharo / dasharo-issues

The Dasharo issue tracker
https://dasharo.com/
25 stars 0 forks source link

MSI Z690A coreboot crash on reboot after suspend/resume cycle in Qubes OS #427

Open verygreen opened 1 year ago

verygreen commented 1 year ago

Dasharo version v1.1.1

Dasharo variant MSU Z690-A wifi DDR5 128G RAM

Affected component(s) or functionality reboot crashes the board

Brief summary issuing a reboot sometime after a suspend/resume cycle makes the board beep with long beeps and then hang in place blinking HDD access light. Connecting a serial console I see this crash emitted:

CPU Index 0 - APIC 0 Unexpected Exception:13 @ 10:46b315d8 - Halting
Code: 0 eflags: 00010002 cr2: 00000000
eax: 00000005 ebx: 46b270a0 ecx: 0000003a edx: 00000000
edi: 00000005 esi: 00000000 ebp: 465b5e48 esp: 465b5e2c

0x46b31598: ff 50 14 59 59 c3 55 8b 
0x46b315a0: ec 83 ec 14 56 57 8b f2 
0x46b315a8: 89 4d fc 8b 4d fc 0f 32 
0x46b315b0: ff 75 10 8b ce ff 75 0c 
0x46b315b8: 52 8b 55 08 50 e8 9e 00 
0x46b315c0: 00 00 8b f8 8b f2 83 c4 
0x46b315c8: 10 89 7d f0 89 75 f4 8b 
0x46b315d0: 55 f4 8b 45 f0 8b 4d fc 
0x46b315d8: 0f 30 8b c7 8b d6 5f 5e 
0x46b315e0: c9 c3 53 56 57 6a fe 8b 
0x46b315e8: da 8b f1 8b 4c 24 14 83 
0x46b315f0: c8 ff 8b 54 24 1c 5f d3 
0x46b315f8: e7 8b cb d3 e0 f7 d7 23 
0x46b31600: c7 d3 e2 f7 d0 23 d7 5f 
0x46b31608: 23 c6 5e 0b c2 5b c3 55 
0x46b31610: 8b ec 83 ec 10 83 4d f4 
0x465b5ea8: 0x4679fa70
0x465b5ea4: 0x01000000
0x465b5ea0: 0x00000006
0x465b5e9c: 0x46b2a000
0x465b5e98: 0x00000007
0x465b5e94: 0x46b270a0
0x465b5e90: 0x0000000b
0x465b5e8c: 0x46b31a1c
0x465b5e88: 0x465b5eb0
0x465b5e84: 0x00000000
0x465b5e80: 0x00000000
0x465b5e7c: 0x46b2b000
0x465b5e78: 0x46b31932
0x465b5e74: 0x46b2f209
0x465b5e70: 0x00000100
0x465b5e6c: 0x465b5e88
0x465b5e68: 0x46b2f209
0x465b5e64: 0x46b2b000
0x465b5e60: 0x46b2b000
0x465b5e5c: 0x46b2c000
0x465b5e58: 0x00000000
0x465b5e54: 0x00000000
0x465b5e50: 0x00000001
0x465b5e4c: 0x46b2f1f6
0x465b5e48: 0x465b5ea8 <-ebp
0x465b5e44: 0x0000003a
0x465b5e40: 0xffffffff
0x465b5e3c: 0x00000000
0x465b5e38: 0x00000005
0x465b5e34: 0x00000003
0x465b5e30: 0x00000006
0x465b5e2c: 0x46b2a000 <-esp

The host os is Qubes OS

How reproducible 100%

How to reproduce

Steps to reproduce the behavior:

  1. Boot into Qubes OS
  2. Suspend to RAM
  3. resume after a bit
  4. select logout -> reboot

Expected behavior system should reboot

Actual behavior system crashes.

Additional context On a side note, when a crash like this happen, it would be great if the system reset itself in a short while so no manuakl intervention was necessary when it happens.

verygreen commented 1 year ago

I tested windows and a fedora38 livecd and both suspend resume and reboot just fine, so the problem is specific to Qubes OS usage

verygreen commented 1 year ago

another note that might be important, I guess - Qubes runs with usb controller disconnected from dom0 (ps/2 keyboard). Because of this(?) the resume by pressing a key on the keyboard does not work, have to press the power button on the case.

verygreen commented 1 year ago

I captured lolglevel8 coreboot log after reboot for QubesOS and for Fedora38 livecd (does not crash) for comparison purposes. Does not tell me much to my untrained eye, but hopefully would help you QubesOS (crash): suspend-qubes-afterresume-reboot.txt

Fedora (no crash): suspend-fedora-afterresume-reboot.txt

verygreen commented 1 year ago

to save you time, here's the diff. Not sure how important, but

# diff -u  /tmp/suspend2-afterresume.txt /tmp/suspend-fedora-afterresume.txt  
--- /tmp/suspend2-afterresume.txt   2023-04-25 17:00:06.737231032 -0400
+++ /tmp/suspend-fedora-afterresume.txt 2023-04-25 18:32:46.862987271 -0400
@@ -191,7 +191,7 @@
 TPM: Digest of `CBFS: fallback/ramstage` to PCR 2 logged
 Loading module at 0x4653b000 with entry 0x4653b000. filesize: 0x48800 memsize: 0x987b0
 Processing 5289 relocs. Offset value of 0x4253b000
-BS: postcar times (exec / console): total (unknown) / 62 ms
+BS: postcar times (exec / console): total (unknown) / 61 ms

 coreboot-msi_ms7d25_v1.1.1-dirty-v1.1.1 Wed Feb 22 16:59:52 UTC 2023 ramstage starting (log level: 8)...
@@ -261,7 +261,7 @@
 Found variable with state 3f and GUID: d15b327e-ff2d-4fc1-abf6c12bd08c1359
 FMAP: area SI_DESC found @ 0 (4096 bytes)
 Update of Descriptor is not required!
-BS: BS_PRE_DEVICE entry times (exec / console): 4 / 418 ms
+BS: BS_PRE_DEVICE entry times (exec / console): 4 / 419 ms
 FMAP: area FW_MAIN_A found @ 10c8000 (5324544 bytes)
 CBFS: Found 'cpu_microcode_blob.bin' @0x18c80 size 0x68000 in mcache @0x46bfe9a0
 VB2:vb2_secdata_kernel_get() VB2_SECDATA_KERNEL_FLAGS not supported for secdata_kernel v0, return 0
@@ -286,54 +286,54 @@
 Waiting for 10ms after sending INIT.
 Waiting for SIPI to complete...
 LAPIC 0x1 in XAPIC mode.
-LAPIC 0x19 in XAPIC mode.
-LAPIC 0x10 in XAPIC mode.
-LAPIC 0x9 in XAPIC mode.
-LAPIC 0x21 in XAPIC mode.
-AP: slot 7 apic_id 1, MCU rev: 0x0000001f
-LAPIC 0x44 in XAPIC mode.
-LAPIC 0x28 in XAPIC mode.
-LAPIC 0x4a in XAPIC mode.
-LAPIC 0x30 in XAPIC mode.
-LAPIC 0x18 in XAPIC mode.
-LAPIC 0x4c in XAPIC mode.
+done.
 LAPIC 0x42 in XAPIC mode.
-LAPIC 0x46 in XAPIC mode.
+LAPIC 0x9 in XAPIC mode.
 LAPIC 0x39 in XAPIC mode.
-AP: slot 13 apic_id 30, MCU rev: 0x0000001f
+LAPIC 0x19 in XAPIC mode.
+Waiting for SIPI to complete...
+done.
+LAPIC 0x46 in XAPIC mode.
+LAPIC 0x40 in XAPIC mode.
+AP: slot 9 apic_id 1, MCU rev: 0x0000001f
+LAPIC 0x18 in XAPIC mode.
+AP: slot 18 apic_id 19, MCU rev: 0x0000001f
+LAPIC 0x10 in XAPIC mode.
+LAPIC 0x20 in XAPIC mode.
+AP: slot 15 apic_id 18, MCU rev: 0x0000001f
+AP: slot 11 apic_id 42, MCU rev: 0x0000001f
 LAPIC 0x4e in XAPIC mode.
-LAPIC 0x11 in XAPIC mode.
+AP: slot 4 apic_id 46, MCU rev: 0x0000001f
+LAPIC 0x4c in XAPIC mode.
 LAPIC 0x48 in XAPIC mode.
-AP: slot 4 apic_id 4e, MCU rev: 0x0000001f
-LAPIC 0x40 in XAPIC mode.
+LAPIC 0x44 in XAPIC mode.
+LAPIC 0x4a in XAPIC mode.
+AP: slot 16 apic_id 20, MCU rev: 0x0000001f
 AP: slot 3 apic_id 4c, MCU rev: 0x0000001f
-AP: slot 8 apic_id 39, MCU rev: 0x0000001f
+AP: slot 7 apic_id 40, MCU rev: 0x0000001f
+LAPIC 0x30 in XAPIC mode.
+AP: slot 17 apic_id 10, MCU rev: 0x0000001f
+AP: slot 2 apic_id 44, MCU rev: 0x0000001f
+LAPIC 0x28 in XAPIC mode.
+AP: slot 5 apic_id 4e, MCU rev: 0x0000001f
+LAPIC 0x8 in XAPIC mode.
+AP: slot 13 apic_id 9, MCU rev: 0x0000001f
+AP: slot 6 apic_id 30, MCU rev: 0x0000001f
 AP: slot 1 apic_id 4a, MCU rev: 0x0000001f
-AP: slot 9 apic_id 46, MCU rev: 0x0000001f
-LAPIC 0x38 in XAPIC mode.
-AP: slot 6 apic_id 48, MCU rev: 0x0000001f
+AP: slot 22 apic_id 39, MCU rev: 0x0000001f
 LAPIC 0x31 in XAPIC mode.
-done.
-Waiting for SIPI to complete...
-done.
-AP: slot 23 apic_id 40, MCU rev: 0x0000001f
-AP: slot 2 apic_id 42, MCU rev: 0x0000001f
-AP: slot 17 apic_id 19, MCU rev: 0x0000001f
-AP: slot 5 apic_id 38, MCU rev: 0x0000001f
-AP: slot 15 apic_id 18, MCU rev: 0x0000001f
-AP: slot 22 apic_id 44, MCU rev: 0x0000001f
-AP: slot 18 apic_id 21, MCU rev: 0x0000001f
-LAPIC 0x20 in XAPIC mode.
-AP: slot 12 apic_id 10, MCU rev: 0x0000001f
-AP: slot 10 apic_id 9, MCU rev: 0x0000001f
-AP: slot 16 apic_id 31, MCU rev: 0x0000001f
-LAPIC 0x8 in XAPIC mode.
-AP: slot 19 apic_id 20, MCU rev: 0x0000001f
-AP: slot 21 apic_id 28, MCU rev: 0x0000001f
-LAPIC 0x29 in XAPIC mode.
-AP: slot 11 apic_id 8, MCU rev: 0x0000001f
+LAPIC 0x11 in XAPIC mode.
+LAPIC 0x21 in XAPIC mode.
+LAPIC 0x38 in XAPIC mode.
+AP: slot 8 apic_id 48, MCU rev: 0x0000001f
 AP: slot 14 apic_id 11, MCU rev: 0x0000001f
+AP: slot 19 apic_id 21, MCU rev: 0x0000001f
+AP: slot 12 apic_id 8, MCU rev: 0x0000001f
+AP: slot 10 apic_id 31, MCU rev: 0x0000001f
+LAPIC 0x29 in XAPIC mode.
+AP: slot 21 apic_id 28, MCU rev: 0x0000001f
 AP: slot 20 apic_id 29, MCU rev: 0x0000001f
+AP: slot 23 apic_id 38, MCU rev: 0x0000001f
 smm_setup_relocation_handler: enter
 smm_setup_relocation_handler: exit
 Loading module at 0x00038000 with entry 0x00038000. filesize: 0x208 memsize: 0x208
@@ -507,23 +507,33 @@
 New SMBASE=0x4b9e9000 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e7400, cpu = 7
-In relocation handler: CPU 7
-New SMBASE=0x4b9e7400 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4c00, cpu = 17
+In relocation handler: CPU 17
+New SMBASE=0x4b9e4c00 IEDBASE=0x4bc00000
+Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8c00, cpu = 1
-In relocation handler: CPU 1
-New SMBASE=0x4b9e8c00 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e3800, cpu = 22
+In relocation handler: CPU 22
+New SMBASE=0x4b9e3800 IEDBASE=0x4bc00000
+Relocation complete.
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e3400, cpu = 23
+In relocation handler: CPU 23
+New SMBASE=0x4b9e3400 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e7800, cpu = 6
-In relocation handler: CPU 6
-New SMBASE=0x4b9e7800 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e7000, cpu = 8
+In relocation handler: CPU 8
+New SMBASE=0x4b9e7000 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e6c00, cpu = 9
-In relocation handler: CPU 9
-New SMBASE=0x4b9e6c00 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e6400, cpu = 11
+In relocation handler: CPU 11
+New SMBASE=0x4b9e6400 IEDBASE=0x4bc00000
+Writing SMRR. base = 0x4b800006, mask=0xff800c00
+Relocation complete.
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8000, cpu = 4
+In relocation handler: CPU 4
+New SMBASE=0x4b9e8000 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
 smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e6000, cpu = 12
@@ -531,89 +541,79 @@
 New SMBASE=0x4b9e6000 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e5c00, cpu = 13
+In relocation handler: CPU 13
+New SMBASE=0x4b9e5c00 IEDBASE=0x4bc00000
+Relocation complete.
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8800, cpu = 2
+In relocation handler: CPU 2
+New SMBASE=0x4b9e8800 IEDBASE=0x4bc00000
+Writing SMRR. base = 0x4b800006, mask=0xff800c00
+Relocation complete.
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e5400, cpu = 15
+In relocation handler: CPU 15
+New SMBASE=0x4b9e5400 IEDBASE=0x4bc00000
+Writing SMRR. base = 0x4b800006, mask=0xff800c00
+Relocation complete.
 smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e7c00, cpu = 5
 In relocation handler: CPU 5
 New SMBASE=0x4b9e7c00 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4800, cpu = 18
-In relocation handler: CPU 18
-New SMBASE=0x4b9e4800 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e7400, cpu = 7
+In relocation handler: CPU 7
+New SMBASE=0x4b9e7400 IEDBASE=0x4bc00000
+Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8000, cpu = 4
-In relocation handler: CPU 4
-New SMBASE=0x4b9e8000 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e5000, cpu = 16
+In relocation handler: CPU 16
+New SMBASE=0x4b9e5000 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e6c00, cpu = 9
+In relocation handler: CPU 9
+New SMBASE=0x4b9e6c00 IEDBASE=0x4bc00000
+Relocation complete.
 smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e6800, cpu = 10
 In relocation handler: CPU 10
 New SMBASE=0x4b9e6800 IEDBASE=0x4bc00000
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4000, cpu = 20
-In relocation handler: CPU 20
-New SMBASE=0x4b9e4000 IEDBASE=0x4bc00000
-Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e3800, cpu = 22
-In relocation handler: CPU 22
-New SMBASE=0x4b9e3800 IEDBASE=0x4bc00000
-Writing SMRR. base = 0x4b800006, mask=0xff800c00
-Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e6400, cpu = 11
-In relocation handler: CPU 11
-New SMBASE=0x4b9e6400 IEDBASE=0x4bc00000
-Writing SMRR. base = 0x4b800006, mask=0xff800c00
-Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e5c00, cpu = 13
-In relocation handler: CPU 13
-New SMBASE=0x4b9e5c00 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8c00, cpu = 1
+In relocation handler: CPU 1
+New SMBASE=0x4b9e8c00 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e7000, cpu = 8
-In relocation handler: CPU 8
-New SMBASE=0x4b9e7000 IEDBASE=0x4bc00000
-Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e3400, cpu = 23
-In relocation handler: CPU 23
-New SMBASE=0x4b9e3400 IEDBASE=0x4bc00000
-Writing SMRR. base = 0x4b800006, mask=0xff800c00
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4800, cpu = 18
+In relocation handler: CPU 18
+New SMBASE=0x4b9e4800 IEDBASE=0x4bc00000
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8800, cpu = 2
-In relocation handler: CPU 2
-New SMBASE=0x4b9e8800 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8400, cpu = 3
+In relocation handler: CPU 3
+New SMBASE=0x4b9e8400 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
 smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e5800, cpu = 14
 In relocation handler: CPU 14
 New SMBASE=0x4b9e5800 IEDBASE=0x4bc00000
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e8400, cpu = 3
-In relocation handler: CPU 3
-New SMBASE=0x4b9e8400 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e7800, cpu = 6
+In relocation handler: CPU 6
+New SMBASE=0x4b9e7800 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e5400, cpu = 15
-In relocation handler: CPU 15
-New SMBASE=0x4b9e5400 IEDBASE=0x4bc00000
-Writing SMRR. base = 0x4b800006, mask=0xff800c00
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4000, cpu = 20
+In relocation handler: CPU 20
+New SMBASE=0x4b9e4000 IEDBASE=0x4bc00000
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4c00, cpu = 17
-In relocation handler: CPU 17
-New SMBASE=0x4b9e4c00 IEDBASE=0x4bc00000
+smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4400, cpu = 19
+In relocation handler: CPU 19
+New SMBASE=0x4b9e4400 IEDBASE=0x4bc00000
 Relocation complete.
 smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e3c00, cpu = 21
 In relocation handler: CPU 21
 New SMBASE=0x4b9e3c00 IEDBASE=0x4bc00000
 Writing SMRR. base = 0x4b800006, mask=0xff800c00
 Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e4400, cpu = 19
-In relocation handler: CPU 19
-New SMBASE=0x4b9e4400 IEDBASE=0x4bc00000
-Writing SMRR. base = 0x4b800006, mask=0xff800c00
-Relocation complete.
-smm_do_relocation : curr_smbase 0x30000 perm_smbase 0x4b9e5000, cpu = 16
-In relocation handler: CPU 16
-New SMBASE=0x4b9e5000 IEDBASE=0x4bc00000
-Relocation complete.
 Initializing CPU #0
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
@@ -624,183 +624,183 @@
 Turbo is available and visible
 microcode: Update skipped, already up-to-date
 CPU #0 initialized
+Initializing CPU #21
 Initializing CPU #7
-Initializing CPU #2
-Initializing CPU #20
-CPU: vendor Intel device 90672
-CPU: family 06, model 97, stepping 02
-Initializing CPU #3
-Initializing CPU #11
-Initializing CPU #15
-Using generic CPU ops (good)
 Initializing CPU #16
 Initializing CPU #13
-Initializing CPU #17
-Initializing CPU #1
-CPU: vendor Intel device 90672
+Initializing CPU #9
+Initializing CPU #14
 Initializing CPU #4
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
-Initializing CPU #22
-Initializing CPU #9
+Initializing CPU #2
+Using generic CPU ops (good)
+Initializing CPU #8
+Initializing CPU #1
 CPU: vendor Intel device 90672
-CPU: family 06, model 97, stepping 02
+Initializing CPU #10
+Initializing CPU #11
+Initializing CPU #3
+Initializing CPU #5
+Initializing CPU #17
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
-Initializing CPU #12
+CPU: family 06, model 97, stepping 02
 Initializing CPU #6
-Using generic CPU ops (good)
+Initializing CPU #12
 CPU: vendor Intel device 90672
-Using generic CPU ops (good)
-CPU: family 06, model 97, stepping 02
-Initializing CPU #18
-Using generic CPU ops (good)
-Initializing CPU #21
-Initializing CPU #5
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
+Using generic CPU ops (good)
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
-CPU: family 06, model 97, stepping 02
 Clearing out pending MCEs
-Initializing CPU #23
-Using generic CPU ops (good)
-Using generic CPU ops (good)
-Using generic CPU ops (good)
 Clearing out pending MCEs
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
-Clearing out pending MCEs
 cpu: energy policy set to 7
+Initializing CPU #22
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
+Using generic CPU ops (good)
+CPU: vendor Intel device 90672
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
+Initializing CPU #23
 CPU: vendor Intel device 90672
+Using generic CPU ops (good)
+CPU: vendor Intel device 90672
+CPU: family 06, model 97, stepping 02
+CPU: family 06, model 97, stepping 02
 CPU: family 06, model 97, stepping 02
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
 CPU: vendor Intel device 90672
+Initializing CPU #18
+Using generic CPU ops (good)
+Using generic CPU ops (good)
 microcode: Update skipped, already up-to-date
-CPU #2 initialized
-Clearing out pending MCEs
-CPU: vendor Intel device 90672
+CPU #9 initialized
 CPU: family 06, model 97, stepping 02
 CPU: vendor Intel device 90672
-CPU: family 06, model 97, stepping 02
-Clearing out pending MCEs
-Clearing out pending MCEs
-cpu: energy policy set to 7
-cpu: energy policy set to 7
-cpu: energy policy set to 7
-Initializing CPU #19
+CPU: vendor Intel device 90672
+CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
 Using generic CPU ops (good)
 Using generic CPU ops (good)
-cpu: energy policy set to 7
 Using generic CPU ops (good)
-microcode: Update skipped, already up-to-date
-CPU #13 initialized
-microcode: Update skipped, already up-to-date
-CPU #4 initialized
 Clearing out pending MCEs
-microcode: Update skipped, already up-to-date
-CPU #9 initialized
-Initializing CPU #14
-microcode: Update skipped, already up-to-date
-CPU #6 initialized
-CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
-cpu: energy policy set to 7
-Initializing CPU #8
-microcode: Update skipped, already up-to-date
-CPU #3 initialized
-Clearing out pending MCEs
-Clearing out pending MCEs
-Clearing out pending MCEs
-Initializing CPU #10
+CPU: family 06, model 97, stepping 02
 Using generic CPU ops (good)
 cpu: energy policy set to 7
-cpu: energy policy set to 7
-cpu: energy policy set to 7
+CPU: family 06, model 97, stepping 02
 Using generic CPU ops (good)
 Clearing out pending MCEs
-microcode: Update skipped, already up-to-date
-CPU #23 initialized
-CPU: vendor Intel device 90672
+Using generic CPU ops (good)
+Initializing CPU #15
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
 Using generic CPU ops (good)
-cpu: energy policy set to 7
-Clearing out pending MCEs
-cpu: energy policy set to 7
-microcode: Update skipped, already up-to-date
-CPU #1 initialized
 Using generic CPU ops (good)
-microcode: Update skipped, already up-to-date
-CPU #5 initialized
+cpu: energy policy set to 7
 CPU: vendor Intel device 90672
 CPU: family 06, model 97, stepping 02
 Using generic CPU ops (good)
-microcode: Update skipped, already up-to-date
-CPU #7 initialized
-microcode: Update skipped, already up-to-date
-CPU #22 initialized
 Using generic CPU ops (good)
+Clearing out pending MCEs
 Using generic CPU ops (good)
 Clearing out pending MCEs
 cpu: energy policy set to 7
+Using generic CPU ops (good)
 Clearing out pending MCEs
-cpu: energy policy set to 7
 Clearing out pending MCEs
 Using generic CPU ops (good)
+Clearing out pending MCEs
+microcode: Update skipped, already up-to-date
+CPU #13 initialized
+Clearing out pending MCEs
+cpu: energy policy set to 7
+Clearing out pending MCEs
+cpu: energy policy set to 7
+cpu: energy policy set to 7
 cpu: energy policy set to 7
-CPU: vendor Intel device 90672
-CPU: family 06, model 97, stepping 02
 Using generic CPU ops (good)
-CPU: family 06, model 97, stepping 02
 Clearing out pending MCEs
 Clearing out pending MCEs
-Using generic CPU ops (good)
 microcode: Update skipped, already up-to-date
-CPU #8 initialized
+CPU #5 initialized
 Clearing out pending MCEs
 Clearing out pending MCEs
 cpu: energy policy set to 7
-cpu: energy policy set to 7
-CPU: vendor Intel device 90672
-CPU: family 06, model 97, stepping 02
-Using generic CPU ops (good)
 microcode: Update skipped, already up-to-date
 CPU #11 initialized
 Clearing out pending MCEs
+Initializing CPU #19
+Clearing out pending MCEs
+cpu: energy policy set to 7
+Clearing out pending MCEs
+cpu: energy policy set to 7
 cpu: energy policy set to 7
 microcode: Update skipped, already up-to-date
-CPU #17 initialized
+CPU #7 initialized
+Clearing out pending MCEs
+microcode: Update skipped, already up-to-date
+CPU #23 initialized
+cpu: energy policy set to 7
+cpu: energy policy set to 7
 cpu: energy policy set to 7
 microcode: Update skipped, already up-to-date
-CPU #14 initialized
+CPU #4 initialized
 microcode: Update skipped, already up-to-date
-CPU #10 initialized
+CPU #1 initialized
+CPU: vendor Intel device 90672
+CPU: family 06, model 97, stepping 02
+microcode: Update skipped, already up-to-date
+CPU #2 initialized
+Clearing out pending MCEs
 cpu: energy policy set to 7
 microcode: Update skipped, already up-to-date
-CPU #16 initialized
+CPU #3 initialized
 microcode: Update skipped, already up-to-date
 CPU #15 initialized
+cpu: energy policy set to 7
+cpu: energy policy set to 7
+microcode: Update skipped, already up-to-date
+CPU #8 initialized
+microcode: Update skipped, already up-to-date
+CPU #16 initialized
+Using generic CPU ops (good)
+cpu: energy policy set to 7
 microcode: Update skipped, already up-to-date
 CPU #12 initialized
+microcode: Update skipped, already up-to-date
+CPU #18 initialized
+CPU: vendor Intel device 90672
+CPU: family 06, model 97, stepping 02
+microcode: Update skipped, already up-to-date
+CPU #6 initialized
+microcode: Update skipped, already up-to-date
+CPU #22 initialized
+Clearing out pending MCEs
 cpu: energy policy set to 7
+microcode: Update skipped, already up-to-date
+CPU #14 initialized
+microcode: Update skipped, already up-to-date
+CPU #17 initialized
 Using generic CPU ops (good)
-Using generic CPU ops (good)
-Clearing out pending MCEs
+Initializing CPU #20
 microcode: Update skipped, already up-to-date
-CPU #19 initialized
-cpu: energy policy set to 7
+CPU #10 initialized
+CPU: vendor Intel device 90672
+CPU: family 06, model 97, stepping 02
 Clearing out pending MCEs
+cpu: energy policy set to 7
+Using generic CPU ops (good)
 microcode: Update skipped, already up-to-date
-CPU #18 initialized
+CPU #19 initialized
 cpu: energy policy set to 7
 Clearing out pending MCEs
 microcode: Update skipped, already up-to-date
@@ -808,11 +808,11 @@
 cpu: energy policy set to 7
 microcode: Update skipped, already up-to-date
 CPU #20 initialized
-bsp_do_flight_plan done after 1636 msecs.
+bsp_do_flight_plan done after 1707 msecs.
 CPU: frequency set to 5200 MHz
 Enabling SMIs.
 Watchdog: WDT enabled
-BS: BS_DEV_INIT_CHIPS entry times (exec / console): 1148 / 743 ms
+BS: BS_DEV_INIT_CHIPS entry times (exec / console): 1149 / 743 ms
 EFIVARS: UEFI FV with size 262144 found
 EFIVARS: UEFI variable store with size 65464 found
 Found variable with state 3f and GUID: c076ec0c-7028-4399-a07271ee5c448b9f
@@ -1002,56 +1002,2677 @@
 Detected 16 core, 24 thread CPU.
 Detected 16 core, 24 thread CPU.
 Detected 16 core, 24 thread CPU.
-CPU Index 0 - APIC 0 Unexpected Exception:13 @ 10:46b315d8 - Halting
-Code: 0 eflags: 00010002 cr2: 00000000
-eax: 00000005 ebx: 46b270a0 ecx: 0000003a edx: 00000000
-edi: 00000005 esi: 00000000 ebp: 465b5e48 esp: 465b5e2c
-
-0x46b31598:    ff 50 14 59 59 c3 55 8b 
-0x46b315a0:    ec 83 ec 14 56 57 8b f2 
-0x46b315a8:    89 4d fc 8b 4d fc 0f 32 
-0x46b315b0:    ff 75 10 8b ce ff 75 0c 
-0x46b315b8:    52 8b 55 08 50 e8 9e 00 
-0x46b315c0:    00 00 8b f8 8b f2 83 c4 
-0x46b315c8:    10 89 7d f0 89 75 f4 8b 
-0x46b315d0:    55 f4 8b 45 f0 8b 4d fc 
-0x46b315d8:    0f 30 8b c7 8b d6 5f 5e 
-0x46b315e0:    c9 c3 53 56 57 6a fe 8b 
-0x46b315e8:    da 8b f1 8b 4c 24 14 83 
-0x46b315f0:    c8 ff 8b 54 24 1c 5f d3 
-0x46b315f8:    e7 8b cb d3 e0 f7 d7 23 
-0x46b31600:    c7 d3 e2 f7 d0 23 d7 5f 
-0x46b31608:    23 c6 5e 0b c2 5b c3 55 
-0x46b31610:    8b ec 83 ec 10 83 4d f4 
-0x465b5ea8:    0x4679fa70
-0x465b5ea4:    0x01000000
-0x465b5ea0:    0x00000006
-0x465b5e9c:    0x46b2a000
-0x465b5e98:    0x00000007
-0x465b5e94:    0x46b270a0
-0x465b5e90:    0x0000000b
-0x465b5e8c:    0x46b31a1c
-0x465b5e88:    0x465b5eb0
-0x465b5e84:    0x00000000
-0x465b5e80:    0x00000000
-0x465b5e7c:    0x46b2b000
-0x465b5e78:    0x46b31932
-0x465b5e74:    0x46b2f209
-0x465b5e70:    0x00000100
-0x465b5e6c:    0x465b5e88
-0x465b5e68:    0x46b2f209
-0x465b5e64:    0x46b2b000
-0x465b5e60:    0x46b2b000
-0x465b5e5c:    0x46b2c000
-0x465b5e58:    0x00000000
-0x465b5e54:    0x00000000
-0x465b5e50:    0x00000001
-0x465b5e4c:    0x46b2f1f6
-0x465b5e48:    0x465b5ea8 <-ebp
-0x465b5e44:    0x0000003a
-0x465b5e40:    0xffffffff
-0x465b5e3c:    0x00000000
-0x465b5e38:    0x00000005
-0x465b5e34:    0x00000003
-0x465b5e30:    0x00000006
-0x465b5e2c:    0x46b2a000 <-esp
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+Detected 16 core, 24 thread CPU.
+FSPS returned 0
+Display FSP Version Info HOB
+Reference Code - CPU = c.0.69.74
+uCode Version = 0.0.0.1f
pietrushnic commented 1 year ago

@verygreen thank you for reporting.

Let me bring that to the Qubes OS Team's attention. TBH, if this is not a firmware issue we probably should migrate that problem to qubes-issues.

pietrushnic commented 1 year ago

I guess we should change title :)

miczyg1 commented 1 year ago

Ahh damn.. After disassembling the code around RIP it does #GP on WRMSR to IA32_FEATURE_CONTROL. But it does so inside FSP SiliconInit, not coreboot code part...

miczyg1 commented 1 year ago

Reasons for WRMSR to #GP according to Intel SDM:

Protected Mode Exceptions
#GP(0)
If the current privilege level is not 0.
If the value in ECX specifies a reserved or unimplemented MSR address.
If the value in EDX:EAX sets bits that are reserved in the MSR specified by ECX.
If the source register contains a non-canonical address and ECX specifies one of the following
MSRs: IA32_DS_AREA, IA32_FS_BASE, IA32_GS_BASE, IA32_KERNEL_GS_BASE,
IA32_LSTAR, IA32_SYSENTER_EIP, IA32_SYSENTER_ESP.

The most likely cause is the If the value in EDX:EAX sets bits that are reserved in the MSR specified by ECX.. SO FSP SIliconInit writes to reserved bits inside IA32_FEATURE_CONTROL... Great

miczyg1 commented 1 year ago

Also If the lock bit is set, WRMSR to the IA32_FEATURE_CONTROL MSR will cause a general-protection exception fro mSDM

marmarek commented 1 year ago

After disassembling the code around RIP it does #GP on WRMSR to IA32_FEATURE_CONTROL. But it does so inside FSP SiliconInit, not coreboot code part...

Is it trying to disable VMX? That's the main part I see, if firmware left it unlocked, Xen will enable it and lock it. That said, why does it survive platform reset, it shouldn't, no? Maybe it's related to a crash in EFI ResetSystem() runtime service?

``` (XEN) Reboot in five seconds... (XEN) ----[ Xen-4.18-unstable x86_64 debug=y Not tainted ]---- (XEN) CPU: 0 (XEN) RIP: e008:[<0000000045f1e11f>] 0000000045f1e11f (XEN) RFLAGS: 0000000000010206 CONTEXT: hypervisor (XEN) rax: 0000000000000033 rbx: 0000000000000000 rcx: 00000000465fe000 (XEN) rdx: 0000000000000033 rsi: ffff82d04046fa90 rdi: 0000000000000001 (XEN) rbp: ffff82d04046f950 rsp: ffff82d04046f910 r8: 0000000000000001 (XEN) r9: ffff82d04046f990 r10: 0000000000000002 r11: 0000000000000000 (XEN) r12: 0000000000000033 r13: 0000000000000000 r14: 0000000000000000 (XEN) r15: ffff82d0405f5300 cr0: 0000000080050033 cr4: 0000000000d526e0 (XEN) cr3: 000000045bdd9000 cr2: 00000000465fe004 (XEN) fsb: 0000000000000000 gsb: 0000000000000000 gss: 0000000000000000 (XEN) ds: 0000 es: 0000 fs: 0000 gs: 0000 ss: 0000 cs: e008 (XEN) Xen code around <0000000045f1e11f> (0000000045f1e11f): (XEN) 2d 00 00 48 85 c9 74 5e <8b> 71 04 8b 01 89 f3 81 e3 ff ff ff 0f 39 c3 73 (XEN) Xen stack trace from rsp=ffff82d04046f910: (XEN) 0000000000000000 0000000000000000 ffff82d0402624a9 0000000000000000 (XEN) 0000000000000000 0000000000000000 ffff82d04046fa90 ffff82d04046f990 (XEN) ffff82d04046fb50 0000000045f1e6a9 0000000000000086 0000000000000000 (XEN) ffff82d04046f988 ffff82d0402349cf ffff82d0404d13c8 ffff82d04046fb70 (XEN) 6573655220455844 326d657473795374 547465736552203a 646c6f4320657079 (XEN) 44206c6c6143202c 31203d2068747065 00000000000a0d2e 0000000045f2d7c0 (XEN) ffff82d04046fa10 0000000045f2b901 ffff82d04046fa10 0000000045f2b3c5 (XEN) ffff82d04033295c ffff82d04046fa08 0000000000000000 0000000000000004 (XEN) ffff82d04046fb50 0000000045f2bd90 0000000000000046 0000000000000067 (XEN) ffff83045bdd6000 ffff82d04046fa48 ffff82d040331794 ffff82d04046fa98 (XEN) ffff82d04033295c ffff83045e211b18 ffff82d0405da4a0 0000000000000046 (XEN) 0000000000000000 0000000000000000 0000000000000000 0000000000000000 (XEN) 0000000000000000 0000000000000000 0000000000000000 0000000000000000 (XEN) 0000000000000000 0000000000000000 0000000000000000 0000000000000000 (XEN) 0000000000000000 0000000000000000 0000000000000000 0000000000000000 (XEN) 0000000000000000 0000000000000000 0000000000000000 0000000000000000 (XEN) 0000000000000000 0000000000000000 0000000000000000 0000000000000000 (XEN) 0000000000000000 0000000000000004 000000045bdd9000 0000000000000000 (XEN) ffff82d04046fc70 0000000045f1e999 0000000000000001 000000000311100a (XEN) 0000000045f20a84 0000000000000001 0000000000000000 ffff82d040271cbb (XEN) Xen call trace: (XEN) [<0000000045f1e11f>] R 0000000045f1e11f (XEN) [<0000000000000000>] S 0000000000000000 (XEN) [<0000000045f1e6a9>] F 0000000045f1e6a9 (XEN) [<0000000045f1e999>] F 0000000045f1e999 (XEN) [] F efi_reset_system+0x46/0x6a (XEN) [] F machine_restart+0x14e/0x270 (XEN) [] F console_suspend+0/0x28 (XEN) [] F __start_xen+0x2612/0x272d (XEN) [] F __high_start+0x94/0xa0 (XEN) (XEN) Pagetable walk from 00000000465fe004: (XEN) L4[0x000] = 000000045bdd8063 ffffffffffffffff (XEN) L3[0x001] = 00000000436c7063 ffffffffffffffff (XEN) L2[0x032] = 00000000463ff063 ffffffffffffffff (XEN) L1[0x1fe] = 0000000000000000 ffffffffffffffff (XEN) (XEN) **************************************** (XEN) Panic on CPU 0: (XEN) FATAL PAGE FAULT (XEN) [error_code=0000] (XEN) Faulting linear address: 00000000465fe004 (XEN) **************************************** (XEN) (XEN) Reboot in five seconds... (XEN) Resetting with ACPI MEMORY or I/O RESET_REG. ```
miczyg1 commented 1 year ago

Judging from the content of EAX it tired to set Enable VMX outside SMX operation bit and lock bit, so definitely not disabling. Although we don't know if it tried to set the lock bit or set the VMX enable with logical OR but the lock was already set.

miczyg1 commented 1 year ago

@verygreen could you please try applying this patch, rebuilding, flashing and resubmitting the serial console log from the crash like you did previously in this comment https://github.com/Dasharo/dasharo-issues/issues/427#issuecomment-1522510726 ?

diff --git a/src/soc/intel/alderlake/cpu.c b/src/soc/intel/alderlake/cpu.c
index 027e9787296..e8f9085a28e 100644
--- a/src/soc/intel/alderlake/cpu.c
+++ b/src/soc/intel/alderlake/cpu.c
@@ -141,6 +141,8 @@ void soc_core_init(struct device *cpu)
        /* Enable Turbo */
        enable_turbo();

+       set_feature_ctrl_vmx();
+
        if (CONFIG(INTEL_TME) && is_tme_supported())
                set_tme_core_activate();
 }

It should apply directly on msi_ms7d25/release branch

verygreen commented 1 year ago

Boot after flashing suspend-patch1-boot.txt

Log during resume suspend-patch1-resume.txt

Log at reboot with the crash: suspend-patch1-afterresume.txt

verygreen commented 1 year ago

aha, the boot after flashing was not actually involving a full board poweroff. Boot after poweroff is different (And similar to resume) in that VMX is disabled and has to be enabled, so here's that log for completeness: suspend-patch1-boot-from-poweroff.txt