SchOS/.claude/memory/schos-bootcheck-trust.md
Nexoniarz 7b2d4037a4 Rebuild when RAMROOT is toggled, and add an opt-in KVM target
`make ramroot` wiped the objects on the way in, and nothing wiped on the
way out. So a plain `make` afterwards kept every RAMDISK_ROOT object and
linked the 24 MB ramdisk back into a kernel that no longer used it: 25 MB
where a clean build is 836 KB. It still booted -- from the ramdisk -- and
the only outward symptom was stage2 having thirty times as much to load
through PIO, one sector at a time. That is the "booting got slower"
report this came from.

A stamp file records which setting the objects were built with, and the
tree is dropped when it changes in either direction.

qemu-kvm is opt-in and the default stays TCG, because the suite's timings
were established there. Measured with the guest timing itself,
`ls /bin | wc -l` goes 2.9s -> 1.1s. Boot does not improve and gets
slightly worse: every PIO port access in stage2 is a VM exit under KVM.

Retracts a claim from earlier today. The "2.2x speedup" attributed to the
region-based allocator was a measurement artifact -- the probe sent a
command, slept a fixed 50s on the host, then read /proc/uptime, so it
timed the sleep rather than the command, through a guest clock that drifts
under load. Bracketing the command inside one guest command line shows no
measurable difference. The e820 change is still correct; it is simply not
a performance change.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2026-08-09 22:46:00 +02:00

5.1 KiB

name description metadata
schos-bootcheck-trust bootcheck silently stopped running and five of seven modes asserted nothing; how to tell a real pass from a script that died
node_type originSessionId modified
memory 9d8a2aef-bcf0-47a0-96c6-f706efab4a95 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:

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:

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.

  1. 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.