diff --git a/.github/workflows/lab.yml b/.github/workflows/lab.yml index e7a5aae..c611e49 100644 --- a/.github/workflows/lab.yml +++ b/.github/workflows/lab.yml @@ -35,9 +35,7 @@ on: - boot:initcalls - boot:userspace - boot:systemd - - boot:unitload - boot:ssh-load - - boot:memory-policy - boot:page-cache - boot:firmware - boot:firmware-stages diff --git a/boot/Taskfile.yml b/boot/Taskfile.yml index df58bed..68fc499 100644 --- a/boot/Taskfile.yml +++ b/boot/Taskfile.yml @@ -48,16 +48,6 @@ tasks: cmds: - SPIN_PAGE_CACHE=1 go test ./boot/ -run '^TestPageCache$' -count=1 -v -timeout 60m - memory-policy: - desc: >- - A process that takes memory until something stops it, in a login session of a 1 GiB - guest: logins while it grows, how long until it is gone and what killed it, with the image - as built and without MGLRU's min_ttl_ms. Needs /dev/kvm and a built release; no sudo. - REPS= boots per variant. - deps: [':tools'] - cmds: - - SPIN_MEMORY_POLICY=1 go test ./boot/ -run '^TestMemoryPolicy$' -count=1 -v -timeout 90m - logind: desc: >- Check first SSH login, reconnect, user services and logout in a disposable guest. @@ -88,17 +78,6 @@ tasks: cmds: - SPIN_INITCALL_PROBE=1 go test ./boot/ -run TestKernelInitcalls -count=1 -v -timeout 30m - unitload: - desc: >- - What systemd spends loading units and building the initial transaction, from its own - instrumentation: `systemd --test` reports it at LOG_INFO where a real boot logs it at - LOG_DEBUG. Many runs inside one boot, so there is no boot-to-boot noise, and it - measures the generators by masking two that cannot do anything on this machine. Needs - KVM, a built release and sudo. - deps: [':tools'] - cmds: - - SPIN_UNITLOAD_PROBE=1 go test ./boot/ -run TestUnitLoadCost -count=1 -v -timeout 15m - userspace: desc: >- systemd's own account of the boot: its kernel/userspace split, `blame` and the diff --git a/boot/memory_policy_test.go b/boot/memory_policy_test.go deleted file mode 100644 index 62275e8..0000000 --- a/boot/memory_policy_test.go +++ /dev/null @@ -1,77 +0,0 @@ -// SPDX-License-Identifier: Apache-2.0 - -package boot_test - -import ( - "fmt" - "os" - "strings" - "testing" - "time" -) - -// TestMemoryPolicy runs a process that takes memory until something stops it, in a login -// session of a 1 GiB guest, and reports whether SSH still got in while it grew, how long until -// it was gone and what killed it - with the image as built, and without the one setting that -// decides it, MGLRU's min_ttl_ms (image/.../etc/tmpfiles.d/lru-gen.conf). -// -// Two cases, from testdata/ssh-load.sh: memory taken at full speed, which the kernel stops -// within a second or two either way; and memory taken at ~80 MB/s while the session re-reads -// its libraries, which is the one that hangs a machine on the old LRU. -// -// Chosen 2026-09-28 from this, 3 boots of each, kernel 7.2.8 with CONFIG_LRU_GEN and -// CONFIG_ZRAM (removed since); killed after, median, and the worst SSH login in the slow case: -// -// fast slow worst login, slow -// nothing 753 ms 13.8 s 611 / 693 / 1785 ms -// min_ttl_ms=1000 615 ms 11.2 s 106 / 105 / 106 ms -// zram, 512M lz4 1664 ms 20.2 s 1341 / 530 / 3817 ms -// zram + min_ttl 662 ms 18.2 s 204 / 107 / 106 ms -// -// zram gave the runaway process room and it was killed later, with worse logins: compressed -// swap is for cold memory, not for this. systemd-oomd (one boot each, an image with the package, -// a 50%/5 s policy on user.slice) killed nothing: the kernel always got there first. Ubuntu's -// package also ships its policy for user@.service and -.slice only, and a login's processes are -// in session-N.scope beside user@.service, so out of its sight. Neither is in the machine. -// -// SPIN_MEMORY_POLICY=1 run at all -// REPS= boots per variant (default 3) -// -// Needs /dev/kvm and a built release; no sudo. -func TestMemoryPolicy(t *testing.T) { - if os.Getenv("SPIN_MEMORY_POLICY") == "" { - t.Skip("set SPIN_MEMORY_POLICY=1: this exhausts the memory of guests on purpose") - } - out := releaseDir(t) - reps := envInt(t, "REPS", 3) - - variants := []struct { - label string - guest sshLoadGuest - }{ - {"as built", sshLoadGuest{}}, - {"no min_ttl", sshLoadGuest{remove: []string{"/etc/tmpfiles.d/lru-gen.conf"}}}, - } - - var r strings.Builder - r.WriteString("\nlogins while it grows (ms, FAIL after 20 s, 90 s at most), then what the guest did about it\n") - for range reps { - for _, v := range variants { - g := v.guest - g.cases = "idle exhaust exhaust_slow" - res := sshLoadRun(t, out, g, 8*time.Minute) - for _, c := range []string{"exhaust", "exhaust-slow"} { - fmt.Fprintf(&r, "\n%-11s %-13s logins: %s\n", v.label, c, strings.Join(res.logins[c], " ")) - for _, n := range res.notes { - if strings.HasPrefix(n, c+" gone_after_ms") { - fmt.Fprintf(&r, "%-25s %s\n", "", strings.TrimPrefix(n, c+" ")) - } - } - } - if !res.finished { - fmt.Fprintf(&r, "%-11s the guest did not finish in 8 minutes\n", "") - } - } - } - t.Log(r.String()) -} diff --git a/boot/testdata/ssh-load.sh b/boot/testdata/ssh-load.sh index 28bbdb5..7378031 100644 --- a/boot/testdata/ssh-load.sh +++ b/boot/testdata/ssh-load.sh @@ -82,47 +82,6 @@ tmp_full() { rm -f /tmp/sshload-fill } -# The logins while a process in spin's session takes memory until something stops it, then how -# long that took, who stopped it and whether the machine answers afterwards. Last in a run, -# because the guest may not come out of it. -grow() { - label=$1 hog=$2 - $SSH "nohup sh -c '$hog' >/dev/null 2>&1 &" /dev/null; then - gone=$(( ($(date +%s%N) - start) / 1000000 )) - break - fi - done - echo "SSHLOAD $label$out" - after=$(login) - echo "SSHLOADEXHAUST $label gone_after_ms=${gone:-never} login_after=$after" \ - "kernel_oom_kills=$(journalctl -k -b --no-pager | grep -c 'Out of memory: Killed')" \ - "min_ttl_ms=$(cat /sys/kernel/mm/lru_gen/min_ttl_ms 2>/dev/null || echo none)" \ - "swap_total=$(awk '/^SwapTotal:/ { print int($2 / 1024) }' /proc/meminfo)MiB" \ - "victims=$(journalctl -k -b --no-pager | sed -n 's/.*Killed process [0-9]* (\([^)]*\)).*/\1/p' | sort | uniq -c | tr -s ' ' | tr '\n' ',')" - pkill -KILL -u spin || true - sleep 2 -} - -# tail keeping a line that never ends, from a pipe: `tail /dev/zero` seeks to the end of the -# device, keeps nothing and measured nothing (2026-09-28). At full speed the kernel runs out of -# anything to reclaim within a second or two and kills it. -exhaust() { - grow exhaust "cat /dev/zero | tail" -} - -# The case that hangs a machine: memory taken slowly, ~80 MB/s, while the session reads its -# libraries over and over, as a build reads headers. Reclaim keeps finding page cache to evict -# and the reader keeps faulting it back, so the kernel is never out of options and the OOM -# killer is never called: the old LRU's thrash. -exhaust_slow() { - grow exhaust-slow "(while :; do cat /usr/lib/x86_64-linux-gnu/*.so* >/dev/null 2>&1; done) & while :; do head -c 8M /dev/zero; sleep 0.1; done | tail" -} - for c in ${SSHLOAD_CASES:-idle cpu_service cpu_session tmp_full}; do case $c in idle) measure idle ;; diff --git a/boot/unitload_test.go b/boot/unitload_test.go deleted file mode 100644 index deb5672..0000000 --- a/boot/unitload_test.go +++ /dev/null @@ -1,163 +0,0 @@ -// SPDX-License-Identifier: Apache-2.0 - -package boot_test - -import ( - "fmt" - "os" - "regexp" - "strings" - "testing" - "time" -) - -// What systemd spends loading units and building the initial transaction, and what the -// generators cost inside it. -// -// The number comes from systemd itself. src/core/main.c brackets manager_startup() and -// do_queue_default_job() and logs "Loaded units and determined initial transaction in %s" — -// at LOG_DEBUG normally, and at LOG_INFO under `--test`. So `systemd --test --system` reports -// it without the debug logging that inflates every other way of seeing it, and it does only -// that work: MANAGER_IS_TEST_RUN skips the preset pass and nothing is started. -// -// Which makes this a paired measurement inside one boot rather than a boot per sample. That -// matters more than it sounds: two boots on this host have read 59.5 and 167.7 ms for the -// same kernel, and nothing about generators is a 100 ms effect. -// -// What manager_startup() does, from the source rather than from a guess: -// lookup_paths_init, the environment generators, the generators, manager_preset_all, -// manager_enumerate (device units out of udev, mount units out of mountinfo), deserialize, -// fd distribution. preset_all does not run here — it needs first_boot, and systemd decides -// that from /etc/machine-id, which this image ships present and empty rather than absent or -// "uninitialized", so systemd reads it as an initialised system. -// -// SPIN_UNITLOAD_PROBE=1 run at all -// REPS= `systemd --test` runs per configuration (default 7) -func TestUnitLoadCost(t *testing.T) { - if os.Getenv("SPIN_UNITLOAD_PROBE") == "" { - t.Skip("set SPIN_UNITLOAD_PROBE=1: boots a VM and needs sudo to write into its overlay") - } - out := releaseDir(t) - if !canSudo() { - t.Skip("this writes a unit into the boot's own overlay through qemu-nbd, which needs sudo") - } - reps := envInt(t, "REPS", 7) - - // Masked, not removed, and both are generators that cannot do anything on this machine: - // the tpm2 one because there is no TPM — the boot log says libtss2-esys.so.0 cannot be - // opened — and the factory-reset one because this machine is not booted in EFI mode, which - // the log also says. Seven of the thirteen the image carries are masked already. - const masked = "systemd-tpm2-generator systemd-factory-reset-generator" - - // Not as root: systemd refuses test mode for the root user outright ("Don't run test mode - // as root."), so this drops to nobody with setpriv. The generators and the unit files are - // world readable, and both configurations run as the same user, so the comparison holds - // even where a generator behaves differently without privileges. - // - // It also means the absolute number is a floor for what PID 1 pays: this run sets up no - // cgroups, inherits no file descriptors and deserialises nothing. What it is for is the - // order of magnitude and the difference between two configurations, and it fails rather - // than measuring the wrong user if setpriv cannot drop privileges. - script := fmt.Sprintf(`set -u -AS="setpriv --reuid=65534 --regid=65534 --clear-groups" -$AS true || { echo "setpriv cannot drop to nobody, nothing to measure" >&2; exit 1; } -run() { - i=0 - while [ $i -lt %d ]; do - $AS /usr/lib/systemd/systemd --test --system 2>&1 | grep -F 'initial transaction' - i=$((i+1)) - done -} -{ - echo SPIN-UNITLOAD-BEGIN - echo TAG:generators-on - run - mkdir -p /etc/systemd/system-generators - for g in %s; do ln -sf /dev/null "/etc/systemd/system-generators/$g"; done - echo TAG:generators-masked - run - echo SPIN-UNITLOAD-END -} > /dev/ttyS0 2>&1 -`, reps, masked) - - v := variant{ - label: "unit load", cpus: "2", memory: "2048", - files: map[string]string{ - "/usr/local/bin/spin-unitload": script, - "/etc/systemd/system/spin-unitload.service": `[Unit] -Description=Measure systemd's unit load with and without two generators -After=multi-user.target -[Service] -Type=simple -StandardOutput=null -ExecStart=/bin/sh /usr/local/bin/spin-unitload -[Install] -WantedBy=multi-user.target -`, - }, - links: map[string]string{ - "/etc/systemd/system/multi-user.target.wants/spin-unitload.service": "/etc/systemd/system/spin-unitload.service", - }, - } - - console := bootUntil(t, out, v, "", "SPIN-UNITLOAD-END", 180*time.Second) - reportUnitLoad(t, console, reps) -} - -// "Loaded units and determined initial transaction in 212ms." — and systemd's spelling of a -// duration varies with its size, so this takes the same route mustDur does. -var reLoaded = regexp.MustCompile(`initial transaction in ([^.]+)\.`) - -func reportUnitLoad(t *testing.T, console string, reps int) { - t.Helper() - samples := map[string][]float64{} - var order []string - var tag string - for _, line := range strings.Split(console, "\n") { - line = strings.TrimSpace(strings.TrimRight(line, "\r")) - if i := strings.Index(line, "TAG:"); i >= 0 { - tag = line[i+4:] - order = append(order, tag) - continue - } - m := reLoaded.FindStringSubmatch(line) - if m == nil || tag == "" { - continue - } - samples[tag] = append(samples[tag], mustDur(t, m[1])) - } - if len(samples) < 2 { - t.Fatalf("expected two tagged sets of `systemd --test` output, got %d; console tail:\n%s", - len(samples), tail([]byte(console), 1500)) - } - - var b strings.Builder - fmt.Fprintf(&b, "\nsystemd's own \"loaded units and determined initial transaction\", "+ - "p50/p95 over %d runs in one boot\n\n", reps) - fmt.Fprintf(&b, "%-20s %8s %8s %6s\n", "CONFIGURATION", "P50", "P95", "N") - var first, second float64 - for i, tag := range dedup(order) { - s := samples[tag] - fmt.Fprintf(&b, "%-20s %8.1f %8.1f %6d ms\n", tag, pct(s, 50), pct(s, 95), len(s)) - switch i { - case 0: - first = pct(s, 50) - case 1: - second = pct(s, 50) - } - } - fmt.Fprintf(&b, "\ntwo generators masked: %.1f ms\n", first-second) - t.Log(b.String()) -} - -func dedup(in []string) []string { - seen := map[string]bool{} - var out []string - for _, s := range in { - if !seen[s] { - seen[s] = true - out = append(out, s) - } - } - return out -} diff --git a/image/mkosi.extra/usr/local/lib/spin-base/optimize-systemd.sh b/image/mkosi.extra/usr/local/lib/spin-base/optimize-systemd.sh index 6c2fcaa..3241205 100755 --- a/image/mkosi.extra/usr/local/lib/spin-base/optimize-systemd.sh +++ b/image/mkosi.extra/usr/local/lib/spin-base/optimize-systemd.sh @@ -167,7 +167,7 @@ DISABLE_GENERATORS=( # runs on a machine systemd itself logs as not booted in EFI mode. # # Worth 1.0 ms of the 26 ms systemd spends loading units and building the initial - # transaction — measured 2026-09-26 with `task boot:unitload`, which asks systemd for that + # transaction — measured 2026-09-26 with the unitload probe (ad05544), which asks systemd for that # number through `systemd --test` rather than reading it out of a debug-logged boot. The # same number read from a debug boot is 212 ms, and that difference is the logging. systemd-tpm2-generator diff --git a/image/mkosi.extra/usr/local/lib/spin-base/rootfs/etc/tmpfiles.d/lru-gen.conf b/image/mkosi.extra/usr/local/lib/spin-base/rootfs/etc/tmpfiles.d/lru-gen.conf index c30c502..016fc15 100644 --- a/image/mkosi.extra/usr/local/lib/spin-base/rootfs/etc/tmpfiles.d/lru-gen.conf +++ b/image/mkosi.extra/usr/local/lib/spin-base/rootfs/etc/tmpfiles.d/lru-gen.conf @@ -4,7 +4,7 @@ # page cache still counts as reclaimable, and the OOM killer never comes: the VM is up and # answers nothing. # -# Measured 2026-09-28 with boot/memory_policy_test.go, 1 GiB, 2 vCPUs, memory taken at ~80 MB/s +# Measured 2026-09-28 with the memory-policy probe (337c08d), 1 GiB, 2 vCPUs, memory taken at ~80 MB/s # while a session re-read its libraries, 3 boots: the worst SSH login was 611-1785 ms without # this and 105-106 ms with it, and the process was killed after 11.2 s instead of 13.8. 1000 ms # is the value the kernel's documentation suggests; the kernel needs CONFIG_LRU_GEN, which diff --git a/kernel/Dockerfile b/kernel/Dockerfile index 18cfa05..ed06a69 100644 --- a/kernel/Dockerfile +++ b/kernel/Dockerfile @@ -204,7 +204,7 @@ RUN <