Harness: metal boots taken whole by name, a stalled wait carries what the guest said, a guest test boots the console image

issues/the-power-offs-last-drain-gives-up-on-a-wire-whose-holder-cannot-run.md

@@ -0,0 +1,62 @@
+---
+status: open
+kind: defect
+opened: 2026-10-08
+---
+
+# The power-off's last drain counts iterations on a wire whose holder may be unable to run, and then powers off without the tail
+
+Read from the code at `d78350c71`, not run. Named by the review of pull
+request #767 (its comment 6058801505); every line below was read again here.
+
+`serial::flush_final` (`kernel/src/drivers/serial.rs:263`) is the last drain
+before `power::shutdown` and `power::reboot` end the machine
+(`kernel/src/power.rs:21`, `:53`). It asks `try_wire` up to
+`PANIC_LOCK_SPIN_LIMIT` times (`serial.rs:131`, `:264`, `serial_lock::within`)
+and, if the wire never came free, appends one line to the black box and
+returns: the machine powers off with its last records undrained.
+
+The wire is a `SleepLock` "held with interrupts on and preemption allowed"
+(`serial.rs:278-279`), and `klogd` takes it once per pass
+(`kernel/src/log/console.rs:417`, `body`: `serial::wire(&parkable)`). On the
+way to the power-off, `quiesce` (`kernel/src/syscall/machine.rs:69`) logs the
+boot's last word (`:109`) and calls `console::drain_inline` (`:112`), which
+declines a held wire (`console.rs:94`:
+`let Some(wire) = serial::try_wire() else { return }`). Its last call is
+`xhci::seal_shut` (`machine.rs:132`), which, where it gets the controller
+lock, forgets the guard: "Preemption stays disabled with it"
+(`kernel/src/drivers/xhci/mod.rs:1550`; the `forget` is `:1565`).
+
+The seal is the point this turns on. Up to it nothing read here takes
+preemption from the stop's thread (it parks at `:94`), so a `klogd` holding
+the wire when `drain_inline` declined can still run, finish its pass and let
+go: nothing between `:112` and `:132` prevents that. From a seal that was
+taken to the power-off the stop's thread has preemption off. So on one CPU,
+a `klogd` descheduled inside its hold when `seal_shut` takes the controller
+lock is never run again: `flush_final`'s count is then a wait on a
+holder that cannot run, and it expires. Whatever that hold had not yet put on
+the wire, and every record committed after it, is on no console. On more than
+one CPU the holder runs elsewhere and lets go. Where the seal is refused
+(`seal_shut`'s `None` arm) no guard is forgotten, and this reading does not
+apply.
+
+**Not established**: how `klogd` comes to be descheduled inside its hold at
+the seal. `drain_for_the_stop` (`machine.rs:94`) parks on the wire and so
+finds it free once, but the two censuses, the stop's record and the last
+word are logged after it (`:96`-`:109`) and before the seal, and a record's
+commit wakes `klogd`. No run shows the loss. `machine_shutdown_short_stop`
+waits on `Shutting down.` on one CPU through this drain, so its history on
+`main` is the base rate.
+
+## Owner
+
+The orchestrator.
+
+## Exit condition
+
+`flush_final` waits on the wire's release where its holder can still run, or
+the stop keeps the holder from being left inside its hold at the seal; and a
+one-CPU guest test, whose actuator leaves `klogd` descheduled inside its hold
+of the wire as the stop's thread takes the seal in `seal_shut`, reads
+`Shutting down.` on the console. That test is red on a kernel whose last
+drain is today's.

src/testargs.rs

@@ -1,9 +1,10 @@
 //! The suite's command line, checked against the flags it actually has.
 //!
-//! `tests/toyos.rs` takes the first word that is nobody's value as the run's
-//! filter, so a flag this table does not declare would hand its own value to
-//! that filter and report a one-test run as a pass. The table is the harness's
-//! whole vocabulary, and [`SUITE`] is the only way to read a word off its argv.
+//! `tests/toyos.rs` takes every word that is nobody's value as one of the
+//! run's filters, so a flag this table does not declare would hand its own
+//! value to them and report a one-test run as a pass. The table is the
+//! harness's whole vocabulary, and [`SUITE`] is the only way to read a word
+//! off its argv.
 
 use crate::flags::declare_flags;
 use std::path::PathBuf;
@@ -23,18 +24,29 @@ declare_flags!(pub SUITE = {
     pub METAL_READBACK = "--metal-readback", Next;
 });
 
-/// The run's filter and `--metal`'s mode, both decided by [`parse`]: an unknown
-/// flag refuses the line before either is read.
+/// How a filter word names one of the metal profile's boots whole, ahead of
+/// the boot's name as `--metal --list` prints it.
+pub const BOOT: &str = "boot:";
+
+/// The run's filters and `--metal`'s mode, all decided by [`parse`]: an unknown
+/// flag refuses the line before any is read.
 pub struct Parsed<'a> {
-    pub filter: Option<&'a str>,
+    /// A run takes every name any of these is part of, and with none, and no
+    /// `boots`, every name there is.
+    pub filters: Vec<&'a str>,
+    /// The [`BOOT`] words, without it: boots `--metal` takes whole.
+    pub boots: Vec<&'a str>,
     pub metal: Option<MetalMode>,
 }
 
