Stop asking systemd to wait for a unit to be gone, and pin the property that made asking twice safe: a second stop neither signals again nor moves the kill deadline.

This commit is contained in:
heaven 2026-09-11 00:25:16 +03:00
parent 7af35daf96
commit 560ca2070a
5 changed files with 366 additions and 2 deletions

View file

@ -49,6 +49,102 @@ committed_usd, which is what would let this side say "at most Y"». Движок
чтение оценочных строк из потока. Промт ещё не написан — если у вас есть довод против любой из четырёх
позиций, скажите ДО того, как я его напишу.
## ДОФИКС ПО ОТМЕНЁННОМУ ПАКУ: `--no-block` С ПИНОМ (11.09, `textmachine-5c`)
> Взят владельцем ОТДЕЛЬНО от отменённого пака и взят ровно в той форме, которую зона просила: правка
> вместе с пином, а не правка с довеском. Довод, который дошёл дословно: без пина в коде остаётся
> утверждение «asking again is free and idempotent», которое держится на недокументированном
> поведении systemd и которое никто не проверяет.
> ⛔ **Границы захода:** только это. Ни режима остановки, ни второго сигнала, ни кадра событий — пак
> отменён и остаётся отменённым.
### Что сделано, тремя правками
**1. `Runner.Stop` больше не ждёт конца прогона** (`platform/internal/runner/runner.go`). Замер, ради
которого правка и берётся, уже в журнале решений: блокирующая форма вернулась через **15,058 с**
(по SIGKILL, юнит с `TimeoutStopSec=15`), `stop --no-block` — через **0,014 с**. Комментарий над
функцией несёт оба следствия и НЕ несёт третьего, которого нет (см. правку 3).
**2. Пин на то, что раньше держалось на удаче** —
`runner.TestARepeatedStopNeitherSignalsNorExtendsTheGrace`, живой, на настоящем systemd. Он
спрашивает у systemd ровно те два свойства, которые УТВЕРЖДАЕТ комментарий свипа: повторный `stop` на
юните в `deactivating` (а) не доставляет второго сигнала и (б) не перезапускает `TimeoutStopSec`.
Числа прогона: три стопа в t+0 / t+2 / t+4 против грейса 6 с → процесс получил **1** сигнал, юнит
умер на **t+6,06 с**.
⚠ **Контроль встроен в сами числа, отдельного прогона не требуется, и это сказано в теле теста:**
«один сигнал» не читается как отсутствие, потому что тот же лог доказывает, что фикстура сигналы
СЛЫШИТ (первый стоп доставил); а юнит не «просто не убит» — он УБИТ, и утверждение о том, по чьим
часам: по первому стопу (t+6), тогда как перезапущенный таймер дал бы t+10.
**3. Комментарий свипа перестал утверждать без основания** (`platform/internal/runs/reconcile.go`,
ветка пере-выдачи стопа): «free and idempotent» теперь названо ЗАМЕРЕННЫМ свойством systemd, с обеими
половинами и с ценой потери каждой, и со ссылкой на пин.
### Мутационная проверка — выполнена, на КОПИИ, три посадки
⚠ Это то, чего смена не сделала в отменённом паке и записала в «что не удалось». Здесь сделано.
Копия дерева зоны жила в `~/.cache/tm-5c/mut/platform` (не в общем скретчпаде — его чистит не только
свой процесс), перед каждой правкой утверждались `test -f go.mod` и точный `pwd`; после прогона копия
сверена с деревом (`diff -rq` по `internal/runner` — идентично) и удалена.
| посадка | что сломано | вердикт и **текст** падения |
|---|---|---|
| M1 | снят `--no-block` у `Stop` | КРАСНО, `TestTheSoftStopDoesNotWaitForTheRunToEnd`: «the stop waits for the unit to be gone: [systemctl --user stop tm-run-X-1.service]» |
| M3 | пере-выдача ДОСТАВЛЯЕТ (`systemctl kill --signal=SIGTERM` вместо `Stop`) | КРАСНО: «the process received **3** signals from three stops, want exactly 1» |
| M4 | часы грейса идут от ПОЗДНЕГО стопа (первый стоп сдвинут на t+4) | КРАСНО: «the unit died at **t+10,09s** against a 6s grace: a repeated stop restarted the stop timeout» |
**Каждая посадка засчитана по ТЕКСТУ, а не по цвету:** в каждом случае сообщение называет ровно то,
что сломано. И две половины утверждения оказались независимо различающими — M3 краснит только счёт
сигналов, M4 только часы.
**M1 живой пин НЕ ловит, и это названо, а не обойдено:** без `--no-block` первый стоп блокируется на
весь грейс, остальные два приходят уже на мёртвый юнит, и числа сходятся прежние. Флаг ловит
argv-пин, который для того и написан отдельно — живой тест скипается на хосте без пользовательского
менеджера systemd, и флаг на таком хосте остался бы непроверенным вовсе.
**Флейковость проверена, а не предположена:** живой пин прогнан **5 раз подряд** — 5 зелёных,
разброс смерти 6,046,12 с при пороге 8 с, счёт сигналов 1 во всех пяти. Пин не маргинален ни по
одной из двух осей.
### Числа
```
$ TM_PLATFORM_TEST_DSN=…55433 TM_PLATFORM_TEST_ENGINE_BIN=… TM_PLATFORM_TEST_BOOK_TEMPLATE=… \
TM_PLATFORM_TEST_PGDUMP=… TM_PLATFORM_TEST_PGRESTORE=… make check
MAKE-EXIT=0 · пакетов `ok` 20 · строк FAIL 0 · линтер «0 issues» · скипов 5
gofmt / go vet / sqlc diff чисты · ALARM PD-count: 15 (baseline 15) — не сдвинут
скипы поимённо, условие у всех ОДНО и названное — нет деплой-артефакта
`configs/mining-contrast.zh.txt`: TestTheRealEngineNamesItsRestorePointInTheLineThisPlatformParses ·
TestALivePreviewWritesNothingAndALiveApplyWrites · TestALiveBuildOfAHollowBookWritesTheMarkedCopyInsteadOfRefusing ·
TestWithoutPartialTheSameBookIsRefusedWithTheBuildsOwnNumber · TestTheSnapshotGuardIsLoudWithoutTheFlagsAndPassesWithThem
$ go test ./internal/runner/ -run TestARepeatedStopNeitherSignalsNorExtendsTheGrace -count=1 -v (×5)
5 зелёных · сигналов 1 во всех пяти · смерть юнита 6,04 / 6,09 / 6,09 / 6,10 / 6,12 с при пороге 8 с
```
**Новый пин ВНУТРИ батареи отработал, а не проскочил:** цель `check` гоняет `-v` и печатает КАЖДЫЙ
`--- SKIP`; скипов ровно пять, и пина среди них нет, при нуле падений. Числа выше — из отдельных
прогонов той же командой, потому что `t.Logf` в сводку `make check` не попадает.
⚠ Гейты стенда закрыты все четыре намеренно: без `TM_PLATFORM_TEST_DSN` та же батарея печатает те же
`ok` и прячет ~370 тестов (эррата `08.09-д`).
### Что НЕ удалось
**1. Живой пин не покрывает саму правку, и это названо выше, а не обойдено** — снятие `--no-block`
ловит только argv-пин. Разделение осознанное (живой тест скипается без пользовательского менеджера
systemd), но означает: на хосте без systemd свойство «стоп не ждёт» проверено, а «systemd инертен к
повтору» — нет, и это не чинится в зоне.
**2. Пин говорит о ЮНИТЕ, а утверждение живёт в СВИПЕ.** Тест проверяет `Runner.Stop` напрямую;
никакой тест не гоняет пере-выдачу ЧЕРЕЗ реконсайлер против настоящего systemd — такого стенда в зоне
нет. То есть цепочка «свип → `Stop` → systemd» на живом юните не пройдена ни разу, и если однажды
свип начнёт звать не `Stop`, а что-то другое, пин этого не заметит.
**3. Ущерб от блокировки не предъявлен исполнением — ни одна половина.** Что запрос повиснет, а свип
запишет ложный клин, взято ЧТЕНИЕМ кода (`reconcileOne`, комментарий про израсходованный бюджет) плюс
замером самой блокировки. Сценария «блокирующий стоп внутри прохода довёл прогон до отсрочки» я не
ставила; на предмет правки это не влияет, но утверждение о механизме ущерба остаётся выведенным.
**4. Прочие девять адресов улова не тронуты** — они вне границ захода и живут строками бэклога
**392****397**.
## ПАК «ДВЕ ОСТАНОВКИ» — ОТМЕНЁН ВЛАДЕЛЬЦЕМ, РАБОТА ОТКАЧЕНА (10.09, `textmachine-5c`)
> Промт `docs/PLATFORM_SOFT_STOP_SESSION_PROMPT.md` (редакция `ac9a24d`), вход HEAD `ac9a24d`.
@ -87,7 +183,18 @@ committed_usd, which is what would let this side say "at most Y"». Движок
Пробник на транзиентном юните с `TimeoutStopSec=15`, процесс ловит SIGTERM и не выходит (systemd 259):
блокирующая форма вернулась через **15,058 с** (по SIGKILL), `stop --no-block` — через **0,014 с**,
юнит в `deactivating`. Сегодня движок на жёстком сигнале умирает за секунды, поэтому это невидимо.
Носители последствия: `WriteTimeout: 30 s` (`cmd/tmplatformd/main.go:208`) и свип (п.2).
**Испр. 11.09 по эррате `10.09-з`:** носитель последствия НЕ `WriteTimeout` — тридцать секунд стоят у
слушателя МЕТРИК (`cmd/tmplatformd/main.go:204-208`, комментарий там прямо говорит «for once a WriteTimeout
too: nothing here streams»), а у API-слушателя его НЕТ намеренно (`internal/httpapi/serve.go:36`, «No
WriteTimeout» — срезал бы SSE). Пере-снято моей рукой: во всей зоне вне тестов `WriteTimeout`
УСТАНАВЛИВАЕТСЯ **в одном месте**`main.go:208`. Контроль, что прибор спрашивал существующее:
`grep -rn WriteTimeout platform/ --include=*.go | grep -v _test.go` на `1c5bd2a` даёт четыре строки, из
которых три — комментарии, и ДВЕ из них объясняют, почему у API-слушателя его нет.
⭐ И механизм, на который поправка меняет ущерб, в зоне УЖЕ ЗАРЕГИСТРИРОВАН: `PD-103` — «зависший Postgres
паркует хендлеры и ждущих в пуле, пока клиент сам не уйдёт», ровно потому что `WriteTimeout` у сервера
отсутствует по проекту (SSE) и `TimeoutHandler` в цепочке нет. Блокирующий `Stop` — тот же класс, другой
источник блокировки; ⇒ поправка садится на существующий носитель, а не заводит новое утверждение. ⇒ ущерб не «оборванный `202`», а **зависший запрос с удержанной горутиной обработчика**
(контракт описывает этот вызов АСИНХРОННЫМ) плюс ложный клин свипа (п.2).
**2. Израсходованный бюджет прогона свип считает ПРОВАЛОМ реконсиляции — прочитано в коде.**
`reconcileOne` (`internal/runs/reconcile.go:89-90`) заворачивает каждый прогон в `s.runBudget()`

