Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
43 changes: 33 additions & 10 deletions boot/ssh_first_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -94,12 +94,29 @@ install -m 600 -o "${ids%:*}" -g "${ids#*:}" ` + key + `.pub "$MNT/home/spin/.ss
// logind in the boot and spin lingering 510/525, with sshd accepting no later. The image
// now has no motd and lingers. Then, lab run 43312419007, 15 boots of each: the host keys
// generated in the boot (the keygen wanted by multi-user.target) 518/542 against 514/531 -
// nothing, so the keys stay with the first sshd that needs them. Each row's edit was checked in its setup, so a row that
// nothing: with default dependencies the keygen starts after basic.target, no sooner than the
// first connection's sshd@ starts it. Each row's edit was checked in its setup, so a row that
// matched nothing failed rather than measuring the image under another name.
//
// The rows below are written so they hold on a release from before this branch as well as
// after it, because the lab boots published releases: each puts the image in the state this
// branch builds - logind in the boot, spin lingering - whether or not it already was.
//
// Then three image changes, one row each and the three together, 20 boots of each, lab run
// 43483372488 (2026-11-13), p50/p95 ms of the first login and of accept to login: as built
// 489/506, 177/194; the host keys generated from the boot's first dispatch 468/494, 154/168;
// sshd-socket-generator and systemd-run-generator masked 489/501, 180/192; the eleven units
// of the initial transaction whose condition fails on every boot here masked (the pcr*
// units, kmod-static-nodes, apparmor, the distribution's sshd-keygen, getty-static,
// getty@tty1) 484/501, 178/191; all three 469/490, 156/173. Only the keys moved the login,
// so the image makes them early and the other two stay out. What those two were after:
// sshd-socket-generator loads libcrypto to find sshd_config at its defaults and is the
// slowest generator, 3.5-23.5 ms in a guest against ~1.5 for each of systemd's, but the
// generators run side by side and masking both took their phase from 5.3 to 3.7 ms p50 (a
// laptop, 8 boots of each); the units are parsed in the gap boot:waits shows after the unit
// load, which is PID 1 building the initial transaction (see waits_probe_test.go).
//
// The row below is written so it holds on a release from before this branch as well as
// after it, because the lab boots published releases: it puts the image in the state this
// branch builds - logind in the boot, spin lingering, the host keys made from the boot's
// first dispatch - whether or not it already was.
const asThisBranch = `rm -f "$MNT/etc/systemd/system/multi-user.target.wants/systemd-logind.service"
test -e "$MNT/usr/lib/systemd/system/multi-user.target.wants/systemd-logind.service"
install -d "$MNT/var/lib/systemd/linger" && touch "$MNT/var/lib/systemd/linger/spin"
Expand All @@ -112,11 +129,15 @@ install -d "$MNT/var/lib/systemd/linger" && touch "$MNT/var/lib/systemd/linger/s
// connections. Then lab run 43479854381, 20 of each, first login / a second: the runner's
// OpenSSH 9.6, which took sntrup761x25519, 489/104; x/crypto/ssh with mlkem768x25519
// 461/40, and with curve25519 461/39.
rows := []variant{
row("as this branch", asThisBranch),
asBuilt := row("as this branch", asThisBranch)
asBuilt.files["/etc/systemd/system/spin-machine-sshd-keygen.service.d/early.conf"] =
"[Unit]\nDefaultDependencies=no\nConflicts=shutdown.target\nBefore=shutdown.target\n"
asBuilt.links = map[string]string{
"/etc/systemd/system/sysinit.target.wants/spin-machine-sshd-keygen.service": "/usr/lib/systemd/system/spin-machine-sshd-keygen.service",
}
rows := []variant{asBuilt}

type samples struct{ listen, login, again, prompt []time.Duration }
type samples struct{ listen, login, accepted, again, prompt []time.Duration }
got := map[string]*samples{}
failed, classical := map[string]int{}, map[string]int{}
for range reps {
Expand All @@ -135,6 +156,7 @@ install -d "$MNT/var/lib/systemd/linger" && touch "$MNT/var/lib/systemd/linger/s
}
g := got[v.label]
g.listen, g.login, g.again, g.prompt = append(g.listen, r.listen), append(g.login, r.login), append(g.again, r.again), append(g.prompt, r.prompt)
g.accepted = append(g.accepted, r.login-r.listen)
}
}
ms := func(ds []time.Duration, q float64) string {
Expand All @@ -146,14 +168,15 @@ install -d "$MNT/var/lib/systemd/linger" && touch "$MNT/var/lib/systemd/linger/s
}
var b strings.Builder
fmt.Fprintf(&b, "\nms from the moment before QEMU is exec'd, p50/p95 over %d boots of each, interleaved, %s vCPUs\n\n", reps, rows[0].cpus)
fmt.Fprintf(&b, " %-16s %15s %15s %15s %15s %9s %14s\n", "", "SSHD ACCEPTS", "FIRST LOGIN", "A SECOND TOOK", "CONSOLE PROMPT", "NO LOGIN", "CURVE25519 IN")
fmt.Fprintf(&b, " %-16s %15s %15s %15s %15s %15s %9s %14s\n", "", "SSHD ACCEPTS", "FIRST LOGIN", "ACCEPT TO LOGIN", "A SECOND TOOK", "CONSOLE PROMPT", "NO LOGIN", "CURVE25519 IN")
for _, v := range rows {
g := got[v.label]
if g == nil {
g = &samples{}
}
fmt.Fprintf(&b, " %-16s %7s/%-7s %7s/%-7s %7s/%-7s %7s/%-7s %9d %14d\n", v.label,
ms(g.listen, .5), ms(g.listen, .95), ms(g.login, .5), ms(g.login, .95), ms(g.again, .5), ms(g.again, .95),
fmt.Fprintf(&b, " %-16s %7s/%-7s %7s/%-7s %7s/%-7s %7s/%-7s %7s/%-7s %9d %14d\n", v.label,
ms(g.listen, .5), ms(g.listen, .95), ms(g.login, .5), ms(g.login, .95), ms(g.accepted, .5), ms(g.accepted, .95),
ms(g.again, .5), ms(g.again, .95),
ms(g.prompt, .5), ms(g.prompt, .95), failed[v.label], classical[v.label])
}
t.Log(b.String())
Expand Down
9 changes: 9 additions & 0 deletions boot/waits_probe_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -388,6 +388,15 @@ func waitsReport(boots []waitsBoot, target string, top int, minGap time.Duration
fmt.Fprintf(&b, " %8s %8s %7s %7s %s\n", ms(u.Ready), ms(x.usable), ms(x.usable-u.Ready), "", "(Type=idle: the job queue draining, then exec)")
}
}
// The first gap, from the end of the unit load to the first job (32 ms p50 on the bench
// fleet, lab run 43361486792), is PID 1 and nothing else. systemd stamps UnitsLoadFinish
// after enumerating mounts, devices and slices, and only then loads the units the boot
// starts: coldplug, then "Activating default unit: default.target" parses every unit file
// default.target reaches, and a stub for each name an After= or RequiresMountsFor= gives,
// builds the initial transaction (64 jobs), and collects the stubs before the first job is
// dispatched - task boot:trace with systemd.log_level=debug, 2026-11-13. It shrinks only with
// the transaction: eleven of its units whose condition fails on every boot here, masked, did
// not move the first SSH login (boot:ssh-first, lab run 43483372488).
gaps := x.w.Gaps(x.target().Start, minGap)
fmt.Fprintf(&b, "\n no unit activating, for at least %s ms: systemd waiting on the kernel, or on itself\n\n", ms(minGap))
var idle time.Duration
Expand Down
6 changes: 5 additions & 1 deletion image/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -101,7 +101,11 @@ from outside:
them instead: every boot here *is* a first boot, since the root filesystem is a fresh
overlay, so the keys live exactly as long as the VM does. Every sshd waits for it,
including the per-connection `sshd@.service` that `systemd-ssh-generator` starts for vsock
and `ssh .host`: without that, those connections found no host keys and were dropped.
and `ssh .host`: without that, those connections found no host keys and were dropped. It
starts from the boot's first dispatch, wanted by `sysinit.target` without default
dependencies, so the keys exist before the vsock socket listens and the first login does not
wait for them. A guest checkpointed after it has booted therefore carries its host keys, and
whoever restores it hands each VM its own.
- **Two thirds of the boot was systemd asking the console questions.** The kernel execs
`/sbin/init` at 59 ms and systemd's first log line arrived at 852, with nothing running in
between. It was a terminfo query and a terminal reset, 334 ms of timeout each, waiting for
Expand Down
12 changes: 12 additions & 0 deletions image/build.sh
Original file line number Diff line number Diff line change
Expand Up @@ -364,6 +364,18 @@ in_image /etc/systemd/system/systemd-logind-varlink.socket.d/10-seats.conf || {
grep -qx 'KexAlgorithms mlkem768x25519-sha256' || {
echo "ERROR: sshd does not offer mlkem768x25519-sha256 alone" >&2
exit 1; }
# And the keys are made from the boot's first dispatch, not by the first login's sshd@, which
# would wait for them before its banner: 18 ms of the first login over vsock (the numbers are in
# the unit). Both halves: the link is what starts it in the boot, and without
# DefaultDependencies=no the unit waits for the sysinit.target that wants it and is late anyway.
stat_in_image /etc/systemd/system/sysinit.target.wants/spin-machine-sshd-keygen.service |
grep -qF '/usr/lib/systemd/system/spin-machine-sshd-keygen.service' || {
echo "ERROR: spin-machine-sshd-keygen.service is not wanted by sysinit.target" >&2
exit 1; }
"$bin/debugfs" -R "cat /usr/lib/systemd/system/spin-machine-sshd-keygen.service" /work/base.raw 2>/dev/null |
grep -qx 'DefaultDependencies=no' || {
echo "ERROR: spin-machine-sshd-keygen.service has default dependencies; it starts after sysinit.target" >&2
exit 1; }
if stat_in_image /etc/systemd/system/systemd-logind.service | grep -q '/dev/null'; then
echo "ERROR: systemd-logind.service is masked - it never starts, no login gets a" \
"session, and spin's manager never starts either" >&2
Expand Down
6 changes: 6 additions & 0 deletions image/mkosi.extra/usr/local/lib/spin-base/optimize-systemd.sh
Original file line number Diff line number Diff line change
Expand Up @@ -213,6 +213,12 @@ log "Configuring SSH for socket activation..."
rm -f /etc/systemd/system/multi-user.target.wants/ssh.service 2>/dev/null || true
mkdir -p /etc/systemd/system/sockets.target.wants
ln -sf /lib/systemd/system/ssh.socket /etc/systemd/system/sockets.target.wants/ssh.socket
# The host keys from the boot's first dispatch rather than the first login's: the unit says why
# and what it was worth. Its [Install] says sysinit.target, and this is that enable. Dangling
# until mkosi.postinst.chroot copies the unit in, as the containerd and docker links above are.
mkdir -p /etc/systemd/system/sysinit.target.wants
ln -sf /usr/lib/systemd/system/spin-machine-sshd-keygen.service \
/etc/systemd/system/sysinit.target.wants/spin-machine-sshd-keygen.service

# logind stays in the boot transaction, as the package wants it
# (/usr/lib/systemd/system/multi-user.target.wants/systemd-logind.service), because spin
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,17 +17,33 @@

[Unit]
Description=Generate SSH host keys for this VM
# Ordered before the daemon and pulled in by it, and deliberately NOT by ssh.socket.
# Hanging it off the socket puts it inside sockets.target, which is ordered before
# basic.target, which a service is ordered after by default — and systemd breaks the loop
# by dropping an edge at random:
# Started from the boot's first dispatch, beside journald and udev - wanted by sysinit.target,
# without default dependencies - and not by the first sshd that needs the keys. The first login
# over vsock is accepted by a per-connection sshd@.service, which waits for this unit (its
# drop-in, sshd@.service.d/keygen.conf) before it sends its banner, so a keygen started by that
# connection put the key generation inside the login. Started from the boot, it is done before
# sysinit.target is, and sshd-vsock.socket listens only after that: accept to first login went
# from 177 to 155 ms p50, and the first login from 486 to 468, 20 boots of each interleaved on
# the bench fleet (task boot:ssh-first, lab run 43463472762, 2026-11-13).
#
# Wanted by sysinit.target but not ordered before it: nothing in sysinit waits for host keys,
# and ordering it there would hold the vsock socket behind the key generation instead.
# DefaultDependencies=no takes away the After=sysinit.target and basic.target a service gets by
# default, which would make it wait for the target that wants it. The writes go to /etc/ssh on
# the root filesystem, which the kernel mounts read-write before PID 1 starts.
DefaultDependencies=no
Conflicts=shutdown.target
Before=shutdown.target
# Ordered before the daemons, and NOT pulled in by ssh.socket: hanging it off the socket put it
# inside sockets.target, and with default dependencies systemd broke the loop that made by
# dropping an edge at random:
#
# basic.target: Found ordering cycle: sockets.target/start after ssh.socket/start
# after spin-machine-sshd-keygen.service/start after basic.target/start
#
# Socket activation still works: the socket starts ssh.service, and ssh.service waits for
# this. The per-connection sshd@.service that systemd-ssh-generator's vsock and AF_UNIX
# sockets start waits for it through a drop-in of its own (sshd@.service.d/keygen.conf).
# The per-connection sshd@.service that systemd-ssh-generator's vsock and AF_UNIX sockets start
# waits for it through a drop-in of its own (sshd@.service.d/keygen.conf), which stays: it is
# what makes a connection that arrives first wait rather than find no keys.
Before=ssh.service sshd.service
ConditionPathExists=/usr/bin/ssh-keygen

Expand All @@ -43,4 +59,4 @@ RemainAfterExit=yes
ExecStart=/bin/sh -c 'for t in ed25519 ecdsa; do f=/etc/ssh/ssh_host_$${t}_key; [ -e "$$f" ] || /usr/bin/ssh-keygen -q -t "$$t" -N "" -f "$$f" || exit 1; done'

[Install]
WantedBy=ssh.service sshd.service
WantedBy=sysinit.target
Loading