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
14 changes: 12 additions & 2 deletions Taskfile.yml
Original file line number Diff line number Diff line change
Expand Up @@ -150,6 +150,16 @@ tasks:
cmds:
- SPIN_BOOT_BENCH=1 go test ./boot/ -run TestBootCost -v -timeout 60m

boot:logind:
desc: >-
Check first SSH login, reconnect, user services and logout in a disposable guest.
Needs a built release and debugfs; uses KVM when available, otherwise TCG.
The image does not start logind at boot, so this checks the thing that makes that
safe: that the first login activates it and gets a real session. SPIN_LOGIND_NO_SEATS=1
removes the drop-in that allows it and is expected to fail, not to measure anything.
cmds:
- SPIN_LOGIND_TEST=1 go test ./boot/ -run '^TestLogindSessions$' -count=1 -v -timeout 5m

boot:trace:
desc: >-
One boot's console printed against the host's clock, for finding a gap that belongs to
Expand All @@ -170,7 +180,7 @@ tasks:
cmds:
- |
set -euo pipefail
unformatted=$(gofmt -l machine cmd)
unformatted=$(gofmt -l machine cmd boot)
if [ -n "$unformatted" ]; then
echo "not gofmt'd:"; echo "$unformatted"; exit 1
fi
Expand All @@ -184,7 +194,7 @@ tasks:
- |
set -euo pipefail
for f in hack/release image/build.sh image/mkosi.postinst.chroot \
image/mkosi.extra/usr/local/lib/spin-base/*.sh; do
image/mkosi.extra/usr/local/lib/spin-base/*.sh boot/testdata/*.sh; do
bash -n "$f" || { echo "$f does not parse" >&2; exit 1; }
done
echo "OK: the shell scripts parse"
Expand Down
50 changes: 50 additions & 0 deletions boot/bench_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,11 @@ func without(units ...string) variant {

func labelled(l string, v variant) variant { v.label = l; return v }

func withFile(m map[string]string, path, content string) map[string]string {
m[path] = content
return m
}

var variants = []variant{
{label: "as shipped", cpus: "2", memory: "2048"},
{label: "baseline", cpus: "2", memory: "2048", files: gettyDropin(gettyEcho)},
Expand Down Expand Up @@ -112,6 +117,51 @@ var variants = []variant{
// The chrony rows are kept as the record of what removing it bought, and cannot be run
// again: there is no time daemon in the image since 2026-09-10 (see image/mkosi.conf).
labelled("sin logind", without("systemd-logind.service")),
// The inverse of what the image ships: logind put back into the boot transaction, which
// is the configuration this replaced. Since 2026-09-12 the want is overridden with a
// /dev/null symlink and the first login starts logind over its Varlink socket instead.
// 25 boots of each, same run, measured that day:
//
// as shipped, deferred 248/275 logind at boot (this row) 272/294
// deferred, no drop-in 244/264 at boot, with the drop-in 282/322
// masked outright 241/265
//
// So deferring it is worth 24 ms, of which the drop-in gives 4 back for its fork, and
// masking it outright — which breaks every login — would be worth 7 more.
//
// This row neutralises the drop-in as well, and that is the whole reason it is written
// the long way instead of just restoring the want. With the drop-in left in place the
// same comparison reads 43 ms, because a service is implicitly ordered after the socket
// that triggers it: logind starting at boot then waits for an ExecStartPre fork that the
// shipped machine never puts on any path, and the row flatters the change by 19 ms.
//
// What makes the deferral possible is that drop-in rather than anything here:
// pam_systemd decides whether to register a session by calling logind_running(), which
// is access("/run/systemd/seats/") — a test for "is this a logind system", not "is
// logind up" — and on a false answer it logs "Skipping logind registration as logind is
// not running" and returns PAM_SUCCESS. Creating that directory on the Varlink socket,
// which carries Service=systemd-logind.service, is what gets pam_systemd as far as the
// connection that starts logind.
//
// Two dead ends on the way, both of which measure well *here* and leave a machine whose
// logins have no session, because the echo marker this row watches needs none:
//
// - Ordering sshd after logind instead repairs SSH and only SSH, with `su -l` and the
// console getty still landing with XDG_RUNTIME_DIR unset. Ordering the getty after
// logind too repairs those and hands the saving straight back.
// - RuntimeDirectory=systemd/seats on the socket, to make the directory without a
// fork, creates nothing: a unit with no Exec* line never applies its execution
// context. It benchmarked as the fastest row here because it *was* the masked
// machine. ExecStartPre=/bin/true makes the directory appear, which is both the
// proof and the reason the drop-in does not bother avoiding the fork.
//
// `task boot:logind` is what holds the half of this that a boot time cannot show.
{label: "logind at boot", cpus: "2", memory: "2048",
files: withFile(gettyDropin(gettyEcho),
"/etc/systemd/system/systemd-logind-varlink.socket.d/10-seats.conf", "[Socket]\n"),
links: map[string]string{
"/etc/systemd/system/multi-user.target.wants/systemd-logind.service": "/lib/systemd/system/systemd-logind.service",
}},
// serial-getty is Type=idle, which holds the service until systemd's job queue is quiet.
// If that dominates, `usable` has been measuring the queue draining rather than the
// machine being ready — and it would have been invisible earlier, because the first test
Expand Down
159 changes: 159 additions & 0 deletions boot/logind_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,159 @@
// SPDX-License-Identifier: Apache-2.0

package boot_test

import (
"bytes"
"context"
"os"
"os/exec"
"path/filepath"
"strings"
"testing"
"time"

"github.com/spin-stack/spin-machine/machine"
)

// A correctness test, including under TCG: none of its durations are boot
// performance measurements. It edits a private raw copy, without mounts or NBD.
func TestLogindSessions(t *testing.T) {
if os.Getenv("SPIN_LOGIND_TEST") != "1" {
t.Skip("set SPIN_LOGIND_TEST=1 to check first SSH login in a built image")
}
out, err := filepath.Abs("../_output")
if err != nil {
t.Fatal(err)
}
rel, err := machine.Open(out)
if err != nil {
t.Fatal(err)
}
base, err := rel.Rootfs()
if err != nil {
t.Fatal(err)
}
dir := t.TempDir()
raw := filepath.Join(dir, "rootfs.raw")
mustRun(t, filepath.Join(out, "bin/qemu-img"), "convert", "-f", "qcow2", "-O", "raw", base, raw)
debugfs := func(command string) string {
t.Helper()
output, err := exec.Command("debugfs", "-w", "-R", command, raw).CombinedOutput()
if err != nil {
t.Fatalf("debugfs %s: %v\n%s", command, err, output)
}
return string(output)
}
write := func(path, content string) {
t.Helper()
src := filepath.Join(dir, "input")
if err := os.WriteFile(src, []byte(content), 0644); err != nil {
t.Fatal(err)
}
// debugfs returns success even if the write failed. Read the guest file
// back to ensure the experiment actually installed its input.
debugfs("write " + src + " " + path)
got, err := exec.Command("debugfs", "-R", "cat "+path, raw).Output()
if err != nil || string(got) != content {
t.Fatalf("guest file %s differs from its input: %v", path, err)
}
}
// The shipped image does not start logind at boot: the first login activates it over
// the Varlink socket, which is worth 18 ms (see the 10-seats.conf drop-in). So the
// state this asserts before any login is `inactive`, and a machine that answers
// `active` has put logind back into the boot transaction.
//
// SPIN_LOGIND_NO_SEATS=1 removes the drop-in and nothing else. It is the experiment
// that says what the drop-in does, and it is expected to fail: without
// /run/systemd/seats, pam_systemd never asks logind for a session and never activates
// it, so every login — SSH and console alike — comes up with XDG_RUNTIME_DIR unset and
// no error anywhere (2026-09-12).
expectedState := "inactive"
if os.Getenv("SPIN_LOGIND_NO_SEATS") == "1" {
path := "/etc/systemd/system/systemd-logind-varlink.socket.d/10-seats.conf"
debugfs("rm " + path)
if strings.Contains(debugfs("stat "+path), "Inode:") {
t.Fatal("the drop-in is still in the image; the experiment would prove nothing")
}
}
for _, name := range []string{"logind-check.sh", "logind-session.sh"} {
content, err := os.ReadFile(filepath.Join("testdata", name))
if err != nil {
t.Fatal(err)
}
write("/"+name, string(content))
}
write("/etc/systemd/system/logind-check.service", `[Unit]
Description=Check on-demand sessions in a disposable guest
After=multi-user.target
[Service]
Type=oneshot
Environment=LOGIND_EXPECT=`+expectedState+`
ExecStart=/bin/sh /logind-check.sh
StandardOutput=journal+console
StandardError=journal+console
`)
write("/etc/systemd/system/logind-check.timer", `[Timer]
OnBootSec=3s
AccuracySec=100ms
`)
debugfs("symlink /etc/systemd/system/timers.target.wants/logind-check.timer /etc/systemd/system/logind-check.timer")
spec := rel.Spec()
spec.BootCPUs = 2
spec.Memory.SizeMB = 1024
spec.Disks = []machine.Disk{{Path: raw, Format: "raw"}}
spec.Serial = "stdio"
c := machine.DefaultCmdline()
c.Root = "/dev/vda"
c.Init = "/sbin/init"
spec.Cmdline = c.String()
args, err := spec.Args()
if err != nil {
t.Fatal(err)
}
if _, err := os.Stat("/dev/kvm"); err != nil {
spec.QEMU = filepath.Join(out, "bin/qemu-system-x86_64-tcg")
for i := range args {
args[i] = strings.ReplaceAll(args[i], "accel=kvm", "accel=tcg")
if args[i] == "host,migratable=on" {
args[i] = "max,migratable=on"
}
}
t.Log("TCG: checking functionality only")
}
ctx, cancel := context.WithTimeout(context.Background(), 2*time.Minute)
defer cancel()
cmd := exec.CommandContext(ctx, spec.QEMU, args...)
var stderr bytes.Buffer
cmd.Stderr = &stderr
stdout, err := cmd.StdoutPipe()
if err != nil {
t.Fatal(err)
}
if err := cmd.Start(); err != nil {
t.Fatal(err)
}
waited := false
stop := func() {
cancel()
if !waited {
_ = cmd.Wait()
waited = true
}
}
defer stop()
var console bytes.Buffer
buf := make([]byte, 4096)
for {
n, err := stdout.Read(buf)
console.Write(buf[:n])
if strings.Contains(console.String(), "LOGIND_CHECK_OK") {
t.Log(console.String())
return
}
if err != nil || strings.Contains(console.String(), "LOGIND_CHECK_FAILED") {
stop()
t.Fatalf("guest session check failed: %v\n%s\n%s", err, &console, &stderr)
}
}
}
46 changes: 46 additions & 0 deletions boot/testdata/logind-check.sh
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
#!/bin/sh
# SPDX-License-Identifier: Apache-2.0
set -eu
trap 'cat /run/logind-session-result 2>/dev/null || true; journalctl -b -u ssh.service -u systemd-logind.service --no-pager; echo LOGIND_CHECK_FAILED' EXIT

# Query PID1, not loginctl: asking login1 would itself activate logind.
test "$(systemctl show systemd-logind.service -p ActiveState --value)" = "$LOGIND_EXPECT"
systemctl is-active --quiet systemd-logind-varlink.socket
echo "LOGIND_INITIAL_STATE_OK $LOGIND_EXPECT"

# Every login is PAM, not only sshd's: the console getty and su go through the same stack.
# Asserted separately from the SSH logins below because a configuration that starts logind
# on sshd's behalf passes those and fails this one (2026-09-12).
test "$(su -l spin -c 'echo ${XDG_RUNTIME_DIR:-unset}' </dev/null | tr -d '\r')" = /run/user/1000

ip link set lo up
ssh-keygen -q -t ed25519 -N '' -f /run/logind-test-key
install -d -m 700 -o spin -g spin /home/spin/.ssh
install -m 600 -o spin -g spin /run/logind-test-key.pub /home/spin/.ssh/authorized_keys
systemctl start ssh.socket

# Test the first login and a reconnect, including a PTY session. Credentials and
# known_hosts exist only in this throwaway guest; no host networking is involved.
previous_session=
for tty in -T -tt; do
ssh -F /dev/null "$tty" -i /run/logind-test-key \
-o BatchMode=yes -o StrictHostKeyChecking=no \
-o UserKnownHostsFile=/run/logind-known-hosts \
spin@127.0.0.1 /bin/sh /logind-session.sh > /run/logind-session-result
cat /run/logind-session-result
grep -q '^SESSION_OK ' /run/logind-session-result
systemctl is-active --quiet systemd-logind.service
session=$(sed -n 's/^SESSION_OK //p' /run/logind-session-result | tr -d '\r')
test "$session" != "$previous_session"
previous_session=$session
# The session scope must finish after logout, even if the user's service
# manager stays alive for its configured stop delay.
for attempt in $(seq 50); do
state=$(systemctl show "session-$session.scope" -p ActiveState --value)
test "$state" != active && break
sleep 0.1
done
test "$state" != active
done
trap - EXIT
echo LOGIND_CHECK_OK
12 changes: 12 additions & 0 deletions boot/testdata/logind-session.sh
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
#!/bin/sh
# SPDX-License-Identifier: Apache-2.0
# Runs as spin, through sshd's real PAM stack, in a disposable test guest.
set -eux
test "$(id -u)" = 1000
test "${XDG_RUNTIME_DIR:-}" = /run/user/1000
test "$(stat -c '%u:%a' "$XDG_RUNTIME_DIR")" = 1000:700
test -n "${XDG_SESSION_ID:-}"
test "$(loginctl show-session "$XDG_SESSION_ID" -p Name --value)" = spin
systemctl --user list-units --no-pager >/dev/null
sudo -n true
printf 'SESSION_OK %s\n' "$XDG_SESSION_ID"
26 changes: 26 additions & 0 deletions image/build.sh
Original file line number Diff line number Diff line change
Expand Up @@ -216,6 +216,32 @@ for u in systemd-random-seed.service tmp.mount; do
exit 1; }
done

# logind is deferred rather than masked, and the two halves of that only work together.
# The drop-in makes pam_systemd's guard — access("/run/systemd/seats/") — true before
# logind has run, so the first login activates it over Varlink instead of being handed a
# session with no XDG_RUNTIME_DIR and no user manager. The overridden want is what keeps
# the 24 ms. Either half alone is a silent failure: without the drop-in every login comes
# up session-less and nothing logs an error, and a re-enabled want costs the boot time back
# while everything still works, so neither shows up anywhere but here.
in_image /etc/systemd/system/systemd-logind-varlink.socket.d/10-seats.conf || {
echo "ERROR: the image has no logind seats drop-in; every login would lose its session" >&2
exit 1; }
# The want is overridden, not deleted: the package ships it in /usr, so the /etc path must
# hold a symlink to /dev/null. Asserting its *absence* is the version of this check that
# passed while the image still started logind at boot, because the /etc path was never
# there to remove (2026-09-12).
if ! stat_in_image /etc/systemd/system/multi-user.target.wants/systemd-logind.service |
grep -q '/dev/null'; then
echo "ERROR: the want for systemd-logind is not overridden; the package ships one in" \
"/usr and logind is back in the boot transaction" >&2
exit 1
fi
if stat_in_image /etc/systemd/system/systemd-logind.service | grep -q '/dev/null'; then
echo "ERROR: systemd-logind.service is masked - deferring it means it still starts" \
"on demand, and masked means it never starts at all" >&2
exit 1
fi

# The distribution's background maintenance, masked by configure-system.sh for reasons
# that are written there. Asserted separately from the three above because the cause is a
# different script: these come back if a package upgrade re-runs a unit's [Install], and
Expand Down
14 changes: 14 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 @@ -281,6 +281,20 @@ rm -f /etc/systemd/system/multi-user.target.wants/ssh.service 2>/dev/null || tru
mkdir -p /etc/systemd/system/sockets.target.wants
ln -sf /lib/systemd/system/ssh.socket /etc/systemd/system/sockets.target.wants/ssh.socket

# logind out of the boot transaction, worth 24 ms. Not masked: masked means never started,
# and a login needs it. It stays enabled in every other sense and is started by the first
# thing that asks for a session over its Varlink socket — see the 10-seats.conf drop-in
# shipped beside it, which is what makes pam_systemd get as far as asking.
#
# A symlink to /dev/null and not `rm`, because the want is not in /etc to begin with: the
# package ships it at /usr/lib/systemd/system/multi-user.target.wants/systemd-logind.service.
# An `rm` of the /etc path is what this said first, and it removed nothing at all — the
# build passed, the image shipped, and logind started at boot exactly as before (2026-09-12).
# The /dev/null symlink in /etc overrides the want in /usr and nothing else: the unit itself
# is untouched, which is why it can still be activated on demand.
mkdir -p /etc/systemd/system/multi-user.target.wants
ln -sf /dev/null /etc/systemd/system/multi-user.target.wants/systemd-logind.service

log "Setting default target to multi-user..."
ln -sf /lib/systemd/system/multi-user.target /etc/systemd/system/default.target

Expand Down
Loading