View file

@ -191,11 +191,46 @@ func (r *Runner) startArgv(s Spec) []string {
// Stop asks the unit to shut down. It returns nil for a unit that is already gone: "stop what is
// not running" is the state the caller wanted, and a reconciler that retries would otherwise treat
// its own success as a failure.
//
// ⛔ `--no-block` IS NOT AN OPTIMISATION. Without it `systemctl stop` waits for the unit to be GONE,
// so the call returns only when the engine has finished shutting down or the stop grace has run out.
// Measured on this stand (systemd 259, a transient unit whose process catches SIGTERM and does not
// exit, TimeoutStopSec=15): the blocking form returned after 15.058 s — by SIGKILL — and
// `--no-block` after 0.014 s, with the unit left in `deactivating`.
//
// Two things pay for that wait, and neither is the one an earlier reading of this named:
//
// - THE CONTRACT DESCRIBES THIS CALL AS ASYNCHRONOUS. §stopRun promises a `202` that «does not mean
// the run has stopped»; a handler that blocks until it HAS stopped keeps that promise's letter and
// breaks its substance. ⚠ It is NOT a cut-off response: the API listener carries no WriteTimeout
// at all, and deliberately (serve.go, «No WriteTimeout» — it would cut the SSE stream). The
// 30-second one belongs to the METRICS listener. So the damage is a request that hangs and a
// handler goroutine held with it, not a `202` that never arrives (D39.235 §4 said otherwise and
// was corrected by its own author, erratum 10.09-з).
// - THE SWEEP RECORDS A WEDGE THAT IS NOT THERE. `runs.reconcileOne` gives each run its own budget
// and counts SPENDING it as a failed reconciliation, so a stop that blocks inside a pass buys the
// run a deferral and, after enough passes, an operator's stalled alarm — for doing exactly what it
// was asked to do. It also eats that pass's share for every other account (D39.236 §5).
//
// Nothing is lost by not waiting: the reconciler re-issues the stop of any live run it finds with an
// intent on file, which is what closes the case this could not close anyway — a platform that died
// between committing the intent and calling systemd.
//
// ⚠ AND THE RE-ISSUE IS SAFE FOR A MEASURED REASON, not an assumed one. On a unit already in
// `deactivating` a second `stop` sends NO further signal and does NOT restart TimeoutStopSec:
// measured with three stops five seconds apart against a process that ignores SIGTERM — one signal in
// the process's own log, and the unit died at t+6.04 s from the FIRST stop rather than the last. That
// is what keeps the sweep's re-issue from pushing the SIGKILL backstop out of reach on every pass,
// and it is undocumented systemd behaviour, so it is pinned rather than trusted:
// TestARepeatedStopNeitherSignalsNorExtendsTheGrace.
func (r *Runner) Stop(ctx context.Context, unit string) error {
out, err := r.run(ctx, "systemctl", "--user", "stop", unitName(unit))
out, err := r.run(ctx, "systemctl", "--user", "stop", "--no-block", unitName(unit))
if err == nil {
return nil
}
// The same two spellings answer a `--no-block` stop as answer a blocking one — measured, because a
// flag that changed the refusal text would turn "the run is already gone" into an error the
// reconciler retries forever.
if bytes.Contains(out, []byte("not loaded")) || bytes.Contains(out, []byte("not found")) {
return nil
}

View file

@ -136,8 +136,36 @@ func TestAliveReadsTheActiveState(t *testing.T) {
}
}
// The stop must not wait for the run to be gone, and the flag that says so is asserted here rather
// than only in the live test: that one skips on a host with no systemd user manager, and a flag
// nothing pins on such a host is a flag that comes off in a refactor nobody notices.
//
// Measured on this stand: the blocking form returns after the whole grace — 15.058 s against a
// TimeoutStopSec of 15, i.e. by SIGKILL — and `--no-block` after 0.014 s. What pays for that wait is
// the contract's own promise that this call is asynchronous, and the sweep, which counts a run that
// spent its budget as a failed reconciliation.
func TestTheSoftStopDoesNotWaitForTheRunToEnd(t *testing.T) {
var got []string
r := &Runner{run: func(_ context.Context, name string, args ...string) ([]byte, error) {
got = append([]string{name}, args...)
return nil, nil
}}
if err := r.Stop(t.Context(), "tm-run-X-1"); err != nil {
t.Fatal(err)
}
if !slices.Contains(got, "--no-block") {
t.Errorf("the stop waits for the unit to be gone: %v", got)
}
if !slices.Contains(got, "tm-run-X-1.service") {
t.Errorf("the stop did not name the unit: %v", got)
}
}
// Stopping something that is already gone is the state the caller wanted. A reconciler that read it
// as a failure would retry its own success forever.
//
// ⚠ The refusal text is the SAME with `--no-block` — measured, because a flag that changed it would
// turn «the run is already gone» into an error the reconciler retries for the life of the account.
func TestStoppingAUnitThatIsGoneSucceeds(t *testing.T) {
r := &Runner{run: func(context.Context, string, ...string) ([]byte, error) {
return []byte("Failed to stop tm-run-X-1.service: Unit tm-run-X-1.service not loaded."), errors.New("exit 5")

View file

@ -0,0 +1,185 @@
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)
}
}

View file

@ -577,6 +577,15 @@ func (s *Service) reconcile(ctx context.Context, l pgstore.LiveRun) (bool, error
// the platform died between writing the intent and asking systemd — or the engine is
// finishing the chunk it has already paid for. Asking again is free and idempotent, and it
// is the only thing that closes the first case.
//
// ⚠ «FREE AND IDEMPOTENT» IS A MEASURED PROPERTY OF systemd AND NOT A HOPE, and it was
// neither documented nor pinned until it was measured: on a unit already stopping, a second
// `stop` delivers no further signal and does not restart the stop timeout — three stops five
// seconds apart against a process that ignores SIGTERM left ONE signal in that process's own
// log, and the unit died on the FIRST stop's clock. Both halves matter here. Without the
// first, this line would signal a run again on every pass; without the second, the SIGKILL
// backstop would recede by a pass each time and a wedged engine would hold its book's lock
// for good. Pinned by runner.TestARepeatedStopNeitherSignalsNorExtendsTheGrace.
if err := s.Runner.Stop(ctx, l.UnitName); err != nil {
return moved, err
}