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
A timer interrupt that arrives while interrupts are disabled is not delayed,
it is lost -- the LAPIC in periodic mode holds one pending interrupt and drops
the rest. So anything the kernel does with interrupts off for longer than
10 ms makes `ticks` run slow, and it never catches up.
That has now presented twice as "uptime is wrong": once as an interrupt storm
taking 83% of the CPU, once as heavy console output on a display that is
expensive to draw to. Both times the tick was the messenger, and both times it
looked like a timekeeping bug.
monotonic() reads the TSC instead. It is a counter in the silicon that
advances whether or not this kernel is paying attention, it is already
measured against the PIT at boot, and reading it is one instruction and no
lock. wallclock(), /proc/uptime, sysinfo, getrusage and times() all go through
it now.
`ticks` keeps the job it is good at -- the scheduler preempts on it, sleep()
counts it -- where losing one means a slightly longer sleep rather than a
wrong answer about what time it is.
Lost ticks are no longer harmful, which makes them invisible, which is worse.
So /proc/interrupts now says
timer: 3383 ticks taken, 3387 expected
and names the gap when it grows, because a machine dropping timer interrupts
is spending too long with interrupts disabled, and that is worth knowing
before it turns into a clock that lies.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VQ7Qx8E1q1M1bbCq8QLHS2
fastfetch reported 3 seconds of uptime after 15 real ones, `time` claimed
3.12s for a 20-second command, and ping's one-second interval was closer to
six. One cause, not three: `ticks` was advancing at ~14.5 Hz instead of 100.
It was not the timer. virtio-gpu-pci shares IRQ 11 with the e1000 and
registered no interrupt handler at all. PCI INTx is level-triggered, so the
device held the line asserted, the kernel signalled EOI, and it fired again
immediately -- 72,000 interrupts a second, 83% of CPU0, starving the tick.
The e1000's handler read ICR as zero half a million times, correctly
answering "not mine", which is what made it look like a network-free problem.
Reading virtio's ISR byte clears it and drops the line. That is the fix.
irq_dispatch now measures each line's rate against the TSC -- not ticks,
which is the first casualty of a storm -- and names the attached handlers
once above 20000/s. It reproduces the original fault as a single line.
Found along the way, and fixed because they were real:
- lapicinit loaded TICR with xv6's uncalibrated 10000000, whose own comment
admitted it was never measured. calibrate_timers() now measures the LAPIC
and the TSC against the 8254 PIT. (It came back at 999.9 MHz, so this was
not the bug -- but the next machine is not obliged to be 1 GHz.)
- microdelay() was an empty function body. Every microdelay(1000) in the
xHCI reset path and the USB hub power-on sequence returned instantly.
- HZ is a constant in param.h now, not the literal 100 written out at a
dozen ticks-to-seconds conversions. USER_HZ is separate and deliberately
does not follow it: musl answers sysconf(_SC_CLK_TCK) with 100 always, so
times() and /proc/stat scale at the syscall boundary the way Linux does.
- TIOCGWINSZ answered a hardcoded 24x80. gfx_cols()/gfx_rows() have known
the real geometry all along; at 1024x768 the console is 128x48, so every
program that lays out a screen was formatting for the wrong one.
- TCFLSH fell through to the catch-all `return 0`, claiming to discard
input without discarding any.
uptime now advances 5.01 seconds per 5 real seconds. schfs-check passes.
Full investigation, including the two wrong hypotheses and the measurement
flaw that protected them, in docs/history/kernel.md section 13.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VQ7Qx8E1q1M1bbCq8QLHS2
An x86-64 operating system built from xv6, now largely rewritten: SMP,
a copy-on-write root filesystem (SchFS), PCI/USB/virtio drivers, a TTF
rasteriser, and a Linux-numbered syscall ABI.
No history before this point -- the tree was never under version control.
This commit exists so the rename that follows has something to undo to.
