From 9d0f93bba8560d05cfa3db20e1347fdc3807480e Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 11 Oct 2026 11:38:08 +0200 Subject: [PATCH] mesh-delivery: hold a stranded stop for a later merge on its way, and keep it loud (review, hq issue 474) A stop is final, so a later merge whose queued walk would carry the modules now holds it off; a stopped one stays in stalled until a later delivered merge carries them. A walk counts only modules it sent, and an old walk record is read again rather than taken as building nothing. --- .../mesh-delivery/cmd/mesh-delivery/holder.go | 64 ++++++++-- .../cmd/mesh-delivery/issue474_test.go | 116 ++++++++++++++---- .../mesh-delivery/cmd/mesh-delivery/model.go | 10 +- .../mesh-delivery/cmd/mesh-delivery/verbs.go | 10 ++ 4 files changed, 164 insertions(+), 36 deletions(-) diff --git a/modules/mesh-delivery/cmd/mesh-delivery/holder.go b/modules/mesh-delivery/cmd/mesh-delivery/holder.go index 8dcb0fc7..3130671b 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/holder.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/holder.go @@ -746,9 +746,9 @@ func (h *Holder) creditReleased(w Walk) { // carriedBy begins the why of a step another walk's send carried, followed by that walk's id. const carriedBy = "carried by " -// askWalk is the ask of one walk's record by its id, once an hour while a step it carried still judges; -// what it answers is taken as said. -func (h *Holder) askWalk(id string, now time.Time) func() { +// askWalk is the ask of one walk's record by its id, at most once an hour; what it answers is taken as said. +// which says, for the log, why it is asked: what the walk is to the delivery that asks. +func (h *Holder) askWalk(id, which string, now time.Time) func() { if asked, was := h.walkAsked[id]; was && now.Sub(asked) < time.Hour { return nil } @@ -758,7 +758,7 @@ func (h *Holder) askWalk(id string, now time.Time) func() { h.mu.Lock() defer h.mu.Unlock() if err != nil { - h.Logf("[mesh-delivery] the walk %s, which carried a step still judging, cannot be read yet: %v", id, err) + h.Logf("[mesh-delivery] the walk %s, %s, cannot be read yet: %v", id, which, err) h.walkAsked[id] = h.Now().Add(time.Minute - time.Hour) // asked again a minute on return } @@ -916,7 +916,7 @@ func (h *Holder) plan() []func() { h.settleAndKeep(d) continue } - if a := h.askWalk(d.Walk.TakenOverBy, now); a != nil { + if a := h.askWalk(d.Walk.TakenOverBy, "which took a delivery's walk over", now); a != nil { asks = append(asks, a) } } @@ -930,6 +930,20 @@ func (h *Holder) plan() []func() { // grace, it is stopped saying so — never left waiting for a start that cannot come. for _, d := range h.deliveries { ended := d.endedUnstarted() + if strandedUncovered(d) { + // Stopped and final, but still read for a later merge that delivered its modules: until one did, + // `stalled` keeps listing it (review of novox/hq issue 474). + var ask []string + if d.CoveredBy, ask = h.coverOf(d); d.CoveredBy != "" { + h.keep(d) + } + for _, in := range ask { + if a := h.askContains(d, in, now); a != nil { + asks = append(asks, a) + } + } + continue + } if d.State != Held && !h.unwalkedPast(d, now) && !ended { continue } @@ -961,7 +975,7 @@ func (h *Holder) plan() []func() { if s.State != StepSent && s.State != StepJudging || !strings.HasPrefix(s.Why, carriedBy) { continue } - if a := h.askWalk(strings.TrimPrefix(s.Why, carriedBy), now); a != nil { + if a := h.askWalk(strings.TrimPrefix(s.Why, carriedBy), "which carried a step still judging", now); a != nil { asks = append(asks, a) } } @@ -1001,7 +1015,7 @@ func (h *Holder) plan() []func() { // Final deliveries past their keeping, once nothing is owed for them. for id, d := range h.deliveries { - if d.State.Final() && len(d.Owed) == 0 && now.Sub(d.Since) > keptFinal { + if d.State.Final() && len(d.Owed) == 0 && now.Sub(d.Since) > keptFinal && !strandedUncovered(d) { if err := h.Store.DeleteDelivery(id); err == nil { delete(h.deliveries, id) delete(h.written, id) @@ -1024,8 +1038,8 @@ func (h *Holder) strand(d *Delivery, pending []string, now time.Time) func() { moved, known := d.walkMovedItsModules() switch { case !known && d.Plan != nil: - return h.askWalk(d.Walk.ID, now) - case !known, moved, d.CoveredBy != "", len(pending) > 0, d.Stranded != "": + return h.askWalk(d.Walk.ID, "whose record, kept before it named the modules it built, is read again", now) + case !known, moved, d.CoveredBy != "", len(pending) > 0, d.Stranded != "", h.laterOnItsWay(d) != "": return nil } ended := d.Walk.Updated @@ -1039,12 +1053,40 @@ func (h *Holder) strand(d *Delivery, pending []string, now time.Time) func() { if d.Walk.Note != "" { note = " (" + d.Walk.Note + ")" } - d.Stranded = fmt.Sprintf("its walk %s ended done before its word without building %s%s, and no later merge "+ - "into %s that contains it delivered them: nothing delivered it (novox/hq issue 474)", d.Walk.ID, + d.Stranded = fmt.Sprintf("a merged change never reached the machines: its walk %s ended done before its word "+ + "without building %s%s, and no later merge into %s that contains it delivered them (novox/hq issue 474)", d.Walk.ID, strings.Join(d.notMovedBy(), ", "), note, orNone(d.Base)) return nil } +// laterOnItsWay is a later merge of the same repository into the same trunk, not yet ended, whose plan moves a +// module this delivery's walk left unbuilt — its walk queued, waiting or running — or empty when there is none +// (review of novox/hq issue 474). A stop is final and nothing moves it to covered, so it waits for that merge: +// once delivered, the cover test reads it; if it ends otherwise, the stop follows. +func (h *Holder) laterOnItsWay(d *Delivery) string { + missing := d.notMovedBy() + for _, o := range h.deliveries { + if o.ID == d.ID || o.State.Final() || o.Plan == nil || o.MergedAs == "" || sameCommit(o.MergedAs, d.MergedAs) || + !strings.EqualFold(o.Repository, d.Repository) || !strings.EqualFold(o.Base, d.Base) || + !o.MergedAt.After(d.MergedAt) { + continue + } + for _, m := range missing { + if containsString(o.Plan.Moved, m) { + return o.ID + } + } + } + return "" +} + +// strandedUncovered is whether a delivery stopped because its ended walk delivered nothing is still uncovered: a +// merged change that never reached the machines, which `stalled` keeps listing until a later delivered merge +// carries its modules (review of novox/hq issue 474). +func strandedUncovered(d *Delivery) bool { + return d.State == Stopped && d.Stranded != "" && d.CoveredBy == "" +} + // unwalkedPast is whether a merged delivery has gone without a walk past the bound one opens within, read // again after it: what holds it for a person, unless something already ends it. func (h *Holder) unwalkedPast(d *Delivery, now time.Time) bool { diff --git a/modules/mesh-delivery/cmd/mesh-delivery/issue474_test.go b/modules/mesh-delivery/cmd/mesh-delivery/issue474_test.go index bf65c1ab..797cffe1 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/issue474_test.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/issue474_test.go @@ -80,7 +80,8 @@ func TestAMergeWhoseBatchWalkEndedIsCoveredByALaterDeliveredMerge(t *testing.T) } // With nothing later to carry its modules, it is stopped once the cover test says so and the walk ended past the -// grace — saying which walk ended without moving what — and not before: a later merge may still cover it. +// grace — saying which walk ended without moving what — and not before. Stopped, it stays loud: `stalled` lists it +// until a later delivered merge carries its modules. func TestAMergeWhoseBatchWalkEndedAndNothingCoversItIsStoppedSayingWhy(t *testing.T) { w := theNight(t) id := IDOf(ctl474, head215) @@ -97,43 +98,114 @@ func TestAMergeWhoseBatchWalkEndedAndNothingCoversItIsStoppedSayingWhy(t *testin w.h.waitsFor(d)) } why := d.Transitions[len(d.Transitions)-1].Why - for _, want := range []string{batchWalk, "build-agent", nothingNote} { + for _, want := range []string{"never reached the machines", batchWalk, "build-agent", nothingNote} { if !strings.Contains(why, want) { t.Fatalf("its stop says %q, not %q", why, want) } } - if len(w.h.Stalled()) != 0 { - t.Fatalf("stalled still lists %+v", w.h.Stalled()) + lines := w.h.Stalled() + if len(lines) != 1 || lines[0].ID != id || !strings.Contains(lines[0].Says, "never reached the machines") { + t.Fatalf("stopped, it is not listed loudly: %+v", lines) + } + // A later merge that delivers build-agent ends the listing; the stop itself stays, final. + w.forge.contains[merge215+" in "+merge219] = true + deliverLater(w, ctl474, 219, "main", head219, merge219, w.now, walkDone, "build-agent") + w.later(2 * time.Minute) + w.settleAll() + if d := w.delivery(id); d.State != Stopped || d.CoveredBy == "" { + t.Fatalf("after #219 it is %s, covered by %q", d.State, d.CoveredBy) + } + if lines := w.h.Stalled(); len(lines) != 0 { + t.Fatalf("stalled still lists %+v", lines) } } -// A walk that ended done before a word, having built every module the merge moves, delivered it: a merge it -// carried for a later one is covered by that one, its own merge delivered. -func TestAMergeWhoseWalkEndedHavingMovedItsModulesIsSettledByIt(t *testing.T) { - for _, own := range []bool{true, false} { +// A later merge whose walk is still queued, and whose plan moves what this one's walk left unbuilt, holds the stop +// off: a stop is final, and that merge may yet cover it (review of issue 474). +func TestAMergeWhoseBatchWalkEndedWaitsForALaterMergeOnItsWay(t *testing.T) { + w := theNight(t) + id := IDOf(ctl474, head215) + p := pr(ctl474, 219, head219, "fix/334", "internal/builder/builder.go") + w.h.PullUpdated(p) + w.h.Checked(verdictMoving(ctl474, 219, head219, "build-agent", "mesh-controller")) + w.later(3 * time.Minute) + w.h.PullMerged(mergedAt(p, merge219, w.now)) + w.settleAll() + w.later(strandedAfter) + w.settleAll() + if d := w.delivery(id); d.State != Published { + t.Fatalf("with #219 on its way it is %s (%s)", d.State, d.Stranded) + } + // #219's walk delivers build-agent: covered. + w.forge.contains[merge215+" in "+merge219] = true + walk := aWalk(walk219, ctl474, merge219, true) + walk.Modules = map[string]*WalkModule{"build-agent": {}, "mesh-controller": {}} + w.h.WalkMoved(w.ctl.put(walk)) + w.settleAll() + walk = w.ctl.walk(walk219) + sent := w.now + for m := range walk.Modules { + walk.Modules[m] = &WalkModule{State: "built", SentAt: &sent} + } + walk.State = walkDone + w.h.WalkMoved(w.ctl.put(walk)) + w.later(2 * time.Minute) + w.settleAll() + if s := w.state(IDOf(ctl474, head219)); s != Delivered { + t.Fatalf("#219 is %s", s) + } + if d := w.delivery(id); d.State != Covered { + t.Fatalf("after #219 delivered build-agent it is %s, waiting for %q", d.State, w.h.waitsFor(d)) + } +} + +// A walk that ended before its word built nothing: a module its record names with why it was not sent is not read +// as delivered. A merge whose plan moves nothing, answered by such a walk, is delivered. +func TestAWalkThatEndedBeforeItsWordBuiltNothing(t *testing.T) { + for _, moves := range [][]string{{"build-agent"}, nil} { w := newWorldOver(t, newMemStore(), newFakeController(), newFakeForge(), at215.Add(-time.Minute)) p := pr(ctl474, 215, head215, "fix/x", "cmd/mesh-builder/main.go") w.h.PullUpdated(p) - w.h.Checked(verdictMoving(ctl474, 215, head215, "build-agent")) + w.h.Checked(verdictMoving(ctl474, 215, head215, moves...)) w.later(time.Minute) w.h.PullMerged(mergedAt(p, merge215, at215)) - commit, merges := merge215, []WalkMerge{{Repository: ctl474, Commit: merge215}} - if !own { - commit, merges = merge217, []WalkMerge{{Repository: ctl474, Commit: merge215, Carried: merge217}} - } w.later(2 * time.Minute) - sent := w.now - w.h.WalkMoved(w.ctl.put(Walk{ID: batchWalk, Repository: ctl474, Branch: "main", Commit: commit, Created: w.now, + w.h.WalkMoved(w.ctl.put(Walk{ID: batchWalk, Repository: ctl474, Branch: "main", Commit: merge215, Created: w.now, Updated: w.now, State: walkDone, Tiers: [][]string{{"build-agent"}}, - Modules: map[string]*WalkModule{"build-agent": {State: "built", SentAt: &sent}}, - Delivery: &WalkDelivery{Awaits: "mesh-delivery", Merges: merges}})) + Modules: map[string]*WalkModule{"build-agent": {Why: "not sent: its walk never started"}}, + Delivery: &WalkDelivery{Awaits: "mesh-delivery", Merges: []WalkMerge{{Repository: ctl474, Commit: merge215}}}})) w.settleAll() - want := Delivered - if !own { - want = Covered + d := w.delivery(IDOf(ctl474, head215)) + want := Published + if len(moves) == 0 { + want = Delivered } - if d := w.delivery(IDOf(ctl474, head215)); d.State != want { - t.Fatalf("own commit %v: it is %s, waiting for %q, not %s", own, d.State, w.h.waitsFor(d), want) + if d.State != want { + t.Fatalf("moving %v: it is %s, waiting for %q, not %s", moves, d.State, w.h.waitsFor(d), want) } } } + +// A walk record kept before it named the modules it built, with tiers, is not read as building nothing: the walk is +// asked for again, and what it answers settles the delivery. +func TestAnOldWalkRecordIsAskedForAgain(t *testing.T) { + w := theNight(t) + id := IDOf(ctl474, head215) + w.h.mu.Lock() + d := w.h.deliveries[id] + d.Walk.Moved, d.Walk.MovedSaid, d.Walk.Tiers = nil, false, 1 + w.h.mu.Unlock() + if got := w.h.waitsFor(w.delivery(id)); !strings.Contains(got, "walk's record") { + t.Fatalf("an old record waits for %q", got) + } + w.later(time.Minute) + w.settleAll() + if d := w.delivery(id); !d.Walk.MovedSaid || d.Walk.Tiers != 0 { + t.Fatalf("the walk was not read again: %+v", d.Walk) + } + w.later(strandedAfter) + w.settleAll() + if s := w.state(id); s != Stopped { + t.Fatalf("read again, it is %s", s) + } +} diff --git a/modules/mesh-delivery/cmd/mesh-delivery/model.go b/modules/mesh-delivery/cmd/mesh-delivery/model.go index 0e92e6e5..5c9617b9 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/model.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/model.go @@ -472,7 +472,7 @@ type WalkSeen struct { Created time.Time `json:"created"` // TakenOverBy is the walk that took a superseded one over (novox/hq ADR 0276): its deliveries follow it. TakenOverBy string `json:"taken_over_by,omitempty"` - // Moved are the modules the walk builds, as its record names them; MovedSaid says they were read, which a + // Moved are the modules the walk sent, as its record names them; MovedSaid says they were read, which a // record kept before novox/hq issue 474 did not. What a walk that ended before its word delivered is read // from them. Moved []string `json:"moved,omitempty"` @@ -492,8 +492,12 @@ func (w Walk) Seen() *WalkSeen { s.Branch = w.Branch s.Created = w.Created s.TakenOverBy = w.takenOverBy() - for name := range w.Modules { - s.Moved = append(s.Moved, name) + // Only a module sent, or passed on its first machine, was built for the machines: one the record names with + // why it was not sent, or a walk that never started, built nothing (review of novox/hq issue 474). + for name, m := range w.Modules { + if m != nil && (m.SentAt != nil || m.Gate != nil && m.Gate.Verdict == "passed") { + s.Moved = append(s.Moved, name) + } } sort.Strings(s.Moved) s.MovedSaid = true diff --git a/modules/mesh-delivery/cmd/mesh-delivery/verbs.go b/modules/mesh-delivery/cmd/mesh-delivery/verbs.go index b9f0f2c1..fbee6df1 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/verbs.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/verbs.go @@ -52,6 +52,9 @@ func (h *Holder) waitsFor(d *Delivery) string { } if d.endedUnstarted() { // Never "its walk's start": a done walk has none (novox/hq issue 474). + if _, known := d.walkMovedItsModules(); !known { + return "its plan or its walk's record, to read what its walk " + d.Walk.ID + ", ended before its word, built" + } return "a later delivered merge to carry " + strings.Join(d.notMovedBy(), ", ") + ": its walk " + d.Walk.ID + " ended without building it, and it is stopped " + strandedAfter.String() + " after that walk ended otherwise" } @@ -197,6 +200,13 @@ func (h *Holder) Stalled() []StalledLine { now := h.Now() var out []StalledLine for _, d := range h.deliveries { + if strandedUncovered(d) { + // Stopped, so past no bound, and still loud (review of novox/hq issue 474): listed until a later + // delivered merge carries its modules. + out = append(out, StalledLine{ID: d.ID, State: d.State, For: now.Sub(d.Since).Round(time.Second).String(), + Bound: "0s", H2: "none: a merge that delivers its modules ends it — the operator's", Says: d.Stranded}) + continue + } if !pastBound(d, now) { continue }