[openvmm/kvm] assertion failed: reset state mismatch in Xsave (vmm_core/virt/src/x86/vp.rs:1841)

[daniel5151]

Command: cargo run (using built-in test Kernel) On commit: 337f42f0 Rust version: 1.86.0 (stable) Linux Kernel: 6.6.72-gbe485e577c3a

Hey folks 👋

I picked up a cheapo little Chromebook to do some work-on-the-go during my few weeks of funemployment, and just for kicks, I thought I'd see if openvmm would run on it. The answer is: kinda.

Seems that shortly after starting the VM, it fails with an assertion failure in the Xsave restore path. Looks like the diff is inside the XsaveHeader, in the xstate_bv field (which is 0x18 on the left-side, but 0x0 on the right side).

The CPU is really old - an Intel Celeron N4000 (2) @ 1.094GHz. That said - the CPU is certainly good enough to run Crostini (i.e: Linux virtualization on ChromeOS), so it probably should be able to run openvmm as well.

Full logs:

  Compiling openvmm v0.0.0 (/home/danielprilik/src/openvmm/openvmm/openvmm)
    Finished `dev` profile [unoptimized] target(s) in 1m 15s
     Running `target/debug/openvmm`
   0.018072799s  INFO run_follower{ local_id=N-c9b65ab101d68897d51b3dd16004143b}: mesh_remote::unix_node:  "new"
   0.018670360s  INFO run_leader{ local_id=N-c9b65ab101d68897d51b3dd16004143b}: mesh_remote::unix_node:  "new"
   0.047409535s  INFO mesh_spawn_process{ mesh_name="openvmm"}: mesh_process:  "new"
   0.047747136s  INFO mesh_spawn_process{ mesh_name="openvmm"}:invite{ local_id=N-c9b65ab101d68897d51b3dd16004143b}: mesh_remote::unix_node:  "new"
   0.049748231s  INFO run_connection{ local_id=N-c9b65ab101d68897d51b3dd16004143b remote_id=N-1fdfa9b649fd5f6e8adf058b941152f1}: mesh_remote::unix_node:  "new"
   0.051343747s  INFO mesh_spawn_process{ mesh_name="openvmm"}:invite{ local_id=N-c9b65ab101d68897d51b3dd16004143b}: mesh_remote::unix_node:  "close" time.busy=118µs time.idle=3.47ms
   0.056255865s  INFO mesh_spawn_process{ mesh_name="openvmm"  pid=8020}: mesh_process:  "close" time.busy=5.28ms time.idle=3.60ms
   0.012111499s  INFO join_generic{ local_id=N-1fdfa9b649fd5f6e8adf058b941152f1 remote_id=N-c9b65ab101d68897d51b3dd16004143b}: mesh_remote::unix_node:  "new"
   0.014238784s  INFO run_follower{ local_id=N-1fdfa9b649fd5f6e8adf058b941152f1}: mesh_remote::unix_node:  "new"
   0.014494279s  INFO run_connection{ local_id=N-1fdfa9b649fd5f6e8adf058b941152f1 remote_id=N-c9b65ab101d68897d51b3dd16004143b}: mesh_remote::unix_node:  "new"
   0.017342126s  INFO join_generic{ local_id=N-1fdfa9b649fd5f6e8adf058b941152f1 remote_id=N-c9b65ab101d68897d51b3dd16004143b}: mesh_remote::unix_node:  "close" time.busy=1.34ms time.idle=9.81ms
   0.020883858s  INFO worker_host_launch_request: mesh_worker::worker:  "new"
   0.022122052s  INFO worker_host_launch_request: mesh_worker::worker:  "close" time.busy=500µs time.idle=740µs
   0.022666369s  INFO worker_new{ name="VmWorker" action="new"}: mesh_worker::worker:  "new"
   0.025823040s  INFO worker_new{ name="VmWorker" action="new"}: hvlite_core::worker::dispatch:  guest RAM config mem_size=0x40000000
   0.049528608s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pic"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.050094218s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pic"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=396µs time.idle=190µs
   0.050233111s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="ioapic"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.050472983s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="ioapic"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=149µs time.idle=90.6µs
   0.050611593s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pci_bus"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.054032680s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pci_bus"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=3.29ms time.idle=107µs
   0.054595805s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pit"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.054938373s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pit"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=241µs time.idle=106µs
   0.055064512s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="rtc"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.055269517s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="rtc"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=113µs time.idle=92.2µs
   0.055391301s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pm"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.055888028s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="pm"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=377µs time.idle=120µs
   0.056028727s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com1"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.059512028s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com1"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=3.35ms time.idle=116µs
   0.060693398s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com2"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.062609502s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com2"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=517µs time.idle=1.39ms
   0.063702227s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com3"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.065235250s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com3"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=1.20ms time.idle=323µs
   0.065494117s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com4"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.065854154s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="serial-com4"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=259µs time.idle=103µs
   0.065978799s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="io-delay-0xed"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.066209432s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="io-delay-0xed"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=136µs time.idle=95.4µs
   0.066333800s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="missing-vmware-backdoor"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.066549628s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="missing-vmware-backdoor"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=101µs time.idle=115µs
   0.066667802s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="missing-gameport"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.067860696s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="missing-gameport"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=922µs time.idle=261µs
   0.068089824s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="fake-bus-root"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.068287819s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="fake-bus-root"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=105µs time.idle=94.5µs
   0.068568647s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="virtio-serial"}: vmotherboard::chipset::backing::arc_mutex::device:  "new"
   0.068909991s  INFO worker_new{ name="VmWorker" action="new"}:add_device{ device="virtio-serial"}: vmotherboard::chipset::backing::arc_mutex::device:  "close" time.busy=248µs time.idle=94.6µs
