Builder: keep each build's start and end in its own module log build-log, and answer builder_builds_since from it, so readers and mesh-catalog read the builder's history without a bare stream (issue 1955, ADR 0571 §1, §9)

This commit is contained in:
2026-10-29 23:48:14 +01:00
parent c045057ca0
commit 17c0734fb2
11 changed files with 179 additions and 55 deletions
@@ -26,7 +26,7 @@ type queueAsker func(key string, value []byte) (json.RawMessage, error)
// Tools are the builder's tools: stuck reads, askAgain writes the reasks value, queue writes a queues value and waits for
// the builder's read, buildAgain writes a reasks value of mode build and waits for the builder's answer.
func Tools(r build.StuckReader, askAgain func(key string, value []byte) error, queue, buildAgain queueAsker, now func() time.Time) []stdio.Tool {
func Tools(r build.StuckReader, askAgain func(key string, value []byte) error, queue, buildAgain queueAsker, since build.LogSince, now func() time.Time) []stdio.Tool {
str := func(args map[string]any, k string) string { s, _ := args[k].(string); return strings.TrimSpace(s) }
return []stdio.Tool{
{Name: build.StuckTool,
@@ -94,6 +94,20 @@ func Tools(r build.StuckReader, askAgain func(key string, value []byte) error, q
return map[string]any{"key": key, "revision": r.Revision, "asks": r.Asks, "answer": r.Answer,
"next": build.StuckTool + " shows the key and its asks while they wait"}, nil
}},
{Name: delivery.BuildsSinceTool,
Description: "Every build that ended since a time, oldest first, from the builder's log build-log (kept 30 days): per build its module, " +
"fingerprint, source revision, repository, directory, commit and ref, the build node, when it ended, its outcome (done, failed or " +
"queued), the manifest built, the bases it was built against and each artifact made with its digest and reference. more says the " +
"log held more than one answer carries: ask again from the last build's time. What mesh-catalog registers a build from. Read-only.",
Input: map[string]any{"type": "object", "required": []string{"since"}, "properties": map[string]any{
"since": map[string]any{"type": "string", "description": "RFC 3339 time; the builds that ended at or after it"}}},
Run: func(args map[string]any) (any, error) {
at, err := time.Parse(time.RFC3339Nano, str(args, "since"))
if err != nil {
return nil, fmt.Errorf("since %q is not an RFC 3339 time: %w", str(args, "since"), err)
}
return build.BuildsSince(since, at)
}},
{Name: build.AnnounceAgainTool,
Description: "Announce a done build again (take in again, compose again): the builder writes the done key of module and fingerprint " +
"again, unchanged, as a new revision of the same key (its content, artifacts and manifest stay identical), so the controller's " +
@@ -250,7 +264,7 @@ func main() {
a, err := build.DecodeReAsk(v)
return err == nil && !a.Answered.IsZero()
})
if err := stdio.Serve("", Tools(r, put, askQueue(stdio.State(build.QueuesState), 25*time.Second), buildAgain, time.Now)); err != nil {
if err := stdio.Serve("", Tools(r, put, askQueue(stdio.State(build.QueuesState), 25*time.Second), buildAgain, stdio.Log(delivery.BuilderLog).Since, time.Now)); err != nil {
fmt.Fprintf(os.Stderr, "[mesh-delivery-builder-tools] %v\n", err)
os.Exit(1)
}
@@ -23,6 +23,7 @@ import (
"github.com/nats-io/nats.go/jetstream"
"git.novox.be/novox/mesh-sdk/go/buildstep"
"git.novox.be/novox/mesh-sdk/go/buscompose"
"git.novox.be/novox/mesh-sdk/go/delivery"
"git.novox.be/novox/mesh-sdk/go/process"
@@ -268,6 +269,12 @@ func startBedWith(t *testing.T, closed bool) *bed {
mk(delivery.ManifestsBucket, delivery.ManifestsHistory)
b.builds = mk(delivery.BuilderBuildsBucket, delivery.BuilderBuildsHistory)
b.instances = mk(instancesBucket, 1)
// The builder's module log, as the runtime raises it (ADR 0297): its stream on the log's subjects.
logStream := buscompose.LogStreamName(delivery.BuilderModule, delivery.BuilderLog)
if _, err := js.CreateStream(ctx, jetstream.StreamConfig{Name: logStream, Subjects: []string{buscompose.LogSubject(delivery.BuilderModule, delivery.BuilderLog) + ".>"},
AllowDirect: true}); err != nil {
t.Fatal(err)
}
b.fake = &fakeBuildModules{js: js, ctx: ctx, calls: map[string]int{}}
b.fake.closed.Store(closed)
b.fake.serve(t, "mesh-build-go", "n1", "n2")
@@ -280,6 +287,29 @@ func startBedWith(t *testing.T, closed bool) *bed {
return b
}
// logged is every entry of module's key in the builder's log, read through process.Conn.ReadLog on the controller's user.
func (b *bed) logged(t *testing.T, module string) []delivery.BuildLogEntry {
t.Helper()
conn, err := process.Connect(process.Account{URL: b.srvURL, Module: "mesh-delivery-view", User: "ctl", Password: "pw"})
if err != nil {
t.Fatal(err)
}
defer conn.Close()
entries, err := conn.ReadLog(delivery.BuilderModule, delivery.BuilderLog).Since(time.Unix(0, 0), module)
if err != nil {
t.Fatal(err)
}
var out []delivery.BuildLogEntry
for _, le := range entries {
e, err := delivery.DecodeBuildLogEntry(le.Value)
if err != nil {
t.Fatal(err)
}
out = append(out, e)
}
return out
}
// report writes a node's toolchains key of a build module and says so on the module's stream, as the module does.
func (b *bed) report(t *testing.T, module, node, language, version, recipe string) {
t.Helper()
@@ -406,6 +436,13 @@ func TestBuilderMakesADoneKeyWithTheDigests(t *testing.T) { // 1607/AC7
if v.Toolchains["go"].Version != "go1.27.1" || v.Toolchains["typescript"].Version != "tsc5" {
t.Errorf("toolchains = %+v", v.Toolchains)
}
// 1955/L7 (ADR 0571 §1): the build's start and end are in the module log build-log under the module's key, read as a
// reader with the log's read reads them, the end naming the manifest and what was made.
ended := b.logged(t, "netcheck")
if len(ended) != 2 || ended[0].Event != delivery.BuildStartedEvent || ended[1].Event != delivery.BuildEndedEvent ||
ended[1].Manifest != digest || len(ended[1].Made) != 2 || ended[1].Node != "n1" {
t.Errorf("logged = %+v, want the start and the end of netcheck's build", ended)
}
for tool, want := range map[string]int{"mesh-build-go.build_go_fetch": 1, "mesh-build-go.build_go_build": 1, "mesh-build-node.build_node_fetch": 1, "mesh-build-node.build_node_build": 1} {
if got := b.fake.count(tool); got != want {
t.Errorf("%s called %d times, want %d (on one node, ADR 0478 clause 4)", tool, got, want)
@@ -130,10 +130,10 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro
trunks := &trunkSource{ctx: ctx, js: js, heads: &sourceHeads{}, moved: b.TrunkMoved, errs: errs, logf: logger.Printf}
trunks.start()
b.Trunk = trunks.head
// The builder's log (ADR 0571 §1): each build's start and end, on its own stream, read by the view, the indexer, the
// assigner and mesh-catalog.
// The builder's log (ADR 0571 §1): each build's start and end in its module log `build-log`, read by the view, the
// indexer and the assigner through their reads, and by mesh-catalog through the tool builder_builds_since.
b.Log = func(e delivery.BuildLogEntry) {
if err := emitLog(context.WithoutCancel(ctx), js, cred, e); err != nil {
if err := appendLog(context.WithoutCancel(ctx), js, cred, e); err != nil {
logger.Printf("%v", err)
}
}
@@ -8,6 +8,7 @@ import (
"strings"
"time"
"git.novox.be/novox/mesh-sdk/go/buscompose"
"git.novox.be/novox/mesh-sdk/go/delivery"
"git.novox.be/novox/mesh-sdk/go/process"
"github.com/nats-io/nats.go"
@@ -140,20 +141,21 @@ func announcedAgain(ctx context.Context, b askAgainer, kv jetstream.KeyValue, e
}
}
// emitLog says one entry of the builder's log on its stream `log` (ADR 0571 §1), under an id the stream keeps one of.
func emitLog(ctx context.Context, js jetstream.JetStream, cred process.Account, e delivery.BuildLogEntry) error {
// appendLog appends one entry to the builder's module log `build-log` (ADR 0297, ADR 0571 §1) under the module's key
// (delivery.BuildLogKey), on the log's own subject: a module's program appends to the logs it keeps on its own credential.
// The id makes a repeated append of one entry one entry.
func appendLog(ctx context.Context, js jetstream.JetStream, cred process.Account, e delivery.BuildLogEntry) error {
data, err := delivery.EncodeBuildLogEntry(e)
if err != nil {
return err
}
msg := nats.NewMsg(process.ModuleStreamSubject(cred.Module, e.Event))
id := e.Event + "." + e.Module + "." + e.FP + "." + e.At.Format(time.RFC3339Nano)
msg.Header.Set("x-event-id", id)
msg.Header.Set("x-source", cred.Module)
msg.Header.Set("x-node", cred.Node)
msg.Header.Set("x-time", e.At.Format(time.RFC3339Nano))
msg.Header.Set("content-type", "application/json")
key, err := delivery.BuildLogKey(e.Module)
if err != nil {
return err
}
msg := nats.NewMsg(buscompose.LogSubject(cred.Module, delivery.BuilderLog) + "." + key)
msg.Data = data
id := e.Event + "." + e.Module + "." + e.FP + "." + e.At.Format(time.RFC3339Nano)
pub, cancel := context.WithTimeout(ctx, 10*time.Second)
defer cancel()
if _, err := js.PublishMsg(pub, msg, jetstream.WithMsgID(id)); err != nil {
+1 -1
View File
@@ -3,7 +3,7 @@ module mesh-delivery-builder
go 1.26.0
require (
git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261029220947-f9a496d3e121
git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261029222821-bb993dd60641
github.com/nats-io/nats-server/v2 v2.11.17
github.com/nats-io/nats.go v1.54.0
)
+2 -2
View File
@@ -1,5 +1,5 @@
git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261029220947-f9a496d3e121 h1:OsA1v6n736a7RqEV8Nkip8pf5ILMbzj0PWuKqcBOhK0=
git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261029220947-f9a496d3e121/go.mod h1:ouERNpZizzwZ0HLEtAypsY9FR20FyUgUYRni6J7kVCY=
git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261029222821-bb993dd60641 h1:nP/jrjm2Qt1wdmd1Bc+E6c4+PobAzW5o64SPArE+jaw=
git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261029222821-bb993dd60641/go.mod h1:ouERNpZizzwZ0HLEtAypsY9FR20FyUgUYRni6J7kVCY=
github.com/antithesishq/antithesis-sdk-go v0.7.0-default-no-op h1:Z/MZK75wC/NSrkgqeNIa7jexam9uWzhLmFTSCPI/kn0=
github.com/antithesishq/antithesis-sdk-go v0.7.0-default-no-op/go.mod h1:FQyySiasQQM8735Ddel3MRojmy4dA1IqCeyJ5jmPMbI=
github.com/google/go-tpm v0.9.8 h1:slArAR9Ft+1ybZu0lBwpSmpwhRXaa85hWtMinMyRAWo=
@@ -435,7 +435,7 @@ func (b *Builder) try(ctx context.Context, module string, m delivery.Module) {
return
}
b.handClaimed(key, cl.Rev)
b.logBuild(LogStarted(module, m, b.Node, b.now()))
b.logBuild(LogStarted(module, m, b.refOf(module, m.FP2), b.Node, b.now()))
if cl.Unasked != nil {
b.logf("%v", cl.Unasked)
}
@@ -485,7 +485,7 @@ func (b *Builder) try(ctx context.Context, module string, m delivery.Module) {
b.logf("%s: the build could not be written: %v", cl.Key, err)
return
}
b.logBuild(LogEnded(module, m, b.Node, b.now(), result))
b.logBuild(LogEnded(module, m, b.refOf(module, m.FP2), b.Node, b.now(), result))
if result.State == delivery.BuildFailed {
b.logf("%s: failed: %s", cl.Key, result.Error)
}
@@ -900,23 +900,40 @@ func (b *Builder) logBuild(e delivery.BuildLogEntry) {
b.Log(e)
}
// LogStarted is the log's entry of a build of module's fingerprint starting (ADR 0571 §1): the module, the fingerprint, the
// source revision, where it is built from (repository, directory, commit), the node of the builder that asked it and the time.
func LogStarted(module string, m delivery.Module, by string, at time.Time) delivery.BuildLogEntry {
dir := m.Path
if dir == "" {
dir = "."
// refOf is the ref a candidate's build of module's fingerprint is built for, "" for the trunk's.
func (b *Builder) refOf(module, fp string) string {
key, err := delivery.BuilderBuildKey(module, fp)
if err != nil {
return ""
}
return delivery.BuildLogEntry{Event: delivery.BuildStartedEvent, Module: module, FP: m.FP2, Source: strconv.FormatUint(m.Src, 10),
Repository: m.Repository, Directory: dir, Commit: m.Commit, Node: by, At: at.UTC()}
b.mu.Lock()
defer b.mu.Unlock()
return b.via[key].Ref
}
// LogEnded is the log's entry of that build ending: the outcome (done, failed or queued) and each artifact's digest.
func LogEnded(module string, m delivery.Module, by string, at time.Time, result delivery.BuilderBuild) delivery.BuildLogEntry {
e := LogStarted(module, m, by, at)
e.Event, e.Outcome = delivery.BuildEndedEvent, result.State
for _, a := range result.Artifacts {
e.Artifacts = append(e.Artifacts, delivery.BuiltDigest{Name: a.Name, Digest: a.Digest})
// LogStarted is the log's entry of a build of module's fingerprint starting (ADR 0571 §1): the module, the fingerprint, the
// source revision, where it is built from (repository, directory, commit, the candidate's ref), the node of the builder
// that asked it and the time.
func LogStarted(module string, m delivery.Module, ref, by string, at time.Time) delivery.BuildLogEntry {
dir := m.Path
if dir == "" {
dir = delivery.RootPath
}
return delivery.BuildLogEntry{Event: delivery.BuildStartedEvent, Module: module, FP: m.FP2, Source: strconv.FormatUint(m.Src, 10),
Repository: m.Repository, Directory: dir, Commit: m.Commit, Ref: ref, Node: by, At: at.UTC()}
}
// LogEnded is the log's entry of that build ending: the outcome (done, failed or queued), the manifest built, the bases it
// was built against and each artifact made, as the done key has them: what mesh-catalog registers a build from.
func LogEnded(module string, m delivery.Module, ref, by string, at time.Time, result delivery.BuilderBuild) delivery.BuildLogEntry {
e := LogStarted(module, m, ref, by, at)
e.Event, e.Outcome, e.Manifest = delivery.BuildEndedEvent, result.State, m.Manifest
if result.Manifest != "" {
e.Manifest = result.Manifest
}
if m.Inputs2 != nil {
e.Against = append([]string(nil), m.Inputs2.Bases...)
}
e.Made = append([]delivery.BuiltArtifact(nil), result.Artifacts...)
return e
}
@@ -5,7 +5,6 @@ import (
"encoding/json"
"errors"
"fmt"
"git.novox.be/novox/mesh-sdk/go/delivery/buildrun"
"strconv"
"strings"
"sync"
@@ -13,9 +12,11 @@ import (
"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/catalogue"
"git.novox.be/novox/mesh-sdk/go/delivery"
"git.novox.be/novox/mesh-sdk/go/delivery/buildrun"
)
// buildModules simulates the two build modules on the nodes: a long tool answers a step and key at once and writes the
@@ -228,7 +229,8 @@ func TestABundleAndAnArchiveAreBuiltOnOneNodeAndDone(t *testing.T) { // 1607/AC7
// 1955/L7 (ADR 0571 §1): the build is one start and one end in the builder's log, every field named, its duration read
// from the two.
if len(logged) != 2 || logged[0].Event != delivery.BuildStartedEvent || logged[1].Event != delivery.BuildEndedEvent ||
logged[1].Outcome != delivery.BuildDone || len(logged[1].Artifacts) != 3 || logged[0].Repository != "novox/mesh-catalog" ||
logged[1].Outcome != delivery.BuildDone || len(logged[1].Made) != 3 || logged[1].Made[0].Reference == "" ||
logged[1].Manifest != manifestD || logged[0].Manifest != "" || logged[0].Repository != "novox/mesh-catalog" ||
logged[0].Directory != "modules/m" || logged[0].Commit != "7a74cee83f88e6585a5511c3cc53bdf0f5303d20" || logged[0].Node != "novox" ||
logged[0].FP != fp1 || logged[0].Module != "m" {
t.Fatalf("logged = %+v", logged)
@@ -241,6 +243,21 @@ func TestABundleAndAnArchiveAreBuiltOnOneNodeAndDone(t *testing.T) { // 1607/AC7
if _, ok := delivery.BuildDuration(logged[0], logged[1]); !ok {
t.Error("no duration from the two entries")
}
// builder_builds_since (ADR 0571 clause 9) answers the end alone from the log's page, and says when the log holds more.
var page stdio.LogPage
for i, e := range logged {
raw, _ := delivery.EncodeBuildLogEntry(e)
page.Entries = append(page.Entries, stdio.LogEntry{Sequence: uint64(i + 1), Key: e.Module, Value: raw, At: e.At})
}
page.Next = 3
since, err := BuildsSince(func(time.Time, string, int) (*stdio.LogPage, error) { return &page, nil }, logged[0].At)
if err != nil || len(since.Builds) != 1 || since.Builds[0].Event != delivery.BuildEndedEvent || len(since.Builds[0].Made) != 3 || !since.More {
t.Errorf("builds since = %+v, %v, want the one end and more", since, err)
}
page.Entries[0].Value = []byte(`{"v":0}`)
if _, err := BuildsSince(func(time.Time, string, int) (*stdio.LogPage, error) { return &page, nil }, logged[0].At); err == nil {
t.Error("an entry that does not read was skipped, want it refused")
}
if v.State != delivery.BuildDone || v.By != "novox.builder" || v.Manifest != manifestD || len(v.Artifacts) != 3 {
t.Fatalf("build = %+v, want done by novox.builder with three artifacts", v)
}
@@ -0,0 +1,43 @@
package build
import (
"fmt"
"time"
stdio "git.novox.be/novox/mesh-sdk/go"
"git.novox.be/novox/mesh-sdk/go/delivery"
)
// BuildsSinceLimit is how many entries one answer of BuildsSinceTool reads of the log; More says the log held more.
const BuildsSinceLimit = 500
// LogSince is one page of the builder's log from a time on: stdio.Log(BuilderLog).Since.
type LogSince func(at time.Time, keys string, limit int) (*stdio.LogPage, error)
// BuildsSince answers delivery.BuildsSinceTool (ADR 0571 clause 9): every ended build in the builder's log from since on,
// oldest first, read through the runtime's log verbs; More when the page was not the log's last, so the caller asks again
// from the last build's time. An entry the log holds that does not read is refused, naming its sequence: a reader that
// skipped it would register too little.
func BuildsSince(read LogSince, since time.Time) (delivery.BuildsSince, error) {
out := delivery.BuildsSince{Since: since.UTC(), Builds: []delivery.BuildLogEntry{}}
page, err := read(since, "", BuildsSinceLimit)
if err != nil {
return out, fmt.Errorf("the builder's log %s from %s: %w", delivery.BuilderLog, since.Format(time.RFC3339), err)
}
if page == nil {
return out, nil
}
var entries []delivery.BuildLogEntry
for _, le := range page.Entries {
e, err := delivery.DecodeBuildLogEntry(le.Value)
if err != nil {
return out, fmt.Errorf("the builder's log %s, entry %d: %w", delivery.BuilderLog, le.Sequence, err)
}
entries = append(entries, e)
}
if ended := delivery.EndedSince(entries, since); ended != nil {
out.Builds = ended
}
out.More = page.Next != 0
return out, nil
}
+11 -11
View File
@@ -10,6 +10,8 @@ import (
"slices"
"strings"
"testing"
"git.novox.be/novox/mesh-sdk/go/delivery"
)
// The controller's manifest reader is mesh-controller internal/catalogue (Manifest, manifest.go: Consumes :521,
@@ -40,11 +42,10 @@ type manifest struct {
Emits []string `json:"emits"`
Consumes []string `json:"consumes"`
State []state `json:"state"`
Streams []struct {
Name string `json:"name"`
Events []string `json:"events"`
MaxAgeDays int `json:"max-age-days"`
} `json:"streams"`
Logs []struct {
Name string `json:"name"`
MaxAgeDays int `json:"max-age-days"`
} `json:"logs"`
Reads []string `json:"reads"`
Uses []string `json:"uses"`
Invokes []string `json:"invokes"`
@@ -123,18 +124,17 @@ func TestManifestDeclarations(t *testing.T) { // 1607/AC1
t.Errorf("secrets-owner = %q", m.SecretsOwner)
}
// 1945: the builder's tools (builder_seat_queue: note 62), served by its tools bundle, and the event it says when it asks an ask again.
if want := []string{"builder_announce_again", "builder_ask_again", "builder_build_again", "builder_seat_queue", "builder_stuck"}; !reflect.DeepEqual(sorted(m.Tools), want) {
if want := []string{"builder_announce_again", "builder_ask_again", "builder_build_again", "builder_builds_since", "builder_seat_queue", "builder_stuck"}; !reflect.DeepEqual(sorted(m.Tools), want) {
t.Errorf("tools = %v, want %v", m.Tools, want)
}
if want := []string{"build.asked-again"}; !reflect.DeepEqual(m.Emits, want) {
t.Errorf("emits = %v, want %v", m.Emits, want)
}
// 1955/L7 (ADR 0571 §1): its log, each build's start and end, kept 30 days.
if len(m.Streams) != 1 || m.Streams[0].Name != "log" || m.Streams[0].MaxAgeDays != 30 ||
!reflect.DeepEqual(m.Streams[0].Events, []string{"build.started", "build.ended"}) {
t.Errorf("streams = %+v, want the log", m.Streams)
// 1955/L7 (ADR 0571 §1): its module log, each build's start and end, kept 30 days; no bare stream.
if len(m.Logs) != 1 || m.Logs[0].Name != delivery.BuilderLog || m.Logs[0].MaxAgeDays != delivery.BuilderLogDays {
t.Errorf("logs = %+v, want %s kept %d days", m.Logs, delivery.BuilderLog, delivery.BuilderLogDays)
}
for _, k := range []string{"logs", "claims", "provides", "requires", "defines-seats", "seat", "seats", "bus", "config"} {
for _, k := range []string{"streams", "claims", "provides", "requires", "defines-seats", "seat", "seats", "bus", "config"} {
if _, ok := top[k]; ok {
t.Errorf("the manifest declares %q: the builder has none", k)
}
+3 -9
View File
@@ -6,6 +6,7 @@
"builder_announce_again",
"builder_ask_again",
"builder_build_again",
"builder_builds_since",
"builder_seat_queue",
"builder_stuck"
],
@@ -29,15 +30,8 @@
{ "name": "queues", "history": 1 },
{ "name": "reasks", "history": 1 }
],
"streams": [
{
"name": "log",
"events": [
"build.started",
"build.ended"
],
"max-age-days": 30
}
"logs": [
{ "name": "build-log", "max-age-days": 30 }
],
"reads": [
"mesh-build-go.steps",