diff --git a/FABRIC-3.md b/FABRIC-3.md index 4f2af80..7a1238b 100644 --- a/FABRIC-3.md +++ b/FABRIC-3.md @@ -3060,3 +3060,170 @@ too, not just the amd64 boot it was reformatted under. Commit `09d78c9`. `CERTVERIFY` → `RUNCAP` → `MINT` → the console/user pair → `WIREBIND` → `BINDSTEP` → persistence across a real reboot. Every phase closure from §F.18 onward flagged the next gap; none remain flagged as "still open" in this chain. + +### F.25 — `make qemu` boots with Zuse attached by default: a real xHCI driver gap, not a config gap + +Directive: a plain `make -f Makefile.starkernel qemu` (all three arches) should always attach +both the Artemis disk (already default via `ARTDISK`) and Zuse's own thumbdrive, landing +already authenticated into the Zuse identity, unless told otherwise. Traced before touching +anything: attaching `-device usb-storage` on the QEMU command line at *launch* (rather than +hot-plugging post-boot via QMP, this session's established workaround since Milestone 2) +looked like it should just work now that §F.21–§F.24 closed the whole attach/authenticate +chain. It didn't, and the reason is a real gap in the xHCI driver, confirmed by reading +`xhci_poll_events()` (`src/starkernel/usb/xhci.c`) directly: it is *purely* +event-ring-driven, reacting only to `XHCI_TRB_TYPE_PORT_STATUS_CHANGE_EVT` events, with no +code anywhere that proactively checks `PORTSC.CCS` across ports at `xhci_bringup()` time. A +device already connected before the controller resets never generates a "change" event — +nothing changed from the controller's perspective once it starts looking — so it stays +invisible forever, not just late. + +**Fix, not workaround:** extracted the existing "device connected" handling (Enable Slot +kickoff, single-outstanding-connect discipline) out of `xhci_poll_events()`'s +`PORT_STATUS_CHANGE_EVT` case into a shared `xhci_handle_port_connected()`. Added +`xhci_scan_ports_for_already_connected()`, called once from `xhci_bringup()` right after the +controller starts running and `g_xhci_dev` is latched: scans tracked ports directly for +`PORTSC.CCS`, and drives the first connected one found through the exact same Enable Slot path +a real hotplug event would — same single-device-at-a-time scope this driver already commits to +elsewhere. This is the technically correct fix (a real USB host controller driver enumerates +already-connected ports at bring-up, it doesn't rely solely on later hotplug events), not a +QEMU-side or Makefile-side scripted delay. Verified live: `"xhci: device already connected at +bring-up"` fires, followed by the full enable-slot → address-device → configure → BOT +enumeration sequence, all before the REPL ever prints its first `ok>` — no post-boot QMP step +needed. + +**Makefile wiring, and a real bug found in the first attempt:** added `ZUSEDISK ?= +disk/zuse.img`, attached unconditionally on the `xhci0` bus each arch's `qemu` target already +creates (`ZUSEDISK=` empties it for a bare boot). First attempt inlined +`$(if $(ZUSEDISK),-drive if=none,id=zusedrv,...,-device usb-storage,...,)` directly at each +call site — GNU make's `$(if)` splits its own arguments on every *top-level* comma, and the +drive/device spec is comma-heavy, so the flags silently truncated to just `-drive if=none` +with everything past the next comma dropped. Confirmed live via `ps aux` showing the broken +qemu command line — no error, just a quietly wrong one. Fixed by precomputing a +`ZUSEDISK_QEMU_ARGS` variable with a plain `ifneq` instead of inlining `$(if)`. + +**A real consequence of the §F.24 `disk/artemis.img` reformat, not a new bug:** with the xHCI +fix and Makefile wiring both correct, the boot still didn't reach Zuse authentication. +`capsule_zuse_boot_try_attach()` (`src/starkernel/capsule/capsule_zuse_boot.c:70-71`) only +takes the genesis-mint path when the Artemis fence has *no* genesis marker **and** the +attached drive reads `HOMEBLOCKS_SIG_BLANK`. `disk/zuse.img` still carried the real identity +minted (§F.20, Apollo test rig) against the *old*, pre-reformat `artemis.img` — so it read +`HOMEBLOCKS_SIG_OK`, not blank, while the reformatted `artemis.img` had no marker to confirm +it against. Neither branch fired; the code correctly, silently declined to act on a mismatched +pair rather than guessing. Confirmed with the user and reformatted `disk/zuse.img` too (same +category of destructive action as the `disk/artemis.img` reformat — explicit confirmation +obtained first), so a fresh genesis-mint can run against the current fence on next boot. + +**The apparent "hang" chased down, not assumed:** the post-reformat genesis-mint boot appeared +to sit silent for 9+ minutes at 100% CPU with no new log output — killed once on the +assumption it had hung, per Captain Bob's direct pushback ("i know this machine, it's never +that slow") that the slow-TCG explanation didn't hold up. Root-caused properly instead of +re-guessing, via temporary `console_println`/`log_message` probes at every step +(`capsule_mint_identity()`, `capsule_zuse_boot_try_attach()`, `blk_meta_zone_read()`, and a +`heartbeat_ticks()`-instrumented `xhci_bot_wait_for_idle()`), each reverted immediately after +capturing what was needed (`feedback_revert_probes_after_capture.md`). Two real, independent +findings came out of it, neither a driver bug: + +1. **`capsule_mint_identity()` ran a fully redundant second `homeblocks_sig_check()`** on the + same USB drive `sk_repl_idle()` had *just* checked moments earlier, doubling the wait for no + reason. Fixed with a new `drive_known_blank` parameter (`capsule_mint.h`/`capsule_mint.c`): + `capsule_zuse_boot_try_attach()` passes `1` (it already confirmed `HOMEBLOCKS_SIG_BLANK` + before ever calling in); the manual `MINT` word (`mama_forth_words.c`) passes `0` since it + has no pre-check to rely on and still needs the safety refusal. +2. **Dozens of orphaned `tail -f logs/.../qemu-*.log` processes** (`Makefile.starkernel`'s own + qemu recipe backgrounds one per run and only reaps it via `kill $TAILPID` on a *normal* + qemu exit) had accumulated going back to **2026-08-27**, one per every `kill -9` this + session's own iterative testing had used to stop a run early. `pkill -f "tail -n \+1 -f + logs/"` cleared ~60 of them. Timing before/after, same exact code path, same boot: **~200s + to reach the sig-check result with the leaked processes present, 26s clean.** That is the + dominant real-world cost this whole investigation kept tripping over — not a kernel bug. + +**Residual, understood, not a code defect:** even on a freshly cleaned host, run-to-run timing +still varies (one clean run: 26s; a later one under load: 190s+, no error, still progressing). +Traced to ordinary desktop contention on the dev machine itself — CLion (188+ accumulated CPU- +minutes), its Rider.Backend, and the desktop shell were all live and competing for host CPU +during the slower runs (`uptime` load average 1.3–1.6 at those moments). TCG needs steady host +CPU time to advance guest virtual time at the intended rate; when the host scheduler starves +QEMU in bursts, the guest's own polling/BOT-command pacing visibly stalls with no corresponding +guest-side bug. Not something kernel code can or should compensate for. + +**Where this leaves the original directive:** the xHCI initial-port-scan fix, the `ZUSEDISK` +Makefile wiring, the redundant-check fix, and the leaked-process cleanup are all real, correct, +and independently verified in isolation (each confirmed via its own live boot evidence above). +A full clean end-to-end run — genesis-mint completing (`MINT_OK`) and landing in an +authenticated `zuse)ok>` session — was in progress but not yet observed to completion when the +session was paused to resume from a terminal; `disk/zuse.img` and `disk/artemis.img` may +therefore be mid-genesis-mint rather than either cleanly blank or cleanly minted (mint writes +its `homeblocks_sig_t` block *last*, specifically so an interrupted mint still reads back as +blank rather than a corrupt partial identity — the next boot's own sig-check settles this +safely either way, no manual disk surgery needed). Next session: rerun the full three-arch +acceptance (`clean qemu` each) with the host otherwise idle, confirm `MINT_OK` and +`"Zuse: genesis minted onto attached thumbdrive"`, then decide on committing. + +### F.26 — the "hang" wasn't a hang: a mismatched marker/drive pair, root-caused live (2026-08-28) + +Resuming §F.25: what looked like a genuine infinite loop (QEMU pegged at 100% CPU, zero new +serial output for 60+ seconds) was chased down with temporary bracketing `console_println`/ +`log_message` probes at every step of the attach path (`capsule_zuse_boot_try_attach()` → +`capsule_mint_identity()` → `blk_subsys_attach_device()` → `blk_format_or_load_disk()`), +reverted immediately after capture per standing convention +(`feedback_revert_probes_after_capture.md`). Two real findings, neither a code defect: + +1. **`log_message(LOG_INFO, ...)` calls are silently swallowed once the REPL starts.** + `kernel_main.c`'s own `log_set_level(repl_level)` defaults to `LOG_WARN` when no explicit + `--log-*` kernel arg is given, and `LOG_INFO > LOG_WARN` fails the level check in + `log_message()` — so every `LOG_INFO`-level probe placed in `block_subsystem.c` (a vendored, + non-kernel-only file, so `console.h` isn't available there) printed nothing, giving a false + "never reached" reading for code that was actually running fine. Confirmed by temporarily + promoting the same probes to `LOG_ERROR` (unfiltered) — the exact same call sites all fired + immediately, in order, no code changes needed. A real investigative trap, not a bug: don't + trust `LOG_INFO`-level silence as "not reached" once the REPL is up. +2. **The actual root cause: `capsule_zuse_boot_try_attach()` found `have_marker=1`** (a + `zuse_genesis_marker_t` already on Artemis's top-of-device fence, left over from before + §F.25's mid-session reformat) **but the freshly-reformatted `disk/zuse.img` read back + `HOMEBLOCKS_SIG_BLANK`** — a mismatched pair. Per the function's own documented design + (§F.21: "Only act if THIS attach is that drive"), it correctly, silently declined rather + than guessing, and returned immediately. With no re-mint and no re-authentication ever + happening, the boot settled into the REPL's ordinary busy-poll idle loop (no `HLT`, polls + `console_getc()` every iteration) with nothing left to log — indistinguishable from a true + hang by CPU usage or serial silence alone, especially under slow TCG with no periodic + heartbeat print. Traced end-to-end by bracketing probes through `blk_subsys_attach_device()` + confirming the *entire* attach path, including its own final (also `LOG_INFO`, also + filtered) summary `log_message()` call, completes and returns cleanly every time — the + system was never stuck in kernel code at all, just correctly idling at an unauthenticated + `ok>`. + +**Fix:** zeroed both `disk/artemis.img` (30 MiB) and `disk/zuse.img` (64 MiB) at their existing +sizes (`dd if=/dev/zero` + `truncate` to the exact original byte count) — a genuine reformat, +explicitly confirmed with the user first (same destructive-action category as §F.24's), giving +a matched blank pair with no stale marker and no stale volume header. Not a code change. + +**Verified, full three-architecture acceptance, one clean run each:** +- amd64: fresh genesis-mint — `"Zuse: genesis minted onto attached thumbdrive"` +- aarch64: reload path — `"Zuse: identity confirmed from attached thumbdrive"` (shares the + same now-minted disk images written by the amd64 run — correct, expected cross-arch behavior, + not a separate mint per architecture) +- riscv64: reload path — `"Zuse: identity confirmed from attached thumbdrive"`, same as aarch64 + +**Design question raised and answered, no code change needed:** why not trigger a cold reboot +right after `MINT` instead of activating live in the same boot? Two decisive reasons: every +`qemu` target in `Makefile.starkernel` passes `-no-reboot` unconditionally, so a triggered +reboot would terminate QEMU rather than cycle the kernel; and a real reboot re-runs the entire +Tripod fleet birth sequence from scratch, a real cost under TCG. More fundamentally, there is +no duplicate logic to reconcile: both the fresh-genesis branch and the reload branch already +call the exact same `install_and_activate()` (`capsule_zuse_boot.c:98` and `:113`) — they only +differ in *where* the seed/pubkey come from (freshly generated vs. read back off disk), which +is an inherent, appropriate difference, not drift risk. The live-activation path is also not +optional overhead: it's the same mechanism a live (non-cold-boot) thumbdrive attach needs, so +reboot-then-reload would still need it built, just as an additional path rather than the only +one. + +**Confirmed going forward:** genesis-mint is a one-time event tied to the persistent disk image +files, not the kernel binary — `make clean`/`make -f Makefile.starkernel` never touches +`disk/*.img` (grepped, confirmed: every `ARTDISK`/`ZUSEDISK` reference in the Makefile is a +`-drive` attach flag, nothing writes to or resets either file). Rebuilding the kernel any +number of times against the same, now-matched disk-image pair will keep taking the fast reload +branch, not re-mint, exactly as seen on aarch64/riscv64 above. + +Where this leaves the original F.25 directive: fully closed. `make qemu` (any arch, default +invocation) now reliably attaches both disks, lands in an authenticated Zuse session, and +reruns cleanly. Commit follows.