A boot printed about thirty lines before reaching a prompt. Every one was
useful once, and printed on every boot for ever they train the person in front
of the machine to stop reading their own console -- which is expensive on the
day one of them changes.
SchOS UEFI loader
Press F8 for boot options... booting
Welcome to SchOS! (F8 at boot for the full log, or dmesg once you are in)
root@schos / »
**Nothing was deleted, it was routed.** consputc() already wrote to the klog
ring before anywhere else, so a line can be kept in full while being held back
from the two places a person looks. kinfo() is cprintf() with that routing, and
`dmesg` still has the whole boot with timestamps afterwards. The rule for which
is which is not how interesting a line is -- everything was interesting to
somebody once -- but whether you would want to see it on a machine that is
*working*. `pci: 7 devices` is yes the first time and no every time after;
`e1000: no DMA memory for the rings` is yes for ever and stays a cprintf.
The verbose boot the F8 menu already offered now means something much bigger,
which is the other half of this: it is the only way to see any of it live.
Userspace follows through /proc/bootmode, one word. schinit, schinitd and vgpud
hold back their progress lines and never their failures -- a supervisor that
goes quiet when a job dies is worse than one that chatters.
Two things found by testing rather than by reading:
- schinit read /proc/bootmode *before* bootstrap() mounted /proc, so it got
"quiet" every time and the verbose boot was quiet in the one process that
runs first. It reads after the mount now.
- resolvconf announced "already exists; -f to replace it" on every boot after
the first, which is a line about having done nothing. It is quiet when the
file already says what it would have written, and speaks only when the two
disagree -- which means the nameserver changed and the machine is using the
old one.
Verified both ways: quiet boot is six lines, a forced-verbose build prints all
thirty plus the `verbose boot:` steps, and /proc/kmsg holds every line in both.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VQ7Qx8E1q1M1bbCq8QLHS2
docs/plan/debugger.md D3 and D4, which finish the plan apart from the
network transport.
D3 -- `whose <addr>`. The views each speak for one subsystem, which is what
keeps them cheap and current, and it is exactly why none of them can see
the bug that matters: a page on the DMA arena's free list looks fine from
dma.c, the same page on kalloc's free list looks fine from kalloc.c, and
that it is on both is a fact no single subsystem holds.
# schdbg whose 0x3e239000
phys 0x000000003e239000 kernel va 0xffff80003e239000
dma arena, handed out
pcidma slot 2, 0 KB into a 4000 KB block given to pid 4 (vgpud)
mapped pid 4 (vgpud) at 0x000000004000d000 rwu vma[5] no_free
consistent: 1 owner, 1 mapping(s)
Claimants register the way views do -- one line in the file that owns the
data -- so the kernel image, the log region, the arena, the page allocator,
the pciuser DMA blocks and every page table each answer for themselves.
`mapped` is the one no allocator can answer: there is no reverse map, so
vm_walk_user() goes forward over every mapped page of every live process.
Two verdicts are shouted and everything else is reported as fact. More than
one owner means the second allocator to hand the page out is handing out
memory the first is still using -- the H2 bug, which would have printed as
three lines. Free-but-still-mapped means a page will be given away from
under the page tables that point at it. Deliberately *not* a finding: no
owner at all, because kalloc keeps a free list and no record of what it has
handed out, so an ordinary allocated page has nobody to speak for it and
saying otherwise would be the query crying wolf.
D4 -- watchpoints, on the four debug registers that had been sitting unused
since this kernel was written. Armed against the same framebuffer page and
then killing the driver:
watch 0: 0xffff80003e239000 written, 8 byte(s), by stosq+0x1f, pid 12 vgpud
#0 memset+0xba
#1 dma_alloc+0x2e2
#2 do_dma+0x22a
#3 pciuser_ioctl+0x13b
#4 sys_ioctl+0x3c7
#5 syscall+0xf6
The chain is the answer, not the rip. It reports and continues -- a data
watchpoint is a trap, delivered after the store completes, so returning
carries on with the program none the wiser, which is what lets this be used
on a machine that is still running.
Debug registers are per-CPU and there is no general IPI here, so the table
carries a generation number and each CPU reloads from its timer interrupt
when it notices the number has moved: one comparison per tick, one tick of
latency at worst. `watch` prints which CPUs have caught up, because "this
watchpoint is watching" and "this watchpoint is watching one CPU" must not
look the same.
Also fixed while testing: watch_init() was called from mpmain(), which runs
on every processor, so the command appeared in the list once per CPU.
dbg_register() now refuses a duplicate name outright, so the next init that
runs per-CPU fails loudly in the list rather than quietly doubling it.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VQ7Qx8E1q1M1bbCq8QLHS2
docs/plan/debugger.md, milestones D0, D1 and D2. What they replace is the
ninety-second loop -- add a cprintf, rebuild, boot, read the serial log --
which answers exactly the one question you thought of before the rebuild.
The rule the shape follows: **it observes, it does not control.** No
stepping, no software breakpoints, no stopping the world. Half the bugs
this kernel produces are timing -- an interrupt storm, a level-triggered
line nobody acknowledges, a driver that faults only on its second start --
and every one of them disappears when you halt the machine to look. And
the layering rule, which is the circularity rule the display already has:
a debugger that needs lwIP cannot debug lwIP.
D0 -- symbols. tools/ksyms.pl turns the first link pass into a table the
second pass carries. Two passes is enough because .ksym is placed after
.text and .rodata, so carrying the table cannot move anything recorded in
it; the build lists both passes' text symbols and refuses to link if they
ever disagree, because a symbol table that is subtly wrong gives confident
false answers. ksym.c reads it through weak symbols, so pass one -- which
has no table -- still links. A crash chain now reads panic+0x5f <-
proc_sysrq_cmd+0x99 <- ... <- syscall+0xf6.
D1 -- a log that outlives the kernel. Every character through consputc()
lands in a byte ring with a timestamp per line, readable as /proc/kmsg.
It sits in a region carved before the page allocator gets anything, with a
magic header, so a kernel finds the previous kernel's log still there --
including the whole PSOGM report. panic.c's own comment said "there is no
core dump and no log to go back to"; that is no longer true.
The obvious place for it is the top of RAM beside the DMA arena. That
was the first attempt and the magic came back as ASCII on the reboot,
because the top of usable memory is exactly where the firmware makes its
own allocations. It lives above the kernel image instead, which is a
stable address across boots of the same build.
D2 -- the introspection registry. A subsystem publishes its state with one
line at the bottom of the file that owns the data:
dbg_register("dma", dma_dump, "the DMA arena's free extents");
Seven views -- dma, mem, proc, vma, claims, pci, sock -- reachable three
ways: sysrq 'g' (always, no process and no filesystem), /dev/dbg (echo a
line, cat the answer), and schdbg. The protocol is lines of text because
the same bytes have to work where nothing can allocate or frame a record,
and because a protocol you cannot drive by hand is one you cannot debug.
struct sbuf moved out of kernel/dev/procfs.c into include/sbuf.h rather
than being written a second time.
Several views exist because of a specific bug. `vma` is the table that
decides whether exit() frees a page, and the DMA ownership bug that made
this worth building was a block that was never in it.
Also fixed, found by building with clang for the first time in a while:
struct iovec was defined in both posix.h and socket.h, and every file that
included both was a redefinition. GCC 15 defaults to C23, which permits an
identical struct redeclaration, so the gcc path never noticed -- while
clang defaults to gnu17 and rejected it, breaking the one toolchain
shell.nix exists to provide and the UEFI loader requires. Both are now
guarded.
D3 (`whose <addr>`, the cross-subsystem ownership query) and D4 (hardware
watchpoints on DR0-DR3) are not built and are described honestly as
missing in the architecture doc's "What it does not do".
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VQ7Qx8E1q1M1bbCq8QLHS2
Nexoniarz