Skip to content

doctor: H4 fails hosts whose reference clock wanders, because it gates their current clock correction at 100 ppm #1008

Closed

Description

Summary

From 2026-10-28 23:00Z to 2026-10-29 15:00Z, H4, the TSC rate check of nvx.py doctor, failed 9 of the 75 microVM and platform jobs on azure-mshv-1, each in Validate runner before any test ran, and with them 8 CI runs: three pull requests, a manual run, the nightly run #2579 (#998), and the dev pushes #2557, #2576, and #2597. None of the 1,172 such jobs on the other runners failed H4.

The runner's TSC keeps its rate. What moves is the clock that chronyd follows, the Hyper-V PTP clock, its only source (#768), whose rate has wandered since about 20:00Z on 2026-10-28. H4 gates the host's current clock correction, the TSC's error plus that wander, against 100 ppm, a bound that the time ABI set for the TSC's error alone, and no short measurement can tell the two apart. So H4 fails a host whose guests the time ABI can serve.

Taking the runner out of service isn't a fix: NVX has to qualify hosts whose clocks wander, in CI and in deployments, where nvx.py doctor runs once and keeps no history. This issue proposes gating H4 on the guest's actual frequency-correction budget, 250 ppm, which needs no saved state and changes neither the time ABI nor its restore tolerance. #1009 tracks the structural fix, in which the host publishes its clock correction to the guest.

Failures

Job started (UTC) Run Job H4 deviation (ppm), and its range within chronyd's skew H4
2026-10-28 23:33 #2520 (pull request) Shard 2 of 2 +96.1 (76.6 to 115.5) Inconclusive
2026-10-29 02:55 #2560 (pull request) Shard 2 of 2 +189.1 (58.5 to 319.8) Inconclusive
2026-10-29 02:56 #2559 (pull request) Shard 1 of 2 +116.9 (61.8 to 172.0) Inconclusive
2026-10-29 04:25 #2573 (manual) Debug kernel +130.6 (115.4 to 145.7) Failed
2026-10-29 05:34 #2579 (nightly) Shard 2 of 2 +127.7 (114.4 to 141.0) Failed
2026-10-29 05:35 #2579 (nightly) Debug kernel +108.8 (87.5 to 130.1) Inconclusive
2026-10-29 06:44 #2557 (push) Shard 2 of 2 +123.7 (98.4 to 149.0) Inconclusive
2026-10-29 08:08 #2576 (push) Debug kernel +136.4 (124.4 to 148.4) Failed
2026-10-29 14:13 #2597 (push) Shard 1 of 2 +127.9 (117.3 to 138.6) Failed

H1 to H3 passed in every job. Run #2557's H4 line:

NVX-DOCTOR: check=H4 status=fail detail="the measurement is inconclusive: the backend rate is 123.702 ppm from the measured rate, 98.380 to 149.025 ppm within chronyd's skew of 25.316 ppm, which straddles the limit of 100 ppm; tsc_hz=2300283074 against CLOCK_MONOTONIC_RAW corrected by chronyd's frequency estimate of +123.918 ppm (skew 25.316 ppm, reference PHC0) from 3 samples 1 s apart; against CLOCK_MONOTONIC_RAW (resolution 1 ns) the interval rates agree within 0.001 ppm, largest interval uncertainty 0.046 ppm; 123.702 ppm from the backend's 2299998559 Hz; 2300149354 Hz against CLOCK_MONOTONIC, which chronyd also slews (evidence); host clocksource tsc (evidence)"

A failure fails Required status check, which skipped the development release and the performance-history update of the dev pushes #2557 and #2576.

Evidence