thread 'vp-0' panicked at /home/danielprilik/src/openvmm/vmm_core/virt/src/x86/vp.rs:1841:1:
assertion `left == right` failed: reset state mismatch (actual/expected)
  left: Xsave { legacy: Fxsave { fcw: 37f, fsw: 0, ftw: 0, reserved: 0, fop: 0, fip: 0, fdp: 0, mxcsr: 1f80, mxcsr_mask: 0, st: [[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]], xmm: [[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]], reserved2: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], unused: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] }, header: XsaveHeader { xstate_bv: 18, xcomp_bv: 800000000000001b, reserved: [0, 0, 0, 0, 0, 0] }, data: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] }
 right: Xsave { legacy: Fxsave { fcw: 37f, fsw: 0, ftw: 0, reserved: 0, fop: 0, fip: 0, fdp: 0, mxcsr: 1f80, mxcsr_mask: 0, st: [[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]], xmm: [[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]], reserved2: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], unused: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] }, header: XsaveHeader { xstate_bv: 0, xcomp_bv: 800000000000001b, reserved: [0, 0, 0, 0, 0, 0] }, data: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] }

[jstarks]

These states aren't meaningfully different, but our assertions want to make sure they're exactly the same for consistency.

Probably the easiest thing is to update virt_kvm to just set_xsave() to the at_reset value as part of initialization.

[daniel5151]

Probably the easiest thing is to update virt_kvm to just set_xsave() to the at_reset value as part of initialization.

I suspect this isn't what you meant, but I tried to ignore the passed in value: vp::Xsave, and instead reinit a fresh let value = vp::Xsave::at_reset(...) as part of the method impl. That didn't seem to have any effect though (same assert failure).

I proceeded to go full grug mode and simply commented out the assertion inside the macro, and after doing that, it looks like things booted alright.

Now, admittedly, not all is fine post-boot, as upon running ls, I'm hit with this lovely message:

/ # ls
[  781.446407] ls[60]: segfault at 7ffc8b1f1dc0 ip 0000000000402549 sp 00007ffc8b1efd98 error 4 in ls[401000+268000] likely on CPU 0 (core 0, socket 0)
[  781.526262] Code: 10 06 0f 10 4e 10 0f 10 56 20 0f 10 5e 30 0f 10 a6 00 10 00 00 0f 10 ae 10 10 00 00 0f 10 b6 20 10 00 00 0f 10 be 30 10 00 00 <44> 0f 10 86 00 20 00 00 44 0f 10 8e 10 20 00 00 44 0f 10 96 20 20
Segmentation fault
/ #

...so clearly, something else is afoot.

But honestly, I'm willing to chalk it up to "maybe running openvmm, nested, on a chromebook from 2017 isn't the best idea", so I probably wouldn't worry about it too much.

[chris-oo]

that segfault seems similar to something i saw long ago - i wonder if we're doing something wrong in our kvm backend.