-/// Validate the harness's argv and return the run's filter and metal mode.
+/// Validate the harness's argv and return the run's filters and metal mode.
 ///
 /// `Err` is a refusal to print and exit on. It is asked before the sysroot lock
-/// and before anything is compiled, so a stale command line costs a message
-/// rather than a queue behind it.
+/// and before anything is compiled, so a line this refuses costs a message
+/// rather than a queue behind it. Not every dead word is refused here: under
+/// `--metal`, whether a filter or a [`BOOT`] word takes anything is known only
+/// against the profile's built members, so that refusal comes after the shared
+/// binaries' build.
 pub fn parse(args: &[String]) -> Result<Parsed<'_>, String> {
     let line = SUITE.walk(args);
     if let Some(word) = line.unknown {
@@ -49,20 +61,17 @@ pub fn parse(args: &[String]) -> Result<Parsed<'_>, String> {
         return Err(refusal);
     }
 
-    let mut filter: Option<&str> = None;
-    for word in line.positionals {
-        if let Some(first) = filter {
-            return Err(format!(
-                "{first:?} and {word:?}: the suite takes one filter, and the second word \
-                 would have been dropped in silence.\n\
-                 A filter is a substring, so `{first}` and `{word}` are one run only if one \
-                 substring matches both."
-            ));
-        }
-        filter = Some(word);
-    }
+    let (boots, filters): (Vec<&str>, Vec<&str>) =
+        line.positionals.into_iter().partition(|word| word.starts_with(BOOT));
+    let boots: Vec<&str> = boots.into_iter().map(|word| &word[BOOT.len()..]).collect();
 
     let has = |want| SUITE.present(args, want);
+    if let (Some(boot), false) = (boots.first(), has(&METAL)) {
+        return Err(format!(
+            "{BOOT}{boot} names a boot of the metal profile, and a run without --metal has \
+             none, so it would be dropped in silence; add --metal"
+        ));
+    }
     if has(&JOBS) && has(&JOBS_SHORT) {
         return Err(
             "--jobs and -j are two spellings of one width, and the run would read one of \
@@ -87,12 +96,12 @@ pub fn parse(args: &[String]) -> Result<Parsed<'_>, String> {
                 ));
             }
         }