From H4's lines in all 308 jobs on azure-mshv-1 since 2026-10-27, and in 812 jobs sampled across the self-hosted runners since 2026-10-22, up to 2026-10-29 13:14Z:

  • The TSC holds its rate. In every job on azure-mshv-1, the interval rates against CLOCK_MONOTONIC_RAW agreed within 0.005 ppm.
  • The reference clock moves. Until about 20:00Z on 2026-10-28, chronyd's estimate on azure-mshv-1 stayed between +42.1 and +52.0 ppm over 181 readings, with a median skew of 0.36 ppm. In the 126 readings since, it ranged from +2.5 to +189.3 ppm, with a median skew of 7.0 ppm and a largest of 130.6 ppm. Within 15 minutes from 02:51Z on 2026-10-29, it read +19.1, +189.3, +117.1, +51.5, +7.2, and +3.5 ppm, the last with a skew of 0.08 ppm.
  • Its long-run rate doesn't. Averaged over any 6 hours of jobs, the rate that H4 reads against CLOCK_MONOTONIC stayed between +34 and +48 ppm.
  • chronyd's skew doesn't bound the wander. Run #2576's +136.4 ppm reading had a skew of 12 ppm, and the runner read +41.6 ppm an hour later.
  • The other runners are steady. In 311 readings sampled outside this episode, chronyd's skew had a median of 0.5 ppm and a 99th percentile of 9 ppm. The largest deviation since ci: gate H4 on chronyd's frequency estimate and end leaked VMs #779 merged is about +57 ppm (ci: track azure-mshv-1's intermittent H4 failures after a live migration to a host with an unstable clock #768).
  • The runner's declared rate changed during a gap in its jobs on 2026-10-28, from 2,300,000,507 Hz at 03:54Z to 2,299,998,559 Hz at 15:24Z, while chronyd's estimate stayed at +44.6 ppm. The wander began about five hours after its jobs resumed.

Why H4 fails a host that the time ABI can serve

Proposed fix

In check_rate:

  • Gate on the guest's budget. Make RATE_TOLERANCE_PPM 250 ppm, Linux's 500 ppm frequency limit minus the 250 ppm restore tolerance, still over chronyd's whole skew range: a range above it fails, and one that straddles it is inconclusive. Add a unit test that reads FREQUENCY_LIMIT and RATE_DEVIATION_LIMIT from nvx-rs and TSC_TOLERANCE_PPM from the OpenVMM gitlink's commit, as the CPU profile test reads OpenVMM's profiles, and checks that H4's limit is their difference.
  • Re-read chronyd before declaring a result inconclusive. When the range straddles the limit, query chrony_frequency again for up to 60 s, and use the first conclusive estimate; otherwise fail as inconclusive, as now. The rate against CLOCK_MONOTONIC_RAW needs no new samples, because only chronyd's estimate changes.
  • Warn above 100 ppm. Without failing, say in the H4 detail, the step summary, and a CI ::warning:: annotation how much of the 250 ppm budget the host's correction uses, and that one run can't tell the TSC's error from the reference's wander.
  • Report the average correction since boot, as evidence. CLOCK_MONOTONIC and CLOCK_MONOTONIC_RAW both exclude suspend, and only the time service's gradual adjustments, after a small offset at boot, separate them, so their difference over the uptime averages the wander out without saved state. Measure it on a runner before gating on it: slews just after boot and a live migration bias it.
  • Use the kernel's correction without chronyd. On Linux hosts with another time service, such as systemd-timesyncd, read the kernel's frequency correction, adjtimex's freq, which its PLL maintains, while the kernel reports the clock synchronized, instead of the 2-s CLOCK_MONOTONIC window, whose slews read +946.1 ppm in ci: track azure-mshv-1's intermittent H4 failures after a live migration to a host with an unstable clock #768.
  • Update the tests and the documentation. Update the H4 tests, whose chronyd cases assume 100 ppm. Update the H4 row of doc/ci.md with the limit, the re-read, and the warning, restoring the budget's rationale that the rewrite dropped, and tie H4's limit to the budget in the wall-clock discipline.

These stay as they are and still fail closed: the interval checks against CLOCK_MONOTONIC_RAW (0.25 ppm uncertainty, 1 ppm agreement), the rate's plausibility, an unreadable or unrecognized chronyd report, H6's warp probe, and the time ABI's 250 ppm restore tolerance.

