ci: track azure-mshv-1's intermittent H4 failures after a live migration to a host with an unstable clock

Summary

Since 2026-10-21, runner validation has failed three times on azure-mshv-1 (machine esaurez-nvx-ci-linux-vmss000000), each time in H4 alone, the host TSC rate check of nvx.py doctor. No test ran in any of the three jobs. In the 400 CI runs from 2026-10-20 03:49Z to 2026-10-22 17:31Z, runner validation ran 3,548 times and failed only twice, both times on this runner; the third failure followed at 18:47Z.

By every sign visible inside the VM, Azure live-migrated azure-mshv-1 to another physical host on 2026-10-18 at 19:35:41Z. Measured from inside the VM on 2026-10-22, the host clock that Hyper-V reports drifts against the TSC by tens of ppm within minutes, while on azure-mshv-4 it stays within a few ppm. chrony disciplines the VM's clock to that host clock, and H4's 2-second sample measures chrony's momentary correction rather than the TSC. H4 fails when the host's drift and chrony's catch-up push the reading past 100 ppm. The TSC itself is stable, and the product isn't at fault, although H4's design makes it sensitive to this (see Next steps).

The investigation also found an OpenVMM VM that a cancelled job had left running on this runner for 8 days. It didn't cause the H4 failures, but the test harness lets such leaks happen (see below).

Incidents

Run (attempt)	Commit	Job	H4 reading	Outcome
39688204465 (1)	823aff0	MSHV / Debug kernel, 2026-10-21 23:44Z	+109.2 ppm	Not rerun
39821559035 (1)	2f4b337	MSHV / Debug kernel, 2026-10-22 17:22Z	+100.03 ppm	Attempt 2 passed on azure-mshv-5 (+12.2 ppm)
39833953233 (1)	58a4a8f	MSHV / Shard 1 of 2, 2026-10-22 18:47Z	+946.1 ppm	Attempt 2 passed on azure-mshv-5

All three are dev pushes. The latest failure's H4 line:

NVX-DOCTOR: check=H4 status=fail detail="the backend rate is 946.1 ppm from the measured rate (limit 100 ppm); tsc_hz=2302176486 against CLOCK_MONOTONIC from 3 samples 1 s apart; against CLOCK_MONOTONIC_RAW (resolution 1 ns) the interval rates agree within 0.000 ppm, largest interval uncertainty 0.056 ppm; 946.1 ppm from the backend's 2300000507 Hz; host clocksource tsc (evidence)"

• Only H4 failed each time; H1 to H3 passed. One minute after the +946.1 ppm failure, the same run's Shard 2 of 2 passed H4 on azure-mshv-1 at +73.9 ppm.
• Each failure fails Required status check, which skips the development release and the performance-history update for that commit. Run 39688204465 was never rerun, so 823aff0 has neither.
• Both reruns passed only because the scheduler placed them on azure-mshv-5. No label distinguishes azure-mshv-1 from azure-mshv-2, -3, and -5: they all carry self-hosted, Linux, X64, virtual-machine, mshv, and general, so any general MSHV job can land on it.
• H4's code is identical at 764ba59, 2f4b337, and 58a4a8f, and 764ba59 passed H4 on azure-mshv-1 20 minutes before the second failure.
• The failure message rounds to one decimal place: the second failure was 100.027 ppm but reads 100.0 ppm from the measured rate (limit 100 ppm).

H4 readings from runner validation, 2026-10-20 to 2026-10-22, before the +946.1 ppm failure:

Runner	Readings	Median	p95	Max	Std dev	Failures
azure-mshv-1	79	+44.3	+66.1	+109.2	16.1	2
azure-mshv-4 (benchmark)	255	+52.3	+55.5	+84.3	4.2	0

In the runs of the last two failures, the KVM runners read between +0.7 and +4.3 ppm.

Root cause

The evidence comes from the CI logs and from read-only measurements on the runners on 2026-10-22, between 18:51Z and 20:19Z.

The live migration

azure-mshv-1 has been up since 2026-10-12 12:45Z. On 2026-10-18 at 19:35:41Z, without a reboot:

