From d5f41d6e057300c82b83653b4afadeffb45a9f19 Mon Sep 17 00:00:00 2001 From: salmonik Date: Mon, 3 Aug 2026 01:34:31 +0200 Subject: v0.5.7: fix vt verify content check — expect BLANK (0x70020), not zero MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The pre-verify 0x70020 'mystery' was a debug artifact, not corruption: BLANK = {ch:32, fg:7, bg:0} = raw 0x70020, and vec![BLANK; n] fills both grids with it at init. The old check compared cells against 0 and its probe loop break-ed on the first non-zero cell, so probes 1-3 stayed at their zero-initialized slots — c=[0x70020,0,0,0] was bogus on every healthy boot. A full-grid dump proves QEMU grids are 100% BLANK at shell entry (nz=3700 blank=3700). Fix: probes compare against blank_raw (0x70020), record all four values (no early break), probe both cells and rendered, and add a full-grid nz/blank summary line. The OptiPlex firmware 0x00AAAAAA scrub remains cleanly distinguishable (scrub != blank). Markers: the shell banner occupies grid rows 0-1 and the prompt row 2 (proven by screendump), and a stale crash.log replays at rows 2+, so the shadow and vt markers moved to the bottom of the screen via the new gop::text_rows()/bottom_row(off) helpers instead of rows 1-2. QEMU verified: verify: ok every boot; test-msg + test-fault PASS; debug and release builds 0 warnings. --- DEBUG_NOTES.md | 204 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 204 insertions(+) create mode 100644 DEBUG_NOTES.md (limited to 'DEBUG_NOTES.md') diff --git a/DEBUG_NOTES.md b/DEBUG_NOTES.md new file mode 100644 index 0000000..d44c8bf --- /dev/null +++ b/DEBUG_NOTES.md @@ -0,0 +1,204 @@ +# rsdos Debug Notes — heap/cells corruption family (v0.5.7) + +Handoff state: **HEAD = `ab633ce`**; the mystery below is SOLVED and the +verify rework is committed on top (see git log). + +## TL;DR + +- Real-hardware (OptiPlex, no serial) boots crash in the shell with heap + corruption. Two **distinct** bug families: + - **(A) scroll-crash family**: in-heap `ptr=0x404443e0` with zeroed header. + - **(B) 0xAA family**: `0xaaaaaa00aaaaaa` = two `0x00AAAAAA` u32s = UEFI + firmware memory-scrub fill. A dropped object's memory was never + allocated/freed by us — it's firmware-fresh scrub. +- Everything converges on **the `vt` static `Vec`s' VecData (ptr/cap/len) + or their heap blocks being corrupted/stale** — the cells VecData ptr at shell + entry was `heap+0x1D8630` (= cells region) in the last crash, and the dropped + 126-byte String (`cap 0x7e`) is the vt verify klog line itself. +- **SOLVED — the pre-verify `0x70020` "mystery" was a debug artifact, not + corruption.** `BLANK = {ch:32, fg:7, bg:0}` = raw `0x70020`, and + `vec![BLANK; rows*cols]` fills the whole grid with it at init. The old + content check compared cells against **0** (wrong expectation — BLANK is not + zero), and its probe loop `break`-ed on the first non-zero cell, so probes + 1–3 were never written and stayed at their zero-initialized slots. The + serial line `c=[0x70020,0x0,0x0,0x0]` was therefore bogus on **every healthy + boot**. A full-grid dump on QEMU proves it: `nz=3700 blank=3700` — both + grids are 100% BLANK at shell entry. The OptiPlex's `0x00AAAAAA` firmware + scrub is still cleanly distinguishable (scrub ≠ 0x70020). + +## The two confirmed bugs + +1. **(A) scroll-crash family** — heap allocator returns an in-heap block whose + header is zeroed (`ptr=0x404443e0`). Dropping it panics in the guard. +2. **(B) 0xAA family** — freed garbage pointer `0xaaaaaa00aaaaaa`; the memory at + that address is firmware scrub fill. Something handed the allocator a pointer + that was never a live allocation (or the VecData fields themselves got + clobbered with scrub values — the cap was `0xAA` garbage in the boot crash). + +## What we've fixed / proven already + +- **IST=1 stack collision → ROOT CAUSE of ACTIVE_VOL corruption**: vec 14 ran on + `PF_STACK`, a 4 KiB `.bss` static overlapping FAT `ACTIVE_VOL`. Fixed in + `gdt.rs`: heap-allocated 32 KiB IST stacks. (Done, earlier.) +- **AHCI/DMA EXONERATED**: user removed all disks; crashes persisted. +- **All QEMU repro attempts were clean** (mem/klog/tail-crash) until the content + probe upgrade — which tripped the *content check only* on a healthy boot for + the reason above (expectation bug + break bug). Fixed: the check now expects + `blank_raw` (0x70020), records all four probe values, and adds a full-grid + nz/blank summary line. QEMU now reports `verify: ok` on every boot. +- **Clean heap geometry (OptiPlex)**: heap = `0x40400000..0xc7e34000` (~2.2 GB), + boot stack ~1 MiB above heap end. +- **Shadow geometry (QEMU)**: shadow = first alloc at `heap+0x20` (`0x1980020`), + 480000 words → span `[heap+0x20, heap+0x1D4C20)`; cells data at + `heap+0x1D4C40`; VecDatas at ~`heap+0x1D8630`. +- **Shadow-rejection hypothesis (unproven)**: on the OptiPlex the shadow alloc + may have been rejected (or the cells alloc landed inside the would-be shadow + span), leaving that block free + scrub-filled. `0x40444970 = heap+0x44970` is + *inside* the would-be shadow span. The last crash's `r9=0x405d8630 = + heap+0x1D8630` is the cells VecData region. +- **Original #GP resolved**: crashed image was RELEASE; drop of `Parsed` struct; + cause = real memory corruption (laytest excluded compiler bug). +- **Stale PDB trap**: fresh PDB re-resolved shell-entry #GP → + `rsnix::vt::put_byte+0x16a` (`mov %ax,(%rdx,%rcx,4)`) — u16 char at 4-byte + stride into cells buffer via garbage ptr from `r9=0x405d8630`. bt chain: + `shell::run → GopWriter::write_str → fmt::Formatter::pad_integral → + klog::LineBuf::write_str → core::fmt::write → Display(u32)`. +- **Crash decoded**: the dropped object in the last boot crash was a 126-byte + String (`cap 0x7e`) = the vt verify klog line (19-char prefix + 106-char text + + `\n`); `ptr=0x40444970` is STALE (inside the would-be shadow span, back-pointer + never written). + +## Allocator layout (verified, `memory.rs`) + +- `HEADER_SIZE=16`, `MINI_SIZE=8`, `MIN_BLOCK=32`, `MIN_ALIGN=16` +- payload = `align_up(block+24, align)` +- split: rewrites rem header + `free_list_insert` + back-pointer at `payload-8` +- `back_pointer_ok(ptr)` validates `[ptr-8]`; guard v0.5.7 (`0187b80`) reports + + halts on failure; `corrupt` QEMU hook verified. + +## vt grid facts + +- `put_cell(r,c,ch)` sets `ch` + fg/bg from statics `SGR_FG=7`/`SGR_BG=0`. +- Cell raw encoding: `ch | fg<<16 | bg<<24`; BLANK = 0; cursor-inverse blank = + `0x07000000` (bg and fg swapped). **`0x70020` is NOT a cursor-inverse cell** — + it's a literal space with fg=7 (ch=0x20, fg=7, bg=0). +- `flush()` diffs cells vs rendered; cursor pass writes inverse colors into both + FB and `rendered`. +- `term_println(s)` = `gop_print!` + blank line + explicit `serial::write_line`. + Display mirror to serial is NOT automatic for `gop_println!`. +- Boot order after vt init: shadow → boot markers → memory self-test → page + allocator + self-tests → paging adopt + self-test → sched init → + rtc/pci/ahci/fat/fs → **cursor spawn** → **`debug_verify()`** → `shell::run()` + (first banner `rs-dos v0.5.7 …`, then `=====`, then crash-log read). + +## Current committed work (post-`ab633ce`) + +- `gop::boot_marker_at(msg, row)` + `gop::text_rows()` + `gop::bottom_row(off)` + — shadow marker now on the LAST text row, vt verify marker one above it + (both survive the banner, prompt, and crash.log replay). +- `debug_verify()` fixed: compares probes against `blank_raw` (0x70020), not + zero; records all four probe values (no early break); probes BOTH cells and + rendered; adds a full-grid `grids c nz=… blank=… r nz=… blank=…` summary + (serial). Marker format: + `vt: c {ptr:#x} cap={cap:#x} ok|GARBAGE | r {ptr:#x} ok|GARBAGE` at + `bottom_row(1)`. +- QEMU verified: `verify: ok` every boot; screendump shows the banner (gray), + prompt, and both bottom markers. test-msg + test-fault PASS; debug and + release builds 0 warnings. + +## QEMU reproduction of the content-check failure (RESOLVED) + +- Serial showed `probes c=[0x70020,0x0,0x0,0x0] r=[0x70020,0x0,0x0,0x0]` — this + was **misread** as "a single stray cell". The full-grid dump (3700 reads) + showed `nz=3700 blank=3700` in both grids: **every cell is BLANK (0x70020), + the grids are healthy**. The probe array's 1–3 slots were zero-initialized + leftovers from the early-`break` bug. +- Memory dump proves grids are fully healthy on QEMU: cells block base + `0x1b54c20` `{size=0x39f0, free=0}`, back-ptr written; rendered block base + `0x1b58650`; both grids contain the shell banner post-draw. **No heap + corruption on QEMU.** +- QEMU verify geometry: cells ptr `0x1b54c40` cap `0xe74` len `0xe74`; rendered + ptr `0x1b58670`. +- ⇒ `CONTENT-GARBAGE` was never evidence of OptiPlex corruption — the check was + comparing against the wrong expectation. Now: probes compare against + `blank_raw` (0x70020); every probe value is logged; a `grids c nz=… blank=…` + summary is the definitive health signal. + +## The pre-verify `0x70020` at grid(0,0) — MYSTERY SOLVED + +**There was no writer.** `0x70020` is the grid's own init fill: +`BLANK = Cell{ch:32, fg:7, bg:0}` encodes as `0x70020`, and `vt::init` builds +both grids with `vec![BLANK; rows*cols]`. The old content check expected +all-zero cells (wrong), and the probe loop's early `break` made probes 1–3 +look like zeros. Nothing writes a pre-banner space; the shell banner (gray +VGA-7 text, rows 0–1) and the `>` prompt (row 2) are the only vt writes +before the markers. + +Also learned while verifying with a screendump: + +- The shell banner occupies grid rows **0 and 1** (motd + `=====` line), and + the prompt sits at row 2 — so a marker at FB row 1 (the old shadow marker) + is **clobbered** by the banner, and row 2's first glyphs get eaten by the + prompt + cursor. Markers whose values matter now live at the **bottom** + (`gop::bottom_row(0)` = last row, `bottom_row(1)` = second-to-last), which + also survive a stale crash.log replay (~20 lines at grid rows 2+). +- Banner text renders VGA gray `0xAAAAAA` (fg 7), boot markers white `0xFFFFFF` + — a white-only pixel matcher misses the banner. QEMU screendump decode of + the bottom rows: `vt: c 0x1b54c40 cap=0xe74 ok | r 0x1b58670 ok` and + `gop: shadow 0x1980020 1.83 MiB`. + +**Excluded candidates (all still true, now moot):** cursor task (FB/shadow +only), flush cursor-inverse pass (0x07000000 ≠ 0x70020), boot markers (direct +FB), memory self-test, shell banner (runs after verify), backspace (BLANK). + +## OptiPlex flash — what to look for (the linchpin) + +New image puts on screen (markers are **bottom-anchored** now — they survive +the banner rows 0–1, the prompt row 2, AND a stale crash.log replay at rows +2+; use `gop::bottom_row(off)` to place any future ones): + +1. **Last row (bottom_row(0))**: `gop: shadow {ptr:#x} {MiB}` vs + `gop: NO-SHADOW (fallback)`. + - If NO-SHADOW ⇒ shadow-rejection hypothesis gains weight (first block left + free + scrub-filled). +2. **Second-to-last row (bottom_row(1))**: `vt: c {ptr:#x} cap={cap:#x} ok|GARBAGE | r {ptr:#x} ok|GARBAGE`. + - **The cells ptr value is the linchpin**: if it equals `0x40444970`, the + cells VecData itself is stale at shell entry (matches boot-crash decode). + - If cap shows `0xAA…` garbage ⇒ VecData fields scrubbed (bug family B). + - `ok` = all probed cells read BLANK (0x70020); `GARBAGE` = probe ≠ BLANK + (the OptiPlex firmware scrub reads back `0x00AAAAAA`). +3. If it crashes: the full guard band (`hdr:` + all four `mem:` lines, 16 stack + words) plus the bottom markers if still visible. + +Serial-side (QEMU only): the verify lines are captured in the klog ring +(`serial_println!` → ring), so a healthy OptiPlex boot can also dump them with +the `klog` shell command. + +## Build/flash/test loop (traps) + +- Build 0 warnings, edition 2024, `no_std`, `x86_64-unknown-uefi`, workspace + v0.5.7. Zero new deps. +- Real-hardware boot chain: rsboot at `EFI/BOOT/BOOTX64.EFI` → kernel at + `bzImage`. QEMU dev loop boots kernel as BOOTX64.EFI. +- CRASHLOG stick must be FAT32; `mdir` grep gotcha: match `crash` + case-insensitively. +- **Stale qemu holds flock** → `pkill -9 -f 'qemu[-]system'` in a SEPARATE + command; `rm -f esp/NvVars` between boots. +- Use repo `scripts/` infra: test-msg/test-fault/test-mouse; monitor socket; HMP + `mouse_move`. +- Fault-context serial rule: never `serial_println!` in ISR/fault code; use + `serial::write_raw`; guard report must not allocate (stack `FmtBuf`). +- Marker on row 0 gets overwritten by the shell MOTD — use `boot_marker_at(msg, row>0)`. +- Stale PDBs misname symbols — re-resolve with a fresh PDB per build (PDB math + is decimal); `r9` = struct base with Vec layout `{ptr@0, cap@8, len@16}`. + +## Next steps (priority order) + +1. **Flash to OptiPlex** and relay the two bottom markers: shadow state (last + row) + vt marker (`bottom_row(1)` — the cells ptr value is the linchpin: + equals `0x40444970`? cap scrubbed `0xAA…`? `ok` vs `GARBAGE`?). If crash: + full `hdr:` + all four `mem:` lines. +2. Reattach the window-manager milestone once the crash family is resolved. + +(QEMU control arm is green: content check now passes on every healthy boot; +no further QEMU-side investigation is needed.) -- cgit v1.2.3