diff --git a/go/buildstep/conformance/conformance.go b/go/buildstep/conformance/conformance.go index 42c2ca1..78596ff 100644 --- a/go/buildstep/conformance/conformance.go +++ b/go/buildstep/conformance/conformance.go @@ -4,7 +4,9 @@ // path, the code that turns a runner's output into the failures of its test result; the kit fails the test when a // failure is not named, its cause is missing or wrong, or a passing line stands in its place. // -// A catalogue check (mesh-catalog checks/failurekit) refuses a build module with a test step whose tests do not call Run. +// A catalogue check (mesh-catalog checks/failurekit) refuses a build module with a test step whose tests do not call Run, +// and any build module whose tests do not call LeftRunning, the kit's case of steps a previous process left running +// (leftrunning.go, issue 1890). package conformance import ( diff --git a/go/buildstep/conformance/conformance_test.go b/go/buildstep/conformance/conformance_test.go index 2e1648d..3ee2367 100644 --- a/go/buildstep/conformance/conformance_test.go +++ b/go/buildstep/conformance/conformance_test.go @@ -1,9 +1,11 @@ package conformance import ( + "context" "encoding/json" "strings" "testing" + "time" "git.novox.be/novox/mesh-sdk/go/buildstep" ) @@ -19,6 +21,23 @@ func TestTheFailureContract(t *testing.T) { }) }) + // 1890/AC7: the SDK's start sweep keeps the left-running case, and the kit refuses a sweep that ends nothing or ends + // everything. + t.Run("the left-running case", func(t *testing.T) { + LeftRunning(t, func(ctx context.Context, scan buildstep.Scan, node string, before time.Time, logf func(string, ...any)) { + buildstep.EndStaleAtStart(ctx, scan, node, before, logf) + }) + if p := JudgeLeftRunning(func(context.Context, buildstep.Scan, string, time.Time, func(string, ...any)) {}); len(p) != 13 { + t.Errorf("a sweep that ends nothing: %d problems, want 13 (five steps not ended, each unsaid, three owners unnamed):\n%s", len(p), strings.Join(p, "\n")) + } + wrongNode := func(ctx context.Context, scan buildstep.Scan, _ string, before time.Time, logf func(string, ...any)) { + buildstep.EndStaleAtStart(ctx, scan, "kitother", before, logf) + } + if p := JudgeLeftRunning(wrongNode); len(p) == 0 { + t.Error("a sweep of another node's steps is not refused") + } + }) + // node's output cut to its first fifteen lines with no cause, whose first line was a passing test of the first file // (mesh-build-node's lines() before the contract), and a Go failure keeping its first line. t.Run("the kit refuses a failure that hides its cause", func(t *testing.T) { diff --git a/go/buildstep/conformance/leftrunning.go b/go/buildstep/conformance/leftrunning.go new file mode 100644 index 0000000..3860d96 --- /dev/null +++ b/go/buildstep/conformance/leftrunning.go @@ -0,0 +1,185 @@ +package conformance + +import ( + "context" + "encoding/json" + "fmt" + "sort" + "strings" + "sync" + "testing" + "time" + + stdio "git.novox.be/novox/mesh-sdk/go" + "git.novox.be/novox/mesh-sdk/go/buildstep" + "git.novox.be/novox/mesh-sdk/go/delivery" +) + +// **A step left running by a previous process** (novox/hq issue 1890, note 21): when a delivery replaced mesh-build-go +// on a node while a check ask ran, the new process's start sweep let the ask's key stand as running, and it held one +// of the node's build slots until a hand end. Every build module runs this case (LeftRunning) through the start sweep +// its main runs: the steps a previous process left are ended at once and loud, what this process runs is kept. A +// catalogue check (mesh-catalog checks/failurekit) refuses a build module whose tests do not call LeftRunning. + +// Sweep is a build module's own start sweep, as its main runs it once at its start: it ends node's steps in scan that +// no process of the module runs any more (buildstep.EndStaleAtStart, here with the runtime already serving), before +// being the start of the process, saying each end with logf. +type Sweep func(ctx context.Context, scan buildstep.Scan, node string, before time.Time, logf func(string, ...any)) + +// LeftNode is the node the case's steps are of. +const LeftNode = "kitnode" + +// leftCase is one step in the steps state before the sweep, and whether the sweep must end it. +type leftCase struct { + id, tool, owner, state string + node string + age time.Duration // started this long before the process began (negative: after it) + ended bool +} + +// gone is a previous process's owner on the same node. +var gone = "b00t-of-the-kit.4242.mvp0000" + +func leftCases() []leftCase { + return []leftCase{ + {id: "mvpwlkzi7e6ca8", tool: "check ask", owner: gone, age: 5 * time.Minute, ended: true}, // note 21's ghost + {id: "mvpwlkzi7e6ca9", tool: "delivery ask", owner: gone, age: -time.Second, ended: true}, + {id: "gonehand1", tool: "build_x_test", owner: gone, age: time.Minute, ended: true}, + {id: "oldhand1", tool: "build_x_fetch", age: time.Hour, ended: true}, // no owner: an older build's + {id: "mvpwlkzi7e6caa", tool: "check ask", age: time.Hour, ended: true}, // no owner, past the bound + {id: "mvpwlkzi7e6cab", tool: "check ask", age: 5 * time.Minute}, // no owner, the stream's still + {id: "mvpwlkzi7e6cac", tool: "check ask", owner: buildstep.Owner, age: time.Minute}, // this process's + {id: "minehand1", tool: "build_x_test", owner: buildstep.Owner, age: -time.Second}, + {id: "donehand1", tool: "build_x_test", owner: gone, age: time.Hour, state: delivery.StepPassed}, + {id: "otherhand1", tool: "build_x_test", owner: gone, age: time.Hour, node: "kitother"}, + } +} + +// LeftRunning runs the case through sweep and fails the test for each step the sweep ended or kept wrongly, or ended +// without saying it. +func LeftRunning(t *testing.T, sweep Sweep) { + t.Helper() + for _, problem := range JudgeLeftRunning(sweep) { + t.Error(problem) + } +} + +// JudgeLeftRunning says what is wrong with what sweep did to the case; nothing when it keeps the rule. +func JudgeLeftRunning(sweep Sweep) []string { + st := &steps{vals: map[string][]byte{}, revs: map[string]uint64{}} + before := time.Now() + for _, c := range leftCases() { + node, state := c.node, c.state + if node == "" { + node = LeftNode + } + if state == "" { + state = delivery.StepRunning + } + key, _ := delivery.StepKey(node, c.id) + raw, err := delivery.EncodeStep(delivery.Step{ID: c.id, Tool: c.tool, Node: node, State: state, Started: before.Add(-c.age).UTC(), Owner: c.owner}) + if err != nil { + return []string{"the kit's step " + c.id + ": " + err.Error()} + } + st.set(key, raw) + } + served := make(chan struct{}) + close(served) + was := buildstep.StaleServed + buildstep.StaleServed = func() <-chan struct{} { return served } + defer func() { buildstep.StaleServed = was }() + var mu sync.Mutex + var said []string + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + sweep(ctx, st.scan(), LeftNode, before, func(f string, a ...any) { + mu.Lock() + defer mu.Unlock() + said = append(said, fmt.Sprintf(f, a...)) + }) + mu.Lock() + log := strings.Join(said, "\n") + mu.Unlock() + var problems []string + for _, c := range leftCases() { + node := c.node + if node == "" { + node = LeftNode + } + key, _ := delivery.StepKey(node, c.id) + s, err := delivery.DecodeStep(st.get(key)) + if err != nil { + problems = append(problems, key+": "+err.Error()) + continue + } + want := c.state + if want == "" { + want = delivery.StepRunning + } + if c.ended { + want = delivery.StepFailed + } + if s.State != want { + problems = append(problems, fmt.Sprintf("left running: the step %s (%s, owner %q, %s before the start) is %s after the sweep, want %s", key, c.tool, c.owner, c.age, s.State, want)) + } + if c.ended && !strings.Contains(log, key) { + problems = append(problems, "left running: the end of "+key+" is not said") + } + if c.ended && c.owner != "" && !strings.Contains(log, c.owner) { + problems = append(problems, "left running: the end of "+key+" does not name its owner "+c.owner) + } + } + sort.Strings(problems) + return problems +} + +// steps is a steps state with revisions, whose Update lands only at the revision read (stdio.ErrChanged otherwise). +type steps struct { + mu sync.Mutex + vals map[string][]byte + revs map[string]uint64 +} + +func (s *steps) set(key string, raw []byte) { + s.mu.Lock() + defer s.mu.Unlock() + s.vals[key], s.revs[key] = raw, s.revs[key]+1 +} + +func (s *steps) get(key string) []byte { + s.mu.Lock() + defer s.mu.Unlock() + return s.vals[key] +} + +func (s *steps) scan() buildstep.Scan { + return buildstep.Scan{ + Keys: func() ([]string, error) { + s.mu.Lock() + defer s.mu.Unlock() + var out []string + for k := range s.vals { + out = append(out, k) + } + return out, nil + }, + Get: func(key string) (json.RawMessage, uint64, error) { + s.mu.Lock() + defer s.mu.Unlock() + return s.vals[key], s.revs[key], nil + }, + Update: func(key string, value any, revision uint64) (uint64, error) { + raw, err := json.Marshal(value) + if err != nil { + return 0, err + } + s.mu.Lock() + defer s.mu.Unlock() + if s.revs[key] != revision { + return 0, stdio.ErrChanged + } + s.vals[key], s.revs[key] = raw, revision+1 + return revision + 1, nil + }, + } +} diff --git a/go/buildstep/pull_test.go b/go/buildstep/pull_test.go index fca0690..56a3ce1 100644 --- a/go/buildstep/pull_test.go +++ b/go/buildstep/pull_test.go @@ -166,7 +166,7 @@ func TestPullHoldsAtMostItsCapacity(t *testing.T) { waitFor(t, "a phase on the step key", func() bool { key, _ := delivery.AskStepKey("shanks", p.Running()[0].ID) s, _ := st.get(key) - return s.State == delivery.StepRunning && s.Phase == "unit: tests of 3 packages" && !s.PhaseAt.IsZero() + return s.State == delivery.StepRunning && s.Phase == "unit: tests of 3 packages" && !s.PhaseAt.IsZero() && s.Owner == Owner // 1890/AC5 }) release <- struct{}{} waitFor(t, "the third taken", func() bool { return src.Waiting(delivery.AskDelivery) == 0 }) @@ -176,7 +176,7 @@ func TestPullHoldsAtMostItsCapacity(t *testing.T) { waitFor(t, "all acked", func() bool { a, _, _ := src.Fates(); return len(a) == 3 }) for _, a := range asks { key, _ := delivery.AskStepKey("shanks", a.ID) - if s, _ := st.get(key); s.State != delivery.StepPassed || s.Phase != "unit: tests of 3 packages" { + if s, _ := st.get(key); s.State != delivery.StepPassed || s.Phase != "unit: tests of 3 packages" || s.Owner != Owner { t.Errorf("the end of %s = %+v, want passed in its last phase", a.ID, s) } } diff --git a/go/buildstep/stale.go b/go/buildstep/stale.go index 4147934..1156253 100644 --- a/go/buildstep/stale.go +++ b/go/buildstep/stale.go @@ -5,6 +5,8 @@ import ( "encoding/json" "errors" "fmt" + "os" + "strconv" "strings" "time" @@ -14,16 +16,36 @@ import ( // **A step left running** (novox/hq issue 1890, note 5). A build module that stops while a step runs leaves its key in // state running for good: nothing else writes that key's end, and the stream's redelivery only rewrites it when the same -// ask comes back. At its start a module ends the steps its node left running before the process began (EndStale), and -// its step-end tool ends one by hand (EndOne). +// ask comes back. At its start a module ends the steps its node left running by another process (EndStale: every step +// names its owner, delivery.Step.Owner; note 21), and its step-end tool ends one by hand (EndOne). The conformance kit's +// left-running case holds every build module to the start sweep (conformance.LeftRunning). // RestartReason is why a step a previous process left running is ended. const RestartReason = "the build module restarted while it ran" -// Boot is when this process began. A step started at or after it belongs to this process, which may still run it, so -// EndOne refuses it. +// Boot is when this process began. A step with no owner (written by an older build) started at or after it is taken +// for this process's, which may still run it, so EndOne refuses it. var Boot = time.Now() +// Owner is this process as a step's owner (delivery.Step.Owner): `..`, the node's boot id +// (/proc/sys/kernel/random/boot_id), the pid and Boot in milliseconds, base 36. The start keeps two processes apart +// that a reboot or a pid namespace gave the same pid. A running step whose owner is another is a previous process's. +var Owner = ownerOf(readBootID(), os.Getpid(), Boot) + +func ownerOf(bootID string, pid int, start time.Time) string { + return bootID + "." + strconv.Itoa(pid) + "." + strconv.FormatInt(start.UnixMilli(), 36) +} + +// readBootID is the node's boot id, or "no-boot-id" where it cannot be read (the pid and the start then tell the +// processes apart). +func readBootID() string { + b, err := os.ReadFile("/proc/sys/kernel/random/boot_id") + if id := strings.TrimSpace(string(b)); err == nil && id != "" { + return id + } + return "no-boot-id" +} + // Scan reads and writes a steps state with its revisions: its keys, a key's stored value and revision (nil and 0 for // none), and a write that lands only while the key is still at the revision read (KeptState.Update), failing with // stdio.ErrChanged when another writer was first. @@ -95,12 +117,20 @@ func endRunning(scan Scan, key string, step delivery.Step, revision uint64, why return err } -// EndStale ends this node's steps that are running and started before `before` (the start of this process) as failed -// with RestartReason, and answers their ids. Only keys of node are read; a value that is no step is left alone. A step -// of a pulled ask is left to the stream's redelivery (isAsk) until its start is older than delivery.StepBound: its asker -// stopped waiting then, whether the stream gave it to another node or gave it up, and it is ended as failed, "past the -// step bound: its asker stopped waiting at