From 084acc042b98d1b491e0b76572bbb8eecf4c8161 Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 11 Oct 2026 11:31:43 +0200 Subject: [PATCH 1/2] mesh-delivery: a merge whose walk ended before its word is settled from that walk's record (hq issue 474) A batch's walk the controller judged to move nothing is done when it is cut, and a merge it carried stayed published waiting for a start that cannot come. Its walk's record now settles it: delivered or covered when that walk built its modules, covered when a later delivered merge carried them (ADR 0270), and otherwise stopped with why once the cover test says none did. --- .../mesh-delivery/cmd/mesh-delivery/holder.go | 47 +++++- .../cmd/mesh-delivery/issue474_test.go | 139 ++++++++++++++++++ .../mesh-delivery/cmd/mesh-delivery/model.go | 52 +++++++ .../mesh-delivery/cmd/mesh-delivery/table.go | 45 +++++- .../cmd/mesh-delivery/table_test.go | 9 ++ .../mesh-delivery/cmd/mesh-delivery/verbs.go | 5 + 6 files changed, 293 insertions(+), 4 deletions(-) create mode 100644 modules/mesh-delivery/cmd/mesh-delivery/issue474_test.go diff --git a/modules/mesh-delivery/cmd/mesh-delivery/holder.go b/modules/mesh-delivery/cmd/mesh-delivery/holder.go index 9223c804..8dcb0fc7 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/holder.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/holder.go @@ -925,12 +925,16 @@ func (h *Holder) plan() []func() { // (novox/hq issue 319). A plan that moves nothing is delivered; one whose every module a later merge into the // same trunk delivered is covered. Read again each tick, so a delivery read back after a restart, or held // before this was known, ends by itself. + // A published delivery whose walk ended done before its word is read the same way (novox/hq issue 474): what + // that walk did not build, a later delivered merge may have; and when the cover test says none did, past the + // grace, it is stopped saying so — never left waiting for a start that cannot come. for _, d := range h.deliveries { - if d.State != Held && !h.unwalkedPast(d, now) { + ended := d.endedUnstarted() + if d.State != Held && !h.unwalkedPast(d, now) && !ended { continue } + var ask []string if d.CoveredBy == "" { - var ask []string d.CoveredBy, ask = h.coverOf(d) for _, in := range ask { if a := h.askContains(d, in, now); a != nil { @@ -938,6 +942,11 @@ func (h *Holder) plan() []func() { } } } + if ended { + if a := h.strand(d, ask, now); a != nil { + asks = append(asks, a) + } + } if ts := settle(d, Facts{Now: now}); len(ts) > 0 { h.moved(d, ts) h.closeGroupOf(d) @@ -1002,6 +1011,40 @@ func (h *Holder) plan() []func() { return asks } +// strandedAfter is how long after its walk ended unstarted a delivery that walk did not deliver waits for a later +// merge to cover it before it is stopped (novox/hq issue 474): within the bound of a published delivery, so it is +// stopped, saying why, before `stalled` would list it. +const strandedAfter = 20 * time.Minute + +// strand says why a delivery whose walk ended done before its word is stopped, once that is so: the walk did not +// build every module it moves, the cover test asked the forge everything it had to and found no later delivered +// merge that carried them, and the walk ended strandedAfter ago. A walk record kept before it named its modules is +// asked for again (askWalk) rather than read as moving nothing. +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 nil + } + ended := d.Walk.Updated + if ended.IsZero() { + ended = d.Since + } + if now.Sub(ended) < strandedAfter { + return nil + } + note := "" + 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, + strings.Join(d.notMovedBy(), ", "), note, orNone(d.Base)) + return nil +} + // 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 new file mode 100644 index 00000000..bf65c1ab --- /dev/null +++ b/modules/mesh-delivery/cmd/mesh-delivery/issue474_test.go @@ -0,0 +1,139 @@ +package main + +import ( + "strings" + "testing" + "time" +) + +// novox/hq issue 474: a merge batched behind a later one of its branch (ADR 0276) whose walk ended done before +// any word was asked — the controller judged the batch's files moved nothing it holds, "nothing to walk" — was +// left published, waiting for "its walk's start", which a done walk never has. Its walk's record settles it: it +// is delivered when that walk moved its modules, covered when a later delivered merge carried them (ADR 0270), +// and otherwise stopped, saying why — never left waiting. +// +// The shape is the night's own (2026-10-11): mesh-controller #215 (merged as fbc7bc97, its check's plan moving +// build-agent) and #217 (merged as 8305e4e3 a minute later, moving nothing) in one batch, walked as +// plan-1791681624611167730 at 8305e4e3: done, no tier, still saying it awaits mesh-delivery. + +const ( + ctl474 = "novox/mesh-controller" + head215 = "d2e9dc61590f950b" + merge215 = "fbc7bc976b3c115b" + head217 = "68fbd99e894443ce" + merge217 = "8305e4e3d126594d" + head219 = "ef551fdfb6b29d4a" + merge219 = "0a2e58c0704ccc09" + batchWalk = "plan-1791681624611167730" + walk219 = "plan-1791686195314774150" + nothingNote = "moved nothing the mesh holds: nothing to walk" +) + +var at215 = time.Date(2026, 10, 11, 1, 20, 19, 0, time.UTC) + +// theNight is #215 and #217 checked and merged, and their batch's walk done with no tier, as the controller said it. +func theNight(t *testing.T) *world { + w := newWorldOver(t, newMemStore(), newFakeController(), newFakeForge(), at215.Add(-time.Minute)) + p215 := pr(ctl474, 215, head215, "fix/431-make-check-runs-what-the-gate-runs", "Makefile") + p217 := pr(ctl474, 217, head217, "fix/432-a-test-reads-what-it-carries", "cmd/mesh-controller/check_test.go") + w.h.PullUpdated(p215) + w.h.PullUpdated(p217) + w.h.Checked(verdictMoving(ctl474, 215, head215, "build-agent")) + w.h.Checked(verdictMoving(ctl474, 217, head217)) + w.later(time.Minute) + w.h.PullMerged(mergedAt(p215, merge215, at215)) + w.later(time.Minute) + w.h.PullMerged(mergedAt(p217, merge217, at215.Add(56*time.Second))) + w.later(90 * time.Second) + cut := w.now + w.h.WalkMoved(w.ctl.put(Walk{ID: batchWalk, Repository: ctl474, Branch: "main", Commit: merge217, Created: cut, + Updated: cut, State: walkDone, Tiers: [][]string{}, Modules: map[string]*WalkModule{}, Note: nothingNote, + Delivery: &WalkDelivery{Awaits: "mesh-delivery", Merges: []WalkMerge{ + {Repository: ctl474, Commit: merge215, Carried: merge217}, {Repository: ctl474, Commit: merge217}}}})) + w.settleAll() + return w +} + +// The live delivery: its walk ended without moving build-agent, and a later merge (#219) delivered build-agent +// everywhere from main holding its merge — covered, from the walk's record and the forge's word, never waiting. +func TestAMergeWhoseBatchWalkEndedIsCoveredByALaterDeliveredMerge(t *testing.T) { + w := theNight(t) + id := IDOf(ctl474, head215) + if s := w.state(IDOf(ctl474, head217)); s != Delivered { + t.Fatalf("#217, which moves nothing, is %s", s) + } + w.forge.contains[merge215+" in "+merge219] = true + deliverLater(w, ctl474, 219, "main", head219, merge219, at215.Add(76*time.Minute), walkDone, "build-agent") + w.later(2 * time.Minute) + w.settleAll() + d := w.delivery(id) + if d.State != Covered { + t.Fatalf("#215, its walk %s done with nothing moved and build-agent delivered later by #219, is %s, waiting "+ + "for %q", batchWalk, d.State, w.h.waitsFor(d)) + } + if why := d.Transitions[len(d.Transitions)-1].Why; !strings.Contains(why, IDOf(ctl474, head219)) { + t.Fatalf("covered, but not by #219: %q", why) + } + if len(w.h.Stalled()) != 0 { + t.Fatalf("stalled still lists %+v", w.h.Stalled()) + } +} + +// 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. +func TestAMergeWhoseBatchWalkEndedAndNothingCoversItIsStoppedSayingWhy(t *testing.T) { + w := theNight(t) + id := IDOf(ctl474, head215) + w.later(5 * time.Minute) + w.settleAll() + if s := w.state(id); s != Published { + t.Fatalf("within the grace it is %s", s) + } + w.later(strandedAfter) + w.settleAll() + d := w.delivery(id) + if d.State != Stopped { + t.Fatalf("its walk done without build-agent and nothing later carrying it, it is %s, waiting for %q", d.State, + w.h.waitsFor(d)) + } + why := d.Transitions[len(d.Transitions)-1].Why + for _, want := range []string{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()) + } +} + +// 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} { + 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.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, + 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}})) + w.settleAll() + want := Delivered + if !own { + want = Covered + } + 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) + } + } +} diff --git a/modules/mesh-delivery/cmd/mesh-delivery/model.go b/modules/mesh-delivery/cmd/mesh-delivery/model.go index 25ec79e1..0e92e6e5 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/model.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/model.go @@ -65,6 +65,9 @@ type Delivery struct { // (novox/hq issue 319); Lifted why what held it for a person no longer holds (issue 316). CoveredBy string `json:"covered_by,omitempty"` Lifted string `json:"lifted,omitempty"` + // Stranded says why a merge whose walk ended done before its word, without moving every module it moves, is + // stopped: nothing later delivered them either (novox/hq issue 474). Set once the cover test says no. + Stranded string `json:"stranded,omitempty"` // TurnAwaits says, for a group member whose turn waits for a later merge to carry a superseded member before it, // which merges and until when; TurnAwaitsUntil is that moment, which bounds the wait (ADR 0276 decision 9, // novox/hq issue 445). `show` shows both, and `stalled` says them past that moment. @@ -469,6 +472,11 @@ 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 + // 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"` + MovedSaid bool `json:"moved_said,omitempty"` } // Seen is a walk as a delivery keeps it. @@ -484,9 +492,53 @@ 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) + } + sort.Strings(s.Moved) + s.MovedSaid = true return s } +// endedUnstarted is whether a published delivery's walk ended done without ever being let go: a batch's walk the +// controller judged to move nothing it holds is done when it is cut (novox/hq issue 474). No start can come for it, +// so its record settles the delivery. +func (d *Delivery) endedUnstarted() bool { + return d.State == Published && d.Walk != nil && d.Walk.State == walkDone && !d.Walk.Started() +} + +// walkMovedItsModules is whether the walk it follows built every module its plan moves, and whether that is known: +// from the modules the walk's record names, or, for a record kept before they were, from a walk of no tier, which +// moved nothing. Unknown when its plan is not known. +func (d *Delivery) walkMovedItsModules() (moved, known bool) { + if d.Walk == nil || d.Plan == nil { + return false, false + } + if !d.Walk.MovedSaid && d.Walk.Tiers > 0 { + return false, false + } + for _, m := range d.Plan.Moved { + if !containsString(d.Walk.Moved, m) { + return false, true + } + } + return true, true +} + +// notMovedBy is the modules its plan moves that the walk it follows did not build. +func (d *Delivery) notMovedBy() []string { + var out []string + if d.Walk == nil || d.Plan == nil { + return nil + } + for _, m := range d.Plan.Moved { + if !containsString(d.Walk.Moved, m) { + out = append(out, m) + } + } + return out +} + // Started is whether the walk is past its wait: it waited for nobody, or was let go — whatever came of it // since. A walk superseded or stopped while it waited never started. func (s *WalkSeen) Started() bool { return s != nil && !s.Waits && (s.WaitedFor == "" || s.GoBy != "") } diff --git a/modules/mesh-delivery/cmd/mesh-delivery/table.go b/modules/mesh-delivery/cmd/mesh-delivery/table.go index ad55d7ff..76005611 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/table.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/table.go @@ -231,8 +231,21 @@ var Table = []Row{ return unless(d.Walk != nil && d.Walk.State == walkSuperseded, "its walk is not superseded") }}, {From: []State{Published}, Event: EvDone, To: Delivered, - Guard: "nothing for a walk to move", - Holds: func(d *Delivery, f Facts) error { return unless(d.Walk == nil && d.MovesNothing(), "a walk moves it") }}, + Guard: "nothing for a walk to move; or its walk, carrying its own commit, ended done before its word having built " + + "every module it moves (novox/hq issue 474)", + Holds: func(d *Delivery, f Facts) error { + if d.Walk == nil && d.MovesNothing() { + return nil + } + moved, _ := d.walkMovedItsModules() + return unless(d.endedUnstarted() && !d.carriedLater() && moved, "a walk moves it") + }, + Says: func(d *Delivery) string { + if d.Walk == nil { + return "nothing for a walk to move" + } + return fmt.Sprintf("its walk %s ended done before its word, having built every module it moves", d.Walk.ID) + }}, {From: []State{Published, Ready}, Event: EvHold, To: Held, Guard: "something holds it for a person: its group's composed check did not pass for the heads that merged, " + "or it merged and no walk was opened for it", @@ -248,6 +261,34 @@ var Table = []Row{ } return unless(d.Walk != nil && d.Walk.Started(), "its walk waits") }}, + // **A walk that ended before its word settles its delivery** (novox/hq issue 474): a batch's walk the + // controller judged to move nothing it holds is done when it is cut, and a merge it carried was left published, + // waiting for a start that cannot come. Covered when that walk, carrying a later merge for it, built its modules, + // or when a later delivered merge carried them (ADR 0270's covered test); stopped, saying why, when neither. + {From: []State{Published}, Event: EvCovered, To: Covered, + Guard: "its walk ended done before its word, and its modules were delivered by a later merge that contains it: " + + "that walk, carrying it, built them, or a later merge's finished walk sent them everywhere (ADR 0270)", + Holds: func(d *Delivery, f Facts) error { + if !d.endedUnstarted() { + return errors.New("its walk has not ended before its word") + } + moved, _ := d.walkMovedItsModules() + return unless(d.carriedLater() && moved || d.MergedAs != "" && d.CoveredBy != "", + "nothing later delivered its modules") + }, + Says: func(d *Delivery) string { + if moved, _ := d.walkMovedItsModules(); d.carriedLater() && moved { + return "covered: a later merge that contains it was delivered: " + d.Carrier + } + return "covered: a later merge that contains it was delivered: " + d.CoveredBy + }}, + {From: []State{Published}, Event: EvStop, To: Stopped, + Guard: "its walk ended done before its word without building every module it moves, and no later merge that " + + "contains it delivered them: no start can come, and nothing delivered it (novox/hq issue 474)", + Holds: func(d *Delivery, f Facts) error { + return unless(d.endedUnstarted() && d.Stranded != "", "its walk has not ended unstarted, or something may cover it") + }, + Says: func(d *Delivery) string { return d.Stranded }}, {From: []State{Held}, Event: EvGo, To: Delivering, Guard: "its walk started on a word that was not this owner's: the controller's own path, which waits for " + "nobody, or a person's `plans go`", diff --git a/modules/mesh-delivery/cmd/mesh-delivery/table_test.go b/modules/mesh-delivery/cmd/mesh-delivery/table_test.go index 072def6c..75f5fecc 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/table_test.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/table_test.go @@ -48,6 +48,11 @@ func aDeliveryFor(r Row) (*Delivery, Facts) { if r.Event == EvStop && !r.Act { f = Facts{Now: now} d.Walk = &WalkSeen{ID: "plan-1", State: walkFailed, StoppedBy: "mesh-delivery for jochen"} + if r.From[0] == Published { + // Its walk ended done before its word, and nothing delivered it (novox/hq issue 474). + d.Walk = &WalkSeen{ID: "plan-1", State: walkDone, Waits: true, WaitedFor: "mesh-delivery", MovedSaid: true} + d.Stranded = "its walk plan-1 ended done before its word without building app" + } } case EvReask: f.Why, f.By = "delivery stalled", byH2 @@ -65,6 +70,10 @@ func aDeliveryFor(r Row) (*Delivery, Facts) { } case EvCovered: d.MergedAs, d.CoveredBy = "aaaa1111", "delivered with novox/app@bbbb (merged as bbbb2222, walk plan-2): app" + if r.From[0] == Published { + // Its walk ended done before its word; a later merge delivered its modules (novox/hq issue 474). + d.Walk = &WalkSeen{ID: "plan-1", State: walkDone, Waits: true, WaitedFor: "mesh-delivery", MovedSaid: true} + } if r.From[0] == Delivering { // Answered by its successor in one walk (ADR 0276): the walk done, carrying a later merge. d.CoveredBy, d.AnsweredBy, d.Carrier = "", "bbbb2222", "novox/app@bbbb (merged as bbbb2222, walk plan-2)" diff --git a/modules/mesh-delivery/cmd/mesh-delivery/verbs.go b/modules/mesh-delivery/cmd/mesh-delivery/verbs.go index e1045ac6..b9f0f2c1 100644 --- a/modules/mesh-delivery/cmd/mesh-delivery/verbs.go +++ b/modules/mesh-delivery/cmd/mesh-delivery/verbs.go @@ -50,6 +50,11 @@ func (h *Holder) waitsFor(d *Delivery) string { if d.Walk != nil && d.Walk.TakenOverBy != "" { return "the walk " + d.Walk.TakenOverBy + ", which took its walk " + d.Walk.ID + " over" } + if d.endedUnstarted() { + // Never "its walk's start": a done walk has none (novox/hq issue 474). + 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" + } if d.Group != "" { return "its turn in group " + d.Group } From 9d0f93bba8560d05cfa3db20e1347fdc3807480e Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 11 Oct 2026 11:38:08 +0200 Subject: [PATCH 2/2] 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 }