boot: one line when it works, all of it when it does not

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
This commit is contained in:
Nexoniarz 2026-09-14 21:19:50 +02:00
commit 617a4aec0a
24 changed files with 373 additions and 60 deletions

View file

@ -44,6 +44,15 @@ puts_(const char *s)
write(1, (void *)s, n);
}
static int
same(const char *a, const char *b, int n)
{
for (int i = 0; i < n; i++)
if (a[i] != b[i])
return 0;
return 1;
}
static int
slurp(const char *path, char *buf, int cap)
{
@ -110,10 +119,24 @@ main(int argc, char *argv[])
}
// An existing file is somebody's decision until told otherwise.
//
// Saying so every boot is the wrong volume for it. On a machine that has
// been up before, /etc/resolv.conf always exists and always says the same
// thing, so this printed a line about having done nothing on every single
// start -- which is exactly the kind of message that teaches people to
// stop reading their own boot.
//
// Quiet when the file already says what this would have written. It is
// still worth a word when the two *disagree*, because then the nameserver
// has changed and the machine is using the old one.
if (!force) {
char old[512];
if (slurp(DST, old, sizeof(old)) > 0) {
puts_("resolvconf: " DST " already exists; -f to replace it\n");
int on = slurp(DST, old, sizeof(old));
if (on > 0) {
if (on == n && same(old, buf, n))
return 0; // already right; nothing to say
puts_("resolvconf: " DST " differs from what DHCP gave;"
" -f to replace it\n");
return 0;
}
}
@ -130,6 +153,8 @@ main(int argc, char *argv[])
}
close(fd);
// Worth one line the first time, because it is the moment names start
// working and somebody may be waiting to know it.
puts_("resolvconf: ");
write(1, buf, n);
return 0;

View file

@ -102,6 +102,23 @@ ends_with(const char *s, const char *suffix)
return seq(s + ls - lf, suffix);
}
// How the machine was booted; see /proc/bootmode and kinfo() in the kernel.
static int verbose_boot;
static void
read_bootmode(void)
{
char b[16];
int fd = open("/proc/bootmode", O_RDONLY);
int n;
if (fd < 0)
return;
n = read(fd, b, sizeof(b) - 1);
close(fd);
if (n > 0) { b[n] = 0; verbose_boot = (b[0] == 'v'); }
}
static void
out(const char *s)
{
@ -522,6 +539,11 @@ main(int argc, char *argv[])
bootstrap();
// Only now: /proc is what bootstrap() mounts, and this reads a file in it.
// Before the mount it silently returned "quiet" every time, which made the
// verbose boot quiet in exactly the one process that runs first.
read_bootmode();
// A reincarnated PID 1 has the children but not the table.
//
// exec() replaced this program's memory and kept everything else -- the
@ -545,13 +567,21 @@ main(int argc, char *argv[])
reclaim();
}
out("schinit: SchOS process 1");
if (generation > 1) {
out(", generation ");
outn((int)generation);
out(" (reincarnated)");
// Quiet unless asked, or unless this is not the first pid 1.
//
// "SchOS process 1" is a line about the system working exactly as designed,
// which is the definition of what a quiet boot leaves out. A *reincarnated*
// pid 1 is the opposite -- it means the last one died and was replaced --
// so that one prints either way.
if (verbose_boot || generation > 1) {
out("schinit: SchOS process 1");
if (generation > 1) {
out(", generation ");
outn((int)generation);
out(" (reincarnated)");
}
out("\n");
}
out("\n");
// Generation 4 is the safety net: a manifest that kills init must not kill
// it for ever, so this generation does not read /etc/schinit at all. One
@ -590,7 +620,8 @@ main(int argc, char *argv[])
}
publish();
out("schinit: ready (pid 1)\n");
if (verbose_boot)
out("schinit: ready (pid 1)\n");
for (;;) {
// Two things can happen -- a request arrives, or a child exits -- and

View file

@ -89,6 +89,44 @@ out(const char *s)
write(1, (void *)s, slen(s));
}
// How the machine was booted, read once.
//
// The routine progress lines below -- one per job started, plus the summary --
// are the userspace half of the same problem the kernel has: worth reading on
// a boot you are watching, and noise on the several thousand after it. They
// are not deleted, they are held back, and `make qemu` with F8 or any verbose
// boot brings all of them back.
//
// Failures are never held back. A job that could not start, a channel that
// closed, a pid 1 that stopped answering: those print either way, because a
// silent supervisor is worse than a chatty one.
static int verbose_boot;
static void
read_bootmode(void)
{
char b[16];
int fd = open("/proc/bootmode", O_RDONLY);
int n;
if (fd < 0)
return; // no procfs: assume quiet
n = read(fd, b, sizeof(b) - 1);
close(fd);
if (n > 0) {
b[n] = 0;
verbose_boot = (b[0] == 'v');
}
}
// Progress, as opposed to news.
static void
vout(const char *s)
{
if (verbose_boot)
write(1, (void *)s, slen(s));
}
static void
outn(int v)
{
@ -560,6 +598,8 @@ main(void)
{
struct schinit_hello h;
read_bootmode();
// Version handshake before anything else. A mismatch is a refusal rather
// than a best-effort interpretation -- see the header for why.
h.op = SCHINIT_HELLO;
@ -580,8 +620,9 @@ main(void)
}
load_jobs();
out("schinitd: "); outn(njobs); out(" job(s) loaded, generation ");
outn((int)h.generation); out("\n");
vout("schinitd: "); if (verbose_boot) outn(njobs);
vout(" job(s) loaded, generation ");
if (verbose_boot) { outn((int)h.generation); out("\n"); }
// Anything PID 1 is already holding is ours again, not something to start.
unsigned int highest = adopt();
@ -593,11 +634,11 @@ main(void)
continue;
if (j->pid)
continue; // adopted; it never stopped running
out("schinitd: starting "); out(j->label); out("\n");
vout("schinitd: starting "); vout(j->label); vout("\n");
ask_spawn(j);
}
out("schinitd: ready\n");
vout("schinitd: ready\n");
// From here on this program does two things: answer PID 1's heartbeat, and
// act on the exits it reports. There is no wait() in this program and

