diff options
Diffstat (limited to '')
| -rw-r--r-- | DEBUG_NOTES.md | 204 |
1 files changed, 204 insertions, 0 deletions
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 @@ | |||
| 1 | # rsdos Debug Notes — heap/cells corruption family (v0.5.7) | ||
| 2 | |||
| 3 | Handoff state: **HEAD = `ab633ce`**; the mystery below is SOLVED and the | ||
| 4 | verify rework is committed on top (see git log). | ||
| 5 | |||
| 6 | ## TL;DR | ||
| 7 | |||
| 8 | - Real-hardware (OptiPlex, no serial) boots crash in the shell with heap | ||
| 9 | corruption. Two **distinct** bug families: | ||
| 10 | - **(A) scroll-crash family**: in-heap `ptr=0x404443e0` with zeroed header. | ||
| 11 | - **(B) 0xAA family**: `0xaaaaaa00aaaaaa` = two `0x00AAAAAA` u32s = UEFI | ||
| 12 | firmware memory-scrub fill. A dropped object's memory was never | ||
| 13 | allocated/freed by us — it's firmware-fresh scrub. | ||
| 14 | - Everything converges on **the `vt` static `Vec<Cell>`s' VecData (ptr/cap/len) | ||
| 15 | or their heap blocks being corrupted/stale** — the cells VecData ptr at shell | ||
| 16 | entry was `heap+0x1D8630` (= cells region) in the last crash, and the dropped | ||
| 17 | 126-byte String (`cap 0x7e`) is the vt verify klog line itself. | ||
| 18 | - **SOLVED — the pre-verify `0x70020` "mystery" was a debug artifact, not | ||
| 19 | corruption.** `BLANK = {ch:32, fg:7, bg:0}` = raw `0x70020`, and | ||
| 20 | `vec![BLANK; rows*cols]` fills the whole grid with it at init. The old | ||
| 21 | content check compared cells against **0** (wrong expectation — BLANK is not | ||
| 22 | zero), and its probe loop `break`-ed on the first non-zero cell, so probes | ||
| 23 | 1–3 were never written and stayed at their zero-initialized slots. The | ||
| 24 | serial line `c=[0x70020,0x0,0x0,0x0]` was therefore bogus on **every healthy | ||
| 25 | boot**. A full-grid dump on QEMU proves it: `nz=3700 blank=3700` — both | ||
| 26 | grids are 100% BLANK at shell entry. The OptiPlex's `0x00AAAAAA` firmware | ||
| 27 | scrub is still cleanly distinguishable (scrub ≠ 0x70020). | ||
| 28 | |||
| 29 | ## The two confirmed bugs | ||
| 30 | |||
| 31 | 1. **(A) scroll-crash family** — heap allocator returns an in-heap block whose | ||
| 32 | header is zeroed (`ptr=0x404443e0`). Dropping it panics in the guard. | ||
| 33 | 2. **(B) 0xAA family** — freed garbage pointer `0xaaaaaa00aaaaaa`; the memory at | ||
| 34 | that address is firmware scrub fill. Something handed the allocator a pointer | ||
| 35 | that was never a live allocation (or the VecData fields themselves got | ||
| 36 | clobbered with scrub values — the cap was `0xAA` garbage in the boot crash). | ||
| 37 | |||
| 38 | ## What we've fixed / proven already | ||
| 39 | |||
| 40 | - **IST=1 stack collision → ROOT CAUSE of ACTIVE_VOL corruption**: vec 14 ran on | ||
| 41 | `PF_STACK`, a 4 KiB `.bss` static overlapping FAT `ACTIVE_VOL`. Fixed in | ||
| 42 | `gdt.rs`: heap-allocated 32 KiB IST stacks. (Done, earlier.) | ||
| 43 | - **AHCI/DMA EXONERATED**: user removed all disks; crashes persisted. | ||
| 44 | - **All QEMU repro attempts were clean** (mem/klog/tail-crash) until the content | ||
| 45 | probe upgrade — which tripped the *content check only* on a healthy boot for | ||
| 46 | the reason above (expectation bug + break bug). Fixed: the check now expects | ||
| 47 | `blank_raw` (0x70020), records all four probe values, and adds a full-grid | ||
| 48 | nz/blank summary line. QEMU now reports `verify: ok` on every boot. | ||
| 49 | - **Clean heap geometry (OptiPlex)**: heap = `0x40400000..0xc7e34000` (~2.2 GB), | ||
| 50 | boot stack ~1 MiB above heap end. | ||
| 51 | - **Shadow geometry (QEMU)**: shadow = first alloc at `heap+0x20` (`0x1980020`), | ||
| 52 | 480000 words → span `[heap+0x20, heap+0x1D4C20)`; cells data at | ||
| 53 | `heap+0x1D4C40`; VecDatas at ~`heap+0x1D8630`. | ||
| 54 | - **Shadow-rejection hypothesis (unproven)**: on the OptiPlex the shadow alloc | ||
| 55 | may have been rejected (or the cells alloc landed inside the would-be shadow | ||
| 56 | span), leaving that block free + scrub-filled. `0x40444970 = heap+0x44970` is | ||
| 57 | *inside* the would-be shadow span. The last crash's `r9=0x405d8630 = | ||
| 58 | heap+0x1D8630` is the cells VecData region. | ||
| 59 | - **Original #GP resolved**: crashed image was RELEASE; drop of `Parsed` struct; | ||
| 60 | cause = real memory corruption (laytest excluded compiler bug). | ||
| 61 | - **Stale PDB trap**: fresh PDB re-resolved shell-entry #GP → | ||
| 62 | `rsnix::vt::put_byte+0x16a` (`mov %ax,(%rdx,%rcx,4)`) — u16 char at 4-byte | ||
| 63 | stride into cells buffer via garbage ptr from `r9=0x405d8630`. bt chain: | ||
| 64 | `shell::run → GopWriter::write_str → fmt::Formatter::pad_integral → | ||
| 65 | klog::LineBuf::write_str → core::fmt::write → Display(u32)`. | ||
| 66 | - **Crash decoded**: the dropped object in the last boot crash was a 126-byte | ||
| 67 | String (`cap 0x7e`) = the vt verify klog line (19-char prefix + 106-char text + | ||
| 68 | `\n`); `ptr=0x40444970` is STALE (inside the would-be shadow span, back-pointer | ||
| 69 | never written). | ||
| 70 | |||
| 71 | ## Allocator layout (verified, `memory.rs`) | ||
| 72 | |||
| 73 | - `HEADER_SIZE=16`, `MINI_SIZE=8`, `MIN_BLOCK=32`, `MIN_ALIGN=16` | ||
| 74 | - payload = `align_up(block+24, align)` | ||
| 75 | - split: rewrites rem header + `free_list_insert` + back-pointer at `payload-8` | ||
| 76 | - `back_pointer_ok(ptr)` validates `[ptr-8]`; guard v0.5.7 (`0187b80`) reports + | ||
| 77 | halts on failure; `corrupt` QEMU hook verified. | ||
| 78 | |||
| 79 | ## vt grid facts | ||
| 80 | |||
| 81 | - `put_cell(r,c,ch)` sets `ch` + fg/bg from statics `SGR_FG=7`/`SGR_BG=0`. | ||
| 82 | - Cell raw encoding: `ch | fg<<16 | bg<<24`; BLANK = 0; cursor-inverse blank = | ||
| 83 | `0x07000000` (bg and fg swapped). **`0x70020` is NOT a cursor-inverse cell** — | ||
| 84 | it's a literal space with fg=7 (ch=0x20, fg=7, bg=0). | ||
| 85 | - `flush()` diffs cells vs rendered; cursor pass writes inverse colors into both | ||
| 86 | FB and `rendered`. | ||
| 87 | - `term_println(s)` = `gop_print!` + blank line + explicit `serial::write_line`. | ||
| 88 | Display mirror to serial is NOT automatic for `gop_println!`. | ||
| 89 | - Boot order after vt init: shadow → boot markers → memory self-test → page | ||
| 90 | allocator + self-tests → paging adopt + self-test → sched init → | ||
| 91 | rtc/pci/ahci/fat/fs → **cursor spawn** → **`debug_verify()`** → `shell::run()` | ||
| 92 | (first banner `rs-dos v0.5.7 …`, then `=====`, then crash-log read). | ||
| 93 | |||
| 94 | ## Current committed work (post-`ab633ce`) | ||
| 95 | |||
| 96 | - `gop::boot_marker_at(msg, row)` + `gop::text_rows()` + `gop::bottom_row(off)` | ||
| 97 | — shadow marker now on the LAST text row, vt verify marker one above it | ||
| 98 | (both survive the banner, prompt, and crash.log replay). | ||
| 99 | - `debug_verify()` fixed: compares probes against `blank_raw` (0x70020), not | ||
| 100 | zero; records all four probe values (no early break); probes BOTH cells and | ||
| 101 | rendered; adds a full-grid `grids c nz=… blank=… r nz=… blank=…` summary | ||
| 102 | (serial). Marker format: | ||
| 103 | `vt: c {ptr:#x} cap={cap:#x} ok|GARBAGE | r {ptr:#x} ok|GARBAGE` at | ||
| 104 | `bottom_row(1)`. | ||
| 105 | - QEMU verified: `verify: ok` every boot; screendump shows the banner (gray), | ||
| 106 | prompt, and both bottom markers. test-msg + test-fault PASS; debug and | ||
| 107 | release builds 0 warnings. | ||
| 108 | |||
| 109 | ## QEMU reproduction of the content-check failure (RESOLVED) | ||
| 110 | |||
| 111 | - Serial showed `probes c=[0x70020,0x0,0x0,0x0] r=[0x70020,0x0,0x0,0x0]` — this | ||
| 112 | was **misread** as "a single stray cell". The full-grid dump (3700 reads) | ||
| 113 | showed `nz=3700 blank=3700` in both grids: **every cell is BLANK (0x70020), | ||
| 114 | the grids are healthy**. The probe array's 1–3 slots were zero-initialized | ||
| 115 | leftovers from the early-`break` bug. | ||
| 116 | - Memory dump proves grids are fully healthy on QEMU: cells block base | ||
| 117 | `0x1b54c20` `{size=0x39f0, free=0}`, back-ptr written; rendered block base | ||
| 118 | `0x1b58650`; both grids contain the shell banner post-draw. **No heap | ||
| 119 | corruption on QEMU.** | ||
| 120 | - QEMU verify geometry: cells ptr `0x1b54c40` cap `0xe74` len `0xe74`; rendered | ||
| 121 | ptr `0x1b58670`. | ||
| 122 | - ⇒ `CONTENT-GARBAGE` was never evidence of OptiPlex corruption — the check was | ||
| 123 | comparing against the wrong expectation. Now: probes compare against | ||
| 124 | `blank_raw` (0x70020); every probe value is logged; a `grids c nz=… blank=…` | ||
| 125 | summary is the definitive health signal. | ||
| 126 | |||
| 127 | ## The pre-verify `0x70020` at grid(0,0) — MYSTERY SOLVED | ||
| 128 | |||
| 129 | **There was no writer.** `0x70020` is the grid's own init fill: | ||
| 130 | `BLANK = Cell{ch:32, fg:7, bg:0}` encodes as `0x70020`, and `vt::init` builds | ||
| 131 | both grids with `vec![BLANK; rows*cols]`. The old content check expected | ||
| 132 | all-zero cells (wrong), and the probe loop's early `break` made probes 1–3 | ||
| 133 | look like zeros. Nothing writes a pre-banner space; the shell banner (gray | ||
| 134 | VGA-7 text, rows 0–1) and the `>` prompt (row 2) are the only vt writes | ||
| 135 | before the markers. | ||
| 136 | |||
| 137 | Also learned while verifying with a screendump: | ||
| 138 | |||
| 139 | - The shell banner occupies grid rows **0 and 1** (motd + `=====` line), and | ||
| 140 | the prompt sits at row 2 — so a marker at FB row 1 (the old shadow marker) | ||
| 141 | is **clobbered** by the banner, and row 2's first glyphs get eaten by the | ||
| 142 | prompt + cursor. Markers whose values matter now live at the **bottom** | ||
| 143 | (`gop::bottom_row(0)` = last row, `bottom_row(1)` = second-to-last), which | ||
| 144 | also survive a stale crash.log replay (~20 lines at grid rows 2+). | ||
| 145 | - Banner text renders VGA gray `0xAAAAAA` (fg 7), boot markers white `0xFFFFFF` | ||
| 146 | — a white-only pixel matcher misses the banner. QEMU screendump decode of | ||
| 147 | the bottom rows: `vt: c 0x1b54c40 cap=0xe74 ok | r 0x1b58670 ok` and | ||
| 148 | `gop: shadow 0x1980020 1.83 MiB`. | ||
| 149 | |||
| 150 | **Excluded candidates (all still true, now moot):** cursor task (FB/shadow | ||
| 151 | only), flush cursor-inverse pass (0x07000000 ≠ 0x70020), boot markers (direct | ||
| 152 | FB), memory self-test, shell banner (runs after verify), backspace (BLANK). | ||
| 153 | |||
| 154 | ## OptiPlex flash — what to look for (the linchpin) | ||
| 155 | |||
| 156 | New image puts on screen (markers are **bottom-anchored** now — they survive | ||
| 157 | the banner rows 0–1, the prompt row 2, AND a stale crash.log replay at rows | ||
| 158 | 2+; use `gop::bottom_row(off)` to place any future ones): | ||
| 159 | |||
| 160 | 1. **Last row (bottom_row(0))**: `gop: shadow {ptr:#x} {MiB}` vs | ||
| 161 | `gop: NO-SHADOW (fallback)`. | ||
| 162 | - If NO-SHADOW ⇒ shadow-rejection hypothesis gains weight (first block left | ||
| 163 | free + scrub-filled). | ||
| 164 | 2. **Second-to-last row (bottom_row(1))**: `vt: c {ptr:#x} cap={cap:#x} ok|GARBAGE | r {ptr:#x} ok|GARBAGE`. | ||
| 165 | - **The cells ptr value is the linchpin**: if it equals `0x40444970`, the | ||
| 166 | cells VecData itself is stale at shell entry (matches boot-crash decode). | ||
| 167 | - If cap shows `0xAA…` garbage ⇒ VecData fields scrubbed (bug family B). | ||
| 168 | - `ok` = all probed cells read BLANK (0x70020); `GARBAGE` = probe ≠ BLANK | ||
| 169 | (the OptiPlex firmware scrub reads back `0x00AAAAAA`). | ||
| 170 | 3. If it crashes: the full guard band (`hdr:` + all four `mem:` lines, 16 stack | ||
| 171 | words) plus the bottom markers if still visible. | ||
| 172 | |||
| 173 | Serial-side (QEMU only): the verify lines are captured in the klog ring | ||
| 174 | (`serial_println!` → ring), so a healthy OptiPlex boot can also dump them with | ||
| 175 | the `klog` shell command. | ||
| 176 | |||
| 177 | ## Build/flash/test loop (traps) | ||
| 178 | |||
| 179 | - Build 0 warnings, edition 2024, `no_std`, `x86_64-unknown-uefi`, workspace | ||
| 180 | v0.5.7. Zero new deps. | ||
| 181 | - Real-hardware boot chain: rsboot at `EFI/BOOT/BOOTX64.EFI` → kernel at | ||
| 182 | `bzImage`. QEMU dev loop boots kernel as BOOTX64.EFI. | ||
| 183 | - CRASHLOG stick must be FAT32; `mdir` grep gotcha: match `crash` | ||
| 184 | case-insensitively. | ||
| 185 | - **Stale qemu holds flock** → `pkill -9 -f 'qemu[-]system'` in a SEPARATE | ||
| 186 | command; `rm -f esp/NvVars` between boots. | ||
| 187 | - Use repo `scripts/` infra: test-msg/test-fault/test-mouse; monitor socket; HMP | ||
| 188 | `mouse_move`. | ||
| 189 | - Fault-context serial rule: never `serial_println!` in ISR/fault code; use | ||
| 190 | `serial::write_raw`; guard report must not allocate (stack `FmtBuf`). | ||
| 191 | - Marker on row 0 gets overwritten by the shell MOTD — use `boot_marker_at(msg, row>0)`. | ||
| 192 | - Stale PDBs misname symbols — re-resolve with a fresh PDB per build (PDB math | ||
| 193 | is decimal); `r9` = struct base with Vec layout `{ptr@0, cap@8, len@16}`. | ||
| 194 | |||
| 195 | ## Next steps (priority order) | ||
| 196 | |||
| 197 | 1. **Flash to OptiPlex** and relay the two bottom markers: shadow state (last | ||
| 198 | row) + vt marker (`bottom_row(1)` — the cells ptr value is the linchpin: | ||
| 199 | equals `0x40444970`? cap scrubbed `0xAA…`? `ok` vs `GARBAGE`?). If crash: | ||
| 200 | full `hdr:` + all four `mem:` lines. | ||
| 201 | 2. Reattach the window-manager milestone once the crash family is resolved. | ||
| 202 | |||
| 203 | (QEMU control arm is green: content check now passes on every healthy boot; | ||
| 204 | no further QEMU-side investigation is needed.) | ||
