runtime-adapter: a KVM clone whose restore brings 2 or more CPUs online can stop answering once its sandbox starts, so the vm_clone processor-target scenarios time out (flaky NVX microVM tests / Linux / KVM / Guests and sandboxes) #1050

Summary

The dev push run for 80d4821 (#1041) failed in NVX microVM tests / Linux / KVM / Guests and sandboxes because the runtime adapter scenario vm_clone a_generation_refuses_clones_of_fewer_processors_than_its_template_booted_with timed out. Its restore brought a clone from 2 to 4 online CPUs. The clone then answered the host's activation, mapping table, and start, and answered nothing more for 30 s, without exiting. OpenVMM logged nothing after the guest acknowledged the restore.

The same signature failed the sister scenario one_generation_serves_clones_of_each_processor_count_from_its_boot_online_count_to_its_capacity once before, on 2026-10-29. That was also a target of 4 CPUs on azure-kvm-1, and nobody reported it. Across the CI runs since the two scenarios were added, they failed 2 of 94 Linux/KVM jobs, and never failed on Linux/MSHV or Windows/WHP.

#1041 did not cause this. It changes only a doc comment and unit tests in nvx-rs/src/guest/sys/rooted.rs, and the earlier occurrence predates it.

The root cause is unknown. A clone discards its console (#996), so CI's evidence cannot tell whether the guest kernel, the guest agent, or OpenVMM stalled. Restore-time CPU activation alone does not explain it: the Alpine scenarios that bring up to 7 CPUs online at restore, through the same time-ABI repair, passed all 353 KVM runs in the same period. What a clone adds is:

• its layered root;
• its control session and sandbox start;
• repair step 7's copy of the clone's mounts, which runtime-adapter: a_clone_refuses_a_scratch_image_whose_upper_an_earlier_clone_used fails intermittently #1020 found runs right after the start.

Incident

• Workflow: CI run 41060782829, attempt 1, push to dev.
• Head: 80d482192b24ca419181e8d2f0e6ef0b4fe637b1, the merge of nvx-rs: retry openat2's EAGAIN in the rooted path test #1041, with OpenVMM bcfc47cff as its openvmm gitlink. Push runs on dev queue rather than cancel each other, so this run was not superseded. The next dev push run, 41060946185 for 78c626d (scripts: give the CLI tests' PowerShell launches a shared 120 s limit, and report what a timed-out launch printed #1043), queued behind it.
• Failed job: NVX microVM tests / Linux / KVM / Guests and sandboxes, step Run runtime adapter scenarios on Linux. The step runs python3 scripts/nvx.py test-runtime-adapter --backend kvm (run-nvx-microvm-tests.yml#L1302-L1308). This was the only failure among the suite's 154 scenarios, and the job's earlier steps passed.
• Runner: self-hosted azure-kvm-1 (self-hosted, linux, kvm, virtual-machine, general), an Azure VM with an Intel Xeon Platinum 8370C (intel.icelake-sp.v1) on Linux 6.6.159.1-1.azl3. doctor H1-H4 passed.
• Downstream:
  • Required status check failed.
  • Publish development release, Persist performance baseline, Package nvx crate, and Publish nvx crate were skipped.
  • Performance regression gate runs only for pull requests.

The scenario (vm_clone.rs#L2557-L2603) captures a template of 4 processors, 2 of them online at boot. Its first two starts behaved as expected: a target of 1 was refused, and a start without a target started. The start with --processors 4 exited with 8 rather than 0. Decisive output, trimmed; the suite's summary, which the log interleaves with it, is left out:

thread 'a_generation_refuses_clones_of_fewer_processors_than_its_template_booted_with' (2596630) panicked at tests/common/mod.rs:276:9:
assertion `left == right` failed: start ["--template", "/tmp/runtime-adapter-cl-boot-2596205-0/store", "--generation", "1", "--distro", "erofs:/tmp/runtime-adapter-cl-boot-2596205-0/platform/ubuntu-distro.erofs", "--distro-identity", "15161d82-9dfa-6e3a-1eeb-850cbeced4f2", "--upper", "ram", "--processors", "4"] ended with exit status: 8
stdout:
generation=1
lease=106f1f600dce344244b894a1fd40a161
downtime=5476109857
source=monotonic
pid=2597033
root=ready
build=0.1.0
table=applied
mapped=0
sandbox=started
failure.outcome=unknown
failure.evidence=timeout
failure.stage=commit
failure.progress=started
failure.status=none
failure.teardown=terminated
failure.code=timed-out
released=106f1f600dce344244b894a1fd40a161
quarantined=no

stderr:
runtime-adapter-host: the guest agent did not answer once the clone's sandbox started: the NVXS operation timed out; see the VMM's log /tmp/runtime-adapter-cl-m-2596205-1/store/openvmm.log

the end of the VMM's log:
   0.000869178s  INFO openvmm_entry:  version="0.3.0+gbcfc47cff"
   0.001672803s  INFO openvmm_entry::microvm::restore:  time ABI restore preflight passed downtime_ns=0x146e93697 source=HostMonotonic generation=0x1 cpu_profile="intel.icelake-sp.v1"
   …
   0.036183768s  INFO openvmm_entry:  restoring VM from snapshot
   0.036681236s  INFO state_unit::start:  state-unit start complete duration=329.342µs
   0.172408945s ERROR virt_kvm::arch::x86_64:  unrecognized msr read index=0x4e
   0.240362473s ERROR virt_kvm::arch::x86_64:  unrecognized msr read index=0x4e
   0.299495657s  WARN openvmm_entry::vm_controller::microvm:  ignoring microVM snapshot request because no destination is configured

  left: Some(8)
 right: Some(0)

The test prints the last 8 KiB of OpenVMM's log (common/mod.rs#L44-L45). This log is shorter and starts at OpenVMM's first line, so it is the whole log: OpenVMM wrote nothing between 0.299 s and the host's termination. The job's artifact nvx-microvm-tests-kvm-guests keeps none of the adapter's /tmp/runtime-adapter-* stores, so nothing else of the clone survives.

History

I checked the runtime adapter step of every NVX microVM tests / * / Guests and sandboxes job in the 446 CI runs created from 2026-10-26 to this run, and the logs of all 34 jobs in which that step failed. The two scenarios first ran on 2026-10-27, on #926's branch. This signature appears twice, both times at a target of 4 CPUs on azure-kvm-1:

How often the two scenarios passed, by the job's runtime adapter step, in the runs whose head has them:

• The 85 KVM passes ran on azure-kvm-1 (28), azure-kvm-2 (28), azure-kvm-4 (15), and azure-kvm-5 (14). Every KVM runner has the same CPU model and Azure Linux 3 kernel series. If failures landed on runners in proportion to their jobs, both would land on azure-kvm-1 about one time in ten.

• Targets of 2 CPUs, which bring one CPU online, have not failed. Both failures brought 2 or 3 online.

• Restore-time activation without a clone has not failed. The Alpine scenarios restore-processors and platform-restore-processors restore a snapshot captured with maxcpus=1:

  • restore-processors restores capacity 8 at 2, 4, and 8 CPUs.
  • platform-restore-processors restores capacity 4 at 2 and 4 CPUs (microvm_tests.py#L5156-L5170, #L328-L329).

  They bring the CPUs online through sysfs and finish the restore with nvx-time restore-finish --new-cpus, which hands step 7 to the same daemon. In the KVM Shard 1 of 2 jobs, which have run both scenarios since 2026-10-23, of the CI runs created since 2026-10-27, 353 ran these scenarios to the end and passed, 78 of them on azure-kvm-1, and none failed them.

Root cause

The root cause is not known yet. Permalinks point to 80d4821 and to OpenVMM's bcfc47c; the linked NVX files are unchanged on the current dev head, 78c626d.

What the evidence establishes:

1. The repair brought the CPUs online and acknowledged the restore.
   • The guest's repair brings each offline CPU of the target's prefix online through sysfs before the acknowledgement (repair.rs#L202-L235).
   • Each unrecognized msr read index=0x4e is one CPU coming up: Linux reads MSR_PPIN_CTL as it identifies each Ice Lake CPU, and OpenVMM refuses the read. There are two here and three in the earlier occurrence, one for each CPU that the restore brought online.
   • The snapshot-request warning is repair step 6, the acknowledgement through the snapshot port (daemon.rs#L937-L941). A clone has no snapshot destination, so OpenVMM answers it by releasing the boundary (microvm.rs#L127-L136, #L539-L554).
   • Both lines appear in clones that pass, too.
2. The clone worked after that. OpenVMM holds the host's input on the clone's control console until the acknowledgement releases it. The guest agent then assembled the root, applied the mapping table, and started the sandbox, as root=ready, table=applied, and sandbox=started show (runtime-adapter-host.rs#L2722-L2740).
3. Then nothing answered.
   • The host's ping, then echo, on the clone's session had 30 s (runtime-adapter-host.rs#L488).
   • The guest agent's worker answers both at once (worker.rs#L990-L991), and its start only sets a flag (order.rs#L57-L61).
   • Neither request got an answer, the VM never exited (failure.status=none), and OpenVMM wrote nothing more before the host terminated it (failure.teardown=terminated).
   • So the guest, or the control console's path through OpenVMM, stalled within moments of the start.
4. Repair step 7 runs in that window.
   • The repair hands step 7 to the nvx-time daemon. The daemon starts it in a child at SCHED_IDLE 150 ms after the acknowledgement, and raises it to normal priority 100 ms later (mod.rs#L94-L97, daemon.rs#L597-L639, #L684).
   • The child runs the restore checks, pinning itself to each new CPU in turn (checks.rs#L734-L763, #L936-L957).
   • It then runs grace_period_release (daemon.rs#L351-L365). That function forces rcu_normal=1 and unshares a private mount namespace, which copies every mount of the clone. It then mounts and unmounts a tmpfs there to force a normal RCU grace period.
   • Throughout, the stall detectors stay suppressed until step 7 releases them, or until their 21 s timeout passes.
   • runtime-adapter: a_clone_refuses_a_scratch_image_whose_upper_an_earlier_clone_used fails intermittently #1020's instrumented reproduction showed step 7 starting only once the clone had started and served its first probes.
5. It needs a clone and a target of 4. The Alpine scenarios above bring up to 7 CPUs online through the same repair and step 7, on the same runners, without failing. Targets of 2 have not failed either.

Candidates, none confirmed:

• A newly activated vCPU on these nested-KVM Azure VMs stops making progress or taking interrupts. The guest then stalls once its work, an IPI, or step 7's grace period depends on that vCPU.
• An interaction between step 7 and the clone's root or sandbox start. Step 7 pins itself to the new CPUs, copies the clone's mounts, and forces a grace period while the stall detectors are suppressed.
• A stall in the control console's path, in OpenVMM's broker or the guest's virtio console.
• A fault specific to azure-kvm-1, as ci: intermittent restored-TSC warp on Linux virtual-machine runners (MSHV, KVM) #211's TSC warps were specific to azure-kvm-4.

Reproduction

Not reproduced yet. The scenario fails in about 1 of 50 KVM jobs, so a reproduction needs a loop on a Linux/KVM Azure VM host, as #1020's did on nvx-kvm-test. Run it with the guest artifacts and OpenVMM staged as CI stages them, and with the guest agent built by cargo build --locked --release --features guest --target x86_64-unknown-linux-musl --bin runtime-adapter-guest:

cd tests/runtime-adapter
NVX_HYPERVISOR=kvm NVX_ARTIFACTS_DIR="$(git rev-parse --show-toplevel)" \
RUNTIME_ADAPTER_GUEST="$PWD/target/x86_64-unknown-linux-musl/release/runtime-adapter-guest" \
cargo test --locked --features host --test vm_clone -- --include-ignored --exact \
  a_generation_refuses_clones_of_fewer_processors_than_its_template_booted_with

A reproduction under today's diagnostics would show only the same timeout. A clone launches with --virtio-console none (launch.rs#L692-L693), so the run also needs:

• what the guest writes: a console that a reader keeps, as nvx-rs: let an adapter read the boot console of a template's clones #996 proposes, or instrumented guest programs, as in runtime-adapter: a_clone_refuses_a_scratch_image_whose_upper_an_earlier_clone_used fails intermittently #1020;
• at the timeout, before the host terminates OpenVMM: OpenVMM's VP states and the kernel stacks of its threads.

Impact

• 80d4821 has a red required check, and neither a development release nor a performance baseline. The next dev push run, 41060946185 for 78c626d, contains 80d4821 and runs the same scenarios.
• On a pull request, the hang turns Required status check red until someone reruns the job.
• Each KVM run takes the risk at each clone start that brings CPUs online. There are three per run: targets of 2 and 4 in one_generation_serves…, and 4 in a_generation_refuses…. Two of the three bring 2 or more CPUs online.
• If it is not specific to the CI runners, a clone started with more CPUs than its template had online at boot can stop answering right after it starts, with no record of why.

Suggested fix

• Make the next occurrence diagnosable before changing behavior:
  • give the adapter's clones a console that CI keeps (nvx-rs: let an adapter read the boot console of a template's clones #996);
  • record OpenVMM's VP states, and its threads' kernel stacks, when a clone's session times out, before the host terminates the VMM;
  • keep the stores of a failed scenario in the job's artifact.
• Reproduce in a loop as above. Then compare runs with step 7's grace-period release, or its namespace copy, delayed or skipped, to tell an interaction with step 7 from a vCPU problem.
• Watch where it lands. If later occurrences stay on azure-kvm-1, check that VM as ci: intermittent restored-TSC warp on Linux virtual-machine runners (MSHV, KVM) #211 did azure-kvm-4.
• Do not retry the scenario or lengthen its 30 s: either would hide a clone that stops answering.

Related work

• nvx-rs: per-clone CPU targets #849 and nvx-rs: serve clones of each processor count from one template #926 added per-clone processor targets and both scenarios.
• nvx-rs: repair a clone's restore in the guest #936 added the guest's repair.
• openvmm: let platform snapshots activate vCPUs at restore #801 (microvm: Platform snapshots can't use restore-time CPU activation #796), with [DO NOT REVIEW] microVM: let platform snapshots activate vCPUs at restore openvmm#4735, lets platform snapshots activate vCPUs at restore. It was validated on bare-metal KVM, MSHV, and WHP hosts only, while CI's KVM runners are Azure VMs running nested KVM.
• runtime-adapter: a_clone_refuses_a_scratch_image_whose_upper_an_earlier_clone_used fails intermittently #1020, closed by nvx-rs: sync an ext4 scratch before a root's teardown unmounts it #1031, is another intermittent KVM vm_clone failure, caused by step 7's copy of the clone's mounts. runtime-adapter: a_clone_refuses_a_scratch_image_whose_upper_an_earlier_clone_used fails intermittently #1020 suggests keeping grace_period_release from copying the workload's mounts, which no issue tracks yet.
• ci: intermittent restored-TSC warp on Linux virtual-machine runners (MSHV, KVM) #211 and ci: Linux/MSHV restore-processors marks restored tsc-early unstable via clocksource watchdog #253 are earlier anomalies of restore-time CPU activation on the Azure runner VMs. Every KVM occurrence of ci: intermittent restored-TSC warp on Linux virtual-machine runners (MSHV, KVM) #211 ran on one VM.
• nvx-rs: let an adapter read the boot console of a template's clones #996 is the clone console that this diagnosis lacks.
• time ABI: publish the host's clock correction with each time sample #1018 rewrites the time daemon and its checks for time ABI 2, step 7 included.
• openvmm: map VM times beyond the host clock to its latest time #1042 (vmtime: armed timeout + restore to a large time panics the keeper task on start() #1038) fixes an OpenVMM VM-time keeper that could spin with its lock held, which would stall the VMM silently. Its triggers, timeouts far beyond the host clock and Hyper-V synthetic timers on WHP, do not match this KVM clone, whose restore came 5.5 s after its capture.