From d0abfa40a9b1c5028ef120ec898cf478f4d12611 Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Fri, 13 Nov 2026 20:07:20 -0300 Subject: [PATCH 1/5] boot: the release's report times the first SSH login The report timed only the serial console's prompt, which nothing a workspace waits for. v20261113.03 showed what that costs: its report read +11-18% on every row, because the getty went back to Type=idle and now waits for the lane's units, while the first login it was built for went 478 -> 402 ms (lab run 43518915618). TestReport now logs into the release as built over SSH through its vsock, as boot:ssh-first does, and Report.FirstLogin holds sshd's accept and the login. compare writes it first and always, moved or not, and says the sections after it time the console. The key and the row come from one helper both tests use. Co-Authored-By: Claude Opus 5.5 --- boot/report.go | 77 +++++++++++++++++++++++++++++++++------- boot/report_test.go | 44 ++++++++++++++++++++++- boot/report_unit_test.go | 39 ++++++++++++++++++++ boot/ssh_first_test.go | 76 +++++++++++++++++++++------------------ 4 files changed, 187 insertions(+), 49 deletions(-) diff --git a/boot/report.go b/boot/report.go index 5903247..d477402 100644 --- a/boot/report.go +++ b/boot/report.go @@ -34,10 +34,17 @@ type Report struct { Only string `json:"only,omitempty"` // Login is how a login prompt was reached: "echo" when the getty was replaced by one, so // agetty's unconditional second is not in the usable column; "agetty" when it was not. - Login string `json:"login"` - Specs []Row `json:"specs"` - Variants []Row `json:"variants"` - Skipped []Skipped `json:"skipped,omitempty"` + Login string `json:"login"` + // FirstLogin is the goal's number: the release as built, logged into over SSH through its + // vsock from the moment before QEMU is exec'd, in phases "accepts" (sshd takes a + // connection) and "login" (`true` has run as spin). The rows below time the serial + // console's prompt, which nothing a workspace does waits for: a change can move the two + // in opposite directions, as v20261113.03 did. Absent from a report made without sudo or + // /dev/vhost-vsock, and from releases before it was added. + FirstLogin *Boot `json:"first_login,omitempty"` + Specs []Row `json:"specs"` + Variants []Row `json:"variants"` + Skipped []Skipped `json:"skipped,omitempty"` } // Host is what the boot times were measured on. @@ -101,16 +108,23 @@ func Summarise(runs []Run, failure string) Boot { ds = append(ds, d) } } - p50, ok := Percentile(ds, 0.5) - if !ok { - continue + if s, ok := SummaryOf(ds); ok { + b.Phases[p.String()] = s } - p95, _ := Percentile(ds, 0.95) - b.Phases[p.String()] = Summary{P50: ms(p50), P95: ms(p95), N: len(ds)} } return b } +// SummaryOf is the p50 and p95 of ds, and false when ds is empty. +func SummaryOf(ds []time.Duration) (Summary, bool) { + p50, ok := Percentile(ds, 0.5) + if !ok { + return Summary{}, false + } + p95, _ := Percentile(ds, 0.95) + return Summary{P50: ms(p50), P95: ms(p95), N: len(ds)}, true +} + func ms(d time.Duration) float64 { return math.Round(float64(d.Microseconds())/10) / 100 } // Diff writes, as Markdown, what changed from old to new: every row whose command line, @@ -136,11 +150,51 @@ func Diff(w io.Writer, old, new Report, threshold float64) { fmt.Fprintf(w, "- `%s` changed: `%s` → `%s`\n", k, short(a), short(b)) } } + firstLogin(w, old.FirstLogin, new.FirstLogin) partial := new.Only != "" section(w, "Feature matrix", old.Specs, new.Specs, threshold, partial) section(w, "Image variants", old.Variants, new.Variants, threshold, partial) } +// firstLogin writes the goal's number first and always, moved or not: it is the one a change is +// decided on, and the sections after it time the console's prompt. +func firstLogin(w io.Writer, old, new *Boot) { + if old == nil && new == nil { + return + } + fmt.Fprintf(w, "\n### First SSH login\n\n") + fmt.Fprintln(w, "| phase | p50 / p95 (ms) | p50 |") + fmt.Fprintln(w, "|---|---|---|") + for _, p := range []string{"accepts", "login"} { + a, aok := phase(old, p) + b, bok := phase(new, p) + move := "-" + if aok && bok && a.P50 > 0 { + move = fmt.Sprintf("%+.1f%%", 100*(b.P50-a.P50)/a.P50) + } + fmt.Fprintf(w, "| %s | %s → %s | %s |\n", p, summary(a, aok), summary(b, bok), move) + } + if new != nil && new.Failed > 0 { + fmt.Fprintf(w, "\n%d of %d boots had no login: %s\n", new.Failed, new.Boots, new.Error) + } + fmt.Fprintln(w, "\nThe sections below time the serial console's prompt, which no workspace waits for.") +} + +func phase(b *Boot, p string) (Summary, bool) { + if b == nil { + return Summary{}, false + } + s, ok := b.Phases[p] + return s, ok +} + +func summary(s Summary, ok bool) string { + if !ok { + return "-" + } + return fmt.Sprintf("%.1f / %.1f", s.P50, s.P95) +} + func section(w io.Writer, title string, old, new []Row, threshold float64, partial bool) { before := map[string]Row{} for _, r := range old { @@ -303,10 +357,7 @@ func outcome(r Row) string { func usable(r Row) string { s, ok := r.Boot.Phases["usable"] - if !ok { - return "-" - } - return fmt.Sprintf("%.1f / %.1f", s.P50, s.P95) + return summary(s, ok) } func name(r Report) string { diff --git a/boot/report_test.go b/boot/report_test.go index cd4963f..706bd0a 100644 --- a/boot/report_test.go +++ b/boot/report_test.go @@ -12,6 +12,7 @@ import ( "runtime" "strings" "testing" + "time" "github.com/spin-stack/spin-machine/boot" ) @@ -75,7 +76,8 @@ func combinations() [][]choice { // // Needs /dev/kvm and a built release tree (SPIN_MACHINE_OUTPUT, or _output). The vsock rows // need /dev/vhost-vsock; without it those rows are listed as skipped rather than reported as -// failing. With sudo and /dev/nbd0 the getty is +// failing. With sudo, /dev/nbd0 and /dev/vhost-vsock the release as built is also logged into +// over SSH, the goal's number (Report.FirstLogin). With sudo and /dev/nbd0 the getty is // replaced by an echo, and every variant of the image runs; without them // the usable column carries agetty's second and the variants that edit the image are skipped. func TestReport(t *testing.T) { @@ -161,6 +163,16 @@ func TestReport(t *testing.T) { r.Specs = append(r.Specs, row) } + switch { + case !only.MatchString("first login"): + case !sudo: + r.Skipped = append(r.Skipped, boot.Skipped{ID: "first login", Why: "writes a key into the overlay, which needs sudo and /dev/nbd0"}) + case missing["vsock=on"] != "": + r.Skipped = append(r.Skipped, boot.Skipped{ID: "first login", Why: missing["vsock=on"]}) + default: + r.FirstLogin = measureFirstLogin(t, out, reps, flags) + } + vs := variants if k := kernelB(t); k != "" { vs = append(vs[:len(vs):len(vs)], variant{label: "kernel B", cpus: "2", memory: "2048", @@ -205,6 +217,36 @@ func measure(t *testing.T, out string, v variant, reps int) boot.Boot { return b } +// measureFirstLogin boots the release as built reps times and logs into each over SSH through +// its vsock, as boot:ssh-first does: the goal's number, in the report beside the console's. +func measureFirstLogin(t *testing.T, out string, reps int, flags []string) *boot.Boot { + t.Helper() + row, signer := sshRow(t) + v := row("first login", "") + v.flags = flags + b := &boot.Boot{Boots: reps, Phases: map[string]boot.Summary{}} + var accepts, logins []time.Duration + for range reps { + r := firstSSH(t, out, v, signer) + if r.listen == 0 || r.login == 0 { + b.Failed++ + if b.Error == "" { + b.Error = r.why + } + continue + } + accepts, logins = append(accepts, r.listen), append(logins, r.login) + } + if s, ok := boot.SummaryOf(accepts); ok { + b.Phases["accepts"] = s + } + if s, ok := boot.SummaryOf(logins); ok { + b.Phases["login"] = s + } + t.Logf("first login: %d/%d boots logged in", b.Boots-b.Failed, b.Boots) + return b +} + // static runs a spin-machine command that builds the machine without starting it, over the // fixed file names a report records, and returns its output lines with the release // directory written as $RELEASE. diff --git a/boot/report_unit_test.go b/boot/report_unit_test.go index 87e83c2..b79b09c 100644 --- a/boot/report_unit_test.go +++ b/boot/report_unit_test.go @@ -150,3 +150,42 @@ func TestDiff(t *testing.T) { t.Errorf("a row a partial run did not ask about is reported gone, or one under the threshold is listed:\n%s", got) } } + +// The goal's number comes before the console's sections, moved or not, and reads "-" on the +// side of a release from before it was measured. +func TestDiffFirstLogin(t *testing.T) { + login := func(accepts, login float64) *Boot { + return &Boot{Boots: 20, Phases: map[string]Summary{ + "accepts": {P50: accepts, P95: accepts + 10, N: 20}, "login": {P50: login, P95: login + 20, N: 20}}} + } + var b bytes.Buffer + Diff(&b, Report{Release: "v1", FirstLogin: login(300, 400)}, Report{Release: "v2", FirstLogin: login(300, 360)}, 0.05) + out := b.String() + for _, want := range []string{ + "| accepts | 300.0 / 310.0 → 300.0 / 310.0 | +0.0% |", + "| login | 400.0 / 420.0 → 360.0 / 380.0 | -10.0% |", + } { + if !strings.Contains(out, want) { + t.Errorf("missing %q in:\n%s", want, out) + } + } + if strings.Index(out, "First SSH login") > strings.Index(out, "Feature matrix") { + t.Errorf("the first login is not before the console's sections:\n%s", out) + } + + b.Reset() + nw := login(300, 360) + nw.Failed, nw.Error = 2, "sshd never accepted" + Diff(&b, Report{Release: "v1"}, Report{Release: "v2", FirstLogin: nw}, 0.05) + for _, want := range []string{"| login | - → 360.0 / 380.0 | - |", "2 of 20 boots had no login: sshd never accepted"} { + if !strings.Contains(b.String(), want) { + t.Errorf("missing %q in:\n%s", want, b.String()) + } + } + + b.Reset() + Diff(&b, Report{Release: "v1"}, Report{Release: "v2"}, 0.05) + if strings.Contains(b.String(), "First SSH login") { + t.Errorf("two reports with no first login have a section for one:\n%s", b.String()) + } +} diff --git a/boot/ssh_first_test.go b/boot/ssh_first_test.go index 4929324..058b4c6 100644 --- a/boot/ssh_first_test.go +++ b/boot/ssh_first_test.go @@ -55,39 +55,7 @@ func TestFirstSSH(t *testing.T) { t.Skip("no /dev/vhost-vsock: run task vsock") } reps := envInt(t, "REPS", 10) - - pub, priv, err := ed25519.GenerateKey(nil) - if err != nil { - t.Fatal(err) - } - signer, err := xssh.NewSignerFromKey(priv) - if err != nil { - t.Fatal(err) - } - sshPub, err := xssh.NewPublicKey(pub) - if err != nil { - t.Fatal(err) - } - key := filepath.Join(t.TempDir(), "key") - if err := os.WriteFile(key+".pub", xssh.MarshalAuthorizedKey(sshPub), 0o644); err != nil { - t.Fatal(err) - } - - // Every row has the key, the echo getty, and sshd@.service ordered after the image's host - // key generation. The image carries that drop-in itself since 2026-11-12; it is written - // here as well because the lab boots published releases, and one from before it cannot be - // logged into over vsock at all - the per-connection sshd finds no host keys. - keySetup := `ids=$(awk -F: '$1=="spin"{print $3":"$4}' "$MNT/etc/passwd"); test -n "$ids" -install -d -m 700 -o "${ids%:*}" -g "${ids#*:}" "$MNT/home/spin/.ssh" -install -m 600 -o "${ids%:*}" -g "${ids#*:}" ` + key + `.pub "$MNT/home/spin/.ssh/authorized_keys" -` - row := func(label, setup string) variant { - files := gettyDropin(gettyEcho) - files["/etc/systemd/system/sshd@.service.d/keygen.conf"] = "[Unit]\nWants=spin-machine-sshd-keygen.service\nAfter=spin-machine-sshd-keygen.service\n" - // The key in spin's own directory, owned by spin: sshd's StrictModes refuses one it - // cannot trust, and a refused key reads as a login that never comes. - return variant{label: label, cpus: cmp.Or(os.Getenv("CPUS"), "2"), memory: "2048", files: files, setup: keySetup + setup} - } + row, signer := sshRow(t) // Rows measured against "as built" and dropped once they had answered, on the bench fleet, // 10 boots of each interleaved, lab run 43308825692 (2026-11-12), p50/p95 ms of the first // login: as built then 570/626; pam_motd off 558/588; logind back in the boot 558/593; @@ -202,6 +170,43 @@ grep -q 'pam_systemd.so.*class=user-early-light' "$MNT/etc/pam.d/common-session" t.Log(b.String()) } +// sshRow makes a key to log in with and returns it with a function that makes a row of the +// release logged into with it: the key in spin's authorized_keys, the echo getty, sshd@ ordered +// after the image's host key generation, and setup run after those. The image carries that last +// drop-in itself since 2026-11-12; it is written here as well because the lab boots published +// releases, and one from before it cannot be logged into over vsock at all - the per-connection +// sshd finds no host keys. +func sshRow(t *testing.T) (func(label, setup string) variant, xssh.Signer) { + t.Helper() + pub, priv, err := ed25519.GenerateKey(nil) + if err != nil { + t.Fatal(err) + } + signer, err := xssh.NewSignerFromKey(priv) + if err != nil { + t.Fatal(err) + } + sshPub, err := xssh.NewPublicKey(pub) + if err != nil { + t.Fatal(err) + } + key := filepath.Join(t.TempDir(), "key") + if err := os.WriteFile(key+".pub", xssh.MarshalAuthorizedKey(sshPub), 0o644); err != nil { + t.Fatal(err) + } + // The key in spin's own directory, owned by spin: sshd's StrictModes refuses one it cannot + // trust, and a refused key reads as a login that never comes. + keySetup := `ids=$(awk -F: '$1=="spin"{print $3":"$4}' "$MNT/etc/passwd"); test -n "$ids" +install -d -m 700 -o "${ids%:*}" -g "${ids#*:}" "$MNT/home/spin/.ssh" +install -m 600 -o "${ids%:*}" -g "${ids#*:}" ` + key + `.pub "$MNT/home/spin/.ssh/authorized_keys" +` + return func(label, setup string) variant { + files := gettyDropin(gettyEcho) + files["/etc/systemd/system/sshd@.service.d/keygen.conf"] = "[Unit]\nWants=spin-machine-sshd-keygen.service\nAfter=spin-machine-sshd-keygen.service\n" + return variant{label: label, cpus: cmp.Or(os.Getenv("CPUS"), "2"), memory: "2048", files: files, setup: keySetup + setup} + }, signer +} + type firstSSHRun struct { listen, login, prompt time.Duration again time.Duration // a second login, right after the first: what any login costs @@ -219,10 +224,11 @@ func firstSSH(t *testing.T, out string, v variant, signer xssh.Signer) firstSSHR // Context ids are the host's: two machines with one fail to start, so this one's is drawn // from a range nothing else here uses. cid := uint32(100000 + rand.IntN(1<<20)) - cmd := exec.Command(filepath.Join(out, "bin", "spin-machine"), "boot", "--release", out, + args := append([]string{"boot", "--release", out, "--disk", overlay, "--memory", v.memory, "--cpus", v.cpus, "--vsock-cid", fmt.Sprint(cid), - "--console", "file:/dev/stdout", "--append", "init=/sbin/init") + "--console", "file:/dev/stdout", "--append", "init=/sbin/init"}, v.flags...) + cmd := exec.Command(filepath.Join(out, "bin", "spin-machine"), args...) cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true} stdout, err := cmd.StdoutPipe() if err != nil { From 19ffaba41087a6d38eb7f74e84004ca2e3f9bb2f Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Fri, 13 Nov 2026 20:07:20 -0300 Subject: [PATCH 2/5] qemu: static-pie, full RELRO, an NX stack and canaries, asserted No configure flag asks for them: they come from QEMU's meson defaults and Alpine's gcc, so a bump of either could drop one with no line here changing. The build now checks each shipped binary's ELF type, RELRO segment, BIND_NOW, GNU_STACK and stack guard reads, as it checks that they are static. As built 2026-11-13: 7111, 2093 and 9274 canary reads in qemu-system-x86_64, qemu-img and the TCG build. Co-Authored-By: Claude Opus 5.5 --- qemu/Dockerfile | 22 ++++++++++++++++++++++ 1 file changed, 22 insertions(+) diff --git a/qemu/Dockerfile b/qemu/Dockerfile index a506706..d913b68 100644 --- a/qemu/Dockerfile +++ b/qemu/Dockerfile @@ -380,6 +380,28 @@ RUN for b in /opt/qemu/bin/qemu-system-x86_64 /opt/qemu/bin/qemu-img \ done && \ echo "OK: every binary is statically linked" +# Hardened, asserted for the same reason. No flag above asks for any of this: static-pie, full +# RELRO, a non-executable stack and stack canaries come from QEMU's meson defaults and Alpine's +# gcc (15.2 on 2026-11-13), so a bump of either could drop one without a line here changing. +# QEMU runs a guest's device emulation on the host, which is where these earn their place. +# +# PIE is the ELF type (DYN for a static-pie, EXEC without); RELRO is full only with BIND_NOW, +# since a lazily bound GOT stays writable; the canaries are counted as reads of the TLS guard +# (%fs:0x28) in the code, because the binaries are stripped and __stack_chk_fail is no longer +# a symbol to look for. 7111 of them in qemu-system-x86_64 as built 2026-11-13. +RUN for b in /opt/qemu/bin/qemu-system-x86_64 /opt/qemu/bin/qemu-img \ + /opt/qemu-tcg/bin/qemu-system-x86_64; do \ + readelf -hW "$b" | grep -q 'Type:.*DYN' || { echo "ERROR: $b is not position-independent"; exit 1; }; \ + readelf -lW "$b" | grep -q GNU_RELRO || { echo "ERROR: $b has no RELRO segment"; exit 1; }; \ + readelf -dW "$b" | grep -q 'FLAGS.*BIND_NOW' || { echo "ERROR: $b is lazily bound; its RELRO is partial"; exit 1; }; \ + stack=$(readelf -lW "$b" | grep GNU_STACK) || { echo "ERROR: $b has no GNU_STACK segment, so its stack is executable"; exit 1; }; \ + case "$stack" in *RWE*) echo "ERROR: $b has an executable stack"; exit 1 ;; esac; \ + canaries=$(objdump -d --no-show-raw-insn "$b" | grep -c '%fs:0x28') || true; \ + [ "${canaries:-0}" -gt 0 ] || { echo "ERROR: $b has no stack canaries"; exit 1; }; \ + echo "$b: static-pie, full RELRO, NX stack, $canaries canary reads"; \ + done && \ + echo "OK: every binary is hardened" + # qboot, the BIOS this machine boots with. QEMU's SeaBIOS is built for every guest a PC can run; this machine boots one Linux kernel # through PVH and nothing else, and qboot is a firmware for exactly that. Measured on the lab # runner, 20 boots interleaved (2026-09-29): 121.9 -> 114.8 ms p50 to a diagnostic init, and From 99d54e899cb627d6310b3febe9dc5c4d80ff43e6 Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Fri, 13 Nov 2026 20:07:20 -0300 Subject: [PATCH 3/5] boot: ssh-first row, one sshd for every connection (experiment) The vsock socket with Accept=no, handed to an sshd -D started from the boot's first dispatch, as Ubuntu's ssh.socket hands TCP's to ssh.service: no transient sshd@ unit and no sshd -i reading its configuration and host keys per connection. Checked in a boot (2026-11-13): Accept=no, one "sshd -D [listener]", no sshd@ units, the login over vsock works. On a laptop, 10 boots of each: first login 251 -> 242 ms, a second 34 -> 30. Co-Authored-By: Claude Opus 5.5 --- boot/ssh_first_test.go | 25 ++++++++++++++++++++++++- 1 file changed, 24 insertions(+), 1 deletion(-) diff --git a/boot/ssh_first_test.go b/boot/ssh_first_test.go index 058b4c6..d490be4 100644 --- a/boot/ssh_first_test.go +++ b/boot/ssh_first_test.go @@ -123,7 +123,30 @@ grep -q 'pam_systemd.so.*class=user-early-light' "$MNT/etc/pam.d/common-session" sed -i 's/^\(session.*pam_systemd\.so\)\(.*\)$/\1\2 class=user-early-light/' "$MNT/etc/pam.d/common-session" grep -q 'pam_systemd.so.*class=user-early-light' "$MNT/etc/pam.d/common-session" ` - rows := []variant{row("as released", ""), asBuilt} + // One sshd for every connection (experiment): the vsock socket with Accept=no, handed to an + // sshd -D started from the boot's first dispatch, as Ubuntu's ssh.socket hands TCP's to + // ssh.service. With Accept=yes each connection is a transient sshd@ unit and an sshd -i that + // reads its configuration and host keys before it forks sshd-session; here only the fork is + // left. + persistent := row("one sshd", "") + persistent.files["/etc/systemd/system/sshd-vsock.socket.d/20-accept.conf"] = "[Socket]\nAccept=no\n" + persistent.files["/etc/systemd/system/sshd-vsock.service"] = `[Unit] +DefaultDependencies=no +Wants=spin-machine-sshd-keygen.service +After=spin-machine-sshd-keygen.service +Conflicts=shutdown.target +Before=shutdown.target +[Service] +Type=notify +ExecStart=/usr/sbin/sshd -D +KillMode=process +RuntimeDirectory=sshd +RuntimeDirectoryMode=0755 +` + persistent.links = map[string]string{ + "/etc/systemd/system/sysinit.target.wants/sshd-vsock.service": "/etc/systemd/system/sshd-vsock.service", + } + rows := []variant{row("as released", ""), persistent} type samples struct{ listen, login, accepted, again, prompt []time.Duration } got := map[string]*samples{} From d8ebd32e34cd82cb9875b1f5fd8cec3e32a2b384 Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Fri, 13 Nov 2026 20:09:42 -0300 Subject: [PATCH 4/5] boot: one sshd for every connection out; docs/log.md, what it and the report found The row answered: on the bench fleet, 20 boots of each interleaved on v20261113.03 (lab run 43524721490), the first login read 382/393 ms against 381/410 as released, and a second login 40 against 48. The goal is the first, so the row is removed and the result is in the log. Co-Authored-By: Claude Opus 5.5 --- boot/ssh_first_test.go | 25 +------------------------ docs/log.md | 3 +++ 2 files changed, 4 insertions(+), 24 deletions(-) diff --git a/boot/ssh_first_test.go b/boot/ssh_first_test.go index d490be4..058b4c6 100644 --- a/boot/ssh_first_test.go +++ b/boot/ssh_first_test.go @@ -123,30 +123,7 @@ grep -q 'pam_systemd.so.*class=user-early-light' "$MNT/etc/pam.d/common-session" sed -i 's/^\(session.*pam_systemd\.so\)\(.*\)$/\1\2 class=user-early-light/' "$MNT/etc/pam.d/common-session" grep -q 'pam_systemd.so.*class=user-early-light' "$MNT/etc/pam.d/common-session" ` - // One sshd for every connection (experiment): the vsock socket with Accept=no, handed to an - // sshd -D started from the boot's first dispatch, as Ubuntu's ssh.socket hands TCP's to - // ssh.service. With Accept=yes each connection is a transient sshd@ unit and an sshd -i that - // reads its configuration and host keys before it forks sshd-session; here only the fork is - // left. - persistent := row("one sshd", "") - persistent.files["/etc/systemd/system/sshd-vsock.socket.d/20-accept.conf"] = "[Socket]\nAccept=no\n" - persistent.files["/etc/systemd/system/sshd-vsock.service"] = `[Unit] -DefaultDependencies=no -Wants=spin-machine-sshd-keygen.service -After=spin-machine-sshd-keygen.service -Conflicts=shutdown.target -Before=shutdown.target -[Service] -Type=notify -ExecStart=/usr/sbin/sshd -D -KillMode=process -RuntimeDirectory=sshd -RuntimeDirectoryMode=0755 -` - persistent.links = map[string]string{ - "/etc/systemd/system/sysinit.target.wants/sshd-vsock.service": "/etc/systemd/system/sshd-vsock.service", - } - rows := []variant{row("as released", ""), persistent} + rows := []variant{row("as released", ""), asBuilt} type samples struct{ listen, login, accepted, again, prompt []time.Duration } got := map[string]*samples{} diff --git a/docs/log.md b/docs/log.md index def577d..780a278 100644 --- a/docs/log.md +++ b/docs/log.md @@ -339,6 +339,8 @@ Measured and not shipped: **11-13 · kernel/qemu · branches `kernel-snapshot`, `qemu-snapshot` (rejected).** QEMU publishes bus 0's configuration space over fw_cfg after the firmware (etc/spin/pci-config) and the kernel answers boot-time configuration reads from it until each dword is written. It works (`PCI: configuration space of 5 devices on bus 0`) and is worth -14 ms against the same kernel without it (lab 43514550646), but only 2-3 ms against 0005, which already removes most repeated reads: 209/217 against 211/222 (lab 43514884598). Not worth a QEMU patch and a 250-line kernel patch. +**11-13 · boot/qemu · branch `first-login-report` (this change).** v20261113.03's report read +11-18% on every row: the report times the serial console's prompt, and the getty drop-in removed in #250 left it Type=idle, waiting for the lane's units. The first login it does not time went 478/500 (v20261113.02, lab 43524334205) -> 381/410 ms (v20261113.03, lab 43524721490), two runs and not interleaved. The report now logs into the release over SSH too (`first_login`), and compare writes it first. The QEMU build asserts static-pie, full RELRO, an NX stack and stack canaries, which come from QEMU's and Alpine's defaults and no flag here. Measured and left out: one sshd for every connection (the vsock socket with Accept=no, an `sshd -D` from the first dispatch), first login 382/393 against 381/410 and a second 40 against 48 ms (lab 43524721490). + --- ## 3. Rework cycles @@ -514,6 +516,7 @@ Also the reusable builder, added and reverted on 10-13. | sntrup761 (OpenSSH default) | 104 vs 40 ms per login | #245, lab 43479854381 | 11-13 | | Configuration-space snapshot over fw_cfg (QEMU + kernel) | 209 vs 211 with 0005 | lab 43514884598 | 11-13 | | CPUWeight/IOWeight/Nice on the first login's lane | −2 ms over coldplug filtered; second login 63 vs 45 | lab 43518915618 | 11-13 | +| One sshd for every connection (vsock Accept=no, `sshd -D` early) | First login 382 vs 381; second 40 vs 48 ms | lab 43524721490 | 11-13 | | Login without pam_systemd (diagnostic bound) | 380 vs 436, but no session, no XDG_RUNTIME_DIR | lab 43518044150 | 11-13 | | Lower the vCPU ceiling, drop the balloon or ACPI for boot time | Not tried: hotplug and dynamic memory are an invariant | AGENTS.md | 11-13 | From fb5f69ec7ef6f290e7db3e76edefb43fd1b7a678 Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Fri, 13 Nov 2026 20:30:47 -0300 Subject: [PATCH 5/5] boot: tests that refuse every edit mutate makes to the first login's section A release before the first login against one without it, a p50 under a millisecond, one failed boot: the five edits to firstLogin no test held. Co-Authored-By: Claude Opus 5.5 --- boot/report_unit_test.go | 19 +++++++++++++++++++ 1 file changed, 19 insertions(+) diff --git a/boot/report_unit_test.go b/boot/report_unit_test.go index b79b09c..2217c1b 100644 --- a/boot/report_unit_test.go +++ b/boot/report_unit_test.go @@ -183,6 +183,25 @@ func TestDiffFirstLogin(t *testing.T) { } } + // The other way round: a report made without sudo or vsock has no first login, and the + // release before it does. Nothing moved by -100%. + b.Reset() + Diff(&b, Report{Release: "v1", FirstLogin: login(300, 400)}, Report{Release: "v2"}, 0.05) + if want := "| login | 400.0 / 420.0 → - | - |"; !strings.Contains(b.String(), want) { + t.Errorf("missing %q in:\n%s", want, b.String()) + } + + // A p50 under a millisecond is still one to move from, and one failed boot is said. + b.Reset() + nw = login(1, 360) + nw.Failed, nw.Error = 1, "refused" + Diff(&b, Report{Release: "v1", FirstLogin: login(0.5, 360)}, Report{Release: "v2", FirstLogin: nw}, 0.05) + for _, want := range []string{"| accepts | 0.5 / 10.5 → 1.0 / 11.0 | +100.0% |", "1 of 20 boots had no login: refused"} { + if !strings.Contains(b.String(), want) { + t.Errorf("missing %q in:\n%s", want, b.String()) + } + } + b.Reset() Diff(&b, Report{Release: "v1"}, Report{Release: "v2"}, 0.05) if strings.Contains(b.String(), "First SSH login") {