View file

@ -31,6 +31,26 @@
// --- small output, since lib/ has no printf ---------------------------------
// How the machine was booted. A driver coming up is progress on a boot you are
// watching and noise on every other one; a driver *failing* is neither, and
// stays on puts(). See kinfo() in kernel/core/console.c for the same rule one
// level down.
static int verbose_boot;
static void
read_bootmode(void)
{
char b[16];
int fd = open("/proc/bootmode", O_RDONLY);
int n;
if (fd < 0)
return;
n = read(fd, b, sizeof(b) - 1);
close(fd);
if (n > 0) { b[n] = 0; verbose_boot = (b[0] == 'v'); }
}
static void
puts(const char *s)
{
@ -39,6 +59,23 @@ puts(const char *s)
write(1, (void *)s, n);
}
// Progress, as opposed to news.
static void
vputs(const char *s)
{
if (verbose_boot)
puts(s);
}
static void putn(long long v);
static void
vputn(long long v)
{
if (verbose_boot)
putn(v);
}
static void
putn(long long v)
{
@ -375,7 +412,7 @@ bring_up(void)
if (width <= 0 || height <= 0)
die("the device reports no display");
puts("vgpud: display is "); putn(width); puts("x"); putn(height); puts("\n");
vputs("vgpud: display is "); vputn(width); vputs("x"); vputn(height); vputs("\n");
// A 2D resource the size of the screen.
struct virtio_gpu_resource_create_2d *c =
@ -431,8 +468,10 @@ bring_up(void)
if (docmd(sizeof(*so), sizeof(struct virtio_gpu_ctrl_hdr)) < 0 || !resp_ok())
die("SET_SCANOUT refused");
puts("vgpud: scanout is ours, framebuffer at physical 0x");
puthex(fb_paddr, 16); puts("\n");
if (verbose_boot) {
puts("vgpud: scanout is ours, framebuffer at physical 0x");
puthex(fb_paddr, 16); puts("\n");
}
}
// Push what has been drawn to the host. Two commands, and both are needed:
@ -735,6 +774,8 @@ control_socket(void)
int
main(int argc, char *argv[])
{
read_bootmode();
pcifd = open("/dev/pci", O_RDWR);
if (pcifd < 0)
die("cannot open /dev/pci");
@ -758,17 +799,19 @@ main(int argc, char *argv[])
if (index_ < 0)
nothing_to_do("no virtio-gpu on this machine");
puts("vgpud: virtio-gpu at "); puthex(info.bus, 2); puts(":");
puthex(info.slot, 2); puts("."); puthex(info.func, 1);
if (info.driver[0]) { puts(", currently held by "); puts(info.driver); }
puts("\n");
if (verbose_boot) {
puts("vgpud: virtio-gpu at "); puthex(info.bus, 2); puts(":");
puthex(info.slot, 2); puts("."); puthex(info.func, 1);
if (info.driver[0]) { puts(", currently held by "); puts(info.driver); }
puts("\n");
}
// The kernel driver is asked to let go here. It puts the VBE framebuffer
// back on screen before returning, so there is never a moment with no
// display -- see vgpu_release() and vga_fb_restore().
if (ioctl(pcifd, PCIIOC_CLAIM, &index_) < 0)
nothing_to_do("claim refused -- the kernel driver would not release it");
puts("vgpud: claimed\n");
vputs("vgpud: claimed\n");
// The info is re-read because claiming is what enables memory space and
// bus mastering, and a BAR read before that can legitimately be zero.
@ -786,9 +829,9 @@ main(int argc, char *argv[])
draw_test_pattern();
present();
puts("vgpud: pid ");
putn(getpid());
puts(" drew a test pattern from userspace\n");
vputs("vgpud: pid ");
vputn(getpid());
vputs(" drew a test pattern from userspace\n");
if (argc > 1 && argv[1][0] == '-' && argv[1][1] == 'x') {
// Exit without releasing, to show what a crashed driver leaves behind:
@ -826,7 +869,7 @@ main(int argc, char *argv[])
sleep(100);
}
puts("vgpud: listening on " VGPUD_SOCKET "\n");
vputs("vgpud: listening on " VGPUD_SOCKET "\n");
for (;;) {
int c = accept(srv, 0, 0);
if (c < 0) {