diff --git a/cmd/mesh-controller/checks.go b/cmd/mesh-controller/checks.go index 1ff6a275..8a8265eb 100644 --- a/cmd/mesh-controller/checks.go +++ b/cmd/mesh-controller/checks.go @@ -429,6 +429,20 @@ func checkedOf(result link.BuildResult) link.Checked { l.Verdict = "error" } } + // **A check run again says so** (novox/hq issue 594). The summaries are the lines the pull request + // shows, clipped by the forge to a few words, so they get only a short marker after the verdict's own + // words; the report gets the whole sentence. Layers copied, so the build's own outcome is left as it came. + if mark := link.RunMarker(result.Delivery); mark != "" { + c.Summary += " " + mark + for _, l := range []**link.CheckLayer{&c.Gate, &c.RepoCheck} { + if *l != nil { + layer := **l + layer.Summary += " " + mark + *l = &layer + } + } + c.Report = link.Restarted(result.Delivery) + "\n\n" + c.Report + } if len(c.Report) > maxCheckReport { c.Report = "…" + c.Report[len(c.Report)-maxCheckReport:] } diff --git a/cmd/mesh-controller/queue.go b/cmd/mesh-controller/queue.go index 5f0c2308..629fe5d4 100644 --- a/cmd/mesh-controller/queue.go +++ b/cmd/mesh-controller/queue.go @@ -141,6 +141,9 @@ type queuedAnswer struct { // Position is its place among the waiting, 1 being handed out next; 0 for an ask not waiting. Position int `json:"position,omitempty"` Seq uint64 `json:"seq"` + // Delivery is the how-manyth time an ask in flight was handed out; more than 1 is a restart + // (novox/hq issue 594). + Delivery int `json:"delivery,omitempty"` } // aCommitRef is a ref that names a commit by its full hash (SHA-1 or SHA-256). @@ -164,7 +167,7 @@ func queueAnswerOf(q link.Queue, now time.Time) queueAnswer { } return queuedAnswer{ID: a.ID, State: a.State, Kind: kind, Repository: link.WithoutPassword(a.Repository), Path: a.Path, Ref: a.Ref, Commit: commit, Machine: a.On, WasOn: a.Was, AskedAt: a.AskedAt, Since: since, - Position: position, Seq: a.Seq} + Position: position, Seq: a.Seq, Delivery: a.Delivery} } for _, a := range running { out.Asks = append(out.Asks, one(a, 0)) @@ -207,6 +210,10 @@ func queueText(q link.Queue, now time.Time) string { switch { case a.On != "": where = fmt.Sprintf("on %s for %s", a.On, now.Sub(a.Started).Round(time.Second)) + // Started again after an earlier taker left it (novox/hq issue 594). + if a.Delivery > 1 { + where += fmt.Sprintf(", handed out %d times", a.Delivery) + } case a.Was != "": where = fmt.Sprintf("handed back by %s, to be handed out again", a.Was) } diff --git a/cmd/mesh-controller/restarted_test.go b/cmd/mesh-controller/restarted_test.go new file mode 100644 index 00000000..380ffa37 --- /dev/null +++ b/cmd/mesh-controller/restarted_test.go @@ -0,0 +1,56 @@ +package main + +import ( + "strings" + "testing" + "time" + + "github.com/novox/mesh-controller/internal/link" +) + +// **A check that ran again says so on the pull request** (novox/hq issue 594): a build agent replaced +// mid-check leaves the ask to be handed out again, and the verdict that finally comes is from a second +// run. Each layer's summary — what the forge shows as the check's line — names the restart. +func TestARestartedCheckSaysSoOnEveryLayer(t *testing.T) { + asked := &link.CheckRequest{Owner: "novox", Repo: "mesh-controller", Number: 279} + gate := &link.CheckLayer{Verdict: "pass", Summary: "every node composes"} + repo := &link.CheckLayer{Verdict: "pass", Summary: "merge-check.sh passed"} + c := checkedOf(link.BuildResult{ID: "b", Ref: "abc", On: "shanks", Checked: asked, Delivery: 2, + Check: &link.CheckOutcome{Verdict: "pass", Summary: "every node composes", Gate: gate, RepoCheck: repo}}) + for name, said := range map[string]string{"summary": c.Summary, "gate": c.Gate.Summary, + "repository check": c.RepoCheck.Summary} { + // The verdict's own words first, then the marker: the forge clips a status to a few words. + if !strings.HasSuffix(said, " (run 2)") || strings.HasPrefix(said, "(run") { + t.Errorf("the %s says %q: a check run twice reads as run once, or its marker pushes its words out", name, said) + } + } + if !strings.HasPrefix(c.Report, "restarted: handed out 2 times") { + t.Errorf("the report does not open with the restart: %q", c.Report) + } + if gate.Summary != "every node composes" { + t.Errorf("the build's own outcome was changed under it: %q", gate.Summary) + } + + // Taken once, nothing is added. + once := checkedOf(link.BuildResult{ID: "b", Ref: "abc", Checked: asked, Delivery: 1, + Check: &link.CheckOutcome{Verdict: "pass", Summary: "every node composes"}}) + if strings.Contains(once.Summary, "(run") || strings.Contains(once.Report, "restarted") { + t.Errorf("a check run once says %q", once.Summary) + } +} + +// And the queue says it of the ask in flight. +func TestTheQueueSaysAnAskInFlightRestarted(t *testing.T) { + now := time.Date(2026, 10, 13, 0, 16, 0, 0, time.UTC) + q := link.Queue{Seat: link.TheBuildMachine, Delivered: 1, AckPending: 1, MaxDeliver: 5, Asks: []link.QueuedAsk{ + {Seq: 1, ID: "build-279", Repository: "ssh://forge/novox/mesh-controller", AskedAt: now.Add(-7 * time.Minute), + State: link.AskInFlight, On: "shanks", Started: now.Add(-time.Minute), Delivery: 2}, + }} + text := queueText(q, now) + if !strings.Contains(text, "handed out 2 times") { + t.Fatalf("the queue does not say the ask was handed out again:\n%s", text) + } + if a := queueAnswerOf(q, now).Asks[0]; a.Delivery != 2 { + t.Errorf("the queue's data says delivery %d, want 2", a.Delivery) + } +} diff --git a/internal/link/build.go b/internal/link/build.go index 33f4c372..8262b8b9 100644 --- a/internal/link/build.go +++ b/internal/link/build.go @@ -257,6 +257,10 @@ type BuildResult struct { // build; then only identical artifacts make a rebuild no move. SourceFingerprint string `json:"source-fingerprint,omitempty"` + // Delivery is the how-manyth time the queue handed this ask out (BuildStart.Delivery): more than 1 + // says the outcome is from a run started again after an earlier taker left it (novox/hq issue 594). + Delivery int `json:"delivery,omitempty"` + // Failed is why, when it did. Failed string `json:"failed,omitempty"` diff --git a/internal/link/builds.go b/internal/link/builds.go index 57576711..7fe20541 100644 --- a/internal/link/builds.go +++ b/internal/link/builds.go @@ -92,6 +92,31 @@ type BuildStart struct { Ref string `json:"ref,omitempty"` On string `json:"on"` At string `json:"at"` + // Delivery is the how-manyth time the queue handed this ask out: 1 for a first start, more for one + // an earlier taker left unfinished — most often a build agent replaced mid-build — and started + // again from the beginning (novox/hq issue 594). 0 from a machine that predates it. + Delivery int `json:"delivery,omitempty"` +} + +// Restarted is how a build handed out again says so (novox/hq issue 594), in its log and in its check's +// report, so a second run never reads as the first. Neutral on why: a holder replaced mid-build, a paused +// holder handing an ask back as it arrived, and a bus that held its acknowledgements past the wait all +// count as a hand-out. Empty for a first start. +func Restarted(delivery int) string { + if delivery < 2 { + return "" + } + return fmt.Sprintf("restarted: handed out %d times; an earlier hand-out did not finish here, so this run "+ + "started from the beginning", delivery) +} + +// RunMarker is the short form of Restarted, for a line clipped to a few words — a check's status on the +// forge (novox/hq issue 594): "(run 2)". Empty for a first start. +func RunMarker(delivery int) string { + if delivery < 2 { + return "" + } + return fmt.Sprintf("(run %d)", delivery) } // BuildLine is one thing a build said while building. diff --git a/internal/link/builds_nats.go b/internal/link/builds_nats.go index b4e7a324..a29087bb 100644 --- a/internal/link/builds_nats.go +++ b/internal/link/builds_nats.go @@ -310,7 +310,7 @@ func (m *natsMachine) Take(ctx context.Context, do func(context.Context, Build)) // built. A set that cannot be read is said and the ask built: a cancel is a person's // exception, and a holder that refused every build while its grant was missing would // stop the mesh building for it. - build := &natsBuild{request: request, msg: msg, on: m.on, js: m.js, seat: m.seat} + build := &natsBuild{request: request, msg: msg, on: m.on, js: m.js, seat: m.seat, delivery: deliveryOf(msg)} if cancelled, err := IsCancelled(m.js.Conn(), m.seat, request.ID); err != nil { fmt.Fprintf(os.Stderr, "could not read whether %s was cancelled, so it is built: %v\n", request.ID, err) } else if cancelled { @@ -336,6 +336,18 @@ type natsBuild struct { // seat is the role this build was taken from; what the machine says about it is that role's. seat string seq int + // delivery is the how-manyth time the queue handed this ask out (novox/hq issue 594); 0 when the + // server did not say. + delivery int +} + +// deliveryOf is how many times the queue has handed this message out, this time included. +func deliveryOf(msg *nats.Msg) int { + meta, err := msg.Metadata() + if err != nil { + return 0 + } + return int(meta.NumDelivered) } func (b *natsBuild) Request() BuildRequest { return b.request } @@ -356,6 +368,11 @@ func (b *natsBuild) Announce(ctx context.Context, result BuildResult) error { if result.Failed == "" && result.Commit != "" { result.Module = ModuleOf(result.Manifest) } + // **Which run this is** (novox/hq issue 594): stamped by the transport, which alone knows, so every + // outcome carries it whatever the machine's code filled in. + if result.Delivery == 0 { + result.Delivery = b.delivery + } body, err := json.Marshal(result) if err != nil { return err @@ -375,11 +392,16 @@ func (b *natsBuild) Done() error { return b.msg.Ack() } func (b *natsBuild) Began(ctx context.Context) error { body, err := json.Marshal(BuildStart{ ID: b.request.ID, Repository: b.request.Repository, Path: b.request.Path, - Ref: b.request.Ref, On: b.on, At: time.Now().UTC().Format(time.RFC3339Nano), + Ref: b.request.Ref, On: b.on, At: time.Now().UTC().Format(time.RFC3339Nano), Delivery: b.delivery, }) if err != nil { return err } + // **A start that is a restart says so in the build's log** (novox/hq issue 594): a reader following + // the build sees why it began again, never a silent second run. + if said := Restarted(b.delivery); said != "" { + b.Say("restarted", said) + } publish, cancel := context.WithTimeout(ctx, 30*time.Second) defer cancel() if _, err := b.js.Context().Publish(BuildStartedOf(b.seat), body, nats.Context(publish)); err != nil { diff --git a/internal/link/builds_nats_test.go b/internal/link/builds_nats_test.go index 8928c60c..ac8a0eb1 100644 --- a/internal/link/builds_nats_test.go +++ b/internal/link/builds_nats_test.go @@ -401,3 +401,97 @@ func TestNatsAHolderSaysItTakesWorkOnceItIsBound(t *testing.T) { t.Fatal("a machine that could not bind said it takes work") } } + +// **An ask handed out again says so** (novox/hq issue 594). A build agent replaced mid-build leaves its +// ask unsettled, and the queue hands it out again to start over from the beginning. That second start +// must not look like a first one: the machine that takes it says it restarted — in its started event, +// in the build's log and in its outcome — so the queue and the pull request can say it too. +func TestNatsAnAskHandedOutAgainSaysItRestarted(t *testing.T) { + js := aBusWithTheBuildRole(t) + ctx, stop := context.WithCancel(context.Background()) + defer stop() + + started, err := js.Conn().SubscribeSync(BuildStarted()) + if err != nil { + t.Fatal(err) + } + defer func() { _ = started.Unsubscribe() }() + lines, err := js.Conn().SubscribeSync(BuildLog("b-594")) + if err != nil { + t.Fatal(err) + } + defer func() { _ = lines.Unsubscribe() }() + outcomes, err := js.Conn().SubscribeSync(BuildOutcome()) + if err != nil { + t.Fatal(err) + } + defer func() { _ = outcomes.Unsubscribe() }() + _ = js.Conn().Flush() + + body, _ := json.Marshal(BuildRequest{ID: "b-594", Repository: "/r"}) + if _, err := js.Context().Publish(BuildWork(), body); err != nil { + t.Fatal(err) + } + + machine := MachineOverNATS(js, "anchor") + defer machine.Close() + var first sync.Once + go func() { + _ = machine.Take(ctx, func(ctx context.Context, work Build) { + _ = work.Began(ctx) + handedBack := false + // The first time it is left unfinished — an agent replaced mid-build — and comes back. + first.Do(func() { _ = work.Hold(100 * time.Millisecond); handedBack = true }) + if handedBack { + return + } + _ = work.Announce(ctx, BuildResult{ID: work.Request().ID, On: "anchor"}) + _ = work.Done() + }) + }() + + var starts []BuildStart + for len(starts) < 2 { + msg, err := started.NextMsg(10 * time.Second) + if err != nil { + t.Fatalf("heard %d start(s) of an ask handed out twice: %v", len(starts), err) + } + var s BuildStart + if err := json.Unmarshal(msg.Data, &s); err != nil { + t.Fatal(err) + } + starts = append(starts, s) + } + if starts[0].Delivery != 1 || starts[1].Delivery != 2 { + t.Fatalf("the starts say deliveries %d and %d, want 1 and 2: a restart reads as a first start", + starts[0].Delivery, starts[1].Delivery) + } + + msg, err := outcomes.NextMsg(10 * time.Second) + if err != nil { + t.Fatal(err) + } + var result BuildResult + if err := json.Unmarshal(msg.Data, &result); err != nil { + t.Fatal(err) + } + if result.Delivery != 2 { + t.Fatalf("the outcome says delivery %d, want 2: the pull request cannot say the check restarted", + result.Delivery) + } + + sawRestarted := false + for { + msg, err := lines.NextMsg(time.Second) + if err != nil { + break + } + var line BuildLine + if json.Unmarshal(msg.Data, &line) == nil && line.Step == "restarted" { + sawRestarted = true + } + } + if !sawRestarted { + t.Fatal("the build's log never said it restarted") + } +} diff --git a/internal/link/queue.go b/internal/link/queue.go index aef98d3a..ff864366 100644 --- a/internal/link/queue.go +++ b/internal/link/queue.go @@ -73,6 +73,9 @@ type QueuedAsk struct { On string `json:"on,omitempty"` Was string `json:"was-on,omitempty"` Started time.Time `json:"started,omitempty"` + // Delivery is the how-manyth time the ask was handed out, as its latest start said: more than 1 is + // a build started again after an earlier taker left it (novox/hq issue 594). + Delivery int `json:"delivery,omitempty"` } // Queue is the seat's work queue as it stands. @@ -162,7 +165,7 @@ func ClassifyQueue(asks []QueuedAsk, delivered uint64, ackPending int, heard Bui } a.State = AskDead if s, ok := current[a.ID]; ok { - a.On, a.Started = s.On, startedAt(s) + a.On, a.Started, a.Delivery = s.On, startedAt(s), s.Delivery running = append(running, i) continue } @@ -183,7 +186,7 @@ func ClassifyQueue(asks []QueuedAsk, delivered uint64, ackPending int, heard Bui for _, i := range group { if slots == 0 { // Past what the worker counts: handed out as often as it may be. - out[i].On, out[i].Started = "", time.Time{} + out[i].On, out[i].Started, out[i].Delivery = "", time.Time{}, 0 continue } out[i].State = AskInFlight