Expected effect

  • 8 of the 9 failures above pass outright at 250 ppm. The ninth, run #2560's +189.1 ppm (58.5 to 319.8), straddles it. The runner's next two jobs, which started 50 s and 87 s later, read +116.9 ppm (61.8 to 172.0) and +51.2 ppm, both conclusive passes, so a 60 s re-read would very likely have passed it.
  • None of the 126 readings on azure-mshv-1 since 2026-10-28 20:00Z lies wholly above 250 ppm.
  • The other runners read at most about +57 ppm, so neither the limit nor the warning changes anything for them.
  • Validate runner, nvx.py doctor, and deployments behave alike, because the check keeps no state.

Validation

Related issues

Activity

  1. ppenna commented on Oct 29, 2026

    @ppenna
    ContributorAuthor

    Failures from 2026-10-29 15:00Z to 22:00Z

    H4 failed 2 more jobs on azure-mshv-1, each in Validate runner before any test ran and with H1 to H3 passing, and with them 2 more CI runs: #2613, the pull-request run of #1012, and #2630, the dev push of its merge. They are 2 of the 40 jobs that ran dev's H4 on the runner in that window, 27 of which compared the TSC's rate with the backend's. None of the 707 jobs that ran Validate runner on the other 19 runners failed H4; 6 of them, all in the manual run #2623, failed before doctor could run a check.

    Job started (UTC) Run Job H4 deviation (ppm), and its range within chronyd's skew H4
    2026-10-29 16:46 #2613 (pull request, attempt 1) Shard 1 of 2 +110.5 (103.6 to 117.3) Failed
    2026-10-29 20:51 #2630 (push) Shard 2 of 2 +72.2 (27.6 to 116.8) Inconclusive

    Run #2630's H4 line:

    NVX-DOCTOR: check=H4 status=fail detail="the measurement is inconclusive: the backend rate is 72.226 ppm from the measured rate, 27.627 to 116.830 ppm within chronyd's skew of 44.595 ppm, which straddles the limit of 100 ppm; tsc_hz=2300164680 against CLOCK_MONOTONIC_RAW corrected by chronyd's frequency estimate of +72.453 ppm (skew 44.595 ppm, reference PHC0) 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.045 ppm; 72.226 ppm from the backend's 2299998559 Hz; 2300063370 Hz against CLOCK_MONOTONIC, which chronyd also slews (evidence); host clocksource tsc (evidence)"
    
    • #2630 failed on chronyd's skew alone. Its deviation, +72.2 ppm, lay within the limit, but a skew of 44.6 ppm, the runner's largest in the window, made its range straddle it. In the same run, H4 passed on the 4 other MSHV runners at +9.6 to +52.1 ppm, with skews of at most 2.4 ppm.
    • It skipped another dev push's release. The failure failed Required status check, which skipped the development release and the performance-history update of efbb8f07b. The next push, #2633 (fd9cb3966), which contains it, passed and published both.
    • #2613's rerun passed. Its second attempt passed on the same runner 15 minutes later, at +27.8 ppm (skew 13.7 ppm).

    The reference clock still wanders

    On azure-mshv-1, in the same window:

    • Over the 40 readings, chronyd's estimate ranged from +14.0 to +132.5 ppm, with a median of +29.3 ppm, a median skew of 5.8 ppm, and a largest of 44.6 ppm.
    • The TSC kept its rate: in every job, the interval rates against CLOCK_MONOTONIC_RAW agreed within 0.003 ppm.
    • The largest estimate, +132.5 ppm (skew 24.8 ppm) at 21:30Z, came from OpenVMM binary / Linux musl in run #2634, whose H4 runs without H3 and so compares no rates. A microVM job would have failed on it.

    Expected effect

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Labels

confirmedIssue affects multiple people.

Type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions