763 lines
34 KiB
Go
763 lines
34 KiB
Go
package runs
|
|
|
|
import (
|
|
"context"
|
|
"errors"
|
|
"fmt"
|
|
"net"
|
|
"os"
|
|
"path/filepath"
|
|
"slices"
|
|
"strings"
|
|
"sync"
|
|
"testing"
|
|
"time"
|
|
|
|
"github.com/jackc/pgx/v5/pgconn"
|
|
|
|
"textmachine/platform/internal/ingest"
|
|
"textmachine/platform/internal/money"
|
|
"textmachine/platform/internal/pgstore"
|
|
"textmachine/platform/internal/runner"
|
|
)
|
|
|
|
// fakeRunner stands in for systemd. What these tests are about is the reconciler's DECISION — start,
|
|
// wait, restart, finish — and every one of those decisions is taken from three facts: the exit
|
|
// marker, whether the unit is alive, and how long ago the attempt was admitted.
|
|
type fakeRunner struct {
|
|
mu sync.Mutex
|
|
started []runner.Spec
|
|
stopped []string
|
|
alive bool
|
|
aliveErr error
|
|
startErr error
|
|
// aliveCalls counts the "is the unit still there" questions. A test whose property is that the
|
|
// sweep DID NOT act needs to know the sweep reached the run at all — otherwise a fixture that
|
|
// never got that far reads as a passing assertion.
|
|
aliveCalls int
|
|
// onStop runs INSIDE the fake's Stop, which is what makes the ORDER of "write the intent, then
|
|
// ask systemd" assertable: by the time this runs, the database must already know.
|
|
onStop func(unit string)
|
|
}
|
|
|
|
func (f *fakeRunner) Start(_ context.Context, s runner.Spec) error {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
if f.startErr != nil {
|
|
return f.startErr
|
|
}
|
|
f.started = append(f.started, s)
|
|
return nil
|
|
}
|
|
|
|
func (f *fakeRunner) Stop(_ context.Context, unit string) error {
|
|
f.mu.Lock()
|
|
hook := f.onStop
|
|
f.stopped = append(f.stopped, unit)
|
|
f.mu.Unlock()
|
|
if hook != nil {
|
|
hook(unit)
|
|
}
|
|
return nil
|
|
}
|
|
|
|
func (f *fakeRunner) stops() []string {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
return append([]string(nil), f.stopped...)
|
|
}
|
|
|
|
func (f *fakeRunner) Alive(context.Context, string) (bool, error) {
|
|
f.mu.Lock()
|
|
f.aliveCalls++
|
|
f.mu.Unlock()
|
|
return f.alive, f.aliveErr
|
|
}
|
|
|
|
func (f *fakeRunner) askedAlive() bool {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
return f.aliveCalls > 0
|
|
}
|
|
|
|
func (f *fakeRunner) starts() []runner.Spec {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
return append([]runner.Spec(nil), f.started...)
|
|
}
|
|
|
|
// fakeEngine stands in for `tmctl status --json`. Guarded because the spawn reads the book's spend
|
|
// baseline, and several spawners legitimately race.
|
|
type fakeEngine struct {
|
|
mu sync.Mutex
|
|
report ingest.StatusReport
|
|
err error
|
|
calls int
|
|
// hangs is the set of workdirs the engine refuses to answer about. A SET and not one path: the
|
|
// wedge that stopped an installation needs two of them at once, and a fixture that can only hang
|
|
// one book cannot reproduce it (fix-list of the P7 acceptance).
|
|
hangs map[string]bool
|
|
// onStatus runs INSIDE the call, which is how a test opens the window the reconciler decides in:
|
|
// a status call is seconds of the engine's CPU, and a user can press stop inside it.
|
|
onStatus func()
|
|
// binaries is every path this engine was invoked as. Recorded because WHICH build answers about a
|
|
// book is a money question: a project file an attempt left in an older schema is one only that
|
|
// attempt's own pinned build can read.
|
|
binaries []string
|
|
}
|
|
|
|
func (f *fakeEngine) Status(ctx context.Context, binary, workdir string) (ingest.StatusReport, error) {
|
|
f.mu.Lock()
|
|
f.calls++
|
|
f.binaries = append(f.binaries, binary)
|
|
hang := f.hangs[workdir]
|
|
hook := f.onStatus
|
|
rep, err := f.report, f.err
|
|
f.mu.Unlock()
|
|
if hook != nil {
|
|
hook()
|
|
}
|
|
if hang {
|
|
// An engine that never answers, which is what a hung `tmctl status` looks like from here. It
|
|
// ends when the CALLER's budget does, and that is the property being measured.
|
|
<-ctx.Done()
|
|
return ingest.StatusReport{}, ctx.Err()
|
|
}
|
|
return rep, err
|
|
}
|
|
|
|
// block makes the engine hang for one book's directory. The run id is taken only to make the call
|
|
// site read like the thing it models.
|
|
func (f *fakeEngine) block(_ string, workdir string) {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
if f.hangs == nil {
|
|
f.hangs = map[string]bool{}
|
|
}
|
|
f.hangs[workdir] = true
|
|
}
|
|
|
|
func (f *fakeEngine) set(rep ingest.StatusReport, err error) {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
f.report, f.err = rep, err
|
|
}
|
|
|
|
func (f *fakeEngine) called() int {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
return f.calls
|
|
}
|
|
|
|
func (f *fakeEngine) askedAs() []string {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
return append([]string(nil), f.binaries...)
|
|
}
|
|
|
|
// usd is a figure the engine DID report, as opposed to one it left out. The status report carries
|
|
// both money figures as pointers precisely so the two can be told apart (PD-40), so a test that
|
|
// wants "the engine said zero" has to say so with a pointer.
|
|
func usd(v money.MicroUSD) *money.MicroUSD { return &v }
|
|
|
|
func decideOutcome(t *testing.T, paused string, m runner.Marker) (string, string) {
|
|
t.Helper()
|
|
status, reason, _ := outcome(pgstore.LiveRun{PausedReason: paused}, m)
|
|
return status, reason
|
|
}
|
|
|
|
// exited builds the marker systemd writes for a process that ended on its own.
|
|
func exited(code string) runner.Marker {
|
|
return runner.Marker{Result: "exit-code", Code: "exited", Status: code}
|
|
}
|
|
|
|
// The engine's exit contract, and the two ways a process can end that have no exit code at all.
|
|
//
|
|
// ⚠ Every line below the plain four is money or a contract-visible status, and each was `failed`
|
|
// before the emitter landed: exit 4 is the ceiling halt the contract forbids calling failed
|
|
// (PD-113), and the 10..19 band is a refusal that did no work at all.
|
|
func TestWhatTheUnitDidBecomesTheProductStatus(t *testing.T) {
|
|
cases := []struct {
|
|
name string
|
|
paused string
|
|
marker runner.Marker
|
|
want string
|
|
wantReason string
|
|
}{
|
|
{name: "clean", marker: exited("0"), want: "ready"},
|
|
{name: "completed with flagged units", marker: exited("2"), want: "ready"},
|
|
{name: "bank signing stop", marker: exited("3"), want: "awaiting_bank"},
|
|
{name: "infra failure", marker: exited("1"), want: "failed"},
|
|
{name: "we asked it to stop",
|
|
marker: runner.Marker{Result: "success", Code: "killed", Status: "TERM"}, want: "stopped"},
|
|
{name: "the kernel took it",
|
|
marker: runner.Marker{Result: "oom-kill", Code: "killed", Status: "TERM"}, want: "failed"},
|
|
{name: "it ran out of time",
|
|
marker: runner.Marker{Result: "timeout", Code: "killed", Status: "KILL"}, want: "failed"},
|
|
// A ceiling halt is `paused`, never `failed`, however the process then ended: the stop is
|
|
// resumable and saying "failed" lies about that (contract §BookStatus).
|
|
{name: "a ceiling halt survives any exit", paused: "credit_exhausted",
|
|
marker: exited("1"), want: "paused", wantReason: "credit_exhausted"},
|
|
// …and it survives a journal that was never written, which is the half only the exit code can
|
|
// carry. The reason has to come with it: a paused run with no reason gives the screen nothing
|
|
// to say and the resume path nothing to judge — and it has to be the reason the platform can
|
|
// actually stand behind. Without an event the SCOPE is unknown, and calling it
|
|
// `credit_exhausted` would light the account-level halted flag for an account with money on it
|
|
// (found by the adversarial review of this pack; the quarantined-projection case reaches this
|
|
// branch on every ceiling halt, so it is not a corner).
|
|
{name: "a ceiling halt with no event at all",
|
|
marker: exited("4"), want: "paused", wantReason: "ceiling_unknown"},
|
|
// The scope the stream reported wins over the default, because it is the only thing that can
|
|
// tell the platform's own ceiling from a limit in the operator's book.yaml.
|
|
{name: "the engine's own daily ceiling", paused: "daily_ceiling",
|
|
marker: exited("4"), want: "paused", wantReason: "daily_ceiling"},
|
|
// The refusal band: the invocation was turned down before it did any work. `failed` for the
|
|
// run — it cannot proceed — and never a restart, which would meet the same answer forever.
|
|
{name: "refused: the configuration will not load", marker: exited("10"), want: "failed"},
|
|
{name: "refused: there is no book in the source", marker: exited("11"), want: "failed"},
|
|
{name: "refused: another process holds the project", marker: exited("12"), want: "failed"},
|
|
{name: "refused: a class this build has no name for", marker: exited("19"), want: "failed"},
|
|
}
|
|
for _, tc := range cases {
|
|
got, reason := decideOutcome(t, tc.paused, tc.marker)
|
|
if got != tc.want || reason != tc.wantReason {
|
|
t.Errorf("%s: %q/%q, want %q/%q", tc.name, got, reason, tc.want, tc.wantReason)
|
|
}
|
|
}
|
|
}
|
|
|
|
// Exit 5 is a caught SIGTERM and says nothing about WHO sent it. With an intent recorded it is the
|
|
// user's stop; without one it is an interruption — a reboot, or a hand-stop — and the run comes back
|
|
// on the restart path rather than being buried as stopped or as failed (PD-152).
|
|
func TestAGracefulSignalIsAStopOnlyWhenThisPlatformAskedForOne(t *testing.T) {
|
|
at := time.Now()
|
|
asked := at.Add(-time.Second)
|
|
cases := []struct {
|
|
name string
|
|
live pgstore.LiveRun
|
|
marker runner.Marker
|
|
interrupted bool
|
|
}{
|
|
{"nobody asked", pgstore.LiveRun{}, exited("5"), true},
|
|
{"we asked", pgstore.LiveRun{StopRequestedAt: &asked}, exited("5"), false},
|
|
// A ceiling halt is decided before this ever runs, and it must not be dragged back to life.
|
|
{"a ceiling halt", pgstore.LiveRun{PausedReason: "credit_exhausted"}, exited("5"), false},
|
|
{"an ordinary crash", pgstore.LiveRun{}, exited("1"), false},
|
|
{"a clean finish", pgstore.LiveRun{}, exited("0"), false},
|
|
{"killed, no code at all", pgstore.LiveRun{},
|
|
runner.Marker{Result: "success", Code: "killed", Status: "TERM"}, false},
|
|
}
|
|
for _, tc := range cases {
|
|
tc.marker.At = at
|
|
if got := interruptedBySomeoneElse(tc.live, tc.marker); got != tc.interrupted {
|
|
t.Errorf("%s: interrupted = %v, want %v", tc.name, got, tc.interrupted)
|
|
}
|
|
}
|
|
// And the other half of the same fact: with the intent recorded, the ending IS the user's stop.
|
|
if got, _ := decideOutcome(t, "", runner.Marker{Result: "exit-code", Code: "exited", Status: "5", At: at}); got != "failed" {
|
|
t.Errorf("exit 5 with no intent read as %q from outcome(); the restart branch is what handles it", got)
|
|
}
|
|
status, _, _ := outcome(pgstore.LiveRun{StopRequestedAt: &asked},
|
|
runner.Marker{Result: "exit-code", Code: "exited", Status: "5", At: at})
|
|
if status != "stopped" {
|
|
t.Errorf("a graceful exit after our own stop read as %q, want stopped", status)
|
|
}
|
|
// …and the ORDER of the two records does not change it (acceptance dofix ФП-6). A stop stamped
|
|
// after the marker is what a reboot the user then reacted to looks like, and the two stamps do
|
|
// not even come from one clock — the marker is written by the unit on its host, the intent by
|
|
// this platform. Answering `failed` there buried a run its owner had cancelled.
|
|
late := at.Add(time.Second)
|
|
status, _, code := outcome(pgstore.LiveRun{StopRequestedAt: &late},
|
|
runner.Marker{Result: "exit-code", Code: "exited", Status: "5", At: at})
|
|
if status != "stopped" {
|
|
t.Errorf("a stop recorded after the marker read as %q, want stopped", status)
|
|
}
|
|
if code == nil || *code != ingest.ExitStopped {
|
|
t.Errorf("the exit code of a stopped attempt was not recorded: %v", code)
|
|
}
|
|
// The guard that must NOT move with it: an ending the engine reached by itself outranks a stop
|
|
// that arrived while it was already over, whenever it arrived.
|
|
for _, tc := range []struct{ exit, want string }{{"0", "ready"}, {"2", "ready"}, {"3", "awaiting_bank"}} {
|
|
got, _, _ := outcome(pgstore.LiveRun{StopRequestedAt: &late},
|
|
runner.Marker{Result: "exit-code", Code: "exited", Status: tc.exit, At: at})
|
|
if got != tc.want {
|
|
t.Errorf("exit %s under a later stop read as %q, want %q", tc.exit, got, tc.want)
|
|
}
|
|
}
|
|
}
|
|
|
|
// PD-241, ratified D39.132 п.2д for "the next touch of this zone": a stop the USER asked for is a
|
|
// stop, even when a ceiling event arrived in the same drain.
|
|
//
|
|
// It is not cosmetic and the money screen is why: `credit_exhausted` is the value the ACCOUNT-level
|
|
// halted flag keys on (`pgstore.ReadUsage`), so the previous order told a user who had pressed stop
|
|
// on an account with most of its balance intact that their credit had run out.
|
|
//
|
|
// Mutation caught: moving the `l.PausedReason != ""` branch back above the stop intent.
|
|
func TestAStopTheUserAskedForOutranksACeilingThatArrivedWithIt(t *testing.T) {
|
|
at := time.Now().UTC()
|
|
asked := at.Add(-time.Second)
|
|
for _, reason := range []string{pgstore.PausedCreditExhausted, pgstore.PausedDailyCeiling,
|
|
pgstore.PausedCeilingUnknown} {
|
|
live := pgstore.LiveRun{PausedReason: reason, StopRequestedAt: &asked}
|
|
status, got, _ := outcome(live, runner.Marker{Result: "exit-code", Code: "exited", Status: "4", At: at})
|
|
if status != "stopped" || got != "" {
|
|
t.Errorf("a stop under %q read as %q/%q, want stopped with no reason", reason, status, got)
|
|
}
|
|
}
|
|
// With NOBODY having asked, the ceiling still decides — the rule is about whose ending it was,
|
|
// not about suppressing the reason.
|
|
status, reason, _ := outcome(pgstore.LiveRun{PausedReason: pgstore.PausedCreditExhausted},
|
|
runner.Marker{Result: "exit-code", Code: "exited", Status: "4", At: at})
|
|
if status != "paused" || reason != pgstore.PausedCreditExhausted {
|
|
t.Errorf("an unrequested ceiling halt read as %q/%q", status, reason)
|
|
}
|
|
// And a run that finished BY ITSELF is not re-labelled by a stop that arrived after it.
|
|
if got, _, _ := outcome(pgstore.LiveRun{PausedReason: pgstore.PausedCreditExhausted, StopRequestedAt: &asked},
|
|
runner.Marker{Result: "exit-code", Code: "exited", Status: "0", At: at}); got != "ready" {
|
|
t.Errorf("a clean finish under a stop intent read as %q, want ready", got)
|
|
}
|
|
}
|
|
|
|
// The configured key file reaches the UNIT's argv (row 211, the platform half of the live-run
|
|
// blocker): the spec is what systemd executes, so this is the level at which "the engine gets its
|
|
// keys" is either true or not.
|
|
//
|
|
// Mutation caught: dropping Cfg.KeysFile on the way into TranslateArgs.
|
|
func TestTheSpawnedUnitCarriesTheDeploymentKeyFile(t *testing.T) {
|
|
svc := service(t, &fakeRunner{}, nil, time.Now())
|
|
svc.Cfg.KeysFile = "/etc/tm/keys.env"
|
|
l := pgstore.LiveRun{RunID: "r1", AttemptNo: 1, Workdir: "/srv/books/bk1", Ceiling: 1}
|
|
spec, err := svc.spec(l, money.MicroUSD(1_000_000), pgstore.SpawnOrder{Resolved: true})
|
|
if err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
i := slices.Index(spec.Args, "--keys-file")
|
|
if i < 0 || i+1 >= len(spec.Args) || spec.Args[i+1] != "/etc/tm/keys.env" {
|
|
t.Errorf("the unit's argv carries no key file: %v", spec.Args)
|
|
}
|
|
for _, kv := range spec.Env {
|
|
if strings.Contains(kv, "keys") || strings.Contains(kv, "KEY") {
|
|
t.Errorf("a key-related variable reached the unit's environment: %q", kv)
|
|
}
|
|
}
|
|
}
|
|
|
|
func service(t *testing.T, rn UnitRunner, eng EngineStatus, now time.Time) *Service {
|
|
t.Helper()
|
|
tpl, err := runner.ParseCeilingTemplate("--ceiling-usd {{usd}}")
|
|
if err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
return &Service{
|
|
Runner: rn, Engine: eng,
|
|
Cfg: Config{
|
|
StateDir: t.TempDir(), EngineBinary: "/opt/engine/2026.08.01/tmctl",
|
|
MarkerArgv: []string{"/usr/local/bin/tmplatformctl", "exit-marker"},
|
|
Ceiling: tpl, ResyncEvery: time.Minute,
|
|
},
|
|
Now: func() time.Time { return now },
|
|
}
|
|
}
|
|
|
|
// "No unit and no marker" is two different situations and the discriminator is time: systemd has not
|
|
// got to it yet, or the whole manager went away with the machine. Reading the second as the first
|
|
// means an interrupted run never comes back; reading the first as the second means a second engine
|
|
// on the same book.
|
|
func TestAnAdmittedRunIsGivenTimeBeforeItIsPresumedLost(t *testing.T) {
|
|
now := time.Now()
|
|
rn := &fakeRunner{}
|
|
svc := service(t, rn, nil, now)
|
|
// The grace belongs to the ATTEMPT: a restarted attempt inherits a run start hours old, and a
|
|
// grace measured from the run would expire before systemd had a chance to create anything.
|
|
fresh := pgstore.LiveRun{RunID: "r1", UnitName: "tm-run-r1-1",
|
|
StartedAt: now.Add(-3 * time.Hour), AttemptStartedAt: now.Add(-5 * time.Second)}
|
|
if _, err := svc.reconcile(t.Context(), fresh); err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
if len(rn.starts()) != 0 {
|
|
t.Errorf("a run admitted five seconds ago was already presumed lost")
|
|
}
|
|
}
|
|
|
|
// A unit that was never recorded means the platform stopped between admitting the run and creating
|
|
// it — or the queue entry was lost. The reconciler is the backstop for both, which is what makes the
|
|
// queue's own retry unnecessary.
|
|
func TestTheUnitAnAttemptGetsCarriesItsPinnedBinaryAndItsCeiling(t *testing.T) {
|
|
now := time.Now()
|
|
svc := service(t, &fakeRunner{}, nil, now)
|
|
l := pgstore.LiveRun{
|
|
RunID: "r1", BookID: "bk1", AttemptID: 7, AttemptNo: 1, Workdir: t.TempDir(),
|
|
Ceiling: 3_000_000, VerifyBank: true, StartedAt: now,
|
|
}
|
|
// $3 of increment on a book that has already committed $1, with $0.50 left reserved by a process
|
|
// that died: the engine is told the CUMULATIVE cap it actually judges against, and the leftover is
|
|
// NOT part of it — the engine clears it on the write open (meter.bookCap, PD-158).
|
|
spec, err := svc.spec(l, meter{committed: 1_000_000, reserved: 500_000}.bookCap(l.Ceiling), pgstore.SpawnOrder{Resolved: true})
|
|
if err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
if spec.Unit != "tm-run-r1-1" {
|
|
t.Errorf("unit %q: the attempt number is part of the name, or a resume cannot reuse it", spec.Unit)
|
|
}
|
|
if spec.Binary != "/opt/engine/2026.08.01/tmctl" {
|
|
t.Errorf("the attempt was not pinned to the configured engine build: %q", spec.Binary)
|
|
}
|
|
// The environment carries the run's IDENTITY and nothing else. Provider keys travel in the book's
|
|
// own .env, so they never pass through this process; the id is here because a stream the platform
|
|
// did not name is a stream it cannot tell from somebody else's (engineStreamID).
|
|
if len(spec.Env) != 1 || spec.Env[0] != "TM_TRACE_ID=tm-stream-r1-1" {
|
|
t.Errorf("the unit's environment is %v, want exactly the run id this attempt was named with", spec.Env)
|
|
}
|
|
wantCeiling := false
|
|
for i, a := range spec.Args {
|
|
if a == "--ceiling-usd" && i+1 < len(spec.Args) && spec.Args[i+1] == "4.000000" {
|
|
wantCeiling = true
|
|
}
|
|
}
|
|
if !wantCeiling {
|
|
t.Errorf("the run's ceiling did not reach the engine as a cumulative cap: %v", spec.Args)
|
|
}
|
|
if spec.MarkerArgv[len(spec.MarkerArgv)-1] != spec.Unit || spec.MarkerArgv[len(spec.MarkerArgv)-2] != spec.ExitMarker {
|
|
t.Errorf("the marker command does not name its own file and unit: %v", spec.MarkerArgv)
|
|
}
|
|
}
|
|
|
|
// A stale marker from an earlier attempt of the same name would be read as this attempt's ending the
|
|
// moment the reconciler looked — settling money against a result nobody produced.
|
|
func TestEachAttemptHasAMarkerOfItsOwn(t *testing.T) {
|
|
svc := service(t, &fakeRunner{}, nil, time.Now())
|
|
if svc.markerPath("r1", 1) == svc.markerPath("r1", 2) {
|
|
t.Fatal("two attempts of one run share an exit marker: the first one's ending would be read as the second's")
|
|
}
|
|
if !strings.HasPrefix(svc.markerPath("r1", 1), svc.Cfg.StateDir) {
|
|
t.Errorf("the marker is not in the platform's state directory: %s", svc.markerPath("r1", 1))
|
|
}
|
|
}
|
|
|
|
// A run cannot be started at all while the engine has no way to be told its ceiling: it would spend
|
|
// under the BOOK's limit instead of the account's (row 145).
|
|
func TestNoRunIsSpawnedUntilTheEngineCanBeToldItsCeiling(t *testing.T) {
|
|
now := time.Now()
|
|
rn := &fakeRunner{}
|
|
svc := service(t, rn, nil, now)
|
|
svc.Cfg.Ceiling = nil
|
|
_, err := svc.spec(pgstore.LiveRun{RunID: "r1", AttemptNo: 1, Workdir: t.TempDir(), Ceiling: 1_000_000}, 1_000_000, pgstore.SpawnOrder{Resolved: true})
|
|
if !errors.Is(err, runner.ErrCeilingNotWired) {
|
|
t.Fatalf("building a unit without a ceiling argument gave %v", err)
|
|
}
|
|
if len(rn.starts()) != 0 {
|
|
t.Fatal("a unit was started with no ceiling")
|
|
}
|
|
}
|
|
|
|
// A deployment that cannot start runs at all must find that out for FREE. The spawn asks the engine
|
|
// for the book's money meter, and that call re-ingests and re-chunks the source (seconds of CPU per
|
|
// call, unified backlog row 100) — paying it for every run on every sweep before arriving at a
|
|
// refusal that depends on nothing but configuration is a cost with no purchase.
|
|
func TestAMisconfiguredDeploymentIsRefusedWithoutAskingTheEngine(t *testing.T) {
|
|
eng := &fakeEngine{report: ingest.StatusReport{Spend: usd(0), Reserved: usd(0)}}
|
|
svc := service(t, &fakeRunner{}, eng, time.Now())
|
|
svc.Cfg.Ceiling = nil
|
|
err := svc.spawnAttempt(t.Context(),
|
|
pgstore.LiveRun{RunID: "r1", AttemptNo: 1, Workdir: t.TempDir(), Ceiling: 1_000_000})
|
|
if !errors.Is(err, runner.ErrCeilingNotWired) {
|
|
t.Fatalf("spawning under a deployment with no ceiling argument gave %v", err)
|
|
}
|
|
if eng.called() != 0 {
|
|
t.Errorf("the engine was asked %d times before a refusal that needed no answer", eng.called())
|
|
}
|
|
}
|
|
|
|
// "I could not ask systemd" must never be read as "the run is gone": that mistake starts a second
|
|
// engine against a project file the first one holds an exclusive lock on.
|
|
func TestAnUnreachableBusNeverCausesARestart(t *testing.T) {
|
|
now := time.Now()
|
|
rn := &fakeRunner{aliveErr: errors.New("Failed to connect to bus")}
|
|
svc := service(t, rn, nil, now)
|
|
l := pgstore.LiveRun{RunID: "r1", UnitName: "tm-run-r1-1", AttemptNo: 1,
|
|
StartedAt: now.Add(-time.Hour), AttemptStartedAt: now.Add(-time.Hour)}
|
|
if _, err := svc.reconcile(t.Context(), l); err == nil {
|
|
t.Fatal("an unreachable bus was treated as a decision")
|
|
}
|
|
if len(rn.starts()) != 0 {
|
|
t.Fatal("a run was restarted on the strength of a question that was never answered")
|
|
}
|
|
}
|
|
|
|
// The resync is a SLOW poll and the interval is what makes it affordable: every call re-ingests and
|
|
// re-chunks the source. A reconciler sweeping every fifteen seconds must not call it every time.
|
|
func TestALiveRunIsResyncedAtMostOncePerInterval(t *testing.T) {
|
|
now := time.Now()
|
|
eng := &fakeEngine{report: ingest.StatusReport{TotalUnits: 10, Done: 3}}
|
|
rn := &fakeRunner{alive: true}
|
|
svc := service(t, rn, eng, now)
|
|
if !svc.dueForResync("r1") {
|
|
t.Fatal("a run that was never resynced is not due")
|
|
}
|
|
if svc.dueForResync("r1") {
|
|
t.Fatal("a second sweep inside the interval asked the engine again")
|
|
}
|
|
if !svc.dueForResync("r2") {
|
|
t.Fatal("the interval is per run, not global")
|
|
}
|
|
svc.Now = func() time.Time { return now.Add(2 * time.Minute) }
|
|
if !svc.dueForResync("r1") {
|
|
t.Fatal("the interval never expires")
|
|
}
|
|
// With no engine wired there is nothing to ask, and asking is what costs.
|
|
svc.Engine = nil
|
|
if svc.dueForResync("r3") {
|
|
t.Fatal("a resync was scheduled with no engine to ask")
|
|
}
|
|
_ = eng
|
|
_ = rn
|
|
}
|
|
|
|
// A status call that fails is not a run that failed.
|
|
func TestAFailedResyncIsNotAFailedRun(t *testing.T) {
|
|
now := time.Now()
|
|
eng := &fakeEngine{err: errors.New("tmctl: config: no such file")}
|
|
svc := service(t, &fakeRunner{alive: true}, eng, now)
|
|
// The store is never reached: a status call that failed has nothing to materialize, so this
|
|
// exercises the branch that must not turn a repair-channel outage into a run failure.
|
|
if _, err := svc.maybeResync(t.Context(), pgstore.LiveRun{RunID: "r1", Workdir: t.TempDir()}, false); err != nil {
|
|
t.Fatalf("a failed status call was reported as a reconciliation failure: %v", err)
|
|
}
|
|
if eng.called() != 1 {
|
|
t.Fatalf("the engine was asked %d times", eng.called())
|
|
}
|
|
}
|
|
|
|
// A journal that is not there yet is ordinary and not a failure: the engine writes its first line
|
|
// whenever it gets there, so every run admitted-but-not-spawned, and every sweep in the seconds
|
|
// before the unit starts, meets exactly this.
|
|
func TestAnAbsentJournalIsNotAReconciliationFailure(t *testing.T) {
|
|
now := time.Now()
|
|
svc := service(t, &fakeRunner{alive: true}, nil, now)
|
|
l := pgstore.LiveRun{RunID: "r1", BookID: "bk1", Workdir: t.TempDir()}
|
|
if _, _, err := svc.drainJournal(t.Context(), l); err != nil {
|
|
t.Fatalf("an absent journal: %v", err)
|
|
}
|
|
}
|
|
|
|
// A quarantined attempt is not read at all: materialization stopped on purpose and the run's
|
|
// freshness now comes from the resync channel.
|
|
func TestAQuarantinedAttemptIsNotTailed(t *testing.T) {
|
|
now := time.Now()
|
|
svc := service(t, &fakeRunner{alive: true}, nil, now)
|
|
dir := t.TempDir()
|
|
// A journal that would fail loudly if it were read.
|
|
if err := os.WriteFile(filepath.Join(dir, ingest.JournalFile), []byte("not json at all\n"), 0o600); err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
l := pgstore.LiveRun{RunID: "r1", BookID: "bk1", Workdir: dir, Quarantined: true}
|
|
if _, _, err := svc.drainJournal(t.Context(), l); err != nil {
|
|
t.Fatalf("a quarantined attempt was tailed anyway: %v", err)
|
|
}
|
|
}
|
|
|
|
// "The journal could not be materialized" is two facts, and treating them alike is expensive in both
|
|
// directions: retrying a malformed line forever wedges a run, and quarantining on a lock Postgres
|
|
// broke blinds the projection of a live, paying run permanently.
|
|
//
|
|
// ⚠ The second half was measured by acceptance: a deadlock out of the materializer reached the
|
|
// reconciler as an unreadable journal.
|
|
func TestOnlyAJournalWeCannotReadStopsTheProjection(t *testing.T) {
|
|
cases := []struct {
|
|
name string
|
|
err error
|
|
want bool
|
|
}{
|
|
{"a gap in the stream", fmt.Errorf("%w: seq 9 after 7", ingest.ErrStreamGap), true},
|
|
{"the same seq saying something else", ingest.ErrPayloadConflict, true},
|
|
{"a line that is not an event", errors.New("ingest: decode line 4: invalid character"), true},
|
|
{"our own shutdown", context.Canceled, false},
|
|
{"a sweep that ran out of time", fmt.Errorf("tail: %w", context.DeadlineExceeded), false},
|
|
{"a deadlock Postgres broke", &pgconn.PgError{Code: "40P01", Message: "deadlock detected"}, false},
|
|
{"a serialization failure", fmt.Errorf("pgstore: move cursor: %w",
|
|
&pgconn.PgError{Code: "40001", Message: "could not serialize access"}), false},
|
|
// A managed database is RESTARTED on a schedule, and every shape that arrives in is one the
|
|
// next sweep reads through. Missing them left the same permanent blindness the deadlock did.
|
|
{"the server is shutting down", &pgconn.PgError{Code: "57P01", Message: "terminating connection due to administrator command"}, false},
|
|
{"a sibling backend crashed", &pgconn.PgError{Code: "57P02", Message: "crash shutdown"}, false},
|
|
{"the server is not accepting connections yet", &pgconn.PgError{Code: "57P03", Message: "cannot connect now"}, false},
|
|
{"the connection failed", &pgconn.PgError{Code: "08006", Message: "connection failure"}, false},
|
|
{"the connection was reset", fmt.Errorf("pgstore: lock attempt: %w",
|
|
&net.OpError{Op: "read", Err: errors.New("connection reset by peer")}), false},
|
|
{"a column that does not exist", &pgconn.PgError{Code: "42703", Message: "no such column"}, true},
|
|
}
|
|
for _, tc := range cases {
|
|
if got := quarantines(tc.err); got != tc.want {
|
|
t.Errorf("%s: quarantines=%v, want %v", tc.name, got, tc.want)
|
|
}
|
|
}
|
|
}
|
|
|
|
// The unit name carries the attempt: systemd will not accept a name that is still loaded, and a
|
|
// resume is a new process.
|
|
func TestTheUnitNameCarriesTheAttempt(t *testing.T) {
|
|
if got := unitName("run_ABC", 2); got != "tm-run-run_ABC-2" {
|
|
t.Errorf("unit name %q", got)
|
|
}
|
|
}
|
|
|
|
// The journal offset an attempt starts from is the size of the file when it was admitted: the
|
|
// journal is per BOOK and append-only, so its own lines begin after everything already there.
|
|
func TestAnAttemptStartsWhereTheJournalAlreadyEnds(t *testing.T) {
|
|
dir := t.TempDir()
|
|
if got, err := journalSize(dir); err != nil || got != 0 {
|
|
t.Fatalf("an absent journal gave %d, %v; want 0 and no error", got, err)
|
|
}
|
|
body := []byte("{\"seq\":1}\n{\"seq\":2}\n")
|
|
if err := os.WriteFile(filepath.Join(dir, ingest.JournalFile), body, 0o600); err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
got, err := journalSize(dir)
|
|
if err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
if got != int64(len(body)) {
|
|
t.Errorf("journal size %d, want %d", got, len(body))
|
|
}
|
|
}
|
|
|
|
// The three values of RunFailureReason answer ONE question — is a retry worth offering — and the
|
|
// discriminator for the no-exit-code half is systemd's own word for what happened.
|
|
//
|
|
// ⚠ The marker was taken as a parameter and never read, so every kill told the client that retrying
|
|
// would help — which for most of them is exactly false: the next spawn dies the same way. Found by
|
|
// cross-model review; nothing pinned it before.
|
|
//
|
|
// ⚠ THE STOP-TIMEOUT ROW MOVED, and it moved because the argument above does not reach it. This test
|
|
// used to pin `timeout` beside `oom-kill` as a deployment fault. But `timeout` is THIS platform's own
|
|
// TimeoutStopSec expiring — our deadline, not a fault of the host — and «the next spawn dies the same
|
|
// way» is false for it: nobody is stopping the next spawn, and the work of this one is in its
|
|
// checkpoints. The argument still holds for every other row here, which is why only one moved.
|
|
// The reasoning, the measurement of what systemd writes, and the `oom-kill` control that keeps the
|
|
// change honest all live in TestAKillByOurOwnGraceIsNotReportedAsABrokenDeployment.
|
|
func TestWhyARunFailedDecidesWhetherARetryIsWorthOffering(t *testing.T) {
|
|
code := func(n int) *int { return &n }
|
|
for _, tc := range []struct {
|
|
name string
|
|
status string
|
|
exit *int
|
|
marker runner.Marker
|
|
want string
|
|
}{
|
|
{name: "a status that is not a failure carries no reason", status: "paused", exit: code(4)},
|
|
{name: "the engine read the file and found no book", status: "failed",
|
|
exit: code(ingest.ExitSourceUnreadable), want: "source_unreadable"},
|
|
{name: "a configuration that will not load", status: "failed",
|
|
exit: code(ingest.ExitConfigInvalid), want: "service_error"},
|
|
{name: "a plain infrastructure failure", status: "failed", exit: code(1), want: "service_error"},
|
|
{name: "out of memory", status: "failed", marker: runner.Marker{Result: "oom-kill"}, want: "service_error"},
|
|
{name: "killed by our own stop deadline", status: "failed", marker: runner.Marker{Result: "timeout"}, want: "interrupted"},
|
|
{name: "an ending nobody described", status: "failed",
|
|
marker: runner.Marker{Result: "signal"}, want: "interrupted"},
|
|
} {
|
|
if got := failureReason(tc.status, tc.exit, tc.marker); got != tc.want {
|
|
t.Errorf("%s: %q, want %q", tc.name, got, tc.want)
|
|
}
|
|
}
|
|
}
|
|
|
|
// A finished run leaves its book OWING a reading surface, in the database and not in the process
|
|
// that noticed the ending.
|
|
//
|
|
// Nothing in the zone saw this seam at all: a queue lost with its process, a `Refresh` that returned
|
|
// an error and was only logged, a drain that never runs — all pass the battery, and the symptom is a
|
|
// run the user PAID for whose text never appears. The pass itself materializes nothing: two full
|
|
// re-chunks of the source inside it held up every account's settlement behind it.
|
|
//
|
|
// Mutation caught: stamping the debt outside the transaction that closes the run.
|
|
func TestAFinishedRunLeavesItsBookOwingAReadingSurface(t *testing.T) {
|
|
f := newFixture(t, "10", 500)
|
|
bookID := f.bookID(t)
|
|
if owed := f.owed(t); len(owed) != 0 {
|
|
t.Fatalf("the book owed a surface before any run finished: %+v", owed)
|
|
}
|
|
runID := f.stopped(t, 100, 0, runner.Marker{Result: "exit-code", Code: "exited", Status: "0",
|
|
At: f.now.Add(time.Second)})
|
|
if got := f.run(t, runID); got.Status != "ready" {
|
|
t.Fatalf("the run is %q", got.Status)
|
|
}
|
|
owed := f.owed(t)
|
|
if len(owed) != 1 || owed[0].ID != bookID || owed[0].Workdir == "" {
|
|
t.Fatalf("the materializer's queue holds %+v, want the book of the run that just finished", owed)
|
|
}
|
|
// ⚠ …and stamped BY THE TRANSACTION THAT CLOSED THE RUN, which is the property and not the debt's
|
|
// mere presence: a stamp written by a second statement afterwards leaves the same end state and a
|
|
// window where a run is finished, settled and owes nothing — and the column is the only retry
|
|
// there is. `xmin` is the transaction that last wrote a row, so the book and the status frame that
|
|
// ending emitted carry one number exactly when one transaction wrote both.
|
|
//
|
|
// ⚠ Against the FRAME and not against the run's own row: settlement stamps the run again a moment
|
|
// later, so `runs.xmin` has moved on by the time anything can read it.
|
|
var bookTx, frameTx string
|
|
if err := f.store.Pool().QueryRow(f.ctx,
|
|
`select xmin::text from books where id = $1`, bookID).Scan(&bookTx); err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
if err := f.store.Pool().QueryRow(f.ctx,
|
|
`select xmin::text from book_events where book_id = $1 order by position desc limit 1`,
|
|
bookID).Scan(&frameTx); err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
if bookTx == "" || bookTx != frameTx {
|
|
t.Errorf("the ending and the debt were written by different transactions (%s vs %s)", bookTx, frameTx)
|
|
}
|
|
}
|
|
|
|
func (f *fixture) owed(t *testing.T) []pgstore.OwedBook {
|
|
t.Helper()
|
|
owed, err := f.store.BooksOwedReadModel(f.ctx, 10)
|
|
if err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
return owed
|
|
}
|
|
|
|
// A resumed run is spawned WITH the flag it was started with: this platform does not decide where
|
|
// the engine stops.
|
|
//
|
|
// ⚠ RE-SIGNED by pack P12 (order D39.158, ping #21), and this is a commissioned change of contract,
|
|
// not a test bent to a green. Its predecessor pinned the OPPOSITE — that a resumed attempt drops
|
|
// `--verify-bank` — and it was right for the engine of its day: that engine halted wherever undecided
|
|
// terms remained, so re-passing the flag put the run straight back into the stop it had just been
|
|
// released from, and the platform masked it to get past. The engine now carries a presented memory
|
|
// (storage schema v16): a stop fires only on a cluster no earlier stop has SHOWN, so the same flag
|
|
// on a resumed attempt auto-continues at that same boundary by the engine's own predicate, and the
|
|
// undecided rows still ride to the editor marked ⟨проверить⟩ (unified backlog row 191). Two answers
|
|
// to one question is what the law of the seam forbids; the answer is the engine's.
|
|
//
|
|
// Mutation caught: masking l.VerifyBank on a resumed attempt — the removed workaround, in any of its
|
|
// forms.
|
|
func TestAResumedRunIsSpawnedWithTheFlagItStartedWith(t *testing.T) {
|
|
before := runner.TranslateArgs("/srv/books/bk1", true, "", false, 0, 0, nil)
|
|
if !slices.Contains(before, "--verify-bank") {
|
|
t.Fatal("a run that asked for the signing stop is spawned without it")
|
|
}
|
|
f := newFixture(t, "10", 500)
|
|
runID := f.stoppedRun(t, StartRequest{UserID: "u1", BookID: f.bookID(t), VerifyBank: true,
|
|
Chapters: order(100)}, 0, runner.Marker{Result: "exit-code", Code: "exited", Status: "3",
|
|
At: f.now.Add(time.Second)})
|
|
// The FIRST attempt must carry it, or this fixture proves nothing about the second.
|
|
first := f.runner.starts()
|
|
if len(first) != 1 || !slices.Contains(first[0].Args, "--verify-bank") {
|
|
t.Fatalf("the signing run was not spawned with the stop: %+v", first)
|
|
}
|
|
if _, err := f.svc.Resume(f.ctx, "u1", runID); err != nil {
|
|
t.Fatalf("resume: %v", err)
|
|
}
|
|
if err := f.svc.Spawn(f.ctx, runID); err != nil {
|
|
t.Fatalf("spawn after resume: %v", err)
|
|
}
|
|
after := f.runner.starts()
|
|
if len(after) != 2 {
|
|
t.Fatalf("%d units started, want the resumed attempt to be the second", len(after))
|
|
}
|
|
if !slices.Contains(after[1].Args, "--verify-bank") {
|
|
t.Errorf("the resumed attempt was spawned without the flag its run asked for: %v", after[1].Args)
|
|
}
|
|
}
|