Guest double fault in live migration testing

[gjcolombo]

Repro scenario: repeatedly live migrate a Debian VM around a multi-machine Omicron cluster. Propolis is from a private branch that's based on 7ff360d and has #359 merged into it.

This works most of the time, but eventually the guest panics:

[  145.267125] traps: PANIC: double fault, error_code: 0x0
[  145.267125] double fault: 0000 [#1] SMP NOPTI
[  145.267126] CPU: 0 PID: 500 Comm: sshd Not tainted 5.10.0-18-amd64 #1 Debian 5.10.140-1
[  145.267126] RIP: 0033:0x55e1662a9c40
[  145.267126] RSP: 002b:00007ffcbb248608 EFLAGS: 00010202
[  145.267127] RAX: 000000000000002f RBX: 000055e1676ed460 RCX: 0000000000000001
[  145.267127] RDX: 0000000000004000 RSI: 000000000000005e RDI: 000055e1676fbce0
[  145.267127] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000001000
[  145.267127] R10: 0000000000000000 R11: 0000000000000246 R12: 000055e1676fbce0
[  145.267128] R13: 00007ffcbb248628 R14: 000055e1676fd530 R15: 000000000000002f
[  145.267128] FS:  00007fd426513900 GS:  ffff927e7bc00000
[  145.267128] Modules linked in: dm_mod nls_ascii nls_cp437 vfat fat ghash_clmulni_intel aesni_intel libaes crypto_simd serio_raw cryptd evdev glue_helper pcspkr efi_pstore button rapl drm fuse configfs efivarfs ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 crc32c_generic virtio_net net_failover virtio_blk failover nvme nvme_core t10_pi crc_t10dif crc32_pclmul crct10dif_generic crc32c_intel virtio_pci crct10dif_pclmul crct10dif_common virtio_ring virtio i2c_piix4
[  145.267135] traps: PANIC: double fault, error_code: 0x0
[  145.279653] ---[ end trace 60c7607a5d74dead ]---
[  145.279653] double fault: 0000 [#2] SMP NOPTI
[  145.279654] CPU: 1 PID: 3437 Comm: cmatrix Tainted: G      D           5.10.0-18-amd64 #1 Debian 5.10.140-1
[  145.279654] RIP: 0033:0x7f75a07503dd
[  145.279655] RSP: 002b:00007ffc541ccc48 EFLAGS: 00010283
[  145.279656] RAX: 0000000000000ec0 RBX: 0000000000000029 RCX: 00007f75a07eabd4
[  145.279657] RDX: 000055b61b792ec0 RSI: 0000000000000000 RDI: 000055b61b792ec0
[  145.279657] RBP: 000055b61b76e8ef R08: 0000000000000000 R09: 0000000000000000
[  145.279658] R10: 000055b61b76e8e7 R11: 00007f75a07703c0 R12: 000055b61b792ec0
[  145.279658] R13: 00007f75a07f5020 R14: 000055b61b76e8e7 R15: 00007f75a07eab50
[  145.279658] FS:  00007f75a05eb040 GS:  ffff927e7bd00000
[  145.279659] Modules linked in: dm_mod nls_ascii nls_cp437 vfat fat ghash_clmulni_intel aesni_intel libaes crypto_simd serio_raw cryptd evdev glue_helper pcspkr efi_pstore button rapl drm fuse configfs efivarfs ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 crc32c_generic virtio_net net_failover virtio_blk failover nvme nvme_core t10_pi crc_t10dif crc32_pclmul crct10dif_generic crc32c_intel virtio_pci crct10dif_pclmul crct10dif_common virtio_ring virtio i2c_piix4
[  145.279672] ---[ end trace 60c7607a5d74deae ]---
[  145.279672] pstore: dump skipped in NMI path because of concurrent dump
[  145.279673] RIP: 0033:0x55e1662a9c40
[  145.279673] RSP: 002b:00007ffcbb248608 EFLAGS: 00010202
[  145.279674] RAX: 000000000000002f RBX: 000055e1676ed460 RCX: 0000000000000001
[  145.279674] RDX: 0000000000004000 RSI: 000000000000005e RDI: 000055e1676fbce0
[  145.279675] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000001000
[  145.279675] R10: 0000000000000000 R11: 0000000000000246 R12: 000055e1676fbce0
[  145.279676] R13: 00007ffcbb248628 R14: 000055e1676fd530 R15: 000000000000002f
[  145.279676] FS:  00007f75a05eb040(0000) GS:ffff927e7bd00000(0000) knlGS:ffff927e7bd00000
[  145.279677] CS:  0033 DS: 0000 ES: 0000 CR0: 0000000080050033
[  145.279677] CR2: 00007ffc541ccc38 CR3: 00000001015c2000 CR4: 00000000003506e0
[  145.279678] Kernel panic - not syncing: Fatal exception in interrupt
[  146.316728] RIP: 0033:0x55e1662a9c40
[  146.316728] RSP: 002b:00007ffcbb248608 EFLAGS: 00010202
[  146.316729] RAX: 000000000000002f RBX: 000055e1676ed460 RCX: 0000000000000001
[  146.316729] RDX: 0000000000004000 RSI: 000000000000005e RDI: 000055e1676fbce0
[  146.316729] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000001000
[  146.316730] R10: 0000000000000000 R11: 0000000000000246 R12: 000055e1676fbce0
[  146.316730] R13: 00007ffcbb248628 R14: 000055e1676fd530 R15: 000000000000002f
[  146.316730] FS:  00007fd426513900(0000) GS:ffff927e7bc00000(0000) knlGS:ffff927e7bc00000
[  146.316730] CS:  0033 DS: 0000 ES: 0000 CR0: 0000000080050033
[  146.316731] CR2: 00007ffcbb2485f8 CR3: 00000001014de000 CR4: 00000000003506f0
[  146.316731] Shutting down cpus with NMI
[  146.316731] Kernel Offset: 0xc600000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
000 R11: 0000000000000246 R12: 000055e1676fbce0
[  146.316730] R13: 00007ffcbb248628 R14: 000055e1676fd530 R15: 000000000000002f
[  146.316730] FS:  00007fd426513900(0000) GS:ffff927e7bc00000(0000) knlGS:ffff927e7bc00000
[  146.316730] CS:  0033 DS: 0000 ES: 0000 CR0: 0000000080050033
[  146.316731] CR2: 00007ffcbb2485f8 CR3: 00000001014de000 CR4: 00000000003506f0
[  146.316731] Shutting down cpus with NMI
[  146.316731] Kernel Offset: 0xc600000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)

A similar panic with CPU state dumped (note that by this point the CPUs have advanced past the oops machinery):

[  876.711184] traps: PANIC: double fault, error_code: 0x0
[  876.711184] double fault: 0000 [#1] SMP NOPTI
[  876.711184] CPU: 1 PID: 4782 Comm: C1 CompilerThre Not tainted 5.10.0-18-amd64 #1 Debian 5.10.140-1
[  876.711184] RIP: 0033:0x7f1c19af5703
[  876.711184] RSP: 002b:00007f1be9ffe3a0 EFLAGS: 00010206
[  876.711184] RAX: 00007f1bc8090ad0 RBX: 00007f1bc8448380 RCX: 0000000000000020
[  876.711184] RDX: 00007f1bc8090c40 RSI: 00007f1c1411f370 RDI: 0000000000000002
[  876.711184] RBP: 00007f1be9ffe3d0 R08: 000000000000002e R09: 00007f1c1411f370
[  876.711184] R10: 0000000000000000 R11: 0000000000000002 R12: 00007f1be9ffe3e0
[  876.711184] R13: 000000000000002e R14: 00007f1c1a933149 R15: 00007f1bc84f3cb0
[  876.711184] FS:  00007f1be9fff700 GS:  ffff97e6fbd00000
[  876.711184] Modules linked in: nls_ascii nls_cp437 vfat fat ghash_clmulni_intel aesni_intel libaes crypto_simd cryptd serio_raw glue_helper evdev efi_pstore pcspkr rapl button drm fuse configfs efivarfs ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 crc32c_generic virtio_net net_failover failover virtio_blk crc32_pclmul nvme crc32c_intel nvme_core t10_pi crc_t10dif crct10dif_generic virtio_pci virtio_ring virtio crct10dif_pclmul crct10dif_common i2c_piix4
[  878.967676] ---[ end trace f43baa658c655632 ]---
[  878.967676] RIP: 0033:0x7f1c19af5703
[  878.967676] RSP: 002b:00007f1be9ffe3a0 EFLAGS: 00010206
[  878.967676] RAX: 00007f1bc8090ad0 RBX: 00007f1bc8448380 RCX: 0000000000000020
[  878.967676] RDX: 00007f1bc8090c40 RSI: 00007f1c1411f370 RDI: 0000000000000002
[  878.967676] RBP: 00007f1be9ffe3d0 R08: 000000000000002e R09: 00007f1c1411f370
[  878.967676] R10: 0000000000000000 R11: 0000000000000002 R12: 00007f1be9ffe3e0
[  878.967676] R13: 000000000000002e R14: 00007f1c1a933149 R15: 00007f1bc84f3cb0
[  878.967676] FS:  00007f1be9fff700(0000) GS:ffff97e6fbd00000(0000) knlGS:ffff97e6fbd00000
[  878.967676] CS:  0033 DS: 0000 ES: 0000 CR0: 0000000080050033
[  878.967676] CR2: 00007f1be9ffe398 CR3: 0000000106792000 CR4: 00000000003506e0
[  878.967676] Kernel panic - not syncing: Fatal exception in interrupt
[  878.967676] Kernel Offset: 0x2000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)


$ pfexec bhyvectl --vm=e36bad09-a283-4c9a-8914-cc8fa4195216 --get-all
ID  Length      Name
0   3072MB      sysmem
1   2048KB      bootrom
2   1024MB      sysmem
Address     Length      Segment     Offset      Prot  Flags
0           3072MB      sysmem      0           RWX   
FFE00000    2048KB      bootrom     0           R-X   
100000000   1024MB      sysmem      0           RWX   
efer[0]         0x0000000000001d01
cr0[0]          0x0000000080050033
cr2[0]          0x00007f1c1ab97000
cr3[0]          0x0000000106792000
cr4[0]          0x00000000003506f0
dr0[0]          0x0000000000000000
dr1[0]          0x0000000000000000
dr2[0]          0x0000000000000000
dr3[0]          0x0000000000000000
dr6[0]          0x00000000ffff0ff0
dr7[0]          0x0000000000000400
rsp[0]          0xffffb88a80003ff0
rip[0]          0xffffffff830379ce
rax[0]          0x110a2000444031fb
rbx[0]          0x0000000000000000
rcx[0]          0x00000000fed83203
rdx[0]          0x00000000178bfbff
rsi[0]          0x00000000000000ff
rdi[0]          0xffff97e6fbc15460
rbp[0]          0xffffb88a81033e50
r8[0]           0xffffb88a80003fd8
r9[0]           0xffffb88a80003fd0
r10[0]          0x0000000000000000
r11[0]          0x0000000000000000
r12[0]          0x0000000000000000
r13[0]          0x0000000000000000
r14[0]          0x0000000000000000
r15[0]          0x0000000000000000
rflags[0]       0x0000000000000092
ds desc[0]      0x0000000000000000/0x00000000/0x00010000
es desc[0]      0x0000000000000000/0x00000000/0x00010000
fs desc[0]      0x00007f1bf8163700/0x00000000/0x00010000
gs desc[0]      0xffff97e6fbc00000/0x00000000/0x00010000
ss desc[0]      0x0000000000000000/0x00000000/0x00014000
cs desc[0]      0x0000000000000000/0xffffffff/0x0000209b
tr desc[0]      0xfffffe0000003000/0x00004087/0x00000089
ldtr desc[0]    0xfffffe0000000000/0x00000000/0x00010000
gdtr[0]         0xfffffe0000001000/0x0000007f
idtr[0]         0xfffffe0000000000/0x00000fff
cs[0]           0x0010
ds[0]           0x0000
es[0]           0x0000
fs[0]           0x0000
gs[0]           0x0000
ss[0]           0x0000
tr[0]           0x0000
ldtr[0]         0x0000
fpu_fcw[0]              0x137f
fpu_fsw[0]              0x0000
fpu_ftw[0]              0x0000
fpu_fop[0]              0x0000
fpu_rip[0]              0x0000000000000000
fpu_rdp[0]              0x0000000000000000
fpu_mxcsr[0]            0x00001fa0
fpu_mxcsr_mask[0]       0x0002ffff
fpu_st0[0]              0x00000000000000000000000000000000
fpu_st0[1]              0x00000000000000000000000000000000
fpu_st0[2]              0x00000000000000000000000000000000
fpu_st0[3]              0x00000000000000000000000000000000
fpu_st0[4]              0x00000000000000000000000000000000
fpu_st0[5]              0x00000000000000000000000000000000
fpu_st0[6]              0x00000000000000000000000000000000
fpu_st0[7]              0x00000000000000000000000000000000
fpu_xmm0[0]             0x00000000000000000000000000000000
fpu_xmm1[0]             0x00000000000000000000000000000000
fpu_xmm2[0]             0x358637bd000000000000000000000000
fpu_xmm3[0]             0xc822d8d000007f1bc822de6000007f1b
fpu_xmm4[0]             0x4712b800000000000000000000000000
fpu_xmm5[0]             0xc9fdcc0800007f1bc9fdd66000007f1b
fpu_xmm6[0]             0x3f4ea924000000000000000000000000
fpu_xmm7[0]             0x4712b800000000000000000000000000
fpu_xmm8[0]             0xc918a0c000007f1bc918c51000007f1b
fpu_xmm9[0]             0x00000000000000000000000000000000
fpu_xmm10[0]            0x39a08cea46293e590000000000000000
fpu_xmm11[0]            0x85d8a000437634570000000000000000
fpu_xmm12[0]            0x72be5d7480deb1fe9bdc06a7c19bf174
fpu_xmm13[0]            0xd807aa9812835b01243185be550c7dc3
fpu_xmm14[0]            0x3956c25b59f111f1923f82a4ab1c5ed5
fpu_xmm15[0]            0x428a2f9871374491b5c0fbcfe9b5dba5
fpu_ymm0[0]             0x00000000000000000000000000000000
fpu_ymm1[0]             0x00000000000000000000000000000000
fpu_ymm2[0]             0x00000000000000000000000000000000
fpu_ymm3[0]             0x00000000000000000000000000000000
fpu_ymm4[0]             0x00000000000000000000000000000000
fpu_ymm5[0]             0x00000000000000000000000000000000
fpu_ymm6[0]             0x00000000000000000000000000000000
fpu_ymm7[0]             0x00000000000000000000000000000000
fpu_ymm8[0]             0x00000000000000000000000000000000
fpu_ymm9[0]             0x00000000000000000000000000000000
fpu_ymm10[0]            0x00000000000000000000000000000000
fpu_ymm11[0]            0x00000000000000000000000000000000
fpu_ymm12[0]            0x00000000000000000000000000000000
fpu_ymm13[0]            0x00000000000000000000000000000000
fpu_ymm14[0]            0x00000000000000000000000000000000
fpu_ymm15[0]            0x00000000000000000000000000000000
cr_intercept[0] 0x00000000
dr_intercept[0] 0x00000000
exc_intercept[0]        0x00000000
inst1_intercept[0]      0x00000000
inst2_intercept[0]      0x00000000
TLB ctrl[0]     0x0000000000000000
exitinfo1[0]    0x0000000000000000
exitinfo2[0]    0x0000000000000000
exitintinfo[0]  0x0000000000000000
v_irq/tpr[0]    0x0000000000000000
AVIC apic_bar[0]        0x0000000000000000
AVIC backing page[0]    0x0000000000000000
AVIC logical table[0]   0x0000000000000000
AVIC physical table[0]  0x0000000000000000
x2apic_state[0] 0
rvi/npt[0]              0x0000000000000000
exception_bitmap[0]     0
io_bitmap[0]    0
tsc_offset[0]   0x0000000000000000
msr_bitmap[0]           0
asid[0]         0x0000
msr[MSR_EFER]    = 1d01
msr[MSR_KGSBASE]         = 0
msr[MSR_STAR]    = 0
msr[MSR_LSTAR]   = 83a00010
msr[MSR_CSTAR]   = 83a01730
msr[MSR_SF_MASK]         = 47700
msr[MSR_SYSENTER_CS_MSR]         = 10
msr[MSR_SYSENTER_ESP_MSR]        = 3000
msr[MSR_SYSENTER_EIP_MSR]        = 83a01680
msr[MSR_PAT]     = 70106
msr[MSR_TSC (offset from system boot)]   = 0
msr[MSR_MTRRcap]         = 50a
msr[MSR_MTRRdefType]     = c06
msr[00000268]    = 0
msr[00000269]    = 0
msr[0000026a]    = 0
msr[0000026b]    = 0
msr[0000026c]    = 0
msr[0000026d]    = 0
msr[0000026e]    = 0
msr[0000026f]    = 0
msr[00000258]    = 6060606
msr[00000259]    = 0
msr[00000250]    = 6060606
msr[00000200]    = c0000000
msr[00000201]    = c0000800
msr[00000202]    = 0
msr[00000203]    = 800
msr[00000204]    = 0
msr[00000205]    = 0
msr[00000206]    = 0
msr[00000207]    = 0
msr[00000208]    = 0
msr[00000209]    = 0
msr[0000020a]    = 0
msr[0000020b]    = 0
msr[0000020c]    = 0
msr[0000020d]    = 0
msr[0000020e]    = 0
msr[0000020f]    = 0
msr[00000210]    = 0
msr[00000211]    = 0
msr[00000212]    = 0
msr[00000213]    = 0
exit_reason[0]  0
rtc nvram[000]: 0x03
rtc time 0x644c1ebb: Fri Apr 28 19:30:03 2023
Capability "hlt_exit" is set on vcpu 0
Capability "mtrap_exit" is not available
Capability "pause_exit" is not set on vcpu 0
Capability "enable_invpcid" is not available
Capability "bpt_exit" is not available
active cpus:     0, 1
suspended cpus:  (none)
pending:        n/a
current:        n/a
vcpu0 stats:
number of NMIs delivered to vcpu                0
number of ExtINTs delivered to vcpu             0
Resident memory                                 2888540160
vcpu migration across host cpus                 3
total number of vm exits                        55
vm exits due to external interrupt              35
number of times hlt was intercepted             20
number of times %cr access was intercepted      0
number of times rdmsr was intercepted           0
number of times wrmsr was intercepted           0
number of monitor trap exits                    0
number of times pause was intercepted           0
vm exits due to interrupt window opening        0
vm exits due to nmi window opening              0
number of times in/out was intercepted          0
number of times cpuid was intercepted           0
vm exits due to nested page fault               0
vm exits for mmio emulation                     0
number of vm exits for unknown reason           0
number of times astpending at exit              0
number of times idle requested at exit          59
number of vm exits due to exceptions            0
number of vm exits due to run_state change      0
EOI without any in-service interrupt            0
error interrupts generated by vlapic            0
timer interrupts generated by vlapic            0
corrected machine check interrupts generated by vlapic  0
lvts triggered[0]                               0
lvts triggered[1]                               0
lvts triggered[2]                               0
lvts triggered[3]                               0
lvts triggered[4]                               0
lvts triggered[5]                               0
lvts triggered[6]                               0
ipis sent from vcpu                             0
ipis received by vcpu                           0
cpu_topology:   sockets=1, cores=1, threads=1, maxcpus=32


$ pfexec bhyvectl --vm=e36bad09-a283-4c9a-8914-cc8fa4195216 --get-all --cpu=1
ID  Length      Name
0   3072MB      sysmem
1   2048KB      bootrom
2   1024MB      sysmem
Address     Length      Segment     Offset      Prot  Flags
0           3072MB      sysmem      0           RWX   
FFE00000    2048KB      bootrom     0           R-X   
100000000   1024MB      sysmem      0           RWX   
efer[1]         0x0000000000001d01
cr0[1]          0x0000000080050033
cr2[1]          0x00007f1be9ffe398
cr3[1]          0x0000000106792000
cr4[1]          0x00000000003506e0
dr0[1]          0x0000000000000000
dr1[1]          0x0000000000000000
dr2[1]          0x0000000000000000
dr3[1]          0x0000000000000000
dr6[1]          0x00000000ffff0ff0
dr7[1]          0x0000000000000400
rsp[1]          0xfffffe0000045730
rip[1]          0xffffffff834f1e53
rax[1]          0x000003be343dede3
rbx[1]          0x000000000002eff4
rcx[1]          0x0000000000d53647
rdx[1]          0x0000000000057e94
rsi[1]          0x0000000000000001
rdi[1]          0x000003be343a3df8
rbp[1]          0xfffffe00000457a8
r8[1]           0x0000000000000001
r9[1]           0x000000000034e083
r10[1]          0xffffffffffffffff
r11[1]          0xffffffff846cb448
r12[1]          0x0000000000000001
r13[1]          0x000000000002f058
r14[1]          0x0000000000000054
r15[1]          0x0000000000000006
rflags[1]       0x0000000000000293
ds desc[1]      0x0000000000000000/0x00000000/0x00010000
es desc[1]      0x0000000000000000/0x00000000/0x00010000
fs desc[1]      0x00007f1be9fff700/0x00000000/0x00010000
gs desc[1]      0xffff97e6fbd00000/0x00000000/0x00010000
ss desc[1]      0x0000000000000000/0xffffffff/0x0000c093
cs desc[1]      0x0000000000000000/0xffffffff/0x0000209b
tr desc[1]      0xfffffe000003e000/0x00004087/0x00000089
ldtr desc[1]    0xfffffe0000000000/0x00000000/0x00010000
gdtr[1]         0xfffffe000003c000/0x0000007f
idtr[1]         0xfffffe0000000000/0x00000fff
cs[1]           0x0010
ds[1]           0x0000
es[1]           0x0000
fs[1]           0x0000
gs[1]           0x0000
ss[1]           0x002b
tr[1]           0x0000
ldtr[1]         0x0000
fpu_fcw[1]              0x137f
fpu_fsw[1]              0x0000
fpu_ftw[1]              0x0000
fpu_fop[1]              0x0000
fpu_rip[1]              0x0000000000000000
fpu_rdp[1]              0x0000000000000000
fpu_mxcsr[1]            0x00001f80
fpu_mxcsr_mask[1]       0x0002ffff
fpu_st1[0]              0x00000000000000000000000000000000
fpu_st1[1]              0x00000000000000000000000000000000
fpu_st1[2]              0x00000000000000000000000000000000
fpu_st1[3]              0x00000000000000000000000000000000
fpu_st1[4]              0x00000000000000000000000000000000
fpu_st1[5]              0x00000000000000000000000000000000
fpu_st1[6]              0x00000000000000000000000000000000
fpu_st1[7]              0x00000000000000000000000000000000
fpu_xmm0[1]             0x0000002e0000002e0000002e0000002e
fpu_xmm1[1]             0x1a833db800007f1c0000000000000000
fpu_xmm2[1]             0xc808f5e000007f1bc844bff000007f1b
fpu_xmm3[1]             0xe9ffeba800007f1b0000000000000000
fpu_xmm4[1]             0x00000000000000000000000000000000
fpu_xmm5[1]             0x00000000000000000000000000000000
fpu_xmm6[1]             0x00000000000000000000000000000000
fpu_xmm7[1]             0x3c89489eff2ee82493eb000800f88348
fpu_xmm8[1]             0x3c5b20005d3e732572410a00656d7567
fpu_xmm9[1]             0x00000000000000000000000000000000
fpu_xmm10[1]            0x0000000a000000000000000b00000000
fpu_xmm11[1]            0x00000008000000000000000900000000
fpu_xmm12[1]            0x00000006000000000000000700000000
fpu_xmm13[1]            0x00000004000000000000000500000000
fpu_xmm14[1]            0x00000002000000000000000300000000
fpu_xmm15[1]            0x00000000000000000000000100000000
fpu_ymm0[1]             0x00000000000000000000000000000000
fpu_ymm1[1]             0x00000000000000000000000000000000
fpu_ymm2[1]             0x00000000000000000000000000000000
fpu_ymm3[1]             0x00000000000000000000000000000000
fpu_ymm4[1]             0x00000000000000000000000000000000
fpu_ymm5[1]             0x00000000000000000000000000000000
fpu_ymm6[1]             0x00000000000000000000000000000000
fpu_ymm7[1]             0x00000000000000000000000000000000
fpu_ymm8[1]             0x00000000000000000000000000000000
fpu_ymm9[1]             0x00000000000000000000000000000000
fpu_ymm10[1]            0x00000000000000000000000000000000
fpu_ymm11[1]            0x00000000000000000000000000000000
fpu_ymm12[1]            0x00000000000000000000000000000000
fpu_ymm13[1]            0x00000000000000000000000000000000
fpu_ymm14[1]            0x00000000000000000000000000000000
fpu_ymm15[1]            0x00000000000000000000000000000000
cr_intercept[1] 0x00000000
dr_intercept[1] 0x00000000
exc_intercept[1]        0x00000000
inst1_intercept[1]      0x00000000
inst2_intercept[1]      0x00000000
TLB ctrl[1]     0x0000000000000000
exitinfo1[1]    0x0000000000000000
exitinfo2[1]    0x0000000000000000
exitintinfo[1]  0x0000000000000000
v_irq/tpr[1]    0x0000000000000000
AVIC apic_bar[1]        0x0000000000000000
AVIC backing page[1]    0x0000000000000000
AVIC logical table[1]   0x0000000000000000
AVIC physical table[1]  0x0000000000000000
x2apic_state[1] 0
rvi/npt[1]              0x0000000000000000
exception_bitmap[1]     0
io_bitmap[1]    0
tsc_offset[1]   0x0000000000000000
msr_bitmap[1]           0
asid[1]         0x0000
msr[MSR_EFER]    = 1d01
msr[MSR_KGSBASE]         = fbd00000
msr[MSR_STAR]    = 0
msr[MSR_LSTAR]   = 83a00010
msr[MSR_CSTAR]   = 83a01730
msr[MSR_SF_MASK]         = 47700
msr[MSR_SYSENTER_CS_MSR]         = 10
msr[MSR_SYSENTER_ESP_MSR]        = 3e000
msr[MSR_SYSENTER_EIP_MSR]        = 83a01680
msr[MSR_PAT]     = 70106
msr[MSR_TSC (offset from system boot)]   = 0
msr[MSR_MTRRcap]         = 50a
msr[MSR_MTRRdefType]     = c06
msr[00000268]    = 0
msr[00000269]    = 0
msr[0000026a]    = 0
msr[0000026b]    = 0
msr[0000026c]    = 0
msr[0000026d]    = 0
msr[0000026e]    = 0
msr[0000026f]    = 0
msr[00000258]    = 6060606
msr[00000259]    = 0
msr[00000250]    = 6060606
msr[00000200]    = c0000000
msr[00000201]    = c0000800
msr[00000202]    = 0
msr[00000203]    = 800
msr[00000204]    = 0
msr[00000205]    = 0
msr[00000206]    = 0
msr[00000207]    = 0
msr[00000208]    = 0
msr[00000209]    = 0
msr[0000020a]    = 0
msr[0000020b]    = 0
msr[0000020c]    = 0
msr[0000020d]    = 0
msr[0000020e]    = 0
msr[0000020f]    = 0
msr[00000210]    = 0
msr[00000211]    = 0
msr[00000212]    = 0
msr[00000213]    = 0
exit_reason[1]  0
rtc nvram[000]: 0x11
rtc time 0x644c1eff: Fri Apr 28 19:31:11 2023
Capability "hlt_exit" is set on vcpu 1
Capability "mtrap_exit" is not available
Capability "pause_exit" is not set on vcpu 1
Capability "enable_invpcid" is not available
Capability "bpt_exit" is not available
active cpus:     0, 1
suspended cpus:  (none)
pending:        n/a
current:        n/a
vcpu1 stats:
number of NMIs delivered to vcpu                0
number of ExtINTs delivered to vcpu             0
Resident memory                                 0
vcpu migration across host cpus                 11
total number of vm exits                        12969
vm exits due to external interrupt              12969
number of times hlt was intercepted             0
number of times %cr access was intercepted      0
number of times rdmsr was intercepted           0
number of times wrmsr was intercepted           0
number of monitor trap exits                    0
number of times pause was intercepted           0
vm exits due to interrupt window opening        0
vm exits due to nmi window opening              0
number of times in/out was intercepted          0
number of times cpuid was intercepted           0
vm exits due to nested page fault               0
vm exits for mmio emulation                     0
number of vm exits for unknown reason           0
number of times astpending at exit              8598
number of times idle requested at exit          149
number of vm exits due to exceptions            0
number of vm exits due to run_state change      0
EOI without any in-service interrupt            0
error interrupts generated by vlapic            0
timer interrupts generated by vlapic            0
corrected machine check interrupts generated by vlapic  0
lvts triggered[0]                               0
lvts triggered[1]                               0
lvts triggered[2]                               0
lvts triggered[3]                               0
lvts triggered[4]                               0
lvts triggered[5]                               0
lvts triggered[6]                               0
ipis sent from vcpu                             0
ipis received by vcpu                           0
cpu_topology:   sockets=1, cores=1, threads=1, maxcpus=32

[gjcolombo]

I was able to reproduce this in the following circumstances:

• Latest Propolis server
• Debian 11 guest, 2 vCPUs, 4 GiB RAM
• Single Crucible-backed NVMe disk with a local-file read-only parent
• Single virtio-net VNIC (no OPTE)
• Both Propolises running on the same host
• Migrated with stress-ng --timer 32 --timer-freq 1000000 running in the guest

I've enabled kernel crash dumps in this guest and will try to reproduce once more.

[pfmooney]

@gjcolombo has been debugging and collecting a bunch of useful data, some of which I'll try to summarize here:

Device migration state (including vCPUs) was captured during one of the migrations which lead to the #DF. Here are the bits from the vCPU which faulted:

run_state:(
    run_state:2,
    sipi_vector:0,
    pending_nmi:false,
    pending_extint:false,
    pending_exception:0,
    pending_intinfo:0
),

gp_regs:(
    rax:34,
    rcx:140384635976491,
    rdx:0,
    rbx:0,
    rsp:140737314712864,
    rbp:140737314713344,
    rsi:140737314713152,
    rdi:140737314713024,
    r8:0,
    r9:140384635720400,
    r10:8,
    r11:582,
    r12:140737314713152,
    r13:140737314713024,
    r14:140737314712864,
    r15:94592597095584,
    rip:94592596610975,
    rflags:518
),

ctrl_regs:(
    cr0:2147811379,
    cr2:140384635535056,
    cr3:901554176,
    cr4:3475184,
    dr0:0,
    dr1:0,
    dr2:0,
    dr3:0,
    dr6:4294905840,
    dr7:1024,
    xcr0:7
),


seg_regs:(
    cs:(base:0,limit:4294967295,access:8443,selector:51),
    ds:(base:0,limit:0,access:65536,selector:0),
    es:(base:0,limit:0,access:65536,selector:0),
    fs:(base:140384635534336,limit:0,access:65536,selector:0),
    gs:(base:0,limit:0,access:65536,selector:0),
    ss:(base:0,limit:4294967295,access:49299,selector:43),
    gdtr:(base:18446741874686300160,limit:127,access:0,selector:0),
    idtr:(base:18446741874686296064,limit:4095,access:0,selector:0),
    ldtr:(base:18446742256938385408,limit:0,access:65536,selector:0),
    tr:(base:18446741874686308352,limit:16519,access:137,selector:0)
),

fpu_state:( ... long, and omitted ...)

lapic:(
    vl_lapic:(
        vlp_id:0,
        vlp_version:393236,
        vlp_tpr:16,
        vlp_apr:0,
        vlp_ldr:16777216,
        vlp_dfr:4294967295,
        vlp_svr:511,
        vlp_isr:(0,0,0,0,0,0,0,0),
        vlp_tmr:(0,0,0,0,0,0,0,0),
        vlp_irr:(0,0,0,0,0,0,0,4096),
        vlp_esr:0,
        vlp_lvt_cmci:65536,
        vlp_icr:144115188075858171,
        vlp_lvt_timer:236,
        vlp_lvt_thermal:65536,
        vlp_lvt_pcint:65536,
        vlp_lvt_lint0:67328,
        vlp_lvt_lint1:1024,
        vlp_lvt_error:254,
        vlp_icr_timer:419,
        vlp_dcr_timer:3
    ),
    vl_msr_apicbase:4276095232,
    vl_timer_target:0,
    vl_esr_pending:0
),

ms_regs:[
    (ident:3221225600,value:7425),
    (ident:3221225730,value:18446622042896728064),
    (ident:3221225601,value:9851692904349696),
    (ident:3221225602,value:18446744072514174992),
    (ident:3221225603,value:18446744072514180976),
    (ident:3221225604,value:292608),
    (ident:372,value:16),
    (ident:373,value:12288),
    (ident:374,value:3099596480),
    (ident:631,value:290206224317088006),
    (ident:16,value:0),
    (ident:254,value:1290),
    (ident:767,value:3078),
    (ident:616,value:0),
    (ident:617,value:0),
    (ident:618,value:0),
    (ident:619,value:0),
    (ident:620,value:0),
    (ident:621,value:0),
    (ident:622,value:0),
    (ident:623,value:0),
    (ident:600,value:434041037028460038),
    (ident:601,value:0),
    (ident:592,value:434041037028460038),
    (ident:512,value:2147483648),
    (ident:513,value:281472829229056),
    (ident:514,value:34359738368),
    (ident:515,value:281440616974336),
    (ident:516,value:0),
    (ident:517,value:0),
    (ident:518,value:0),
    (ident:519,value:0),
    (ident:520,value:0),
    (ident:521,value:0),
    (ident:522,value:0),
    (ident:523,value:0),
    (ident:524,value:0),
    (ident:525,value:0),
    (ident:526,value:0),
    (ident:527,value:0),
    (ident:528,value:0),
    (ident:529,value:0),
    (ident:530,value:0),
    (ident:531,value:0)
]

Notable is that no "extra" interrupt/exception state was present (pending_exception/pending_extint), so it does not appear that we were injecting a bogus or malformed exception which itself lead directly to the #df.

The LAPIC does contain a pending interrupt request:

        vlp_irr:(0,0,0,0,0,0,0,4096),
...
        vlp_lvt_timer:236,

That corresponds to vector 0xEC, which matches the LVT configuration for the LAPIC timer. Considering the guest is under high CPU load via stress-ng, frequent scheduling/firing of the LAPIC timer would be expected as the guest OS schedule does its job.

The next course of action was to enable full exception interception in the guest to see what might be triggering the #DF condition. A subsequent trace captured some of the action in an afflicted guest:

 14  90179           vm_entry_intinfo:entry exit_intinfo: 0     exc_pending: 780000b0e
 14  91481           svm_inject_event:entry 0x780000b0e
 14  90179           vm_entry_intinfo:entry exit_intinfo: 0     exc_pending: 780000b0e
 14  91481           svm_inject_event:entry 0x780000b0e
 10  90179           vm_entry_intinfo:entry exit_intinfo: 780000b0e     exc_pending: 0
 10  91481           svm_inject_event:entry 0x780000b0e
 10  90179           vm_entry_intinfo:entry exit_intinfo: 780000b0e     exc_pending: 380000b0e
 10  91481           svm_inject_event:entry 0x80000b08
 10  90691        vm_inject_exception:entry vcpu: 1     vector:13
 10  90179           vm_entry_intinfo:entry exit_intinfo: 0     exc_pending: 2880000b0d
 10  91481           svm_inject_event:entry 0x2880000b0d

Here we can see an initial page fault (user-mode, write, paging-entry-present), followed by another while injecting the first (supervisor-mode, write, paging-entry-present)

This raised further questions about the address(es) in question for those faults. Armed with an update dtrace script, the conditions were triggered again:

  9  91481           svm_inject_event:entry cpu: 0      event: 0x800000ec                                                                                                                                                                                                                                                    
  9  90691        vm_inject_exception:entry vcpu: 0     vector:14                                                                                                                                                                                                                                                            
  9  90179           vm_entry_intinfo:entry vcpu:0      exit_intinfo: 800000ec  exc_pending: 380000b0e                                                                                                                                                                                                                       
  9  91481           svm_inject_event:entry cpu: 0      event: 0x380000b0e
  9  91481           svm_inject_event:entry cr2: 0x7ffda3c72658
  9  90691        vm_inject_exception:entry vcpu: 0     vector:14
  9  90179           vm_entry_intinfo:entry vcpu:0      exit_intinfo: 380000b0e exc_pending: 380000b0e
  9  91481           svm_inject_event:entry cpu: 0      event: 0x80000b08

Here we see the lapic timer interrupt (0xec) be injected. When attempting to vector that interrupt, a paging fault (supervisor-mode, write, paging-entry-present) was raised. Similar to before, a subsequent #PF was raised in response to the first, resulting in the #DF.

As for next steps, the reasons behind those #PF faults are of interest. Is the VMM failing to move some piece of vCPU state? Are memory contents being mis-copied or corrupted during the sync phase?

[gjcolombo]

We might have a bead on this one.

Some additional investigation and tracing yesterday revealed the following:

• The #PFs were coming from attempts to access a user-mode stack page
• Enabling VM exits on guest exceptions and tracing showed that the %rip associated with these faults was a user-mode IP
• The faults themselves are supervisor write faults
• Disabling SMAP in the guest kernel (with the nosmap kernel cmdline flag) almost completely suppresses the problem

This led us to suspect a problem with stack switching after live migration:

• Some state gets mangled during migration
• The guest takes an interrupt and fails to switch to the kernel stack
• Interrupt delivery attempts to push registers to the current stack
• The pushes generate SMAP faults because the stack is user but the mode has changed to supervisor

Today we were able to get one more guest crash with SMAP disabled. In that crash, the guest took a page fault while (apparently) trying to return from an interrupt handler; the #PF recursed infinitely, ran out of stack, and then double faulted. Analyzing the guest crash showed that the PF handler evidently thought the value of %gs was 0 when it should have been a pointer to a kernel CPU control structure. This is possibly also consistent with operating on the wrong stack or in the wrong mode, smashing something as a result, and then being unable to return from an IRQ.

We then added a USDT probe to the migration resume path that invokes a script that uses mdb to dump the VMCBs from the source and destination VMs just before the destination resumes after migration:

:propolis-server::state_driver_migration_target_start {
    stop();
    system("/path/to/get_vmcbs.sh %d", pid);
}

#!/bin/bash

date
for line in $(mdb -ke 'vmm_list::walk list | ::printf "%p:%s\n" vmm_softc_t vmm_vm vmm_name'); do
        VMPTR=$(echo "$line" | awk -F: '{print $1}')
        VMNAME=$(echo "$line" | awk -F: '{print $2}')

        echo "### VM '$VMNAME'"
        mdb -ke "$VMPTR::print 'struct vm' cookie | ::print 'struct svm_softc' vcpu[0].vmcb vcpu[1].vmcb"
done

if [[ -n $1 ]]; then
        prun $1
fi

In the next repro we observed that the faulting CPU's VMCB had CPL = 3 on the source but CPL = 0 on the destination. This appears to be a bhyve bug: if bhyve is asked to import an SS descriptor, it will copy its DPL into the VM's VMCB... but the corresponding export code doesn't copy VMCB.CPL into SS.DPL, which can lead to an unexpected privilege level change.

@pfmooney has a bhyve patch that I'm currently building and deploying.

[pfmooney]

Written up as 15624 for illumos.

[gjcolombo]

The illumos fix for this has merged and seems to have taken care of the problem (see the issue linked above).