ci: a cold boot's time sample exceeded 100 µs on azure-windows-4 too (flaky NVX microVM tests / Windows / WHP / Runtime adapter) #1317

Summary

NVX microVM tests / Windows / WHP / Runtime adapter failed in the merge group of #1192 on azure-windows-4, because a guest failed time ABI check C12 at its cold boot and powered its VM off: time sample uncertainty 142270 ns exceeds 100000 ns. This is the failure of #1309's second incident, on another runner: both of #1309's incidents were on azure-windows-1.

#1192 didn't cause it. It changes only the Ubuntu distro's build, its documentation, and their tests, and its previous merge group, whose tree is identical, passed the same scenario on the same runner 19 minutes earlier.

Incident

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

• Head: 77fa2677f903f5ba0cde63b5dbeabb3d37de6bff, ubuntu: build runtimes with Python and architecture-independent packages #1192's 404fee6f5 on dev's 8b6257acb. OpenVMM f1e1d85452105fb40b446f964c8f401b69bba186, microVM v5.0 (openvmm: pin microVM v5.0, reorganized onto upstream main #1313).

• Failed job: NVX microVM tests / Windows / WHP / Runtime adapter on azure-windows-4 (self-hosted, windows, whp, virtual-machine, general), step Run runtime adapter scenarios on Windows. Of the suite's 156 scenarios, this was the only failure: vm_layered passed 42 tests, not 43.

• Failure: vm_layered recovery_required_layer_fails_the_assembly expects its launch to exit with ROOT_FAILED, 4, once the guest refuses a layer whose journal needs recovery. The launch ended with 1 instead, cannot attach to the VM: the broker closed the NVXS session, and the scenario failed at 21:06:45Z. The VMM's log ended:

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

  At its cold boot, the guest takes up to 3 samples, and accepts one only within 100 µs. None was, 1.75 s into the boot, so the guest powered off with 0xc1, 193, TIME_CONFORMANCE.

• Downstream: Required status check failed, and the queue removed ubuntu: build runtimes with Python and architecture-independent packages #1192 at 21:18:57Z (failed_checks).

Evidence

• The same tree passed on the same runner. ubuntu: build runtimes with Python and architecture-independent packages #1192's previous merge group, run 42289202400 (head d29f8ccf), has the same tree as 77fa2677. Its WHP runtime-adapter job also ran on azure-windows-4, and passed this scenario at 20:47:14Z, with all 43 of vm_layered's tests.
• The time ABI hasn't changed since 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.
  • The guest's time code is identical to that of 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's reference, 53ad0967.
  • OpenVMM moved from 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's 14dc4116e to f1e1d8545. Between them, vmm_core/virt_whp/src/time_abi.rs and vmm_core/virt/src/time_abi/ are byte-identical, and so is the measurement of the guest TSC's offset before each start. The rest of their difference under vmm_core/virt_whp replaces a Vec push, register-value transmutes, and a Duration conversion with equivalent code.
• This sample was wider than 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's. Its uncertainty was 142,270 ns, against 119,213 ns in 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's second incident.
• No log tells 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's two mechanisms apart. As 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's update explains, OpenVMM's line time ABI: guest TSC offset, with uncertainty_cycles, would separate a wide offset, measured once at the start, from delayed samples. This incident lost it too:
  • The scenario's failure shows only the last 8 KiB of the VMM's log, which began within the kernel's command line, after that line.
  • The sandbox deletes its directory, with the VMM's log, once its VM has ended.
  • A job that runs only the runtime adapter skips the upload of failure logs, as it did here.

History

The 77 CI runs from 2026-11-06 02:09Z, after #1309's incidents, to 20:57Z, this run:

• The WHP runtime-adapter job completed 44 times and failed once, here. azure-windows-4 passed it 8 times, and azure-windows-1, the runner of 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's incidents, 7 times.
• Of the 4 failed NVX microVM tests and Platform jobs, on every backend, only this one logged a time-ABI violation.

Root cause

Probably the transient condition that #1309 describes: OpenVMM on azure-windows-4 could not pair host UTC with the guest TSC within 100 µs in 3 tries during this cold boot, and the guest did what time ABI 2 specifies. Which of #1309's mechanisms caused it is unknown, since no log kept the line that tells them apart.

This is the first incident on a runner other than azure-windows-1, so the condition isn't peculiar to that runner, as #1309's root cause supposes.

Impact

• The failure took ubuntu: build runtimes with Python and architecture-independent packages #1192 out of the merge queue, which needs it re-queued. Its previous merge group had failed for another reason, vm_clone one_template_serves_the_clones_of_every_network_policy_at_its_guest_s_address on Linux/KVM, which this issue doesn't track.
• Any WHP VM's cold boot can fail this way, in any scenario, with that scenario's own symptom, such as the broker closed the NVXS session.

Suggested next steps

1. Keep the VMM log's time-ABI lines when a runtime-adapter scenario fails, as 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's step 3 proposes, so that the next incident names its mechanism. For example, the failure could show the log's time ABI: lines besides its tail, or keep its sandbox for the job to upload.
2. Then take 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's step 4 for the mechanism found.

Related

• 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: the same failure, twice on azure-windows-1, with the analysis of its two mechanisms.
• time ABI: publish the host's clock correction with each time sample #1018: time ABI 2, which made a sample wider than 100 µs fatal at a cold boot.
• ci: run WHP's runtime adapter scenarios in a job of their own #1241: put WHP's runtime-adapter scenarios in a job of their own, which uploads no failure logs.
• openvmm: pin microVM v5.0, reorganized onto upstream main #1313: pinned OpenVMM's microVM v5.0, this run's OpenVMM.
• 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.