• Its accelerated-networking VF moved from slot 0 to slot 1, and the Hyper-V Heartbeat, TimeSync, and KVP integration services renegotiated their versions at 19:35:42.997Z.
• The Azure Linux agent got 410 Gone from the WireServer and restarted at goal-state incarnation 1.
• Hyper-V rewrote the KVP pool that holds the physical host's name at 19:35:43Z.

None of the other nine Linux runners has had such an event since it booted on 2026-10-12. H4's baseline on azure-mshv-1 also moved, from about +46 ppm to about +44 ppm, consistent with a different host:

Period	azure-mshv-1 H4 readings
2026-10-12 to the event	Mostly about +46 ppm, range +27 to +63
2026-10-19	Steady, +43.5 to +45.8
From about 2026-10-20	+7 to +109, then +946.1 on 2026-10-22

The new host's clock drifts

The measurements on azure-mshv-1, and for comparison on azure-mshv-4, ran while both runners were idle between jobs:

• The host clock drifts against the TSC. The Hyper-V PTP clock (/dev/ptp_hyperv) takes the host's time every 5 s. Its updates show the TSC's rate against the host clock, per minute:

  Minute (UTC)	azure-mshv-1	azure-mshv-4
  20:13	+66.5 ppm	+52.4 ppm
  20:14	+60.8	+54.1
  20:15	+51.0	+50.6
  20:16	+48.1	+52.3
  20:17	+44.4	+52.1
  20:18	+43.3	+54.2

  Earlier, azure-mshv-1 read +48.1 ppm around 20:00 and +34.8 ppm on average from 20:02 to 20:11, while azure-mshv-4 read +51.8 and +52.0. From inside the VM, it's impossible to tell whether the host's time service or its oscillator moves; the smooth decay suggests the host's time service correcting its clock.

• chrony follows the host clock. chrony's only source is that PTP clock (refclock PHC /dev/ptp_hyperv). On azure-mshv-1, chronyc tracking reported a frequency between 32.0 and 78.6 ppm and an RMS offset of up to 515 µs; on azure-mshv-4, 51.6 to 53.7 ppm and at most 38 µs.

• H4 reads chrony's correction. With the tsc clocksource, CLOCK_MONOTONIC_RAW is the TSC times a fixed factor, and CLOCK_MONOTONIC adds chrony's frequency correction. So H4's 2-second rate against CLOCK_MONOTONIC is chrony's momentary correction, frequency estimate and offset slew together: over 75 s on azure-mshv-1, the two agreed to within 0.15 ppm on average and 2.8 ppm at worst. H4's stability check against CLOCK_MONOTONIC_RAW compares the TSC with a clock derived from the TSC, so on such runners it passes by construction. At +946.1 ppm, chrony was slewing the clock by about 900 ppm beyond its usual correction, which removes about 1.8 ms in H4's 2-second window.

Ruled out

