diff --git a/cmd/mesh-control/main.go b/cmd/mesh-control/main.go index 3613f2c..9587b0d 100644 --- a/cmd/mesh-control/main.go +++ b/cmd/mesh-control/main.go @@ -65,6 +65,8 @@ func run() error { switch args[0] { case "build": return buildCommand(ctx, args[1:]) + case "builds": + return buildsCommand(ctx, args[1:]) case "pin": return pinCommand(ctx, args[1:], true) case "unpin": @@ -134,6 +136,7 @@ func usage() { settings set --node ...or for one machine settings clear [--node ] take a layer away build [--ref R] have a build machine build it, and record what came out + builds [] what has been built lately, and what came of it pin which node this one gets a provision from unpin put that question back plan [--files|--json] what that node would run, and why @@ -490,6 +493,9 @@ func serve(ctx context.Context) error { return err } defer server.Close() + // And build results nobody was waiting for. A build triggered any other way than `build` + // would otherwise be reported into the void, which is the same as not reporting it. + server.Records(builds{inv}) return server.Serve(ctx) } @@ -1711,6 +1717,19 @@ func buildCommand(ctx context.Context, args []string) error { if err != nil { return err } + + // Kept before it is judged. A failed build that leaves no trace is indistinguishable from one + // nobody asked for, and the difference is the whole of whether somebody should be looking at + // something. + inv, err := openInventory(ctx) + if err != nil { + return err + } + defer inv.Close() + if err := inv.RecordBuild(ctx, buildFrom(result)); err != nil { + return err + } + if result.Failed != "" { // The builder's own words. Wrapping them in something about the control plane would put // two explanations between a person and a build log. @@ -1738,12 +1757,6 @@ func buildCommand(ctx context.Context, args []string) error { return nil } - inv, err := openInventory(ctx) - if err != nil { - return err - } - defer inv.Close() - // Recorded with where it came from, so "is this current?" is answerable without building it // again (novox/hq ADR 0009). if err := inv.RegisterModule(ctx, manifest, inventory.Source{ @@ -1757,3 +1770,108 @@ func buildCommand(ctx context.Context, args []string) error { fmt.Printf(" run `assign %s` to put it somewhere\n", manifest.Module) return nil } + +// buildFrom turns what a builder said into what the mesh keeps. +func buildFrom(result link.BuildResult) inventory.Build { + kept := inventory.Build{ + ID: result.ID, Repository: result.Repository, Ref: result.Ref, + Commit: result.Commit, On: result.On, Failed: result.Failed, + } + for _, made := range result.Made { + kept.Made = append(kept.Made, inventory.Artifact{ + Name: made.Name, Kind: made.Kind, Reference: made.Reference, + }) + } + // The module name comes from the manifest, which only exists when the build got that far. + if len(result.Manifest) > 0 { + if m, err := catalogue.ParseManifest(result.Manifest); err == nil { + kept.Module = m.Module + } + } + return kept +} + +// buildsCommand says what has been built lately. +func buildsCommand(ctx context.Context, args []string) error { + set := flag.NewFlagSet("builds", flag.ContinueOnError) + limit := set.Int("n", 20, "how many to show") + positionals, err := parseAround(set, args) + if err != nil { + return err + } + module := "" + if len(positionals) == 1 { + module = positionals[0] + } else if len(positionals) > 1 { + return errors.New("builds [] [-n N]") + } + + inv, err := openInventory(ctx) + if err != nil { + return err + } + defer inv.Close() + + builds, err := inv.Builds(ctx, module, *limit) + if err != nil { + return err + } + if len(builds) == 0 { + // Said rather than printed as nothing: an empty list and a failed read must never look + // the same, and getting here means the store answered. + if module != "" { + fmt.Printf("nothing has been built for %s\n", module) + return nil + } + fmt.Println("nothing has been built yet") + return nil + } + + for _, b := range builds { + what := b.Module + if what == "" { + // It failed before knowing what it was building, which is most of the interesting + // failures. The repository is what a person has to go and look at. + what = "?" + } + outcome := "built " + short(b.Commit) + if !b.Worked() { + outcome = "failed" + } + fmt.Printf("%-18s %-14s %-10s %s\n", + what, outcome, b.On, b.At.Local().Format("2006-01-02 15:04")) + fmt.Printf(" %s", b.Repository) + if b.Ref != "" { + fmt.Printf(" at %s", b.Ref) + } + fmt.Println() + for _, made := range b.Made { + fmt.Printf(" %-10s %s\n", made.Kind, made.Reference) + } + if !b.Worked() { + // The builder's own first line. The whole failure is often a build log, and printing + // it here would bury every other row. + fmt.Printf(" %s\n", firstLine(b.Failed)) + } + } + return nil +} + +// firstLine is as much of a failure as belongs in a list. +func firstLine(s string) string { + if cut := strings.IndexByte(s, '\n'); cut >= 0 { + return strings.TrimSpace(s[:cut]) + } + return strings.TrimSpace(s) +} + +// builds keeps what a builder said, for the serving control plane. +// +// A type of its own rather than a method on the enrolment, because they are unrelated things +// arriving on one queue and an implementation of one should not have to say anything about the +// other. +type builds struct{ inv *inventory.Inventory } + +func (b builds) Built(ctx context.Context, result link.BuildResult) error { + return b.inv.RecordBuild(ctx, buildFrom(result)) +} diff --git a/internal/inventory/builds.go b/internal/inventory/builds.go new file mode 100644 index 0000000..83fe1d7 --- /dev/null +++ b/internal/inventory/builds.go @@ -0,0 +1,102 @@ +package inventory + +import ( + "context" + "encoding/json" + "time" +) + +// What has been built. +// +// A build result was answered to whoever asked and kept nowhere, so "when did this last build", +// "why did it fail" and "which machine built what is running" had no answer. Failures are recorded +// too: one that leaves no trace is indistinguishable from a build nobody asked for, and the +// difference is the whole of whether somebody should be looking at something. + +// Build is one attempt, whichever way it went. +type Build struct { + ID string + Repository string + Ref string + // Module is empty for a build that failed before it knew what it was building. + Module string + Commit string + // On is the machine that did it. + On string + // Failed is the builder's own words, empty when it worked. + Failed string + Made []Artifact + At time.Time +} + +// Artifact is one thing a build published. +type Artifact struct { + Name string `json:"name"` + Kind string `json:"kind"` + Reference string `json:"reference"` +} + +// Worked reports whether this build produced something. +func (b Build) Worked() bool { return b.Failed == "" } + +// RecordBuild keeps what a builder said. +// +// Idempotent on the correlation id, because a result can arrive twice: once as the answer to +// whoever asked and once on the exchange when nobody was. Recording both would show one build as +// two, and which of the two is real is not a question anybody could answer afterwards. +func (i *Inventory) RecordBuild(ctx context.Context, b Build) error { + made, err := json.Marshal(b.Made) + if err != nil { + return err + } + var module *string + if b.Module != "" { + module = &b.Module + } + _, err = i.store.Pool().Exec(ctx, + `insert into build (id, repository, ref, module, commit_hash, built_on, failed, made) + values ($1, $2, $3, $4, $5, $6, $7, $8) + on conflict (id) do nothing`, + b.ID, b.Repository, b.Ref, module, b.Commit, b.On, b.Failed, made) + return err +} + +// Builds is what has happened lately, newest first. +// +// For one module when named, or across the mesh when not. Both are asked: *what happened just +// now* after something goes wrong, and *what has happened to this* when deciding whether to +// trust it. +func (i *Inventory) Builds(ctx context.Context, module string, limit int) ([]Build, error) { + if limit <= 0 { + limit = 20 + } + query := `select id, repository, ref, coalesce(module,''), commit_hash, built_on, failed, made, at + from build order by at desc limit $1` + args := []any{limit} + if module != "" { + query = `select id, repository, ref, coalesce(module,''), commit_hash, built_on, failed, made, at + from build where module = $2 order by at desc limit $1` + args = append(args, module) + } + + rows, err := i.store.Pool().Query(ctx, query, args...) + if err != nil { + return nil, err + } + defer rows.Close() + + var out []Build + for rows.Next() { + var b Build + var made []byte + if err := rows.Scan(&b.ID, &b.Repository, &b.Ref, &b.Module, &b.Commit, + &b.On, &b.Failed, &made, &b.At); err != nil { + return nil, err + } + if err := json.Unmarshal(made, &b.Made); err != nil { + return nil, err + } + out = append(out, b) + } + return out, rows.Err() +} diff --git a/internal/inventory/builds_test.go b/internal/inventory/builds_test.go new file mode 100644 index 0000000..27de62c --- /dev/null +++ b/internal/inventory/builds_test.go @@ -0,0 +1,138 @@ +package inventory + +import ( + "context" + "strings" + "testing" +) + +// A build result was answered to whoever asked and kept nowhere, so "when did this last build", +// "why did it fail" and "which machine built what is running" had no answer at all. + +func aBuild(id, module, failed string) Build { + b := Build{ + ID: id, Repository: "https://forge.invalid/" + strings.TrimSuffix(module, "?") + ".git", + Module: module, On: "a-build-machine", Failed: failed, + } + if failed == "" { + b.Commit = "c0ffee" + id + b.Made = []Artifact{{Name: "config", Kind: "archive", Reference: "…/blobs/sha256:…"}} + } + return b +} + +func TestAFailedBuildIsARowLikeAnyOther(t *testing.T) { + // One that leaves no trace is indistinguishable from a build nobody asked for, and the + // difference is the whole of whether somebody should be looking at something. + inv := fresh(t) + ctx := context.Background() + if err := inv.RecordBuild(ctx, aBuild("1", "", "cannot clone: no such repository")); err != nil { + t.Fatal(err) + } + got, err := inv.Builds(ctx, "", 10) + if err != nil { + t.Fatal(err) + } + if len(got) != 1 { + t.Fatalf("got %d builds", len(got)) + } + if got[0].Worked() { + t.Fatal("a failure was recorded as a success") + } + if !strings.Contains(got[0].Failed, "no such repository") { + t.Fatalf("the builder's own words were not kept: %q", got[0].Failed) + } + // And it kept what was asked for, which is the only thing a person can go and look at when + // the build never learned what it was building. + if got[0].Module != "" || got[0].Repository == "" { + t.Fatalf("got %+v", got[0]) + } +} + +func TestOneResultRecordedTwiceIsOneBuild(t *testing.T) { + // A result can arrive twice: as the answer to whoever asked, and on the exchange when nobody + // was. Two rows would show one build as two, and which is real is not answerable afterwards. + inv := fresh(t) + ctx := context.Background() + for i := 0; i < 2; i++ { + if err := inv.RecordBuild(ctx, aBuild("same", "shell", "")); err != nil { + t.Fatal(err) + } + } + got, err := inv.Builds(ctx, "", 10) + if err != nil { + t.Fatal(err) + } + if len(got) != 1 { + t.Fatalf("one build was recorded %d times", len(got)) + } +} + +func TestBuildsComeBackNewestFirstAndCanBeAskedPerModule(t *testing.T) { + inv := fresh(t) + ctx := context.Background() + for _, b := range []Build{ + aBuild("1", "shell", ""), + aBuild("2", "meshboard", ""), + aBuild("3", "shell", "the tests failed"), + } { + if err := inv.RecordBuild(ctx, b); err != nil { + t.Fatal(err) + } + } + + all, err := inv.Builds(ctx, "", 10) + if err != nil { + t.Fatal(err) + } + if len(all) != 3 || all[0].ID != "3" { + t.Fatalf("newest is not first: %v", ids(all)) + } + + // Per module, because "what has happened to this" is asked when deciding whether to trust it. + shell, err := inv.Builds(ctx, "shell", 10) + if err != nil { + t.Fatal(err) + } + if len(shell) != 2 { + t.Fatalf("shell has %d builds: %v", len(shell), ids(shell)) + } + for _, b := range shell { + if b.Module != "shell" { + t.Fatalf("asked for shell and got %q", b.Module) + } + } +} + +func TestWhatWasPublishedIsKeptWithTheBuild(t *testing.T) { + // So a digest can be traced back to the build that made it, without keeping the manifest a + // second time in a place that can disagree with the first. + inv := fresh(t) + ctx := context.Background() + if err := inv.RecordBuild(ctx, aBuild("1", "shell", "")); err != nil { + t.Fatal(err) + } + got, _ := inv.Builds(ctx, "", 10) + if len(got[0].Made) != 1 || got[0].Made[0].Kind != "archive" { + t.Fatalf("what was published was not kept: %+v", got[0].Made) + } +} + +func TestAskingForMoreThanThereIsIsNotAnError(t *testing.T) { + inv := fresh(t) + got, err := inv.Builds(context.Background(), "", 100) + if err != nil { + t.Fatal(err) + } + if len(got) != 0 { + t.Fatalf("got %d", len(got)) + } +} + +func ids(builds []Build) []string { + var out []string + for _, b := range builds { + out = append(out, b.ID) + } + return out +} diff --git a/internal/inventory/migrations/0010-builds.sql b/internal/inventory/migrations/0010-builds.sql new file mode 100644 index 0000000..b7d982f --- /dev/null +++ b/internal/inventory/migrations/0010-builds.sql @@ -0,0 +1,44 @@ +-- What has been built, and what came of it. +-- +-- A build result is answered to whoever asked and, until this, kept nowhere. So "when did this +-- module last build", "why did it fail", and "which machine built what is running" had no answer +-- at all -- and a build nobody was waiting for was reported into the void. +-- +-- **Failures are rows too.** A failed build that leaves no trace is indistinguishable from one +-- nobody asked for, and the difference is the whole of whether somebody should be looking at +-- something. This is the same rule the host follows about a service that does not exist. + +create table build ( + -- The correlation the control plane made when it asked. Not the module name: two builds of + -- one module can be in flight, and one is not the other. + id text primary key, + + -- What was asked for. Kept even when the build failed before knowing what the module is + -- called, which is most of the interesting failures. + repository text not null, + ref text not null default '', + + -- What came of it. `module` and `commit` are empty for a build that never got that far. + module text, + commit_hash text not null default '', + + -- The machine that did it, so a failure about one machine can be told from one about the + -- source. Not a foreign key to node: a build machine need not be a node the mesh manages, + -- and a record that vanished when it stopped being one would lose the history. + built_on text not null default '', + + -- Empty when it worked. The builder's own words, because anything this end wrote instead + -- would put a second explanation between a person and a build log. + failed text not null default '', + + -- What was published, as [{name, kind, reference}]. Kept so a digest can be traced back to + -- the build that made it without keeping the manifest twice. + made jsonb not null default '[]', + + at timestamptz not null default now() +); + +-- The two questions asked of this table: what happened lately, and what has happened to this +-- module. Neither is answerable quickly by scanning once there is a year of them. +create index build_lately on build (at desc); +create index build_by_module on build (module, at desc) where module is not null; diff --git a/internal/link/serve.go b/internal/link/serve.go index aeff2e4..74b0f8c 100644 --- a/internal/link/serve.go +++ b/internal/link/serve.go @@ -33,14 +33,32 @@ type Listener interface { Heard(ctx context.Context, report Report) error } +// Recorder keeps what builders say. +// +// Separate from Listener because they are different things arriving: a report is a node saying +// what it did with a declaration, and a build result is a machine saying what came of some work. +// One interface carrying both would mean an implementation of one having to say something about +// the other. +type Recorder interface { + Built(ctx context.Context, result BuildResult) error +} + type Server struct { conn *amqp.Connection channel *amqp.Channel enroller Enroller listener Listener + recorder Recorder log *log.Logger } +// Records tells the server where to keep build results. +// +// Set after Connect rather than passed to it, because a control plane that only publishes — the +// `build` command, which waits for its own answer — needs a connection and no recorder, and +// making it supply one would have it construct something it never uses. +func (s *Server) Records(r Recorder) { s.recorder = r } + // Connect opens the control plane's own connection to the broker. func Connect(enroller Enroller, listener Listener) (*Server, error) { url := strings.TrimSpace(os.Getenv(AMQPVar)) @@ -78,7 +96,7 @@ func Connect(enroller Enroller, listener Listener) (*Server, error) { // accepts, finds no queue for, and drops — the publisher sees success and the consumer sees // nothing. That is exactly what happened to reports: `report` was left unbound while `enrol` // worked, so nodes announced what they had applied into a void for an afternoon. - for _, key := range []string{KeyEnrol, KeyReport, KeyAlive} { + for _, key := range []string{KeyEnrol, KeyReport, KeyAlive, KeyBuilt} { if err := channel.QueueBind(ControlQueue, key, Exchange, false, nil); err != nil { conn.Close() return nil, fmt.Errorf("cannot bind %s to %s/%s: %w", ControlQueue, Exchange, key, err) @@ -121,7 +139,8 @@ func (s *Server) Serve(ctx context.Context) error { } closed := s.conn.NotifyClose(make(chan *amqp.Error, 1)) - s.log.Printf("consuming %s, bound to %s/{%s,%s,%s}", ControlQueue, Exchange, KeyEnrol, KeyReport, KeyAlive) + s.log.Printf("consuming %s, bound to %s/{%s,%s,%s,%s}", + ControlQueue, Exchange, KeyEnrol, KeyReport, KeyAlive, KeyBuilt) for { select { @@ -149,6 +168,8 @@ func (s *Server) handle(ctx context.Context, delivery amqp.Delivery) { s.handleReport(delivery) case KeyAlive: s.handleAlive(delivery) + case KeyBuilt: + s.handleBuilt(ctx, delivery) default: // Rejected without requeue: a message nothing understands will not be understood on the // next attempt either, and requeuing it would spin. @@ -255,3 +276,36 @@ func (s *Server) reply(ctx context.Context, delivery amqp.Delivery, reply EnrolR s.log.Printf("cannot reply to %s: %v", delivery.ReplyTo, err) } } + +// handleBuilt keeps what a builder said, whichever way it went. +// +// This is for results nobody was waiting for. A build asked for with `build` is answered directly +// to the asker; one triggered any other way is published here, and without this it would be +// reported into the void — which is the same as not reporting it. +func (s *Server) handleBuilt(ctx context.Context, delivery amqp.Delivery) { + var result BuildResult + if err := json.Unmarshal(delivery.Body, &result); err != nil { + s.log.Printf("a build result could not be read: %v", err) + _ = delivery.Reject(false) + return + } + if s.recorder == nil { + // Nothing to keep it in. Rejected rather than dropped silently, so the broker's own + // counters show something arriving that nothing handles. + s.log.Printf("a build result arrived and this control plane keeps none") + _ = delivery.Reject(false) + return + } + if err := s.recorder.Built(ctx, result); err != nil { + s.log.Printf("cannot keep a build result from %s: %v", result.On, err) + _ = delivery.Reject(false) + return + } + switch { + case result.Failed != "": + s.log.Printf("%s could not build %s", result.On, result.Repository) + default: + s.log.Printf("%s built %s from %s", result.On, result.Repository, result.Commit) + } + _ = delivery.Ack(false) +}