Merge pull request 'Say a build handed out again restarted: its log, the queue and the check's verdict (issue 594, part)' (#280) from fix/594-a-replaced-agent-finishes-its-build into main

This commit was merged in pull request #280.
This commit is contained in:
2026-10-12 22:55:59 +00:00
8 changed files with 230 additions and 5 deletions
+14
View File
@@ -429,6 +429,20 @@ func checkedOf(result link.BuildResult) link.Checked {
l.Verdict = "error" 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 { if len(c.Report) > maxCheckReport {
c.Report = "…" + c.Report[len(c.Report)-maxCheckReport:] c.Report = "…" + c.Report[len(c.Report)-maxCheckReport:]
} }
+8 -1
View File
@@ -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 is its place among the waiting, 1 being handed out next; 0 for an ask not waiting.
Position int `json:"position,omitempty"` Position int `json:"position,omitempty"`
Seq uint64 `json:"seq"` 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). // 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, 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, 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 { for _, a := range running {
out.Asks = append(out.Asks, one(a, 0)) out.Asks = append(out.Asks, one(a, 0))
@@ -207,6 +210,10 @@ func queueText(q link.Queue, now time.Time) string {
switch { switch {
case a.On != "": case a.On != "":
where = fmt.Sprintf("on %s for %s", a.On, now.Sub(a.Started).Round(time.Second)) 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 != "": case a.Was != "":
where = fmt.Sprintf("handed back by %s, to be handed out again", a.Was) where = fmt.Sprintf("handed back by %s, to be handed out again", a.Was)
} }
+56
View File
@@ -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)
}
}
+4
View File
@@ -257,6 +257,10 @@ type BuildResult struct {
// build; then only identical artifacts make a rebuild no move. // build; then only identical artifacts make a rebuild no move.
SourceFingerprint string `json:"source-fingerprint,omitempty"` 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 is why, when it did.
Failed string `json:"failed,omitempty"` Failed string `json:"failed,omitempty"`
+25
View File
@@ -92,6 +92,31 @@ type BuildStart struct {
Ref string `json:"ref,omitempty"` Ref string `json:"ref,omitempty"`
On string `json:"on"` On string `json:"on"`
At string `json:"at"` 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. // BuildLine is one thing a build said while building.
+24 -2
View File
@@ -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 // 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 // exception, and a holder that refused every build while its grant was missing would
// stop the mesh building for it. // 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 { 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) fmt.Fprintf(os.Stderr, "could not read whether %s was cancelled, so it is built: %v\n", request.ID, err)
} else if cancelled { } 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 is the role this build was taken from; what the machine says about it is that role's.
seat string seat string
seq int 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 } 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 != "" { if result.Failed == "" && result.Commit != "" {
result.Module = ModuleOf(result.Manifest) 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) body, err := json.Marshal(result)
if err != nil { if err != nil {
return err return err
@@ -375,11 +392,16 @@ func (b *natsBuild) Done() error { return b.msg.Ack() }
func (b *natsBuild) Began(ctx context.Context) error { func (b *natsBuild) Began(ctx context.Context) error {
body, err := json.Marshal(BuildStart{ body, err := json.Marshal(BuildStart{
ID: b.request.ID, Repository: b.request.Repository, Path: b.request.Path, 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 { if err != nil {
return err 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) publish, cancel := context.WithTimeout(ctx, 30*time.Second)
defer cancel() defer cancel()
if _, err := b.js.Context().Publish(BuildStartedOf(b.seat), body, nats.Context(publish)); err != nil { if _, err := b.js.Context().Publish(BuildStartedOf(b.seat), body, nats.Context(publish)); err != nil {
+94
View File
@@ -401,3 +401,97 @@ func TestNatsAHolderSaysItTakesWorkOnceItIsBound(t *testing.T) {
t.Fatal("a machine that could not bind said it takes work") 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")
}
}
+5 -2
View File
@@ -73,6 +73,9 @@ type QueuedAsk struct {
On string `json:"on,omitempty"` On string `json:"on,omitempty"`
Was string `json:"was-on,omitempty"` Was string `json:"was-on,omitempty"`
Started time.Time `json:"started,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. // 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 a.State = AskDead
if s, ok := current[a.ID]; ok { 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) running = append(running, i)
continue continue
} }
@@ -183,7 +186,7 @@ func ClassifyQueue(asks []QueuedAsk, delivered uint64, ackPending int, heard Bui
for _, i := range group { for _, i := range group {
if slots == 0 { if slots == 0 {
// Past what the worker counts: handed out as often as it may be. // 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 continue
} }
out[i].State = AskInFlight out[i].State = AskInFlight