ci: a cold boot's time sample exceeded 100 µs, and a clone's repair failed with 195, on azure-windows-1 (flaky NVX microVM tests / Windows / WHP / Runtime adapter) #1309

Summary

Two runs of NVX microVM tests / Windows / WHP / Runtime adapter failed 14 minutes apart on azure-windows-1, in different scenarios, each because a guest failed time ABI 2 and powered its VM off. Neither head changes any time code.

• In the merge group of ci: run pushes to feature/nvx-refactor #1302, a clone of vm_clone a_clone_whose_activation_fails_ends_before_it_is_ready ended with status 195 before its repair acknowledged the restore. 195 is the time ABI's status for a failed restore repair. The test expects the clone to repair, then fail its activation with 54. This took ci: run pushes to feature/nvx-refactor #1302 out of the merge queue.
• In a pull-request run of openvmm: pin the serial socket's read fix and output retention tests #1303, the cold boot of vm_layered a_denied_network_lets_no_probe_through failed check C12, status 193: time sample uncertainty 119213 ns exceeds 100000 ns.

At a cold boot and at a clone's repair alike, the guest takes up to 3 time samples. It accepts one only if OpenVMM paired host UTC with the guest TSC within 100 µs; if none qualifies, the guest powers off (Table 3.10). Incident 2 shows a sample over the bound. Incident 1's status most likely comes from the same check failing during the repair, though no log names the check (see Evidence). In the same two workflow runs, the WHP benchmark runner, azure-windows-5, paired its samples within 136 and 139 ns.

Neither change touches time:

• ci: run pushes to feature/nvx-refactor #1302 changes only CI's workflow, its documentation, and its scripts and their tests.
• openvmm: pin the serial socket's read fix and output retention tests #1303's OpenVMM pin adds 3 commits, in serial_socket and the virtio_console tests only.

#1302's identical tree passed its next merge group on azure-windows-6. azure-windows-1 passed WHP jobs at 01:16Z, before the incidents, and at 02:00Z and 02:11Z, after them.

Incidents

1. Clone repair, merge group of #1302 (2026-11-06 01:34Z)

• Workflow: CI run 42144050826, attempt 1, merge_group.

• Head: c41a9b8c3a52e9fdcfcc8f776c3bf804fc8e2879, ci: run pushes to feature/nvx-refactor #1302's 6224fb785 on dev's 4cfe8330e. OpenVMM 14dc4116ec7e57567633c4b7b07892aca3a58522.

• Failed job: NVX microVM tests / Windows / WHP / Runtime adapter on azure-windows-1, step Run runtime adapter scenarios on Windows. vm_clone passed 34 of its 35 tests.

• Failure, at vm_clone.rs:1492:

  left:  ["repair", "repair-status", "activation", "event", "195", "exited"]
  right: ["request", "unusable-root", "activation", "activating", "54", "exited"]
  

  The start printed:

  {"downtime": "10336688075", "failure.code": "exited", "failure.evidence": "repair-status", "failure.outcome": "repair", "failure.progress": "event", "failure.stage": "activation", "failure.status": "195", "failure.teardown": "exited", "generation": "1", "lease": "42197786ea8a4fe185cd79818a8348d5", "pid": "9868", "quarantined": "no", "released": "42197786ea8a4fe185cd79818a8348d5", "source": "monotonic"}
  

• Downstream:

  • Required status check failed, and the queue removed ci: run pushes to feature/nvx-refactor #1302 at 01:39:08Z (failed_checks).
  • ci: run pushes to feature/nvx-refactor #1302 was re-queued at 01:58:01Z. Its next group, run 42147285388, had the same tree (dc5bbe38) and passed the test on azure-windows-6.
  • ci: run pushes to feature/nvx-refactor #1302 merged at 02:09:13Z, about 30 minutes later than it would have otherwise.

2. Cold boot, pull-request run of #1303 (2026-11-06 01:47Z)

• Workflow: CI run 42144804527, attempt 1, pull_request.

• Head: c96ceaaee37ee97230a2fbc3402c5b9bf88119f4. OpenVMM 6fb64731f03314a3c5ee634d3c85d6782a5babe0, incident 1's pin plus 3 commits in serial_socket and the virtio_console tests only.

• Failed job: NVX microVM tests / Windows / WHP / Runtime adapter on azure-windows-1, the same step. vm_layered passed 42 of its 43 tests.

• Failure: the launch of a_denied_network_lets_no_probe_through exited 1 with cannot attach to the VM: the broker closed the NVXS session. The VMM's log ended:

  NVX-TIME-ABI-VIOLATION: v=1 code=G_CONFORMANCE_C12 source=conformance phase=boot generation=0 boottime_ns=2251650395 detail="time sample uncertainty 119213 ns exceeds 100000 ns"
     3.487992600s  INFO openvmm_entry::vm_controller:  guest halted reason=PowerOffWithStatus { code: c1 }
  

Runner validation passed H1 to H4 in both jobs; H4 found azure-windows-1's TSC rate in agreement with QueryPerformanceCounter. No check measures how long OpenVMM takes to pair a sample.

Evidence

• Same bound at boot and at repair. The guest takes at most SAMPLE_ATTEMPTS, 3, samples, each within SAMPLE_BOUND_NS, 100 µs.
  • At a cold boot, an initial sample over the bound fails check C12, status 193.
  • At a restore's repair, the guest selects its sample with the same bound. A sample over it fails G_REPAIR_SAMPLE, status 195.