• The TSC. Between host time updates, the PTP clock advances with Hyper-V's reference counter. On azure-mshv-1, -3, -4, and -5, that counter and the TSC differ by 0.06 to 0.38 ppm, which matches each runner's truncation of its declared rate to whole kHz (the kernel's tsc_khz) to within 0.04 ppm.
• Steps of the wall clock. None in 9 minutes of monitoring on azure-mshv-1.
• Jitter of individual host time updates (about ±115 µs around their mean): azure-mshv-4 shows the same pattern, more often.
• The workload. No test ran in the failed jobs, and azure-mshv-3 and -5 run the same jobs and stay steady. azure-mshv-1 read a steady +46 ppm for days while the leaked VM below was running, and the drift continued after it was terminated.
• Code changes. See the incidents above.

Leaked VM on azure-mshv-1

• An openvmm process, pid 1409231, ran on azure-mshv-1 from 2026-10-14 17:12:43Z at about 100% of one CPU until it was terminated on 2026-10-22 at 19:45Z. It was a 1-vCPU, 128 MiB VM with --snapshot-destination /tmp/nvx-ipv6-egress-pfqki082/snapshot, the capture VM of the ipv6-egress-policy scenario.
• It came from job 115990822234, the only job on the runner at the time, which was cancelled at 17:12:43Z. The runner's orphan cleanup terminated only the harness (Terminate orphan process: pid (1407583) (python3)), and the VM, started in the same second, kept running under init.
• Nothing ties OpenVMM's lifetime to the harness. OpenvmmProcess starts it through InteractiveProcess as a plain child, without contain_process_tree or a parent-death signal, so if the harness dies before its with block closes the VM, the VM keeps running.
• A scan of all 20 Azure runners on 2026-10-22 at 19:46Z found no other leaked openvmm process. The VM's 64 MB scratch directory, /tmp/nvx-ipv6-egress-pfqki082, is still on azure-mshv-1.

Next steps

Runner infrastructure:

• Remove azure-mshv-1's general label until its VM is moved, as #265 did for azure-mshv-2.
• Confirm the 2026-10-18 19:35Z event in the VM's Azure activity log or Resource Health, and report the host to Azure. The physical host's name is in the VM's Hyper-V KVP data (/var/lib/hyperv/.kvp_pool_3, key PhysicalHostName); it's left out here because the repository is public.
• Redeploy VMSS instance esaurez-nvx-ci-linux-vmss000000 so that it lands on another host, restore its label, and check that its H4 readings settle as they did before 2026-10-20. Then check whether #383's snapshot-generation rejections recur on it.
• Delete /tmp/nvx-ipv6-egress-pfqki082 on azure-mshv-1, unless the redeploy replaces its disk.
• Terminate the leaked VM and scan the other runners for leaked VMs (2026-10-22; none found).

H4 (scripts/nvx_tools/doctor.py):

• Print the rate deviation precisely enough that a failure can't read 100.0 ppm ... (limit 100 ppm).
• Decide how H4 should treat a host clock that is still settling. Options: re-measure, or report the result as inconclusive, while chrony's offset or skew is high; compare with chrony's long-term frequency estimate instead of a 2-second window; or revisit the 100 ppm limit against the time ABI's 250 ppm restore tolerance. On azure-mshv-1 and azure-mshv-4, the declared rate already sits 44 to 52 ppm from the measured one, which leaves about half of the limit for noise.
• Consider recording a host-change signal in runner validation, such as a digest of the KVP PhysicalHostName, so that a live migration shows up next to H4's result. #526's benchmark host record holds the runner and machine names, the CPU, the OS, the VM size, and the disks, none of which a live migration changes.

Test harness (scripts/nvx_tools/openvmm_process.py and scripts/nvx_tools/benchmark.py):

• Tie each OpenVMM process's lifetime to the harness, for example with a parent-death signal, a process group that cleanup kills, or the ProcessTreeContainment helper in scripts/nvx_tools/adversarial_oracles.py.
• Find out why the runner's orphan cleanup, which terminated the harness, missed the VM.
• Have validate-runner report, or terminate, openvmm processes that an earlier job left behind, so that a leak can't run unnoticed for days.

Related issues

Open:

• #383: every Linux/MSHV snapshot-generation stability rejection from 2026-09-29 to 2026-10-05 ran on this same VM. They predate the 2026-10-18 migration, so they don't share this mechanism, but they're a second kind of host-level noise confined to this VM.
• #345: transient Linux/MSHV host stalls that fail the performance gate; several of the outliers it lists ran on azure-mshv-1.
• #720: notes another way that OpenvmmProcess could leak OpenVMM: it builds TimeAbiMonitor outside its cleanup try, although that can't fail on a valid command.

Closed:

• #507: an earlier H4 defect, in which an unreadable clocksource file failed H4 without measuring.
• #366: Linux platform jobs failing on unstable snapshot generation, where the rejections on azure-mshv-1 first appeared; #383 took over tracking the runner.
• #211 and #265: TSC warps on the MSHV runners, traced to an Azure host without an invariant TSC. #265 is the precedent for removing a runner's label and redeploying it. #211 asked whether a host event such as a live migration preceded one of its incidents; the signals used here, the KVP pool's modification time and the kernel's Hyper-V integration-service messages, answer that from inside a VM.
• #526: benchmark host-change detection, which a live migration bypasses.