--- name: schos-bootcheck-trust description: bootcheck silently stopped running and five of seven modes asserted nothing; how to tell a real pass from a script that died metadata: node_type: memory originSessionId: 9d8a2aef-bcf0-47a0-96c6-f706efab4a95 modified: 2026-08-09T20:44:14.569Z --- **A green run is only green if you counted the checks.** On 2026-08-09 the bootcheck suite was reported passing seven times when it had not executed at all, and separately when five of its seven modes asserted nothing whatsoever. **Why:** `bootcheck.ps1` had `[string]$Qemu = (Find-Qemu)` as a param default. PowerShell binds parameter defaults *before* any function in the script body is defined, so it died on its first line with "Find-Qemu is not recognized" — text containing neither `FAIL` nor `Exception`, which were the two words being grepped for. Empty output was read as success. Resolve after the param block: `if (-not $Qemu) { $Qemu = Find-Qemu }`. **And:** an earlier index-based edit (`s[:a] + inner + s[c:]`) that removed the obsolete `-SchFS` block also deleted the `Expect` blocks for `-Tty`, `-Usb`, `-Sock`, `-Ps` and `-Evdev`. Those modes still booted, still printed, and still exited 0 — asserting nothing. It happened before `git init`, so no commit ever had them; they were reconstructed from failure text quoted earlier in the transcript. **How to check a run is real:** ```sh grep -c '\[ok\]' # must be non-zero, and roughly what you expect grep -c 'boot check passed' ``` Counting `FAIL` alone cannot distinguish "passed" from "never ran". Expected counts as of 2026-08-09: base 23, Tty 47, Ps 28, Sock 60, Fb 32, Usb 27, Evdev 25 — Tty and Sock include `[ok]` lines printed by the guest programs themselves. **Never pipe a long bootcheck through `head`.** It closes the pipe, kills the script partway, and looks like a hang. Redirect to a file and grep the file. **Why:** the general lesson is that absence of failure output is not evidence of success. Both of these produced clean-looking runs while testing nothing. **How to apply:** after any change to the harness itself, verify the check count, not just the absence of FAIL. ## The extended suite was timing-fragile — fixed 2026-08-09 `yes writes through a pipe` failed repeatedly on `-Fb -Tty -Usb -Sock -Evdev -Ps` while `y`/`y` were plainly correct in the transcript. Three harness bugs, all fixed in commit 4e0478c and its follow-up: 1. **`Wait-Prompt` waited a fixed 20 s.** Measured from inside the guest, a cold `ls /bin | wc -l` takes **23 s** here (**51 s** before the e820 work), so the wall was always crossed. Now 60 s. 2. **It matched the prompt anywhere in the transcript.** Between sending a command and the guest echoing it, the log still ends with the *previous* prompt — so it could return before the command started. Now anchored to text produced after the command was sent. 3. **On timeout it slept 2 s and typed anyway**, landing the next command in a busy shell and interleaving the transcript, so the check that failed was a *later* unrelated one. Now waits for output to stop growing. The run also names any command that produced no prompt, because after one overrun every later check is reading a possibly-interleaved transcript. **Still treat a lone FAIL here as suspect until you have read the transcript.** **Leaked QEMU made this worse and is now fixed** (commit 4e0478c): the `finally` cannot run when the *script* is killed, so QEMU outlived it and, under TCG, taxed every later run. Each run now records its pid and reaps the previous one's orphan. ## Measuring anything about guest speed Do not use host wall clock, and do not compare runs made minutes apart. Three confounds each produced a confident wrong answer in one session: 1. **Stray QEMU** pinning a core (see above). 2. **`build/schfs.img` ages** — it accumulates writes across boots. Delete and `make build/schfs.img` before every timed boot. 3. **Ordering / host drift** — alternate the variants and run each twice. Time it from inside — **and bracket the command in a single guest command line**: ```sh cat /proc/uptime; ls /bin | wc -l; cat /proc/uptime ``` Sending the command, sleeping a fixed interval on the host, then asking for uptime **measures the host's sleep, not the command**. That produced a confident and completely fictional "2.2x speedup" for the e820 work: the two readings were 50 s apart because the host slept 50 s, and the arm that looked faster only had a guest clock lagging under load. One command line, two readings, no host timing in the loop. 4. **The guest clock drifts under TCG.** Missed timer ticks mean `/proc/uptime` undercounts during heavy load, so it is trustworthy for bracketing a short command and not for comparing long intervals across runs. Baselines, measured correctly 2026-08-09 with an 836 KB kernel: `ls /bin | wc -l` **2.9 s TCG / 1.1 s KVM**; boot to `schinit: ready` ~3.7 s TCG. `make qemu-kvm` is the opt-in KVM target. **KVM does not speed up boot** and slightly slows it: stage2 loads the kernel by PIO one sector at a time, and each port access is a VM exit. See [[schunix-verify-by-driving-shell]].