• Where incident 1's 195 probably came from. This is an inference, not an observation.
  • The record's progress, event, says that the host read OpenVMM's restore-ready event but never saw the repair acknowledge the restore.
  • Before the acknowledgement, the repair ends a clone with 195 only through G_REPAIR_PACKET, G_REPAIR_GENERATION, G_REPAIR_SAMPLE, or G_REPAIR_CLOCK. G_REPAIR_SUPPRESSION comes from repair step 7, which starts 150 ms after the acknowledgement.
  • A bad packet or generation would fail every clone, yet the job's other clones passed through the same repair. An adjtimex failure has no reason to be intermittent.
  • That leaves G_REPAIR_SAMPLE: the same bound that incident 2 exceeded 14 minutes later.
• Why no log can confirm it.
  • A clone's restore discards the guest's console, so the host sees only the status, which it attributes to the repair.
  • A job that runs only the runtime adapter uploads no failure logs.
• Usual values.
  • The WHP platform job is the only WHP job whose log routinely shows the latest accepted sample's uncertainty (NVX-TIME-ABI: … uncertainty_ns=…). On azure-windows-5 it measured 108 to 146 ns in its 17 runs from 2026-11-05 18:35Z to 2026-11-06 01:45Z.
  • A general runner's log shows the value only when a scenario prints it: 13,024 ns on azure-windows-4, in a shard of run 41973357177 that failed for another reason (test-microvm: lifecycle intermittently misses its marker when the byte channel's output interleaves with the boot console's #1290).
  • How close the general runners' parallel suites usually come to 100 µs is unknown.

History

The 300 CI runs from 2026-11-02 08:37Z to 2026-11-06 02:12Z:

• The WHP runtime-adapter job completed 121 times and failed 3.
  • Two failures are these, on azure-windows-1, which passed the job 16 times.
  • The third was on azure-windows-4 (run 42095876865): a network check, vm_layered an_allow_rule_lets_only_its_destination_through, with no time violation.
• Of the 33 jobs that failed in those runs, on every backend, only these two logged a time-ABI violation.

Root cause

Probably a transient condition of azure-windows-1 around 01:34Z and 01:47Z on 2026-11-06, in which OpenVMM could not pair host UTC with the guest TSC within 100 µs in 3 tries. The guest and OpenVMM did what time ABI 2 specifies.

What delayed the pairing is unknown. A stall of the runner VM's vCPUs would explain it, whether from contention with the suite's parallel VMs, a noisy neighbor, or host maintenance such as #768's live migration.

Impact

• Any VM that boots or restores on a runner in this state can fail, in any scenario. The scenario reports its own symptom, such as the broker closed the NVXS session, rather than the time ABI's, unless the VMM's log is printed.
• Incident 1 took ci: run pushes to feature/nvx-refactor #1302 out of the merge queue. Incident 2 failed openvmm: pin the serial socket's read fix and output retention tests #1303's pull-request run.

Suggested next steps

1. Find what azure-windows-1 went through from 01:30Z to 01:50Z on 2026-11-06: the Azure activity log of its VM (maintenance, live migration), its vCPU wait time, and its load, as ci: track azure-mshv-1's intermittent H4 failures after a live migration to a host with an unstable clock #768 did for azure-mshv-1.
2. Record the uncertainty of accepted samples on the general runners, as the platform job's log does, to learn how close their suites come to the bound under parallel load.
3. Make a clone's 195 attributable:
   • Keep the time-ABI violation of a clone's guest where the host can report it.
   • Upload the runtime adapter's VMM logs when its job fails.
4. If the general runners come close to the bound in normal runs, don't loosen the tests. Instead, either:
   • qualify the runners for the bound, as runner validation's H4 does for the TSC rate; or
   • revisit the bound or the number of attempts in the time ABI's design.

Related

• test-microvm: time-host-correction fails when the host's time service slews host UTC by more than 75 ppm during a phase (flaky NVX microVM tests / Linux) #1229, fixed by test-microvm: tolerate host time-service slews in time-host-correction #1285: time-host-correction failed by a host time service's slews. It's the same class of failure, the CI host's clock rather than the product, through another mechanism.
• ci: track azure-mshv-1's intermittent H4 failures after a live migration to a host with an unstable clock #768: azure-mshv-1's intermittent H4 failures after a live migration to a host with an unstable clock.
• ci: the IMDS deadline tests need the request's worker to reach connect within 0.2 s, so a runner stall fails them (flaky NVX CLI / Windows) #1239, OpenVMM: consomme's test_tcp_last_ack_restarts_timeout_after_close_wait races a 1 ms close deadline, so a runner stall hangs it until nextest kills it (flaky OpenVMM unit tests / Windows) #1240: Windows runner stalls that break tight timing bounds.
• time ABI: publish the host's clock correction with each time sample #1018, which pins [DO NOT REVIEW] microVM: publish the host's clock correction with each time sample openvmm#4830: time ABI 2, which set the repair's 3 samples within 100 µs.
• nvx-rs: give a clone's failures documented statuses #937, nvx-rs: attribute a clone's failures, record them, and reattach it #951: the statuses of a clone's failures, and their attribution.