-        if let Some(word) = filter {
+        for word in filters.iter().chain(&boots) {
             if word.trim().is_empty() {
                 return Err("--metal with an empty filter: name a registration or drop the word"
                     .to_string());
             }
-            if let Some(flag) = SUITE.0.iter().find(|f| f.name.trim_start_matches('-') == word) {
+            if let Some(flag) = SUITE.0.iter().find(|f| f.name.trim_start_matches('-') == *word) {
                 return Err(format!(
                     "{word:?} beside --metal is {}'s name without its dashes, and would be \
                      read as a filter that selects whatever contains it",
@@ -125,7 +134,7 @@ pub fn parse(args: &[String]) -> Result<Parsed<'_>, String> {
         }
     });
 
-    Ok(Parsed { filter, metal })
+    Ok(Parsed { filters, boots, metal })
 }
 
 /// What `--metal`'s own flags resolve a run to.
@@ -147,8 +156,9 @@ mod tests {
         args.iter().map(ToString::to_string).collect()
     }
 
+    /// The run's filters, as one text.
     fn parse_owned(args: &[&str]) -> Result<Option<String>, String> {
-        parse(&owned(args)).map(|p| p.filter.map(ToString::to_string))
+        parse(&owned(args)).map(|p| (!p.filters.is_empty()).then(|| p.filters.join(" ")))
     }
 
     fn metal_owned(args: &[&str]) -> Result<Option<MetalMode>, String> {
@@ -186,9 +196,20 @@ mod tests {
     }
 
     #[test]
-    fn two_filters_are_refused_because_only_one_would_run() {
-        let refusal = parse_owned(&["futex", "dlopen"]).unwrap_err();
-        assert!(refusal.contains("\"futex\"") && refusal.contains("\"dlopen\""), "{refusal}");
+    fn every_word_that_is_nobodys_value_is_a_filter() {
+        assert_eq!(parse_owned(&["futex", "--jobs", "4", "dlopen"]).unwrap().as_deref(), Some("futex dlopen"));
+    }
+
+    /// A boot word is `--metal`'s alone, and never one of the filters.
+    #[test]
+    fn a_boot_word_names_a_metal_boot_and_nothing_else() {
+        let line = owned(&["--metal", "boot:shared-2", "control_regs", "boot:ccorpus"]);
+        let parsed = parse(&line).unwrap();
+        assert_eq!((parsed.filters, parsed.boots), (vec!["control_regs"], vec!["shared-2", "ccorpus"]));
+        let refusal = parse_owned(&["boot:shared"]).unwrap_err();
+        assert!(refusal.contains("add --metal"), "{refusal}");
+        let refusal = metal_owned(&["--metal", "boot:"]).unwrap_err();
+        assert!(refusal.contains("empty filter"), "{refusal}");
     }
 
     /// Every `None` here is a default the run then takes in silence: `--jobs`

tests/checks.rs

@@ -781,8 +781,8 @@ mod checks {
     /// architecture.
     #[test]
     fn a_run_selects_by_filter() -> Result<(), String> {
-        let taken = |filter: Option<&str>| -> BTreeSet<String> {
-            let (machine, screen) = select(filter);
+        let taken = |filters: &[&str]| -> BTreeSet<String> {
+            let (machine, screen) = select(filters);
             machine
                 .iter()
                 .map(|n| n.to_string())
@@ -791,12 +791,13 @@ mod checks {
         };
         let names = |of: &[&str]| -> BTreeSet<String> { of.iter().map(|n| n.to_string()).collect() };
         let every: BTreeSet<String> = declared().map(String::from).collect();
-        let cases = [
-            (None, every),
-            (Some("virt_el2"), names(&["virt_el2_drop"])),
-            (Some("el2_drop"), names(&["virt_el2_drop"])),
-            (Some("nested_nmi"), names(&["nested_nmi_is_loud"])),
-            (Some("no_such_test"), BTreeSet::new()),
+        let cases: [(&[&str], _); 6] = [
+            (&[], every),
+            (&["virt_el2"], names(&["virt_el2_drop"])),
+            (&["el2_drop"], names(&["virt_el2_drop"])),
+            (&["nested_nmi"], names(&["nested_nmi_is_loud"])),
+            (&["el2_drop", "nested_nmi"], names(&["virt_el2_drop", "nested_nmi_is_loud"])),
+            (&["no_such_test"], BTreeSet::new()),
         ];
         for (filter, want) in cases {
             let got = taken(filter);
@@ -910,6 +911,11 @@ mod checks {
         metal_checks::a_failing_shared_member_fails_its_boot();
     }
 
+    #[test]
+    fn metal_words_take_rows_members_and_whole_boots() {
+        metal_checks::words_take_rows_members_and_whole_boots();
+    }
+
     #[test]
     fn metal_cleared_page_owes_no_panel() {
         metal_checks::a_cleared_page_owes_no_panel();
@@ -1129,7 +1135,7 @@ mod checks {
     #[test]
     fn the_c_corpus_stages_the_expectation_the_host_compares() {
         let got = "12\n34\n12\n34\n56\n78\n~fred()";
-        let boot = c_corpus_metal(&[("03_struct".to_string(), Vec::new())], |_| true);
+        let boot = c_corpus_metal(&[("03_struct".to_string(), Vec::new())]);
         let staged = boot
             .files
             .iter()

tests/checks/metal.rs

@@ -327,6 +327,56 @@ pub fn a_failing_shared_member_fails_its_boot() {
     );
 }
 
+/// **What a run's words take**: no word the whole profile; a name word every
+/// row and member it is part of, chunked as they come; a boot word that boot
+/// as the whole profile chunks it, with every row that rides it; and a word
+/// that takes nothing is refused.
+pub fn words_take_rows_members_and_whole_boots() {
+    static ROWS: [(&str, Metal); 2] = [
+        ("alpha_row", Metal { arms: &[metal::once("own", "tests/testcases", &[], &[])], judge: |_| Ok(()) }),
+        ("beta_row", Metal { arms: &[metal::once("shared-2", "tests/testcases", &[], &[])], judge: |_| Ok(()) }),
+    ];
+    let boot = |boot: &str, jobs: &[&str]| metal::SharedBoot {
+        boot: boot.to_string(),
+        config: "tests/testcases",
+        params: &[],
+        features: &[],
+        members: const { std::num::NonZeroUsize::new(2).expect("a chunk holds a member") },
+        jobs: jobs.iter().map(ToString::to_string).collect(),
+        files: Vec::new(),
+        links: Vec::new(),
+    };
+    let profile = [boot("shared", &["test_rs_a1", "test_rs_a2", "test_rs_b1"]), boot("ccorpus", &["c1"])];
+    let taken = |names: &[&str], boots: &[&str]| {
+        metal::select(names, boots, &ROWS, &profile).map(|(rows, shared)| {
+            let rows: Vec<&str> = rows.iter().map(|(name, _)| *name).collect();
+            let shared: Vec<String> =
+                shared.iter().map(|boot| format!("{}={}", boot.boot, boot.jobs.join("+"))).collect();
+            (rows.join(","), shared.join(","))
+        })
+    };
+    let took = |rows: &str, shared: &str| Ok::<_, String>((rows.to_string(), shared.to_string()));
+    assert_eq!(
+        taken(&[], &[]),
+        took("alpha_row,beta_row", "shared=test_rs_a1+test_rs_a2,shared-2=test_rs_b1,ccorpus=c1")
+    );
+    assert_eq!(taken(&["b1"], &[]), took("", "shared=test_rs_b1"));
+    assert_eq!(taken(&["alpha", "c1"], &[]), took("alpha_row", "ccorpus=c1"));
+    assert_eq!(taken(&[], &["shared"]), took("", "shared=test_rs_a1+test_rs_a2"));
+    assert_eq!(taken(&[], &["shared-2"]), took("beta_row", "shared-2=test_rs_b1"));
+    assert_eq!(taken(&["alpha"], &["ccorpus", "shared-2"]), took("alpha_row,beta_row", "shared-2=test_rs_b1,ccorpus=c1"));
+    assert_eq!(taken(&[], &["own"]), took("alpha_row", ""));
+    let refused: [(&[&str], &[&str], &str); 3] = [
+        (&["a1", "nope"], &[], "\"nope\" is part of no"),
+        (&["rs_a1"], &[], "\"rs_a1\" is part of no"),
+        (&[], &["shared", "shared-3"], "boot:shared-3 names no boot"),
+    ];
+    for (names, boots, refusal) in refused {
+        let said = taken(names, boots).expect_err("a word that takes nothing was accepted");
+        assert!(said.contains(refusal), "{said}");
+    }
+}
+
 /// **A page the pass after the reset cleared owes no panel**: `foreignrecord`'s
 /// census went with its record, so the boot is green and records its
 /// `complete_ms` alone. The same record cleared by the pass before the handoff