diff --git a/tests/CLAUDE.md b/tests/CLAUDE.md index 9c0d32e564..5d65226cab 100644 --- a/tests/CLAUDE.md +++ b/tests/CLAUDE.md @@ -19,6 +19,7 @@ The mechanics live where the work is: profiles and shapes in `tests/common/`, re - **CI's `guest` lane is two different machines** — twelve hosted EPYC shards for every pull request, push and merge-queue ref, one T14 lane for a `workflow_dispatch` or a non-`ci.yml` schedule — and a duration measured on one does not transfer to the other: the profile in `tests/test-durations` was recorded hosted, and only a hosted run renders the tier verdict, which since 2026-08-22 it does on the pull request itself. - **The dev host's guests boot `-cpu qemu64`, which has no PCID** — every `INVPCID` path in the kernel is dead locally and only a KVM runner with `-cpu host` executes one, so a change gated on a CPUID feature is unverified by a green local suite. - **A liveness ceiling scales by two independent host facts, not one** — boot-derived host speed *and* a guest's own `vcpus/cores` oversubscription, because a mostly-serial boot cannot see the lock-holder preemption a wide-SMP guest pays. The hosted shard is four cores and some guests boot eight, so an `smp:8` guest ran 2× starved and its wedge guards fired on a machine that was only slow (2026-08-23). Widen a *liveness* guard for this, never a correctness bound. +- **Silence is not a wedge by itself, and the clock is not one either** — a healthy idle guest on a boot with no live periodic speaker (no compositor, idle soundd, the kernel's idle-loop cadence halting with it) was measured quiet for 102s, so a guard that fires on silence alone reds a healthy idle boot; and a guest still emitting output past its budget is slow, not stuck, so a guard that fires on the clock alone reds a loaded host. A wedge verdict needs both: the budget spent *and* the guest gone quiet, with only a far backstop behind a guest that keeps talking (2026-08-23). - **A new registered name costs two CI cycles, not one** — the `UNMEASURED` marker buys one measured run (the first `durations` red is by design), and splitting or re-tiering a name after seeing its price buys a second. Plan the round-trips; they are not surprises. A name is only Fast if it is committed under `FAST_COMMIT_MS`, four fifths of the ceiling — a price in the last fifth is decided by which partition ran it, so it reds whichever pull request measures it next rather than the one that introduced it. Since 2026-08-22 a landing renders the price verdict only for the names it registered or re-tiered; for every other name it is a warning on that run and a red on the nightly, so a tier finding about somebody else's test is fixed the next day rather than by the author who happened to measure it. A Rust guest test's registration is the existence of its file under `tests/toyos-rust-tests/src/bin/`, so adding, deleting or renaming one is a registration change with a price verdict attached. - **A measured bound is asserted against the derivation, never against the measurement** — the measured number goes in the doc and the assert message, and a bound that has to be widened to pass is a finding, not a calibration. A test that asserts a kernel `Budget` never expires is asserting a bound the kernel does not promise — the verdict is the disjunction, and the red is only the outcome that is neither the answer nor the declared degradation (`screen_fatal_halt_composited`, 2026-08-22). - **A crafted-input test asserts the harm before the return value, and never Debug-prints a refused value** — an unrefused one is as large as the input asked for, so the arm that asserts the error first panics on the value and never reports the damage (a 2 GB assert log and a hidden root-node clobber, both measured 2026-08-23). diff --git a/tests/common/qemu.rs b/tests/common/qemu.rs index 3a533d441d..f17c4e94f1 100644 --- a/tests/common/qemu.rs +++ b/tests/common/qemu.rs @@ -639,8 +639,27 @@ impl std::fmt::Display for WaitVerdict { /// `panic_recovery`, `heap_ceiling` and `screen_recoverable_untouched` assert. /// Silence is what separates the two, and it is the separation the harness /// already trusts everywhere else ([`GUEST_QUIET`]): a recovering guest keeps -/// talking — it has a periodic speaker on every config and the test's own -/// `===TEST_END` arrives in milliseconds — and a halted one cannot. +/// talking — the test's own `===TEST_END` arrives in milliseconds — and a +/// halted one cannot. +/// +/// **The wall clock is not the wedge; silence is.** A test's `ceiling` is the +/// budgeted wall clock (`budget_smp`-scaled, so it already carries #256's +/// `vcpus/cores` oversubscription widening), and until this it ended the wait +/// the instant it passed — so a merely-slow guest reported exactly what a wedged +/// one did. `launcher_refusals` was killed at `192s "still talking 1s ago"` on a +/// loaded `smp:2` runner its `vcpus/cores` factor clamps to 1, a guest making +/// steady progress called wedged by a clock. So a guest still *talking* is now +/// never ended by `ceiling`: the per-test budget bites only a guest that has +/// *also* gone quiet for [`GUEST_QUIET`], and a talking one runs to the +/// [`GUEST_WEDGED`] backstop below. +/// +/// **`elapsed > ceiling` stays a necessary condition, and that is what keeps +/// this safe.** Silence alone is not a wedge on this suite's boots: a healthy +/// but idle guest on a config with no live periodic speaker — no compositor, an +/// idle soundd, and the kernel's own ~10 s line halting with the idle loop — was +/// measured quiet for as long as 102 s, so a guard that fired on 15 s of silence +/// by itself would red a working machine. A guest's own budget is what says how +/// long its silence is allowed; only past *that* does quiet mean stopped. pub fn ceiling_verdict( dying: Option<&str>, elapsed: Duration, @@ -653,22 +672,33 @@ pub fn ceiling_verdict( return Some(kernel_died_here(line)); } } - if elapsed <= ceiling { - return None; - } - let secs = ceiling.as_secs(); - Some(if quiet >= GUEST_QUIET { - format!( - "{STALLED} {secs}s of guard expired, and the guest had said nothing for the last \ + // The per-test ceiling, now a silence guard rather than a wall-clock one: it + // ends the wait only when the guest has run past its budget *and* fallen + // silent for [`GUEST_QUIET`]. A guest still talking past its budget is slow, + // not wedged, and is given until the backstop. + if elapsed > ceiling && quiet >= GUEST_QUIET { + return Some(format!( + "{STALLED} {}s of guard expired, and the guest had said nothing for the last \ {quiet:.0?} of it — the ceiling caught a machine that had stopped, which is not an \ - answer to what this test asked" - ) - } else { - format!( - "timed out after {secs}s, with the guest still talking {quiet:.0?} ago ({lines} \ - console line(s) while it ran) — it was working and did not finish" - ) - }) + answer to what this test asked", + ceiling.as_secs() + )); + } + // The absolute backstop, for a guest that is stuck *and* chatty and so never + // trips the silence guard — a suite that never ends is worse than one that + // reds. Never below the per-test ceiling, so a long test whose own budget + // already exceeds it is not cut short; never below [`GUEST_WEDGED`], the + // vetted stuck-and-chatty number a talking guest is judged by everywhere + // else. Not itself oversubscription-scaled — `ceiling` already carries that. + let backstop = ceiling.max(GUEST_WEDGED); + if elapsed > backstop { + return Some(format!( + "timed out after {}s, with the guest still talking {quiet:.0?} ago ({lines} \ + console line(s) while it ran) — it was working and did not finish", + backstop.as_secs() + )); + } + None } /// The three verdicts a ceiling reaches and what each carries, staged with no @@ -776,6 +806,62 @@ pub fn ceiling_self_check() -> Result<(), String> { return Err(String::from("a healthy run was given a verdict")); } + // 3b. **The wall-clock/silence split this file's own defect was about**, in + // all four directions. A talking guest past its budget is slow, not + // wedged; a silent one within its budget is idle, not wedged; the wedge + // guard still fires, and fast; and the backstop still catches a guest + // that talks forever. Staged with a ceiling below [`GUEST_WEDGED`] so the + // backstop is a distinct, higher number — the shape every real test has. + const TIGHT: Duration = Duration::from_secs(153); + let bstop = TIGHT.max(GUEST_WEDGED); + assert!(TIGHT < bstop, "the case needs a ceiling below the backstop"); + // (a) The flake itself: `launcher_refusals` at `192s "still talking 1s ago"` + // on a loaded smp:2 runner. Past its 153 s budget, but talking — no + // verdict, it runs on. + if ceiling_verdict(None, Duration::from_secs(192), TIGHT, Duration::from_secs(1), 500).is_some() + { + return Err(String::from( + "a slow-but-talking guest past its budget was still called wedged — the smp:2 flake \ + this change is for", + )); + } + // (b) The backstop still bites a guest that is stuck *and* chatty: past + // `GUEST_WEDGED`, still talking, it is the one thing silence cannot catch. + let Some(forever) = ceiling_verdict( + None, + bstop + Duration::from_secs(1), + TIGHT, + Duration::from_secs(1), + 9000, + ) else { + return Err(String::from("a guest talking forever past the backstop was given no verdict")); + }; + if forever.contains(STALLED) || !forever.contains("did not finish") { + return Err(format!("the chatty-forever backstop misread as a stall: {forever}")); + } + // (c) Negative control — the wedge guard still fires, and *fast*: a guest + // silent past its budget is caught the moment it passes, at 154 s, not + // held to the 300 s backstop. + let Some(wedged) = ceiling_verdict(None, TIGHT + Duration::from_secs(1), TIGHT, GUEST_QUIET, 40) + else { + return Err(String::from( + "a guest silent past its budget was not caught — the liveness guard cannot fire", + )); + }; + if !wedged.starts_with(STALLED) { + return Err(format!("a genuine wedge past the budget stopped reading as one: {wedged}")); + } + // (d) Idle-safety, the property the no-speaker boots demand: a guest silent + // for 90 s — inside the 102 s a healthy idle machine with no periodic + // speaker was measured at — but still *within* its budget is not a wedge. + if ceiling_verdict(None, Duration::from_secs(100), TIGHT, Duration::from_secs(90), 40).is_some() + { + return Err(String::from( + "a guest idle-but-within-budget was called wedged — a boot with no periodic speaker \ + would red healthy", + )); + } + // 4. **What the verdict carries, which is the half that was missing.** Every // arm above names a death in one sentence; until 2026-08-18 that sentence // was the whole of what a failure arm had, and a `DOUBLE FAULT on CPU 1` @@ -2437,6 +2523,66 @@ impl QemuInstance { } } + /// [`Self::screendump_while`], but a guest still *painting* is still working. + /// + /// The screen-channel form of what [`ceiling_verdict`] does for + /// [`Self::run_test_paced`] on serial: past the budgeted deadline the wait + /// does not give up while the framebuffer keeps *changing*. A console + /// rendering slowly under a loaded `smp:2` runner is making progress, which + /// is the case whose paint "never arrived in the window" while the guest was + /// alive — the budget-scaled deadline undercounts a later moment in the run + /// exactly as the serial ceiling did. Only a screen *frozen* for + /// [`GUEST_QUIET`] past the deadline, or the [`GUEST_WEDGED`] backstop, ends + /// the wait; `done` firing ends it at once, so a passing caller is untouched + /// and a real bug (the paint that should not be there, and stays) still fires + /// its assertion, a frozen-screen `GUEST_QUIET` later. + /// + /// **Only for a config whose screen freezes when idle** — no compositor; + /// `/bin/console` repaints on I/O alone. A compositor's cursor blink and its + /// once-a-second taskbar clock never let the screen freeze, so such a caller + /// would wait the whole backstop when its `done` never comes and keeps the + /// plain [`Self::screendump_while`] (which is also why the `screen_blocked_dump` + /// retry loop, whose timeout is a deliberate re-send signal, must not use + /// this). + /// + /// Reuses the one classifier so the two channels cannot drift: `dying` is the + /// serial path's alone, and a halted kernel freezes the screen and is caught + /// by the freeze here. + pub fn screendump_while_rendering( + &mut self, + timeout: Duration, + interval: Duration, + done: impl Fn(&super::screen::Ppm) -> bool, + ) -> super::screen::Ppm { + let ceiling = budget_smp(timeout, self.smp); + let start = Instant::now(); + let mut last_change = start; + let mut prev: Option> = None; + loop { + let dump = self.screendump(); + if done(&dump) { + return dump; + } + let now = Instant::now(); + if prev.as_deref() != Some(dump.pixels.as_slice()) { + last_change = now; + prev = Some(dump.pixels.clone()); + } + if ceiling_verdict( + None, + now.duration_since(start), + ceiling, + now.duration_since(last_change), + 0, + ) + .is_some() + { + return dump; + } + thread::sleep(interval); + } + } + /// Every console line the guest printed before the ready marker. /// /// The kernel's own boot lines sit in the log ring until the scheduler diff --git a/tests/toyos.rs b/tests/toyos.rs index eb9661c939..0b10338b13 100644 --- a/tests/toyos.rs +++ b/tests/toyos.rs @@ -3176,7 +3176,13 @@ fn run_screen_test( QemuInstance::boot_with_options(&config, c_bins, rust_bins, options); let font = screen::ConsoleFont::load(); - let before = qemu.screendump_while( + // `_rendering`, not the plain wait: on a loaded `smp:2` runner the + // console paints slowly and the budget-scaled 30s window undercounts + // a later moment in the run, so a guest still drawing was called + // wedged (`0 of 2073600 pixels`, the paint never arriving). The + // console freezes when idle, so a real failure still ends the wait a + // `GUEST_QUIET` after the deadline. + let before = qemu.screendump_while_rendering( Duration::from_secs(30), Duration::from_millis(200), |d| d.console_text(&font).contains(CONSOLE_PROMPT), @@ -3215,7 +3221,7 @@ fn run_screen_test( m > 0 && d.pixels[(d.height - m) * d.width..].iter().all(|p| *p == c) }; - let painted_over = qemu.screendump_while( + let painted_over = qemu.screendump_while_rendering( Duration::from_secs(30), Duration::from_millis(200), |d| margin_is(d, GRAFFITI), @@ -3259,7 +3265,7 @@ fn run_screen_test( rows.first().is_some_and(|r| r.trim() == CONSOLE_PROMPT) && rows[1..].iter().all(|r| r.is_empty()) }; - let dump = qemu.screendump_while( + let dump = qemu.screendump_while_rendering( Duration::from_secs(30), Duration::from_millis(200), only_prompt,