package runner import ( "context" "os" "os/exec" "path/filepath" "strconv" "strings" "testing" "time" ) // The sweep re-issues the stop of any live run it finds with an intent on file, and the comment above // that line calls it «free and idempotent». That is a property of systemd rather than of Go, it is // not in any manual page, and until it was measured nothing in this repository had asked it. This // file asks it. // signalLog is a stand-in for the engine: it catches SIGTERM, does NOT exit, and writes a line for // every signal it receives plus a heartbeat — so a test can tell «still running» from «killed» by // something the PROCESS said rather than by what systemd reports about it. func signalLog(t *testing.T, dir string) string { t.Helper() if _, err := exec.LookPath("python3"); err != nil { t.Skip("no python3: the signal fixture cannot run on this host") } path := filepath.Join(dir, "hold.py") body := `import signal, sys, time log = open(sys.argv[1], "a", buffering=1) def note(sig, frm): log.write("%.3f SIGNAL\n" % time.time()) signal.signal(signal.SIGTERM, note) signal.signal(signal.SIGINT, note) log.write("%.3f START\n" % time.time()) while True: log.write("%.3f ALIVE\n" % time.time()) time.sleep(0.25) ` if err := os.WriteFile(path, []byte(body), 0o600); err != nil { t.Fatal(err) } return path } // readLog counts what the fixture actually received and when it last spoke. func readLog(t *testing.T, path string) (signals int, lastAlive time.Time) { t.Helper() raw, err := os.ReadFile(path) if err != nil { return 0, time.Time{} } for line := range strings.SplitSeq(string(raw), "\n") { f := strings.Fields(line) if len(f) != 2 { continue } secs, err := strconv.ParseFloat(f[0], 64) if err != nil { continue } switch f[1] { case "SIGNAL": signals++ case "ALIVE": lastAlive = time.UnixMilli(int64(secs * 1000)) } } return signals, lastAlive } func unitState(t *testing.T, unit string) string { t.Helper() out, err := exec.CommandContext(t.Context(), "systemctl", "--user", "show", unit+".service", "--property=ActiveState", "--value").CombinedOutput() if err != nil { return "" } return strings.TrimSpace(string(out)) } // killUnit is the cleanup this fixture needs and the only shape it can take. SIGKILL rather than a // stop, because the fixture ignores SIGTERM by design and a polite cleanup would wait out the very // grace under test; and on a context of its OWN, because a cleanup runs after the test's context has // been cancelled — on that one every command would refuse to start and the unit would be left behind // in the user's manager, where it outlives the process that made it. func killUnit(unit string) { ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() _ = exec.CommandContext(ctx, "systemctl", "--user", "kill", "--signal=SIGKILL", unit+".service").Run() _ = exec.CommandContext(ctx, "systemctl", "--user", "stop", "--no-block", unit+".service").Run() } // holdingUnit starts a transient unit whose process catches SIGTERM and never exits, under the grace // the test names. It carries the properties this package sets on a run — KillSignal, KillMode, // TimeoutStopSec — and the grace is a parameter because the test is ABOUT the grace's clock. func holdingUnit(t *testing.T, grace time.Duration) (unit, log string) { t.Helper() systemdOrSkip(t) dir := t.TempDir() log = filepath.Join(dir, "signals.log") script := signalLog(t, dir) unit = testUnit(t) t.Cleanup(func() { killUnit(unit) }) out, err := exec.CommandContext(t.Context(), "systemd-run", "--user", "--unit="+unit, "--collect", "--quiet", "--property=Slice="+Slice, "--property=KillSignal=SIGTERM", "--property=KillMode=mixed", "--property=TimeoutStopSec="+strconv.Itoa(int(grace.Seconds())), "--", "/usr/bin/env", "python3", script, log).CombinedOutput() if err != nil { t.Fatalf("could not start the holding unit: %v: %s", err, out) } // The fixture has to be running before anything is asked of it, or the test measures a race with // its own start instead of the property it is about. for deadline := time.Now().Add(15 * time.Second); time.Now().Before(deadline); { if _, alive := readLog(t, log); !alive.IsZero() { return unit, log } time.Sleep(20 * time.Millisecond) } t.Fatalf("the holding unit never started writing") return "", "" } // ⛔ WHAT THIS PINS IS AN ASSERTION THE RECONCILER ALREADY MAKES AND NOTHING CHECKED. // // `runs.reconcile` re-issues the stop of a live run whose intent is on file — deliberately, because // that is the only thing that closes «the platform died between committing the intent and asking // systemd». The comment there calls the re-issue «free and idempotent», and both words are claims // about systemd's behaviour on a unit that is ALREADY stopping. Neither is documented. // // - «free» — a second `stop` must not deliver a second signal. If it did, the sweep would signal a // stopping run again on every pass. // - «idempotent» — it must not restart TimeoutStopSec. If it did, the SIGKILL backstop would recede // by one pass every pass, and an engine that has wedged would hold its book's project lock for // good while the sweep politely asked it to stop, forever. // // ⚠ THE TWO ASSERTIONS ARE EACH OTHER'S CONTROL, so there is no separate one to run and no way for // this test to pass by failing to look. «One signal» is not read as an absence: the same log proves // the fixture DOES receive signals, because the first stop delivered one. And the unit is not merely // «not killed early» — it IS killed, and the assertion is on WHICH clock: the first stop's, at t+6 s, // where a restarted timer would give t+10 s. func TestARepeatedStopNeitherSignalsNorExtendsTheGrace(t *testing.T) { const grace = 6 * time.Second unit, log := holdingUnit(t, grace) r := New(nil) start := time.Now() if err := r.Stop(t.Context(), unit); err != nil { t.Fatal(err) } for _, at := range []time.Duration{2 * time.Second, 4 * time.Second} { time.Sleep(time.Until(start.Add(at))) if err := r.Stop(t.Context(), unit); err != nil { t.Fatal(err) } } var died time.Duration for deadline := start.Add(grace * 3); time.Now().Before(deadline); { switch unitState(t, unit) { case "inactive", "failed", "": died = time.Since(start) } if died != 0 { break } time.Sleep(50 * time.Millisecond) } signals, _ := readLog(t, log) if died == 0 { t.Fatalf("the unit was still not gone %s after the first stop, having received %d signal(s)", grace*3, signals) } t.Logf("three stops at t+0s, t+2s, t+4s against a %s grace: the process received %d signal(s) and the unit was gone at t+%.2fs", grace, signals, died.Seconds()) if signals != 1 { t.Errorf("the process received %d signals from three stops, want exactly 1 — zero would mean the fixture "+ "never hears anything and this test measures nothing, and more than one means the sweep re-signals a "+ "run on every pass", signals) } if died > grace+2*time.Second { t.Errorf("the unit died at t+%.2fs against a %s grace: a repeated stop restarted the stop timeout, so the "+ "SIGKILL backstop moves further away on every sweep pass and a wedged engine keeps its project lock", died.Seconds(), grace) } }