From bb1607e424d3cb26e36ad0324ad698de7f4dc8da Mon Sep 17 00:00:00 2001 From: jochen Date: Tue, 6 Oct 2026 10:18:47 +0200 Subject: [PATCH] Say when the mesh is wrong: conditions, watchdogs, the bus's advisories, doctor (hq to-be 45 Phase 1) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Every one of the 48 core failures of research 031 was found by a person looking; the mesh's answers carried the fact for whoever asked and told nobody. - The condition store (to-be 45 §2): mesh-controller_conditions, one key per open condition, written by compare-and-set so a person's silence and the watchdogs never lose each other's word; every transition kept ninety days in mesh-controller_condition-history and said as the seat's events condition-raised / condition-changed / condition-cleared (the condition at the top level, with event, at, change, why, show), offered again while the bus is away. Raised and cleared by observation only; a clearing reopened within ten minutes is the same condition with its count up, its silence kept. Verbs: conditions, conditions show, conditions silence (a hand act, at most a week), conditions history. - ADR 0224's provider standing is the first kind, provider-failing, held by the provider's events; the provider_standing table is no longer read or written (left in place: dropping it is the operator's word). - status leads with the open conditions, urgent first, and says all well only with none open; conditions it cannot read are said and not well. - The signals table compiled in, one watchdog loop over it every 30s: S1 heartbeat (3 intervals, asleep machines excepted, control node urgent after 30 min), S2 report after a send, S3 plan tier, S4 event loop deaf, S5 merge not acted, S6 ask lost, S7 call hung, S8 provider silent, S9 advisories, S10 self-check silent, S11 node tools silent, S13 stale refusals; S12, S14, S15 deferred with their reasons. A row that cannot see raises probe-failed and clears nothing. A test generated from the table suppresses each signal inside and past its bound. - The bus's advisories (maximum deliveries, a mesh consumer deleted) and the controller's own slow consumer and refused subjects, said in the mesh's words. - doctor: the probe registry D1-D10 (D5 deferred) and DW, every five minutes, each in thirty seconds; a probe that cannot run is never a pass. D1 validates with mesh-host's own validator. Every run ends with the doctor-heartbeat event mesh-watcher listens for. - The controller is granted its new buckets, events, the two advisories and $SRV.INFO; the node tools their tools-alive heartbeat. The streams and consumers the controller asserts and the ones D6/D7 expect are one derivation. --- cmd/mesh-controller/build.go | 10 +- cmd/mesh-controller/busobjects.go | 104 +++ cmd/mesh-controller/conditions.go | 431 +++++++++++ cmd/mesh-controller/conditions_test.go | 107 +++ cmd/mesh-controller/doctor.go | 514 +++++++++++++ cmd/mesh-controller/doctor_test.go | 347 +++++++++ cmd/mesh-controller/main.go | 12 + cmd/mesh-controller/mesh_for_test.go | 20 + cmd/mesh-controller/missed_merges.go | 58 ++ cmd/mesh-controller/nodes.go | 22 +- cmd/mesh-controller/probes.go | 764 +++++++++++++++++++ cmd/mesh-controller/push.go | 52 +- cmd/mesh-controller/readable.go | 22 +- cmd/mesh-controller/seatverbs.go | 65 +- cmd/mesh-controller/seatverbs_schema_test.go | 5 +- cmd/mesh-controller/signals.go | 485 ++++++++++++ cmd/mesh-controller/signals_test.go | 275 +++++++ cmd/mesh-controller/standing.go | 201 +++-- cmd/mesh-controller/standing_test.go | 67 +- cmd/mesh-controller/status.go | 28 +- cmd/mesh-controller/status_summary.go | 5 + cmd/mesh-controller/watchdogs.go | 549 +++++++++++++ go.mod | 8 +- go.sum | 2 + internal/broker/controller_buckets.go | 49 +- internal/broker/controller_buckets_test.go | 30 + internal/broker/nats.go | 15 +- internal/broker/states_agreement_test.go | 8 +- internal/broker/streams.go | 18 +- internal/broker/testdata/composed.conf | 4 +- internal/catalogue/seats.go | 4 +- internal/catalogue/verbs.go | 27 + internal/conditions/bus.go | 159 ++++ internal/conditions/bus_test.go | 117 +++ internal/conditions/condition.go | 232 ++++++ internal/conditions/events.go | 73 ++ internal/conditions/memory.go | 147 ++++ internal/conditions/store.go | 502 ++++++++++++ internal/conditions/store_test.go | 379 +++++++++ internal/inventory/plans.go | 9 +- internal/inventory/standing.go | 76 -- internal/inventory/standing_test.go | 130 ---- internal/link/advisories.go | 227 ++++++ internal/link/advisories_test.go | 33 + internal/link/bus.go | 7 + internal/link/calls.go | 17 + internal/link/protocol.go | 14 + internal/link/receive.go | 12 +- internal/link/receive_nats.go | 14 + internal/link/serve.go | 20 + internal/link/watched.go | 227 ++++++ 51 files changed, 6299 insertions(+), 404 deletions(-) create mode 100644 cmd/mesh-controller/busobjects.go create mode 100644 cmd/mesh-controller/conditions.go create mode 100644 cmd/mesh-controller/conditions_test.go create mode 100644 cmd/mesh-controller/doctor.go create mode 100644 cmd/mesh-controller/doctor_test.go create mode 100644 cmd/mesh-controller/probes.go create mode 100644 cmd/mesh-controller/signals.go create mode 100644 cmd/mesh-controller/signals_test.go create mode 100644 cmd/mesh-controller/watchdogs.go create mode 100644 internal/conditions/bus.go create mode 100644 internal/conditions/bus_test.go create mode 100644 internal/conditions/condition.go create mode 100644 internal/conditions/events.go create mode 100644 internal/conditions/memory.go create mode 100644 internal/conditions/store.go create mode 100644 internal/conditions/store_test.go delete mode 100644 internal/inventory/standing.go delete mode 100644 internal/inventory/standing_test.go create mode 100644 internal/link/advisories.go create mode 100644 internal/link/advisories_test.go create mode 100644 internal/link/watched.go diff --git a/cmd/mesh-controller/build.go b/cmd/mesh-controller/build.go index a4b0a3f..cc587ec 100644 --- a/cmd/mesh-controller/build.go +++ b/cmd/mesh-controller/build.go @@ -6,6 +6,7 @@ import ( "errors" "flag" "fmt" + "github.com/novox/mesh-controller/internal/conditions" "os" "strings" "time" @@ -676,9 +677,12 @@ type answers struct { // refused, until the switch — and while there is any, the mesh is not all well: the order the // machines' modules are built in is the mesh's to keep, and this is where it says it is not kept. unheld []catalogue.Unheld - // failing is every consumer a provider says it keeps failing (novox/hq ADR 0224): a provider's - // journal was the only place that said so for a day (04-ISSUES/179). - failing []inventory.ProviderStanding + // conditions is every open condition (novox/hq to-be 45 §2), urgent first and then oldest first: + // what leads status, and what its all-well sentence needs to be none of, silenced ones included. + // A provider failing a consumer is one of them (ADR 0224). conditionsUnread says why they could + // not be read when they could not — never read as none. + conditions []conditions.Condition + conditionsUnread string // overflowing is every module whose identity overflows the bound of a provision it requires // (novox/hq ADR 0225): its provider leaves it out of the grants and composes everything else, so // this is the one place it is said across the mesh. Not well while there is any. diff --git a/cmd/mesh-controller/busobjects.go b/cmd/mesh-controller/busobjects.go new file mode 100644 index 0000000..ffa46f2 --- /dev/null +++ b/cmd/mesh-controller/busobjects.go @@ -0,0 +1,104 @@ +package main + +import ( + "context" + "fmt" + + "github.com/novox/mesh-controller/internal/broker" + "github.com/novox/mesh-controller/internal/inventory" +) + +// The streams and durable consumers the mesh's own traffic needs, derived once (novox/hq to-be 45 §4, +// D6 and D7). +// +// **What the controller asserts at its start and what the self-check expects to find are one +// derivation**, run against the bus to make them and against a recorder to list them. Two lists would +// drift, and a self-check comparing the bus with a second opinion of what should be there would find +// the drift rather than the fault. + +// assertBusObjects brings every stream and consumer into being on r, and answers the machines that +// can now hear a declaration. +func assertBusObjects(ctx context.Context, inv *inventory.Inventory, r broker.Raiser) ([]string, error) { + nodes, err := inv.Nodes(ctx) + if err != nil { + return nil, err + } + names := make([]string, 0, len(nodes)) + for _, n := range nodes { + names = append(names, n.Name) + } + if err := broker.Raise(r, names); err != nil { + return nil, err + } + // The work queues of the mesh's own roles (novox/hq ADR 0121). The queue before the holder, + // deliberately: work queues until somebody arrives to do it, so assigning a build machine a week + // after something started asking for builds flushes the backlog instead of having lost it. + // With the seats' holders, so each role's work queue gets the consumer its holder takes + // work from. Passed as nil until the first live raise, which left the build machine bound to a + // consumer nothing had created (2026-09-28). + holders, err := seatHolders(ctx, inv) + if err != nil { + return nil, err + } + if err := broker.RaiseSeats(r, inventory.MeshSeats(), holders); err != nil { + return nil, err + } + // And how every module hears what it consumes. Derived from the same records the user list is + // composed from, so a module the mesh grants a consumer's subjects has that consumer waiting. + // Done on every raise, not only when a credential is issued: every module moved onto this bus + // by the rollout was issued on the old one, and came up with nothing to bind to (2026-09-28). + consumers, err := moduleConsumers(ctx, inv) + if err != nil { + return nil, err + } + for _, c := range consumers { + if err := r.EnsureConsumer(c.Consumer); err != nil { + return nil, fmt.Errorf("how %s on %s hears what it consumes: %w", c.Module, c.Node, err) + } + } + return names, nil +} + +// moduleConsumers is every module's durable consumer, from the records the user list is composed from. +func moduleConsumers(ctx context.Context, inv *inventory.Inventory) ([]broker.ModuleConsumer, error) { + records, err := inv.BusRecords(ctx) + if err != nil { + return nil, err + } + users, err := broker.Users(records) + if err != nil { + return nil, err + } + return broker.ConsumersOf(users), nil +} + +// moduleConsumerCount is how many modules hear what they consume, for the raise's one line. +func moduleConsumerCount(ctx context.Context, inv *inventory.Inventory) (int, error) { + consumers, err := moduleConsumers(ctx, inv) + return len(consumers), err +} + +// expectedBusObjects is every stream and consumer assertBusObjects would make, made nowhere. +func expectedBusObjects(ctx context.Context, inv *inventory.Inventory) ([]broker.Stream, []broker.Consumer, error) { + var rec recordingRaiser + if _, err := assertBusObjects(ctx, inv, &rec); err != nil { + return nil, nil, fmt.Errorf("what the bus should hold cannot be worked out: %w", err) + } + return rec.streams, rec.consumers, nil +} + +// recordingRaiser keeps what it was asked to assert and asserts nothing. +type recordingRaiser struct { + streams []broker.Stream + consumers []broker.Consumer +} + +func (r *recordingRaiser) EnsureStream(s broker.Stream) error { + r.streams = append(r.streams, s) + return nil +} + +func (r *recordingRaiser) EnsureConsumer(c broker.Consumer) error { + r.consumers = append(r.consumers, c) + return nil +} diff --git a/cmd/mesh-controller/conditions.go b/cmd/mesh-controller/conditions.go new file mode 100644 index 0000000..fc016fb --- /dev/null +++ b/cmd/mesh-controller/conditions.go @@ -0,0 +1,431 @@ +package main + +import ( + "context" + "errors" + "flag" + "fmt" + "os" + "slices" + "strconv" + "strings" + "time" + + "github.com/nats-io/nats.go" + + "github.com/novox/mesh-controller/internal/broker" + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/link" +) + +// What is wrong, kept until observation says it is not (novox/hq to-be 45 §2, ADR 0227). +// +// **`status` used to be the only place the mesh said it was wrong, and only to whoever asked.** Every +// core failure of research 031 was found by a person looking. A condition is the mesh saying it: raised +// by a watchdog when a signal is late (signals.go), by a probe when an invariant does not hold +// (doctor.go), or by an event a provider sends (standing.go); kept on the bus with since-when and +// evidence; said on the bus as it changes, for the operator's channel to carry; and cleared when an +// observation says it is resolved. Nobody resolves one by hand. A person who knows silences it, for a +// while, with a reason, and that is recorded as a hand act. + +// conditionsFrom is the serving controller's keeper; nil in any other process, which opens its own. +var conditionsFrom *conditions.Keeper + +// keeperOn is a keeper over the store on a connection, saying its transitions on that connection. +func keeperOn(ctx context.Context, conn *nats.Conn) (*conditions.Keeper, error) { + store, history, err := conditions.OnTheBus(ctx, conn) + if err != nil { + return nil, err + } + js, err := conn.JetStream() + if err != nil { + return nil, err + } + return conditions.NewKeeper(ctx, conditions.Options{Store: store, History: history, + Teller: link.OverNATS{Conn: conn, JS: js}, + Say: func(format string, args ...any) { fmt.Fprintf(os.Stderr, format+"\n", args...) }, + // What status leads with changed: composed again soon (a nudge outside the serving controller + // does nothing). + Changed: statusFrom.nudge}), nil +} + +// withKeeper runs f with the serving controller's keeper, or one of its own that says everything +// it was given before it returns. +func withKeeper(ctx context.Context, f func(*conditions.Keeper) error) error { + if conditionsFrom != nil { + return f(conditionsFrom) + } + return onTheBus(func(conn *nats.Conn) error { + k, err := keeperOn(ctx, conn) + if err != nil { + return err + } + defer func() { + flushing, cancel := context.WithTimeout(context.Background(), 15*time.Second) + defer cancel() + k.Close(flushing) + }() + return f(k) + }) +} + +// openConditions is every open condition, for `status` and `node show`: from the serving keeper, or +// read from the bus. Where there is no bus to read it from, it says so — never "none open". +func openConditions(ctx context.Context) ([]conditions.Condition, error) { + if conditionsFrom != nil { + return conditionsFrom.Open(ctx) + } + if _, err := broker.BusAddress(); err != nil { + return nil, fmt.Errorf("this process has no bus to read the conditions from: %w", err) + } + var out []conditions.Condition + err := onTheBus(func(conn *nats.Conn) error { + store, _, err := conditions.OnTheBus(ctx, conn) + if err != nil { + return err + } + reading, cancel := context.WithTimeout(ctx, 5*time.Second) + defer cancel() + out, err = conditions.Read(reading, store) + return err + }) + return out, err +} + +// conditionsUsage is how the verb is typed. +const conditionsUsage = "conditions [--scope S] [--severity urgent|warning] [--machine M] [--json] | " + + "conditions show | conditions silence --for --why | " + + "conditions history [--days N] [--key K] [--json]" + +// conditionsCommand is `conditions`, `conditions show`, `conditions silence` and `conditions history`. +func conditionsCommand(ctx context.Context, args []string) error { + sub := "list" + if len(args) > 0 && !strings.HasPrefix(args[0], "-") { + sub, args = args[0], args[1:] + } + switch sub { + case "list": + return listConditions(ctx, args) + case "show": + return showCondition(ctx, args) + case "silence": + return silenceCondition(ctx, args) + case "history": + return conditionHistory(ctx, args) + } + return errors.New(conditionsUsage) +} + +func listConditions(ctx context.Context, args []string) error { + set := flag.NewFlagSet("conditions", flag.ContinueOnError) + scope := set.String("scope", "", "only this scope: "+strings.Join(conditions.Scopes, ", ")) + severity := set.String("severity", "", "only urgent, or only warning") + machine := set.String("machine", "", "only those about this machine") + asJSON := set.Bool("json", false, "as data") + if rest, err := parseAround(set, args); err != nil { + return err + } else if len(rest) > 0 { + return errors.New(conditionsUsage) + } + if *severity != "" && *severity != string(conditions.Urgent) && *severity != string(conditions.Warning) { + return fmt.Errorf("a severity is urgent or warning, not %q", *severity) + } + open, err := openConditions(ctx) + if err != nil { + return err + } + var out []conditions.Condition + for _, c := range open { + if (*scope == "" || c.Subject.Scope == *scope) && (*severity == "" || string(c.Severity) == *severity) && + (*machine == "" || concerns(c, *machine)) { + out = append(out, c) + } + } + if *asJSON { + if out == nil { + out = []conditions.Condition{} + } + return printJSON(map[string]any{"conditions": out, "open": len(open), + "note": "urgent first, then oldest first; a condition clears when observation says so, never by hand"}) + } + if len(out) == 0 { + if len(open) == 0 { + fmt.Println("no open conditions") + } else { + fmt.Printf("none of the %d open condition(s) is about that\n", len(open)) + } + return nil + } + for _, line := range conditionLines(out, time.Now()) { + fmt.Println(line) + } + return nil +} + +// concerns says whether a condition is about a machine: it names it, or its key does. +func concerns(c conditions.Condition, machine string) bool { + if c.Subject.Machine == machine || slices.Contains(c.Subject.Also, machine) { + return true + } + for _, part := range strings.Split(c.Key, ".") { + if part == machine { + return true + } + } + return false +} + +// conditionLines is how a list of conditions reads: one line each, its silence under it. +func conditionLines(list []conditions.Condition, now time.Time) []string { + var out []string + for _, c := range list { + times := "" + if c.Count > 1 { + times = fmt.Sprintf(", raised %d times", c.Count) + } + out = append(out, fmt.Sprintf(" %-7s %s — %s (since %s%s)", strings.ToUpper(string(c.Severity)), + c.Key, c.Summary, c.Raised.Local().Format("2006-01-02 15:04"), times)) + if c.SilencedAt(now) { + out = append(out, fmt.Sprintf(" silenced until %s by %s: %s", + c.Silenced.Until.Local().Format("2006-01-02 15:04"), c.Silenced.By, c.Silenced.Why)) + } + } + return out +} + +func showCondition(ctx context.Context, args []string) error { + set := flag.NewFlagSet("conditions show", flag.ContinueOnError) + asJSON := set.Bool("json", false, "as data") + rest, err := parseAround(set, args) + if err != nil { + return err + } + if len(rest) != 1 { + return errors.New("conditions show ") + } + key := rest[0] + var c conditions.Condition + var found bool + if conditionsFrom != nil { + c, found, err = conditionsFrom.Get(ctx, key) + } else { + err = onTheBus(func(conn *nats.Conn) error { + store, _, err := conditions.OnTheBus(ctx, conn) + if err != nil { + return err + } + c, found, err = conditions.ReadOne(ctx, store, key) + return err + }) + } + if err != nil { + return err + } + if !found { + return fmt.Errorf("no condition %s is open — `conditions` lists those that are, and `conditions "+ + "history --key %s` what became of it", key, key) + } + if *asJSON { + return printJSON(c) + } + now := time.Now() + fmt.Printf("%s %s\n %s\n\n", strings.ToUpper(string(c.Severity)), c.Key, c.Summary) + fmt.Printf(" kind %s\n about %s %s", c.Kind, c.Subject.Scope, c.Subject.ID) + if c.Subject.Machine != "" { + fmt.Printf(", on %s", c.Subject.Machine) + } + fmt.Printf("\n raised by %s\n since %s (%s ago), observed %d time(s), last %s ago\n", + c.Source, c.Raised.Local().Format("2006-01-02 15:04:05"), roughly(now.Sub(c.Raised)), c.Observations, + now.Sub(c.LastObserved).Round(time.Second)) + if c.Count > 1 { + fmt.Printf(" raised %d times, each within ten minutes of clearing\n", c.Count) + } + fmt.Printf(" resolved by %s\n", resolverWords(c.Resolver)) + if c.Silenced != nil { + fmt.Printf(" silenced until %s by %s: %s\n", c.Silenced.Until.Local().Format("2006-01-02 15:04"), + c.Silenced.By, c.Silenced.Why) + } + if len(c.Tried) > 0 { + fmt.Println("\n tried:") + for _, t := range c.Tried { + fmt.Printf(" %s %s: %s\n", t.At.Local().Format("2006-01-02 15:04"), t.What, t.Outcome) + } + } + fmt.Println("\n evidence, newest first:") + for _, e := range c.Evidence { + fmt.Printf(" %s %s\n", e.At.Local().Format("2006-01-02 15:04:05"), e.Said) + } + return nil +} + +func resolverWords(r string) string { + switch r { + case conditions.ResolverSelf: + return "itself: it clears when observation says it is resolved" + case conditions.ResolverOperator: + return "the operator: nothing in the mesh will repair it" + case conditions.ResolverAgent: + return "an agent" + } + return r +} + +// silenceCondition stops a condition's messages for a while (to-be 45 §2). A hand act: recorded with +// who and why before it is done, its cause the condition's kind unless one is given. +func silenceCondition(ctx context.Context, args []string) error { + set := flag.NewFlagSet("conditions silence", flag.ContinueOnError) + forFlag := set.String("for", "", "how long: 30m, 4h, 2d — at most 7d") + acts := addHandActFlags(set) + rest, err := parseAround(set, args) + if err != nil { + return err + } + if len(rest) != 1 { + return errors.New("conditions silence --for --why ") + } + key := rest[0] + if err := acts.require("conditions silence"); err != nil { + return err + } + d, err := parseFor(*forFlag) + if err != nil { + return err + } + if d > conditions.MaxSilence { + return fmt.Errorf("a condition is silenced for at most %s at once; past it, say so again", conditions.MaxSilence) + } + return withKeeper(ctx, func(k *conditions.Keeper) error { + c, found, err := k.Get(ctx, key) + if err != nil { + return err + } + if !found { + return fmt.Errorf("no condition %s is open — `conditions` lists them. Nothing was silenced", key) + } + if strings.TrimSpace(*acts.cause) == "" { + *acts.cause = c.Kind + } + *acts.condition = key + acts.record(ctx, "conditions silence", []string{key, "--for", *forFlag}) + held, err := k.Silence(ctx, key, d, link.Caller(), *acts.why) + if err != nil { + return err + } + fmt.Printf("%s is silenced until %s: no message is sent for it until then. It is still open, and "+ + "`status` still says it; it clears when observation says it is resolved\n", + held.Key, held.Silenced.Until.Local().Format("2006-01-02 15:04")) + return nil + }) +} + +// parseFor reads a duration, days included. +func parseFor(s string) (time.Duration, error) { + s = strings.TrimSpace(s) + if s == "" { + return 0, errors.New("say for how long: --for 30m, 4h or 2d") + } + if days, ok := strings.CutSuffix(s, "d"); ok { + n, err := strconv.Atoi(days) + if err != nil || n <= 0 { + return 0, fmt.Errorf("%q is not a number of days", s) + } + return time.Duration(n) * 24 * time.Hour, nil + } + d, err := time.ParseDuration(s) + if err != nil || d <= 0 { + return 0, fmt.Errorf("%q is not a duration: 30m, 4h or 2d", s) + } + return d, nil +} + +func conditionHistory(ctx context.Context, args []string) error { + set := flag.NewFlagSet("conditions history", flag.ContinueOnError) + days := set.Int("days", 7, "how many days back, at most 90") + key := set.String("key", "", "only this condition") + asJSON := set.Bool("json", false, "as data") + if rest, err := parseAround(set, args); err != nil { + return err + } else if len(rest) > 0 { + return errors.New("conditions history [--days N] [--key K] [--json]") + } + since := time.Now().Add(-time.Duration(*days) * 24 * time.Hour) + var events []conditions.Event + read := func(h conditions.History) error { + var err error + events, err = h.Since(ctx, since) + return err + } + var err error + if conditionsFrom != nil { + events, err = conditionsFrom.HistorySince(ctx, since) + } else { + err = onTheBus(func(conn *nats.Conn) error { + _, history, err := conditions.OnTheBus(ctx, conn) + if err != nil { + return err + } + return read(history) + }) + } + if err != nil { + return err + } + var out []conditions.Event + for _, e := range events { + if *key == "" || e.Key == *key { + out = append(out, e) + } + } + if *asJSON { + if out == nil { + out = []conditions.Event{} + } + return printJSON(map[string]any{"history": out, "days": *days}) + } + if len(out) == 0 { + fmt.Printf("nothing was raised, changed or cleared in the last %d day(s)\n", *days) + return nil + } + for _, e := range out { + line := fmt.Sprintf("%s %-13s %s", e.At.Local().Format("2006-01-02 15:04:05"), e.Change, e.Key) + switch e.Change { + case conditions.ChangeRaised, conditions.ChangeReopened: + line += " — " + e.Summary + case conditions.ChangeSeverity: + line += fmt.Sprintf(" — %s, was %s", e.Severity, e.Was) + case conditions.ChangeResolver: + line += fmt.Sprintf(" — %s, was %s", e.Resolver, e.Was) + default: + if e.Why != "" { + line += " — " + e.Why + } + } + fmt.Println(line) + } + return nil +} + +// printConditions is the status section that leads it: every open condition, urgent first, oldest +// first, silenced ones with their expiry (to-be 45 §2). A store that could not be read is said, and +// is not "none open". +func printConditions(list []conditions.Condition, unread string, now time.Time) { + if unread != "" { + fmt.Printf("the open conditions could NOT be read, so whether anything is wrong is not known: %s\n\n", unread) + return + } + if len(list) == 0 { + return + } + urgent := 0 + for _, c := range list { + if c.Severity == conditions.Urgent { + urgent++ + } + } + fmt.Printf("%d open condition(s), %d urgent:\n\n", len(list), urgent) + for _, line := range conditionLines(list, now) { + fmt.Println(line) + } + fmt.Printf("\n `conditions show ` says more; each clears when observation says it is resolved, " + + "never by hand — `conditions silence --for --why ` stops its messages\n\n") +} diff --git a/cmd/mesh-controller/conditions_test.go b/cmd/mesh-controller/conditions_test.go new file mode 100644 index 0000000..6e33426 --- /dev/null +++ b/cmd/mesh-controller/conditions_test.go @@ -0,0 +1,107 @@ +package main + +import ( + "errors" + "strings" + "testing" + + "github.com/novox/mesh-controller/internal/conditions" +) + +// The verbs of the condition store (novox/hq to-be 45 §2) as the console reaches them, and status led +// by what is open. + +func TestTheConditionsVerbComposesEachShape(t *testing.T) { + for _, c := range []struct { + args map[string]any + want string + }{ + {map[string]any{}, "conditions --json"}, + {map[string]any{"severity": "urgent", "machine": "ace"}, "conditions --json --severity urgent --machine ace"}, + {map[string]any{"key": "machine.ace.silent"}, "conditions show machine.ace.silent --json"}, + {map[string]any{"history": "true", "days": "3", "key": "machine.ace.silent"}, + "conditions history --json --days 3 --key machine.ace.silent"}, + {map[string]any{"silence": "machine.ace.silent", "for": "2h", "why": "on the train"}, + "conditions silence machine.ace.silent --for 2h --why on the train"}, + {map[string]any{"run": "true"}, "doctor run --json"}, + {map[string]any{}, "doctor --json"}, + } { + verb := "conditions" + if strings.HasPrefix(c.want, "doctor") { + verb = "doctor" + } + argv, err := argvFor(verb, c.args) + if err != nil || strings.Join(argv, " ") != c.want { + t.Errorf("%s %v composed %q (%v), want %q", verb, c.args, strings.Join(argv, " "), err, c.want) + } + } + for _, c := range []struct { + verb string + args map[string]any + }{ + {"conditions", map[string]any{"silence": "machine.ace.silent", "why": "x"}}, // no for + {"doctor", map[string]any{"run": "true", "signals": "true"}}, // two at once + {"conditions", map[string]any{"silence": "machine.ace.silent", "for": "1h", "why": "x", "days": "3"}}, // passed over + } { + if argv, err := argvFor(c.verb, c.args); err == nil { + t.Errorf("%s %v composed %v", c.verb, c.args, argv) + } + } + if repairingCommand([]string{"conditions", "silence", "k"}) != "conditions silence" { + t.Error("a silence is not a hand act") + } +} + +// **A silence through the verb is recorded and bounded**; the condition stays open. +func TestASilenceThroughTheVerbHoldsAndTheConditionStaysOpen(t *testing.T) { + k, _ := withConditionsInMemory(t) + ctx := t.Context() + if _, err := k.Observe(ctx, conditions.Observation{Scope: conditions.ScopeMachine, ID: "ace", Kind: "silent", + Severity: conditions.Warning, Summary: "ace is silent", Source: "S1"}); err != nil { + t.Fatal(err) + } + if err := conditionsCommand(ctx, []string{"silence", "machine.ace.silent", "--for", "2d"}); err == nil { + t.Fatal("silenced without saying why") + } + if err := conditionsCommand(ctx, []string{"silence", "machine.ace.silent", "--for", "8d", "--why", "x"}); err == nil { + t.Fatal("silenced for more than a week") + } + said := printed(t, func() error { + return conditionsCommand(ctx, []string{"silence", "machine.ace.silent", "--for", "2d", "--why", "on the train"}) + }) + if !strings.Contains(said, "is silenced until") { + t.Fatalf("%s", said) + } + c, found, _ := k.Get(ctx, "machine.ace.silent") + if !found || c.Silenced == nil || c.Silenced.Why != "on the train" { + t.Fatalf("%+v", c) + } + listed := printed(t, func() error { return conditionsCommand(ctx, nil) }) + if !strings.Contains(listed, "machine.ace.silent") || !strings.Contains(listed, "silenced until") { + t.Fatalf("%s", listed) + } +} + +// **Conditions that cannot be read are not none open**: status says so, and is not well. +func TestUnreadableConditionsAreNotAWellMesh(t *testing.T) { + open := aMesh(t) + _, store := withConditionsInMemory(t) + store.Fail = errors.New("the bus is away") + asked, err := theThreeQuestions(t.Context(), open) + if err != nil { + t.Fatal(err) + } + if asked.well() || asked.conditionsUnread == "" { + t.Fatalf("well with its conditions unread: %+v", asked.conditionsUnread) + } + said := printed(t, func() error { return printStatus(asked) }) + if !strings.HasPrefix(said, "the open conditions could NOT be read") || strings.Contains(said, "no open conditions") { + t.Fatalf("%s", said) + } + store.Fail = nil + asked, _ = theThreeQuestions(t.Context(), open) + said = printed(t, func() error { return printStatus(asked) }) + if asked.well() && !strings.Contains(said, "no open conditions;") { + t.Fatalf("the all-well sentence does not say no conditions are open:\n%s", said) + } +} diff --git a/cmd/mesh-controller/doctor.go b/cmd/mesh-controller/doctor.go new file mode 100644 index 0000000..f4d02ea --- /dev/null +++ b/cmd/mesh-controller/doctor.go @@ -0,0 +1,514 @@ +package main + +import ( + "context" + "encoding/json" + "errors" + "flag" + "fmt" + "sort" + "strings" + "sync" + "time" + + "github.com/nats-io/nats.go" + + "github.com/novox/mesh-controller/internal/broker" + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/link" +) + +// The self-check: `doctor` (novox/hq to-be 45 §4, ADR 0227 rule 6). +// +// **The design's invariants, run against the running mesh.** A probe is one live invariant of a +// design — every machine's declaration composes and validates, every resolver answers, every seat's +// holder answers, every stream and consumer is there as defined — with an id, a bound, and the +// condition it raises when the invariant does not hold. The serving controller runs the registry every +// five minutes, each probe given thirty seconds; a probe that errors or does not finish raises +// `probe-failed` for itself, because an unanswered probe is never a pass. Every run ends with a +// heartbeat on the bus (`doctor-heartbeat`, S10), which mesh-watcher listens for from a second +// machine: a controller that stops checking is itself said, through a channel that does not pass +// through it. +// +// `doctor` answers the last run's verdict at once; `doctor run` runs now; `doctor probes` lists the +// registry; `doctor signals` says, for every row of the signals table, the age of its newest signal. + +// The self-check's clocks. +var ( + // doctorEvery is how often the registry runs; doctorFirstAfter how long after the controller + // starts the first run waits, so what the controller hears at its start has arrived. + doctorEvery = 5 * time.Minute + doctorFirstAfter = time.Minute + // probeWithin is each probe's bound. + probeWithin = 30 * time.Second +) + +// The verdicts a probe can have. +const ( + verdictPass = "pass" + verdictFail = "fail" + verdictFailedToRun = "failed-to-run" + verdictDeferred = "deferred" +) + +// probe is one live invariant. +type probe struct { + ID string + Asserts string + From string + // Kind is the condition kind raised when the invariant does not hold. + Kind string + Phase int + // Deferred says why it is not run yet; empty for one that is. + Deferred string + run func(ctx context.Context, d *doctor) ([]conditions.Observation, error) +} + +// probeRegistry is the registry, in to-be 45's order. **The registry is the design's live form**: a +// probe added to a design is a row added here. +var probeRegistry = []probe{ + {ID: "D1", Asserts: "every machine's declaration composes, and passes the node-engine's validation", + From: "issues 236, 263", Kind: "declaration-refused", Phase: 1, run: probeDeclarations}, + {ID: "D2", Asserts: "every holder of the mesh's resolver answers a machine name for IPv4, and NODATA for IPv6", + From: "issue 262", Kind: "resolver-wrong", Phase: 1, run: probeResolvers}, + {ID: "D3", Asserts: "every seat on record that serves verbs has a live holder that answers, on every " + + "machine that is heard from", From: "issues 208, 218", Kind: "holder-silent", Phase: 1, run: probeHolders}, + {ID: "D4", Asserts: "every kept archive is held by a manifest", From: "issue 253", + Kind: "archives-unheld", Phase: 1, run: probeArchives}, + {ID: "D5", Asserts: "exactly one lease holder; no message from a stale epoch in the last interval", + From: "issue 204", Kind: "lease-split", Phase: 2, + Deferred: "the lease and epoch are built in Phase 2 (to-be 45 §6): nothing holds one yet"}, + {ID: "D6", Asserts: "every durable consumer the mesh expects exists with its definition, and is near its " + + "stream's head", From: "issues 248, 266", Kind: "consumer-wrong", Phase: 1, run: probeConsumers}, + {ID: "D7", Asserts: "every stream the controller defines exists with its definition, and its own buckets", + From: "issue 208", Kind: "stream-wrong", Phase: 1, run: probeStreams}, + {ID: "D8", Asserts: "no address the mesh owns — a machine's private address or its endpoint — is in a ban list", + From: "issue 238", Kind: "own-address-banned", Phase: 1, run: probeBans}, + {ID: "D9", Asserts: "status answers in full within ten seconds, from a summary composed lately", + From: "issue 265", Kind: "status-slow", Phase: 1, run: probeStatus}, + {ID: "D10", Asserts: "every machine runs the node-engine and node tools builds the mesh holds, or is inside " + + "a plan's window", From: "the version split", Kind: "core-behind", Phase: 1, run: probeCoreBuilds}, + {ID: "DW", Asserts: "the watchdogs of the signals table ran within three of their intervals", + From: "ADR 0227 rule 6: the watchers are watched", Kind: "watchdogs-silent", Phase: 1, run: probeWatchdogs}, +} + +// probeVerdict is one probe's outcome in a run. +type probeVerdict struct { + ID string `json:"id"` + Verdict string `json:"verdict"` + Found []string `json:"found,omitempty"` + Error string `json:"error,omitempty"` + Took string `json:"took,omitempty"` +} + +// doctorCounts are a run's verdicts, counted. +type doctorCounts struct { + Passed int `json:"passed"` + Failed int `json:"failed"` + FailedToRun int `json:"failed-to-run"` + Deferred int `json:"deferred"` +} + +// doctorRun is one run of the registry, and the body of its heartbeat. +type doctorRun struct { + Run string `json:"run"` + At time.Time `json:"at"` + Started time.Time `json:"started"` + Took string `json:"took"` + IntervalSeconds int `json:"interval-seconds"` + Counts doctorCounts `json:"counts"` + Probes []probeVerdict `json:"probes"` + // Controller is the machine that ran it, and Why what started it: the schedule, or a person. + Controller string `json:"controller"` + Why string `json:"why"` + // Unsaid is how many condition transitions this controller could not say, since it started. + Unsaid int `json:"unsaid,omitempty"` +} + +// doctor is the registry and what its probes need. +type doctor struct { + open *stores + js *broker.JetStream + keeper *conditions.Keeper + teller conditions.Teller + watchdogs *watchdogs + host string + + running sync.Mutex + mu sync.Mutex + last *doctorRun + ended time.Time +} + +// lastRunEnded is when the last run ended; zero before the first. +func (d *doctor) lastRunEnded() time.Time { + d.mu.Lock() + defer d.mu.Unlock() + return d.ended +} + +// lastRun is the last run's verdict; nil before the first. +func (d *doctor) lastRun() *doctorRun { + d.mu.Lock() + defer d.mu.Unlock() + return d.last +} + +// keep runs the registry on its schedule until ctx ends. +func (d *doctor) keep(ctx context.Context) { + select { + case <-ctx.Done(): + return + case <-time.After(doctorFirstAfter): + } + tick := time.NewTicker(doctorEvery) + defer tick.Stop() + for { + // Only the controller acting checks the mesh on a schedule: one standing by would say a + // heartbeat for a self-check that is not the mesh's. + if d.watchdogs == nil || d.watchdogs.acting == nil || d.watchdogs.acting() { + d.runOnce(ctx, "the schedule") + } + select { + case <-ctx.Done(): + return + case <-tick.C: + } + } +} + +var doctorRuns struct { + sync.Mutex + n uint64 +} + +// runOnce runs every probe the registry runs, keeps what each found, and says the heartbeat. One run +// at a time: a person's `doctor run` during a scheduled one waits for it. +func (d *doctor) runOnce(ctx context.Context, why string) doctorRun { + d.running.Lock() + defer d.running.Unlock() + doctorRuns.Lock() + doctorRuns.n++ + n := doctorRuns.n + doctorRuns.Unlock() + started := time.Now() + run := doctorRun{Run: fmt.Sprintf("doctor-%d-%d", started.Unix(), n), Started: started.UTC(), + IntervalSeconds: int(doctorEvery / time.Second), Controller: d.host, Why: why} + + type result struct { + obs []conditions.Observation + err error + took time.Duration + } + results := make([]result, len(probeRegistry)) + var wg sync.WaitGroup + for i, p := range probeRegistry { + if p.run == nil { + continue + } + wg.Add(1) + go func(i int, p probe) { + defer wg.Done() + probing, cancel := context.WithTimeout(ctx, probeWithin) + defer cancel() + began := time.Now() + done := make(chan result, 1) + go func() { + defer func() { + if r := recover(); r != nil { + done <- result{err: fmt.Errorf("the probe panicked: %v", r)} + } + }() + obs, err := p.run(probing, d) + done <- result{obs: obs, err: err} + }() + select { + case r := <-done: + r.took = time.Since(began) + results[i] = r + case <-probing.Done(): + results[i] = result{err: fmt.Errorf("it did not finish within %s", probeWithin), took: time.Since(began)} + } + }(i, p) + } + wg.Wait() + + var blind []conditions.Observation + for i, p := range probeRegistry { + v := probeVerdict{ID: p.ID} + r := results[i] + switch { + case p.run == nil: + v.Verdict = verdictDeferred + run.Counts.Deferred++ + case r.err != nil: + v.Verdict, v.Error = verdictFailedToRun, r.err.Error() + run.Counts.FailedToRun++ + blind = append(blind, conditions.Observation{Scope: conditions.ScopeProbe, ID: p.ID, Kind: "probe-failed", + Token: "failed", Severity: conditions.Warning, + Summary: fmt.Sprintf("the probe %s (%s) could not run: what it checks is not known — never a pass", p.ID, p.Asserts), + Said: firstLine(r.err.Error())}) + default: + if err := d.keeper.Reconcile(ctx, p.ID, kindedAs(r.obs, p.Kind)); err != nil { + v.Error = "what it found could not be kept: " + err.Error() + } + if len(r.obs) == 0 { + v.Verdict = verdictPass + run.Counts.Passed++ + } else { + v.Verdict = verdictFail + run.Counts.Failed++ + for _, o := range r.obs { + v.Found = append(v.Found, o.Summary) + } + } + } + if p.run != nil { + v.Took = r.took.Round(time.Millisecond).String() + } + run.Probes = append(run.Probes, v) + } + if err := d.keeper.Reconcile(ctx, sourceDoctor, blind); err != nil { + fmt.Printf("the self-check's own failures could not be kept: %v\n", err) + } + ended := time.Now() + run.At, run.Took, run.Unsaid = ended.UTC(), ended.Sub(started).Round(time.Millisecond).String(), d.keeper.Unsaid() + d.mu.Lock() + d.last, d.ended = &run, ended + d.mu.Unlock() + d.sayHeartbeat(ctx, run) + return run +} + +// sourceDoctor is what raises a probe's own failure to run. +const sourceDoctor = "doctor" + +// kindedAs gives each observation of a probe the probe's kind where it named none. +func kindedAs(obs []conditions.Observation, kind string) []conditions.Observation { + out := make([]conditions.Observation, 0, len(obs)) + for _, o := range obs { + if o.Kind == "" { + o.Kind = kind + } + out = append(out, o) + } + return out +} + +// sayHeartbeat publishes the run's heartbeat. Not said is said here, and S10 on the second machine +// says it outward: the watcher hears nothing. +func (d *doctor) sayHeartbeat(ctx context.Context, run doctorRun) { + if d.teller == nil { + return + } + body, err := json.Marshal(run) + if err != nil { + fmt.Printf("the self-check's heartbeat could not be written: %v\n", err) + return + } + saying, cancel := context.WithTimeout(ctx, 10*time.Second) + defer cancel() + if err := d.teller.PublishSeatEvent(saying, conditions.Seat, conditions.HeartbeatEvent, body); err != nil { + fmt.Printf("the self-check's heartbeat (%s) could NOT be said, so the watcher on the second machine "+ + "will say the self-check is silent: %v\n", run.Run, err) + } +} + +// doctorFrom is the serving controller's self-check; nil in any other process. +var doctorFrom *doctor + +// doctorCommand is `doctor`, `doctor run`, `doctor probes` and `doctor signals`. +func doctorCommand(ctx context.Context, args []string) error { + sub := "" + if len(args) > 0 && !strings.HasPrefix(args[0], "-") { + sub, args = args[0], args[1:] + } + set := flag.NewFlagSet("doctor", flag.ContinueOnError) + asJSON := set.Bool("json", false, "as data") + if rest, err := parseAround(set, args); err != nil { + return err + } else if len(rest) > 0 { + return errors.New("doctor [run|probes|signals] [--json]") + } + answer, err := doctorAnswer(ctx, sub) + if err != nil { + return err + } + if *asJSON { + return printJSON(answer) + } + fmt.Print(doctorText(answer)) + return nil +} + +// doctorAnswer is what the verb answers, as data. +func doctorAnswer(ctx context.Context, sub string) (any, error) { + switch sub { + case "": + if doctorFrom != nil { + if run := doctorFrom.lastRun(); run != nil { + return verdictAnswer(*run, time.Now()), nil + } + return nil, fmt.Errorf("the self-check has not finished its first run yet: it runs %s after the "+ + "controller starts, then every %s — `doctor run` runs it now", doctorFirstAfter, doctorEvery) + } + run, err := lastHeartbeat(ctx) + if err != nil { + return nil, err + } + return verdictAnswer(run, time.Now()), nil + case "run": + d := doctorFrom + if d == nil { + local, closeIt, err := localDoctor(ctx) + if err != nil { + return nil, err + } + defer closeIt() + d = local + } + return verdictAnswer(d.runOnce(ctx, "asked by "+link.Caller()), time.Now()), nil + case "probes": + return probesAnswer(), nil + case "signals": + if doctorFrom == nil || doctorFrom.watchdogs == nil { + return nil, errors.New("the age of each signal is known to the serving controller alone, which " + + "hears them: ask it through the mesh-controller seat's doctor verb") + } + return signalsAnswer(doctorFrom.watchdogs.lastFacts(), doctorFrom.watchdogs.lastTick()), nil + } + return nil, fmt.Errorf("doctor answers the last run, or `run`, `probes` or `signals` — not %q", sub) +} + +// verdictAnswer is a run as the verb answers it, with its age. +func verdictAnswer(run doctorRun, now time.Time) map[string]any { + return map[string]any{"run": run, "age": now.Sub(run.At).Round(time.Second).String(), + "note": "a probe that could not run is never a pass; each failure is an open condition until a run passes it"} +} + +// probesAnswer is the registry. +func probesAnswer() map[string]any { + var out []map[string]any + for _, p := range probeRegistry { + row := map[string]any{"id": p.ID, "asserts": p.Asserts, "from": p.From, "kind": p.Kind, "phase": p.Phase} + if p.Deferred != "" { + row["deferred"] = p.Deferred + } + out = append(out, row) + } + return map[string]any{"probes": out, "every": doctorEvery.String(), "each within": probeWithin.String()} +} + +// signalsAnswer is every row of the signals table with the age of its newest signal. +func signalsAnswer(f *signalFacts, ticked time.Time) map[string]any { + var rows []map[string]any + for _, r := range signalsTable { + row := map[string]any{"row": r.Row, "signal": r.Signal, "emitter": r.Emitter, "bound": r.Bound, + "kind": r.Kind, "severity": r.Severity, "phase": r.Phase} + switch { + case r.Deferred != "": + row["deferred"] = r.Deferred + case f == nil: + row["newest"] = "not yet looked at" + default: + if err := r.needs(f); err != nil { + row["blind"] = err.Error() + } else if newest := r.newest(f); newest.IsZero() { + row["newest"] = "none heard" + } else { + row["newest"] = newest.UTC().Format(time.RFC3339) + row["age"] = f.now.Sub(newest).Round(time.Second).String() + } + } + rows = append(rows, row) + } + out := map[string]any{"signals": rows, "every": watchEvery.String()} + if !ticked.IsZero() { + out["looked"] = ticked.UTC().Format(time.RFC3339) + } + return out +} + +// doctorText is an answer as a person reads it. +func doctorText(answer any) string { + body, _ := json.Marshal(answer) + var b strings.Builder + var verdict struct { + Run doctorRun `json:"run"` + Age string `json:"age"` + } + if json.Unmarshal(body, &verdict) == nil && verdict.Run.Run != "" { + r := verdict.Run + fmt.Fprintf(&b, "%s, %s ago (took %s, %s): %d passed, %d failed, %d could not run, %d not built yet\n\n", + r.Run, verdict.Age, r.Took, r.Why, r.Counts.Passed, r.Counts.Failed, r.Counts.FailedToRun, r.Counts.Deferred) + for _, p := range r.Probes { + fmt.Fprintf(&b, " %-4s %-14s %s\n", p.ID, p.Verdict, p.Took) + for _, f := range p.Found { + fmt.Fprintf(&b, " %s\n", f) + } + if p.Error != "" { + fmt.Fprintf(&b, " %s\n", p.Error) + } + } + return b.String() + } + pretty, _ := json.MarshalIndent(answer, "", " ") + return string(pretty) + "\n" +} + +// lastHeartbeat is the newest run's heartbeat, read from the events stream: what a process other than +// the serving controller answers `doctor` from. +func lastHeartbeat(ctx context.Context) (doctorRun, error) { + var run doctorRun + err := onTheBus(func(conn *nats.Conn) error { + js, err := conn.JetStream(nats.Context(ctx)) + if err != nil { + return err + } + msg, err := js.GetLastMsg(broker.EventsStream, link.SeatEventSubject(conditions.Seat, conditions.HeartbeatEvent)) + if errors.Is(err, nats.ErrMsgNotFound) { + return errors.New("the self-check has said no heartbeat on the bus in the last week: it is not running") + } + if err != nil { + return fmt.Errorf("the self-check's last heartbeat cannot be read: %w", err) + } + return json.Unmarshal(msg.Data, &run) + }) + return run, err +} + +// localDoctor is a self-check run by a process other than the serving controller: its own stores, +// its own connection, and its own keeper, closed after. +func localDoctor(ctx context.Context) (*doctor, func(), error) { + open, err := openStores(ctx) + if err != nil { + return nil, nil, err + } + js, err := dialTheBus() + if err != nil { + open.Close() + return nil, nil, err + } + k, err := keeperOn(ctx, js.Conn()) + if err != nil { + js.Close() + open.Close() + return nil, nil, err + } + jsCtx := js.Context() + d := &doctor{open: open, js: js, keeper: k, teller: link.OverNATS{Conn: js.Conn(), JS: jsCtx}, + host: controlHost(ctx, open.inventory)} + return d, func() { + flushing, cancel := context.WithTimeout(context.Background(), 15*time.Second) + defer cancel() + k.Close(flushing) + js.Close() + open.Close() + }, nil +} + +// sortedFound is a probe's findings in a stated order, so two runs over one mesh say the same. +func sortedFound(obs []conditions.Observation) []conditions.Observation { + sort.Slice(obs, func(i, j int) bool { return obs[i].Key() < obs[j].Key() }) + return obs +} diff --git a/cmd/mesh-controller/doctor_test.go b/cmd/mesh-controller/doctor_test.go new file mode 100644 index 0000000..ca4405d --- /dev/null +++ b/cmd/mesh-controller/doctor_test.go @@ -0,0 +1,347 @@ +package main + +import ( + "context" + "encoding/json" + "errors" + "net" + "os" + "slices" + "strings" + "sync/atomic" + "testing" + "time" + + "github.com/nats-io/nats.go" + "github.com/nats-io/nats.go/jetstream" + "golang.org/x/net/dns/dnsmessage" + + "github.com/novox/mesh-controller/internal/broker" + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/link" +) + +// The self-check (novox/hq to-be 45 §4): a probe that fails raises its condition, one that cannot run +// raises probe-failed for itself and is never a pass, and every run ends with its heartbeat. + +// withProbes runs the test with a registry of its own. +func withProbes(t *testing.T, probes ...probe) { + t.Helper() + before := probeRegistry + probeRegistry = probes + t.Cleanup(func() { probeRegistry = before }) +} + +func TestARunKeepsWhatEachProbeFoundAndSaysItsHeartbeat(t *testing.T) { + failing := conditions.Observation{Scope: conditions.ScopeMachine, ID: "anchor", Token: "refused", + Severity: conditions.Urgent, Summary: "anchor's node-engine would refuse its declaration"} + var broken atomic.Bool + broken.Store(true) + withProbes(t, + probe{ID: "P1", Asserts: "passes", Kind: "never", Phase: 1, + run: func(context.Context, *doctor) ([]conditions.Observation, error) { return nil, nil }}, + probe{ID: "P2", Asserts: "finds a fault", Kind: "declaration-refused", Phase: 1, + run: func(context.Context, *doctor) ([]conditions.Observation, error) { + if broken.Load() { + return []conditions.Observation{failing}, nil + } + return nil, nil + }}, + probe{ID: "P3", Asserts: "cannot run", Kind: "x", Phase: 1, + run: func(context.Context, *doctor) ([]conditions.Observation, error) { + if broken.Load() { + return nil, errors.New("the store is away") + } + return nil, nil + }}, + probe{ID: "P4", Asserts: "hangs", Kind: "x", Phase: 1, + run: func(ctx context.Context, _ *doctor) ([]conditions.Observation, error) { + if broken.Load() { + <-ctx.Done() + time.Sleep(50 * time.Millisecond) + } + return nil, nil + }}, + probe{ID: "P5", Asserts: "later", Kind: "x", Phase: 2, Deferred: "not yet"}, + ) + before := probeWithin + probeWithin = 200 * time.Millisecond + t.Cleanup(func() { probeWithin = before }) + + store := conditions.NewInMemory() + told := &conditions.Told{} + k := conditions.NewKeeper(t.Context(), conditions.Options{Store: store, History: store}) + defer k.Close(context.Background()) + d := &doctor{keeper: k, teller: told, host: "anchor"} + run := d.runOnce(t.Context(), "a test") + if run.Counts != (doctorCounts{Passed: 1, Failed: 1, FailedToRun: 2, Deferred: 1}) { + t.Fatalf("counted %+v", run.Counts) + } + open, err := k.Open(t.Context()) + if err != nil { + t.Fatal(err) + } + var keys []string + for _, c := range open { + keys = append(keys, c.Key+"="+c.Kind) + } + for _, want := range []string{"machine.anchor.refused=declaration-refused", "probe.P3.failed=probe-failed", + "probe.P4.failed=probe-failed"} { + if !slices.Contains(keys, want) { + t.Errorf("%s is not open: %v", want, keys) + } + } + // The heartbeat, in the shape mesh-watcher reads (the contract with the operator's channel). + if len(told.Names) != 1 || told.Names[0] != conditions.HeartbeatEvent { + t.Fatalf("said %v", told.Names) + } + if d.lastRunEnded().IsZero() || d.lastRun().Run != run.Run { + t.Fatal("the run is not the last verdict") + } + body, _ := json.Marshal(run) + var shape map[string]any + _ = json.Unmarshal(body, &shape) + for _, field := range []string{"run", "at", "interval-seconds", "counts", "probes", "controller"} { + if _, ok := shape[field]; !ok { + t.Errorf("the heartbeat carries no %q: %s", field, body) + } + } + + // Mended: the next run clears every one of them. + broken.Store(false) + d.runOnce(t.Context(), "a test") + if open, _ := k.Open(t.Context()); len(open) != 0 { + t.Fatalf("a passing run left open %+v", open) + } +} + +// **The registry says what each probe asserts**, and a probe not built says why and when. +func TestTheRegistryIsTheDesignsLiveForm(t *testing.T) { + seen := map[string]bool{} + for _, p := range probeRegistry { + if seen[p.ID] { + t.Errorf("%s twice", p.ID) + } + seen[p.ID] = true + if p.Asserts == "" || p.From == "" || p.Kind == "" { + t.Errorf("%s does not say what it asserts, where from, or what it raises", p.ID) + } + if (p.run == nil) != (p.Deferred != "") || (p.Deferred != "" && p.Phase <= 1) { + t.Errorf("%s is run and deferred, or neither, or deferred out of Phase 1: %+v", p.ID, p) + } + } + for _, id := range []string{"D1", "D2", "D3", "D4", "D5", "D6", "D7", "D8", "D9", "D10"} { + if !seen[id] { + t.Errorf("to-be 45 §4 has %s and the registry does not", id) + } + } +} + +// **The doctor and the watchdogs watch each other**: watchdogs that stopped are DW; a self-check that +// stopped is S10 (signals_test.go). +func TestWatchdogsThatStoppedAreSaid(t *testing.T) { + w := &watchdogs{started: time.Now().Add(-time.Hour)} + d := &doctor{watchdogs: w, host: "anchor"} + got, err := probeWatchdogs(t.Context(), d) + if err != nil || len(got) != 1 || got[0].Severity != conditions.Urgent { + t.Fatalf("%+v %v", got, err) + } + w.ticked = time.Now() + if got, _ := probeWatchdogs(t.Context(), d); len(got) != 0 { + t.Fatalf("%+v", got) + } +} + +// **D1 composes every machine of a healthy mesh and the host's own validator takes each.** +func TestEveryMachineOfAHealthyMeshComposesAndValidates(t *testing.T) { + open := aMesh(t) + got, err := probeDeclarations(t.Context(), &doctor{open: open}) + if err != nil { + t.Fatal(err) + } + if len(got) != 0 { + t.Fatalf("a healthy mesh failed D1: %+v", got) + } +} + +// **D1 names a machine nothing can be sent to**, and the network that cannot be computed for it. +func TestAMachineWhoseDeclarationDoesNotComposeIsSaid(t *testing.T) { + open := aMesh(t) + ctx := t.Context() + one, two := rivals() + register(t, open, one) + register(t, open, two) + for _, m := range []string{"rival-one", "rival-two"} { + if _, err := assign(ctx, open, "laptop", m); err != nil && m == "rival-one" { + t.Fatal(err) + } + } + got, err := probeDeclarations(ctx, &doctor{open: open}) + if err != nil { + t.Fatal(err) + } + if len(got) != 1 || got[0].Key() != "machine.laptop.uncomposable" || !strings.Contains(got[0].Summary, "the-seat") { + t.Fatalf("%+v", got) + } +} + +// **D2: a resolver answering NXDOMAIN for IPv6 is wrong** — musl takes it as no such name (issue 262). +func TestAResolverAnsweringNoSuchNameForIPv6IsWrong(t *testing.T) { + answerAs := func(rcode dnsmessage.RCode) string { + conn, err := net.ListenPacket("udp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { _ = conn.Close() }) + go func() { + buf := make([]byte, 1500) + for { + n, from, err := conn.ReadFrom(buf) + if err != nil { + return + } + var q dnsmessage.Message + if q.Unpack(buf[:n]) != nil { + continue + } + reply := dnsmessage.Message{Header: dnsmessage.Header{ID: q.ID, Response: true}, Questions: q.Questions} + if q.Questions[0].Type == dnsmessage.TypeA { + reply.Answers = []dnsmessage.Resource{{Header: dnsmessage.ResourceHeader{Name: q.Questions[0].Name, + Type: dnsmessage.TypeA, Class: dnsmessage.ClassINET}, Body: &dnsmessage.AResource{A: [4]byte{10, 77, 0, 1}}}} + } else { + reply.RCode = rcode + } + packed, _ := reply.Pack() + _, _ = conn.WriteTo(packed, from) + } + }() + _, port, _ := net.SplitHostPort(conn.LocalAddr().String()) + return port + } + before := resolverPort + t.Cleanup(func() { resolverPort = before }) + + resolverPort = answerAs(dnsmessage.RCodeSuccess) + v4, rcode, err := askResolver(t.Context(), "127.0.0.1", "anchor.internal", dnsmessage.TypeA) + if err != nil || rcode != dnsmessage.RCodeSuccess || !slices.Equal(v4, []string{"10.77.0.1"}) { + t.Fatalf("%v %v %v", v4, rcode, err) + } + v6, rcode, err := askResolver(t.Context(), "127.0.0.1", "anchor.internal", dnsmessage.TypeAAAA) + if err != nil || rcode != dnsmessage.RCodeSuccess || len(v6) != 0 { + t.Fatalf("NODATA read as %v %v %v", v6, rcode, err) + } + resolverPort = answerAs(dnsmessage.RCodeNameError) + if _, rcode, _ := askResolver(t.Context(), "127.0.0.1", "anchor.internal", dnsmessage.TypeAAAA); rcode != dnsmessage.RCodeNameError { + t.Fatalf("NXDOMAIN read as %v", rcode) + } +} + +// **D6, D7: what the controller defines is what it finds**, and a consumer deleted or a stream +// redefined is said — against a real bus, raised by the same derivation the controller starts with. +func TestNatsTheBusIsWhatTheControllerDefines(t *testing.T) { + url := os.Getenv("MESH_TEST_NATS") + if url == "" { + t.Skip("MESH_TEST_NATS unset") + } + open := aMesh(t) + js, err := broker.Dial(url) + if err != nil { + t.Fatal(err) + } + t.Cleanup(js.Close) + for _, s := range []string{"CONTROL", "NODES", "ASSIGNMENTS", "EVENTS"} { + _ = js.Context().DeleteStream(s) + } + if _, err := assertBusObjects(t.Context(), open.inventory, js); err != nil { + t.Fatal(err) + } + if err := js.EnsureControllerBuckets(); err != nil { + t.Fatal(err) + } + d := &doctor{open: open, js: js} + for _, p := range []func(context.Context, *doctor) ([]conditions.Observation, error){probeConsumers, probeStreams} { + got, err := p(t.Context(), d) + if err != nil || len(got) != 0 { + t.Fatalf("a bus just raised fails: %+v %v", got, err) + } + } + if err := js.Context().DeleteConsumer("NODES", "laptop"); err != nil { + t.Fatal(err) + } + info, err := js.Context().StreamInfo("EVENTS") + if err != nil { + t.Fatal(err) + } + cfg := info.Config + cfg.MaxMsgsPerSubject = 3 + if _, err := js.Context().UpdateStream(&cfg); err != nil { + t.Fatal(err) + } + consumers, err := probeConsumers(t.Context(), d) + if err != nil || len(consumers) != 1 || consumers[0].Key() != "bus.NODES.laptop.missing" { + t.Fatalf("the deleted consumer: %+v %v", consumers, err) + } + streams, err := probeStreams(t.Context(), d) + if err != nil || len(streams) != 1 || !strings.Contains(streams[0].Summary, "per subject") { + t.Fatalf("the redefined stream: %+v %v", streams, err) + } +} + +// **S9 hears the bus**: a consumer that gives up on a message, and one deleted, as the server says. +func TestNatsTheBusSaysAConsumerGaveUpAndOneWasDeleted(t *testing.T) { + url := os.Getenv("MESH_TEST_NATS") + if url == "" { + t.Skip("MESH_TEST_NATS unset") + } + conn, err := nats.Connect(url) + if err != nil { + t.Fatal(err) + } + defer conn.Close() + heard := make(chan *nats.Msg, 16) + for _, subject := range broker.BusAdvisories { + if _, err := conn.ChanSubscribe(subject, heard); err != nil { + t.Fatal(err) + } + } + api, _ := jetstream.New(conn) + _ = api.DeleteStream(t.Context(), "SEAT_ADVISED") + stream, err := api.CreateStream(t.Context(), jetstream.StreamConfig{Name: "SEAT_ADVISED", Subjects: []string{"advised.>"}}) + if err != nil { + t.Fatal(err) + } + defer func() { _ = api.DeleteStream(context.Background(), "SEAT_ADVISED") }() + consumer, err := stream.CreateConsumer(t.Context(), jetstream.ConsumerConfig{Durable: "SEAT_ADVISED_worker", + AckPolicy: jetstream.AckExplicitPolicy, MaxDeliver: 1, AckWait: 100 * time.Millisecond}) + if err != nil { + t.Fatal(err) + } + if _, err := api.Publish(t.Context(), "advised.x", []byte("x")); err != nil { + t.Fatal(err) + } + if _, err := consumer.Fetch(1, jetstream.FetchMaxWait(time.Second)); err != nil { + t.Fatal(err) + } + // A seat's worker, so the deletion is of a consumer the mesh names (link.MeshNamed). + // Not acknowledged: after its one delivery the consumer gives up on it — on the next fetch. + time.Sleep(300 * time.Millisecond) + _, _ = consumer.Fetch(1, jetstream.FetchMaxWait(300*time.Millisecond)) + if err := stream.DeleteConsumer(t.Context(), "SEAT_ADVISED_worker"); err != nil { + t.Fatal(err) + } + kinds := map[string]string{} + deadline := time.After(5 * time.Second) + for len(kinds) < 2 { + select { + case m := <-heard: + if a, ok := link.ReadAdvisory(m.Subject, m.Data); ok { + kinds[a.Kind] = a.Said + } + case <-deadline: + t.Fatalf("the bus said only %v", kinds) + } + } + if !strings.Contains(kinds["max-deliveries"], "gave up") || !strings.Contains(kinds["consumer-lost"], "was deleted") { + t.Fatalf("%v", kinds) + } +} diff --git a/cmd/mesh-controller/main.go b/cmd/mesh-controller/main.go index 7880440..7a55adc 100644 --- a/cmd/mesh-controller/main.go +++ b/cmd/mesh-controller/main.go @@ -153,6 +153,11 @@ func run() error { // What the mesh's bounds will be set from (novox/hq to-be 45 Phase 0). case "durations": return durationsCommand(ctx, args[1:]) + // What is wrong, and the self-check (novox/hq to-be 45 §2, §4). + case "conditions": + return conditionsCommand(ctx, args[1:]) + case "doctor": + return doctorCommand(ctx, args[1:]) case "version": fmt.Println(version) return nil @@ -238,6 +243,13 @@ func usage() { hand-act record --why --cause [--condition ] record an act done by hand outside the mesh (to-be 45 §7) hand-acts [--days N] [--json] what was done by hand lately, why, and which causes repeat + conditions [--scope S] [--severity S] [--machine M] [--json] + what is wrong now: every open condition, urgent first (to-be 45 §2) + conditions show one condition whole, with its evidence + conditions silence --for --why send no message for it a while; a hand act + conditions history [--days N] [--key K] every raising, change and clearing lately + doctor [run|probes|signals] [--json] + the self-check: the last verdict, a run now, the probes, the signals' ages durations [--kind K] [--days N] [--json] apply, heartbeat, plan-tier and build durations, per machine or module collection [--json] kept archives held/unheld by a manifest, and what the sweep may let go diff --git a/cmd/mesh-controller/mesh_for_test.go b/cmd/mesh-controller/mesh_for_test.go index 3008697..b2e76be 100644 --- a/cmd/mesh-controller/mesh_for_test.go +++ b/cmd/mesh-controller/mesh_for_test.go @@ -1,11 +1,14 @@ package main import ( + "context" + "crypto/ecdh" "crypto/rand" "encoding/base64" "encoding/json" "fmt" + "github.com/novox/mesh-controller/internal/conditions" "testing" "github.com/novox/mesh-controller/internal/catalogue" @@ -37,6 +40,9 @@ func aMesh(t *testing.T) *stores { t.Fatal(err) } t.Cleanup(open.Close) + // A condition store of its own, held in memory (novox/hq to-be 45 §2): status leads with what is + // open, and a mesh with no bus would otherwise read as one whose conditions cannot be read. + withConditionsInMemory(t) for _, m := range provided { if err := open.inventory.Provide(t.Context(), m); err != nil { t.Fatal(err) @@ -106,3 +112,17 @@ func rivals() (catalogue.Manifest, catalogue.Manifest) { return catalogue.Manifest{Module: "rival-one", Version: "1", Claims: claim}, catalogue.Manifest{Module: "rival-two", Version: "1", Claims: claim} } + +// withConditionsInMemory gives the test a condition store in memory, as the serving controller's. +func withConditionsInMemory(t *testing.T) (*conditions.Keeper, *conditions.InMemory) { + t.Helper() + store := conditions.NewInMemory() + k := conditions.NewKeeper(t.Context(), conditions.Options{Store: store, History: store}) + before := conditionsFrom + conditionsFrom = k + t.Cleanup(func() { + conditionsFrom = before + k.Close(context.Background()) + }) + return k, store +} diff --git a/cmd/mesh-controller/missed_merges.go b/cmd/mesh-controller/missed_merges.go index 4a83e46..d68bfeb 100644 --- a/cmd/mesh-controller/missed_merges.go +++ b/cmd/mesh-controller/missed_merges.go @@ -3,6 +3,7 @@ package main import ( "context" "fmt" + "sync" "time" "github.com/novox/mesh-controller/internal/inventory" @@ -59,9 +60,13 @@ func catchingUpOnMerges(ctx context.Context, open *stores, announced merges) { return case <-tick.C: } + watchedMerges.begin() err := catchUpOnMerges(ctx, time.Now(), announced, catalogued, f.SourceMoved, func(format string, args ...any) { fmt.Printf(format+"\n", args...) }) + // What the pass found is what S5 says (novox/hq to-be 45 §3); a pass that could not read + // says that instead, and leaves what the last one found standing. + watchedMerges.end(time.Now(), err) // A pass that cannot read says so once, not every five minutes, and says when it reads again. why := "" if err != nil { @@ -114,6 +119,8 @@ func catchUpOnMerges(ctx context.Context, now time.Time, announced merges, for _, e := range moves { names = append(names, e.Manifest.Module) } + watchedMerges.found(missedMerge{Owner: a.Owner, Repo: a.Repo, Base: a.Base, Commit: a.Commit, + At: a.At, Modules: names}) say("%s/%s merged into %s (%.8s), announced %s ago, and the controller never acted on it: the bus "+ "did not hand the announcement over (novox/hq issue 266). %s %s behind it; acting on it now", a.Owner, a.Repo, a.Base, a.Commit, now.Sub(a.At).Round(time.Minute), readableList(names), @@ -129,3 +136,54 @@ func catchUpOnMerges(ctx context.Context, now time.Time, announced merges, } return nil } + +// missedMerge is one merge the bus announced and never handed over, as a pass found it. +type missedMerge struct { + Owner, Repo, Base, Commit string + // At is when the bus took the announcement. + At time.Time + Modules []string +} + +// mergeWatch is what the passes found, for S5 (novox/hq to-be 45 §3): **a merge nothing read is +// said**, urgent, even though the pass acts on it at once — the bus skipping a message is a fault of +// the transport the mesh's every change rides on, and acting late is the repair, not the absence of +// the fault. The next pass, finding it acted on, clears it. +type mergeWatch struct { + mu sync.Mutex + passed time.Time + err error + finding []missedMerge + missed []missedMerge +} + +var watchedMerges = &mergeWatch{} + +func (w *mergeWatch) begin() { + w.mu.Lock() + defer w.mu.Unlock() + w.finding = nil +} + +func (w *mergeWatch) found(m missedMerge) { + w.mu.Lock() + defer w.mu.Unlock() + w.finding = append(w.finding, m) +} + +func (w *mergeWatch) end(at time.Time, err error) { + w.mu.Lock() + defer w.mu.Unlock() + w.passed, w.err = at, err + if err == nil { + w.missed = w.finding + } +} + +// last is when the last pass ended, what the last pass that read found, and what the last pass +// could not read. +func (w *mergeWatch) last() (time.Time, []missedMerge, error) { + w.mu.Lock() + defer w.mu.Unlock() + return w.passed, append([]missedMerge(nil), w.missed...), w.err +} diff --git a/cmd/mesh-controller/nodes.go b/cmd/mesh-controller/nodes.go index eb81031..f2bc0b9 100644 --- a/cmd/mesh-controller/nodes.go +++ b/cmd/mesh-controller/nodes.go @@ -6,6 +6,7 @@ import ( "errors" "flag" "fmt" + "github.com/novox/mesh-controller/internal/conditions" "strings" "time" @@ -516,15 +517,22 @@ func showNode(ctx context.Context, inv *inventory.Inventory, name string) error fmt.Printf(" public domain %s\n", domain) } - // A provider here failing a consumer, or a consumer here failed (novox/hq ADR 0224). Before the - // capabilities, because it is something not working now and they are a description. - failing, err := failingProviders(ctx, inv) + // Every open condition about this machine (novox/hq to-be 45 §2) — a provider here failing a + // consumer, or a consumer here failed, among them (ADR 0224). Before the capabilities, because it + // is something not working now and they are a description. Unreadable is said, not passed over. + open, err := openConditions(ctx) if err != nil { - return err + fmt.Printf("\n the open conditions could NOT be read, so whether anything here is wrong is not known: %v\n", err) } - if here := failingOn(failing, name); len(here) > 0 { - fmt.Printf("\n %d consumer(s) a provider keeps failing, here or for a module here:\n", len(here)) - for _, line := range failingLines(here, time.Now()) { + var here []conditions.Condition + for _, c := range open { + if concerns(c, name) { + here = append(here, c) + } + } + if len(here) > 0 { + fmt.Printf("\n %d open condition(s) about this machine:\n", len(here)) + for _, line := range conditionLines(here, time.Now()) { fmt.Printf(" %s\n", line) } } diff --git a/cmd/mesh-controller/probes.go b/cmd/mesh-controller/probes.go new file mode 100644 index 0000000..b4cbb80 --- /dev/null +++ b/cmd/mesh-controller/probes.go @@ -0,0 +1,764 @@ +package main + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "net" + "regexp" + "slices" + "sort" + "strings" + "time" + + "github.com/nats-io/nats.go" + "github.com/nats-io/nats.go/micro" + "github.com/novox/mesh-host/validate" + "golang.org/x/net/dns/dnsmessage" + + "github.com/novox/mesh-controller/internal/artifacts" + "github.com/novox/mesh-controller/internal/broker" + "github.com/novox/mesh-controller/internal/catalogue" + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/link" + "github.com/novox/mesh-controller/internal/overlay" +) + +// The probes of the self-check's registry (doctor.go), one function each. A probe answers what is +// wrong now as observations, or an error when it could not tell — never "nothing" for "could not +// look" (ADR 0227 rule 4). + +// probeDeclarations is D1: every machine's declaration composes, and the node-engine's own validator +// (mesh-host's `validate`, the package the host runs) takes it. +func probeDeclarations(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + open := d.open + nodes, err := open.inventory.Nodes(ctx) + if err != nil { + return nil, err + } + var out []conditions.Observation + // The private network every declaration is composed with. Not computable is not "could not + // look": it is the finding — no machine's declaration composes without it — and the machines that + // do not resolve, which are usually why, are named below. + gens, gensErr := generators(ctx, open) + if gensErr != nil { + if ctx.Err() != nil { + return nil, ctx.Err() + } + out = append(out, conditions.Observation{Scope: conditions.ScopeMesh, ID: "private-network", + Token: "uncomposable", Severity: conditions.Urgent, + Summary: "the private network cannot be computed, so no machine's declaration composes", + Said: firstLine(gensErr.Error())}) + } + for _, n := range nodes { + plan, settings, err := planFor(ctx, open, n.Name) + if err != nil && !unresolvable(err) { + return nil, fmt.Errorf("%s cannot be worked out: %w", n.Name, err) + } + var problems []string + if err == nil && gensErr == nil { + var declared sendable + if declared, err = declarationWith(ctx, open, n.Name, plan, settings, gens, Reading); err == nil { + var body []byte + if body, err = declared.Body(); err == nil { + problems = validate.Declaration(body) + } + } + } + if ctx.Err() != nil { + return nil, ctx.Err() + } + switch { + case err != nil: + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: n.Name, Token: "uncomposable", + Machine: n.Name, Severity: conditions.Urgent, + Summary: fmt.Sprintf("nothing can be sent to %s: its declaration does not compose — %s", n.Name, + oneLine(err.Error())), + Said: oneLine(err.Error())}) + case len(problems) > 0: + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: n.Name, Token: "refused", + Machine: n.Name, Severity: conditions.Urgent, + Summary: fmt.Sprintf("%s's node-engine would refuse its declaration whole: %d problem(s), the first: %s", + n.Name, len(problems), problems[0]), + Said: strings.Join(problems, "; ")}) + } + } + return out, nil +} + +// probeResolvers is D2: every holder of the mesh's resolver answers each machine's name with its +// address for IPv4, and with no address and no error for IPv6 — NODATA, not NXDOMAIN, which musl +// takes as final (issue 262). +func probeResolvers(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + inv := d.open.inventory + shelf, err := inv.Catalogue(ctx) + if err != nil { + return nil, err + } + holders, err := replicatedHolders(ctx, inv, shelf) + if err != nil { + return nil, err + } + resolvers := holders["mesh-dns-resolver"] + if len(resolvers) == 0 { + return nil, nil // the mesh holds no resolver of its own: nothing is asked of one + } + places, err := onTheNetwork(ctx, inv, shelf) + if err != nil { + return nil, err + } + suffix := overlay.Suffix() + var out []conditions.Observation + for holder, at := range resolvers { + var wrong []string + for _, p := range places { + if p.Address == "" { + continue + } + name := p.Name + "." + suffix + v4, rcode, err := askResolver(ctx, at, name, dnsmessage.TypeA) + switch { + case err != nil: + wrong = append(wrong, fmt.Sprintf("%s for %s: %v", "A", name, err)) + continue + case rcode != dnsmessage.RCodeSuccess: + wrong = append(wrong, fmt.Sprintf("%s answered %s for %s (A)", holder, rcode, name)) + case !slices.Contains(v4, p.Address): + wrong = append(wrong, fmt.Sprintf("%s answered %v for %s (A), not %s", holder, v4, name, p.Address)) + } + v6, rcode, err := askResolver(ctx, at, name, dnsmessage.TypeAAAA) + switch { + case err != nil: + wrong = append(wrong, fmt.Sprintf("%s for %s: %v", "AAAA", name, err)) + case rcode != dnsmessage.RCodeSuccess: + wrong = append(wrong, fmt.Sprintf("%s answered %s for %s (AAAA), not NODATA: a musl machine "+ + "takes that as no such name", holder, rcode, name)) + case len(v6) > 0: + wrong = append(wrong, fmt.Sprintf("%s answered %v for %s (AAAA); the mesh has no IPv6 addresses", holder, v6, name)) + } + } + if len(wrong) > 0 { + node := strings.TrimSuffix(holder, "."+suffix) + out = append(out, conditions.Observation{Scope: conditions.ScopeSeat, ID: "mesh-dns-resolver." + node, + Token: "wrong", Machine: node, Severity: conditions.Urgent, + Summary: fmt.Sprintf("the mesh's resolver on %s does not answer machine names as it must: %s", + node, wrong[0]), + Said: strings.Join(wrong, "; ")}) + } + } + return sortedFound(out), nil +} + +// resolverPort is where a resolver answers; a variable so a test can stand one up. +var resolverPort = "53" + +// askResolver asks one resolver one question over UDP, and answers the addresses and the code. +func askResolver(ctx context.Context, at, name string, kind dnsmessage.Type) ([]string, dnsmessage.RCode, error) { + q, err := dnsmessage.NewName(strings.TrimSuffix(name, ".") + ".") + if err != nil { + return nil, 0, err + } + msg := dnsmessage.Message{Header: dnsmessage.Header{ID: uint16(time.Now().UnixNano()), RecursionDesired: true}, + Questions: []dnsmessage.Question{{Name: q, Type: kind, Class: dnsmessage.ClassINET}}} + packed, err := msg.Pack() + if err != nil { + return nil, 0, err + } + dialer := net.Dialer{Timeout: 3 * time.Second} + conn, err := dialer.DialContext(ctx, "udp", net.JoinHostPort(at, resolverPort)) + if err != nil { + return nil, 0, err + } + defer conn.Close() + _ = conn.SetDeadline(time.Now().Add(3 * time.Second)) + if _, err := conn.Write(packed); err != nil { + return nil, 0, err + } + buf := make([]byte, 1500) + n, err := conn.Read(buf) + if err != nil { + return nil, 0, fmt.Errorf("no answer from %s: %w", at, err) + } + var answer dnsmessage.Message + if err := answer.Unpack(buf[:n]); err != nil { + return nil, 0, fmt.Errorf("an answer from %s that cannot be read: %w", at, err) + } + var addresses []string + for _, a := range answer.Answers { + switch r := a.Body.(type) { + case *dnsmessage.AResource: + addresses = append(addresses, net.IP(r.A[:]).String()) + case *dnsmessage.AAAAResource: + addresses = append(addresses, net.IP(r.AAAA[:]).String()) + } + } + return addresses, answer.RCode, nil +} + +// probeHolders is D3: every seat that serves verbs has, on every machine that holds it and is heard +// from, a holder answering the bus's discovery for that seat. A machine past its heartbeat's bound is +// S1's, and is not asked about here. +func probeHolders(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + entries, err := d.open.inventory.Catalogued(ctx) + if err != nil { + return nil, err + } + recorded, err := d.open.inventory.Holdings(ctx) + if err != nil { + return nil, err + } + heard := heardMachines(d) + expected := map[string]map[string]bool{} // seat → machine + add := func(seat, node string) { + if expected[seat] == nil { + expected[seat] = map[string]bool{} + } + expected[seat][node] = true + } + for _, s := range catalogue.SeatsWithAProtocol() { + if len(s.Serves) == 0 || s.Name == catalogue.ControllerSeatName { + continue // a seat with no verb has nothing to answer with; this controller is answering now + } + onRecord := false + for _, h := range recorded { + if h.Claim == s.Name && heard[h.Node] { + add(s.Name, h.Node) + onRecord = true + } + } + if onRecord && s.Scope == catalogue.ScopeMesh { + continue + } + for _, e := range entries { + for _, c := range e.Manifest.Claims { + if c.Name != s.Name { + continue + } + for _, node := range e.On { + if heard[node] && (s.Scope == catalogue.ScopeNode || !onRecord) { + add(s.Name, node) + } + } + } + } + } + if len(expected) == 0 { + return nil, nil + } + answering, err := discoverHolders(ctx, d.js.Conn()) + if err != nil { + return nil, err + } + var out []conditions.Observation + for seat, nodes := range expected { + for node := range nodes { + if answering[seat][node] { + continue + } + out = append(out, conditions.Observation{Scope: conditions.ScopeSeat, ID: seat + "." + node, + Token: "silent", Machine: node, Severity: conditions.Warning, + Summary: fmt.Sprintf("%s's holder on %s does not answer the bus: its verbs reach nothing there", seat, node), + Said: fmt.Sprintf("no answer for %s from %s to the bus's discovery", seat, node)}) + } + } + return sortedFound(out), nil +} + +// heardMachines is every machine within its heartbeat's bound, as the watchdogs last saw. +func heardMachines(d *doctor) map[string]bool { + out := map[string]bool{} + if d.watchdogs == nil { + return out + } + f := d.watchdogs.lastFacts() + if f == nil { + return out + } + for _, m := range f.machines { + if !m.lastHeard.IsZero() && f.now.Sub(m.lastHeard) <= heartbeatBound(m.every) && !m.asleep() { + out[m.name] = true + } + } + return out +} + +// discoveryPatience is how long the discovery's answers are waited for after the last arrived, and at +// the most (ADR 0197: a large runtime's answer arrives last). +const ( + discoveryQuiet = 1500 * time.Millisecond + discoveryPatience = 8 * time.Second +) + +// discoverHolders asks the bus's discovery who serves what, and answers seat → machine for every +// endpoint a seat's verb is served on. +func discoverHolders(ctx context.Context, conn *nats.Conn) (map[string]map[string]bool, error) { + inbox := conn.NewRespInbox() + sub, err := conn.SubscribeSync(inbox) + if err != nil { + return nil, err + } + defer func() { _ = sub.Unsubscribe() }() + if err := conn.PublishRequest("$SRV.INFO", inbox, nil); err != nil { + return nil, fmt.Errorf("asking the bus who serves what: %w", err) + } + out := map[string]map[string]bool{} + deadline := time.Now().Add(discoveryPatience) + for time.Now().Before(deadline) { + wait, cancel := context.WithTimeout(ctx, discoveryQuiet) + msg, err := sub.NextMsgWithContext(wait) + cancel() + if err != nil { + if ctx.Err() != nil { + return nil, ctx.Err() + } + break + } + var info micro.Info + if json.Unmarshal(msg.Data, &info) != nil { + continue + } + for _, e := range info.Endpoints { + seat, node := e.Metadata["seat"], e.Metadata["node"] + if seat == "" { + continue + } + if node == "" { + node = info.ID + } + if out[seat] == nil { + out[seat] = map[string]bool{} + } + out[seat][node] = true + } + // A holder that announces itself as its seat, by name and machine. + if out[info.Name] == nil { + out[info.Name] = map[string]bool{} + } + out[info.Name][info.ID] = true + } + return out, nil +} + +// probeArchives is D4: every archive the mesh keeps is held by its manifest in the artifact store. +func probeArchives(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + inv := d.open.inventory + kept, err := inv.KeptArchives(ctx) + if err != nil { + return nil, err + } + if len(kept) == 0 { + return nil, nil + } + shelf, err := inv.Catalogue(ctx) + if err != nil { + return nil, err + } + store, err := artifactStoreAddress(ctx, inv, shelf, "") + if err != nil { + return nil, err + } + if store == "" { + return nil, errors.New("the mesh keeps archives and has no artifact store on its network to ask") + } + var report collectionReport + if unasked, stopped := askHeld(ctx, artifacts.Store{Address: store}, kept, &report); stopped != "" { + return nil, fmt.Errorf("%d kept archive(s) could not be asked about: %s", unasked, stopped) + } + var out []conditions.Observation + if n := len(report.Unheld); n > 0 { + out = append(out, conditions.Observation{Scope: conditions.ScopeMesh, ID: "artifact-store", Token: "archives-unheld", + Severity: conditions.Warning, + Summary: fmt.Sprintf("%d of %d kept archive(s) are not held by a manifest: the store's collector would "+ + "delete them", n, len(kept)), + Said: "first: " + report.Unheld[0]}) + } + if n := len(report.Missing); n > 0 { + out = append(out, conditions.Observation{Scope: conditions.ScopeMesh, ID: "artifact-store", Token: "archives-missing", + Kind: "archives-missing", Severity: conditions.Warning, + Summary: fmt.Sprintf("%d kept archive(s) are not in the artifact store at all", n), + Said: "first: " + report.Missing[0]}) + } + return out, nil +} + +// consumerFarBehind is how far a durable consumer may be from its stream's head (D6). +const consumerFarBehind = 1000 + +// probeConsumers is D6: every durable consumer the mesh expects exists, as the controller defines it, +// and is near its stream's head. +func probeConsumers(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + _, consumers, err := expectedBusObjects(ctx, d.open.inventory) + if err != nil { + return nil, err + } + js := d.js.Context() + var out []conditions.Observation + for _, c := range consumers { + if ctx.Err() != nil { + return nil, ctx.Err() + } + info, err := js.ConsumerInfo(c.Stream, c.Name, nats.Context(ctx)) + who := c.Stream + "." + c.Name + switch { + case errors.Is(err, nats.ErrConsumerNotFound) || errors.Is(err, nats.ErrStreamNotFound): + out = append(out, conditions.Observation{Scope: conditions.ScopeBus, ID: who, Token: "missing", + Kind: "consumer-lost", Severity: conditions.Warning, + Summary: fmt.Sprintf("%s is not on the bus: what it delivers reaches nobody", consumerWords(c)), + Said: "no consumer " + c.Name + " on " + c.Stream}) + continue + case err != nil: + return nil, fmt.Errorf("%s cannot be read: %w", consumerWords(c), err) + } + if differs := consumerDiffers(c, info.Config); differs != "" { + out = append(out, conditions.Observation{Scope: conditions.ScopeBus, ID: who, Token: "redefined", + Severity: conditions.Warning, + Summary: fmt.Sprintf("%s is not as the controller defines it: %s", consumerWords(c), differs), + Said: differs}) + } + if c.Stream != "NODES" && info.NumPending > consumerFarBehind { + out = append(out, conditions.Observation{Scope: conditions.ScopeBus, ID: who, Token: "behind", + Severity: conditions.Warning, + Summary: fmt.Sprintf("%s is %d message(s) behind its stream's head", consumerWords(c), info.NumPending), + Said: fmt.Sprintf("%d pending, %d handed out and not settled", info.NumPending, info.NumAckPending)}) + } + } + return sortedFound(out), nil +} + +// consumerWords is a consumer as the mesh says it, with its name. +func consumerWords(c broker.Consumer) string { + return fmt.Sprintf("%s (%s on %s)", link.ConsumerInWords(c.Stream, c.Name), c.Name, c.Stream) +} + +// consumerDiffers is what about a consumer on the bus is not as defined; empty when nothing is. The +// delivery subject is not compared: one kept as it was while a holder is bound is the assertion's +// stated choice (novox/hq issue 156). +func consumerDiffers(want broker.Consumer, have nats.ConsumerConfig) string { + var differs []string + haveFilters := append([]string(nil), have.FilterSubjects...) + if have.FilterSubject != "" { + haveFilters = append(haveFilters, have.FilterSubject) + } + wantFilters := append([]string(nil), want.Filters...) + sort.Strings(haveFilters) + sort.Strings(wantFilters) + if !slices.Equal(haveFilters, wantFilters) { + differs = append(differs, fmt.Sprintf("filters %v, defined %v", haveFilters, wantFilters)) + } + if have.AckPolicy != nats.AckExplicitPolicy { + differs = append(differs, "acknowledges "+have.AckPolicy.String()+", defined explicit") + } + if wantMax := want.MaxDeliver; wantMax != 0 && have.MaxDeliver != wantMax { + differs = append(differs, fmt.Sprintf("hands a message over %d times, defined %d", have.MaxDeliver, wantMax)) + } + if wantWait := time.Duration(want.AckWaitSeconds) * time.Second; wantWait != 0 && have.AckWait != wantWait { + differs = append(differs, fmt.Sprintf("waits %s for an acknowledgement, defined %s", have.AckWait, wantWait)) + } + if want.MaxAckPending != 0 && have.MaxAckPending != want.MaxAckPending { + differs = append(differs, fmt.Sprintf("hands out %d at once, defined %d", have.MaxAckPending, want.MaxAckPending)) + } + if wantPush, havePush := want.Push || want.Queue != "", have.DeliverSubject != ""; wantPush != havePush { + differs = append(differs, "delivers by the other shape (push or pull) than defined") + } + return strings.Join(differs, "; ") +} + +// probeStreams is D7: every stream the controller defines exists as defined, and its own buckets. +func probeStreams(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + streams, _, err := expectedBusObjects(ctx, d.open.inventory) + if err != nil { + return nil, err + } + js := d.js.Context() + var out []conditions.Observation + for _, s := range streams { + info, err := js.StreamInfo(s.Name, nats.Context(ctx)) + switch { + case errors.Is(err, nats.ErrStreamNotFound): + out = append(out, conditions.Observation{Scope: conditions.ScopeBus, ID: s.Name, Token: "stream-missing", + Kind: "stream-wrong", Severity: conditions.Urgent, + Summary: fmt.Sprintf("the stream %s is not on the bus: %s", s.Name, firstLine(s.Why)), + Said: "no stream " + s.Name}) + continue + case err != nil: + return nil, fmt.Errorf("the stream %s cannot be read: %w", s.Name, err) + } + if differs := streamDiffers(s, info.Config); differs != "" { + out = append(out, conditions.Observation{Scope: conditions.ScopeBus, ID: s.Name, Token: "stream-redefined", + Kind: "stream-wrong", Severity: conditions.Warning, + Summary: fmt.Sprintf("the stream %s is not as the controller defines it: %s", s.Name, differs), + Said: differs}) + } + } + for _, bucket := range broker.ControllerBuckets() { + if _, err := js.StreamInfo("KV_"+bucket, nats.Context(ctx)); errors.Is(err, nats.ErrStreamNotFound) { + out = append(out, conditions.Observation{Scope: conditions.ScopeBus, ID: bucket, Token: "bucket-missing", + Kind: "stream-wrong", Severity: conditions.Urgent, + Summary: fmt.Sprintf("the controller's bucket %s is not on the bus: what it keeps there is not kept", bucket), + Said: "no bucket " + bucket}) + } else if err != nil { + return nil, fmt.Errorf("the bucket %s cannot be read: %w", bucket, err) + } + } + return sortedFound(out), nil +} + +// streamDiffers is what about a stream on the bus is not as defined; empty when nothing is. +func streamDiffers(want broker.Stream, have nats.StreamConfig) string { + var differs []string + haveSubjects := append([]string(nil), have.Subjects...) + wantSubjects := append([]string(nil), want.Subjects...) + sort.Strings(haveSubjects) + sort.Strings(wantSubjects) + if !slices.Equal(haveSubjects, wantSubjects) { + differs = append(differs, fmt.Sprintf("subjects %v, defined %v", haveSubjects, wantSubjects)) + } + retention, perSubject := nats.LimitsPolicy, int64(want.MaxMsgsPerSubject) + switch want.Retention { + case broker.RetentionWorkQueue: + retention = nats.WorkQueuePolicy + case broker.RetentionLastPerSubject: + perSubject = 1 + } + if have.Retention != retention { + differs = append(differs, fmt.Sprintf("keeps by %s, defined %s", have.Retention, retention)) + } + if perSubject != 0 && have.MaxMsgsPerSubject != perSubject { + differs = append(differs, fmt.Sprintf("keeps %d per subject, defined %d", have.MaxMsgsPerSubject, perSubject)) + } + return strings.Join(differs, "; ") +} + +// ipLike finds the addresses in a ban list, whatever shape its holder answers in. +var ipLike = regexp.MustCompile(`\b(?:\d{1,3}\.){3}\d{1,3}\b`) + +// probeBans is D8: no address the mesh owns is in any machine's ban list. The mesh's own addresses are +// every machine's private address and the address its endpoint names; the ban lists are asked of each +// machine's holder of `node-intrusion-prevention` that is heard from. +func probeBans(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + inv := d.open.inventory + places, err := inv.Overlays(ctx) + if err != nil { + return nil, err + } + owned := map[string]string{} // address → whose + for _, p := range places { + if p.Address != "" { + owned[p.Address] = p.Name + "'s private address" + } + if host, _, err := net.SplitHostPort(p.Endpoint); err == nil && host != "" { + if ip := net.ParseIP(host); ip != nil { + owned[ip.String()] = p.Name + "'s endpoint" + } else if addrs, err := net.DefaultResolver.LookupHost(ctx, host); err == nil { + for _, a := range addrs { + owned[a] = p.Name + "'s endpoint (" + host + ")" + } + } + } + } + entries, err := inv.Catalogued(ctx) + if err != nil { + return nil, err + } + heard := heardMachines(d) + var holders []string + for _, e := range entries { + for _, c := range e.Manifest.Claims { + if c.Name == "node-intrusion-prevention" { + for _, node := range e.On { + if heard[node] && !slices.Contains(holders, node) { + holders = append(holders, node) + } + } + } + } + } + sort.Strings(holders) + var out []conditions.Observation + var unasked []string + for _, node := range holders { + answer, err := askSeatTool(ctx, d.js.Conn(), "node-intrusion-prevention", "banned", node) + if err != nil { + unasked = append(unasked, err.Error()) + continue + } + var banned []string + for _, ip := range ipLike.FindAllString(string(answer), -1) { + if whose, ours := owned[ip]; ours && !slices.Contains(banned, ip+" ("+whose+")") { + banned = append(banned, ip+" ("+whose+")") + } + } + if len(banned) > 0 { + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: node, Token: "bans-the-mesh", + Machine: node, Severity: conditions.Urgent, + Summary: fmt.Sprintf("%s's ban list holds %d of the mesh's own address(es): %s — the mesh is locked out "+ + "of itself there (ADR 0186)", node, len(banned), strings.Join(banned, ", ")), + Said: strings.Join(banned, ", ")}) + } + } + if len(unasked) > 0 { + return nil, fmt.Errorf("a ban list could not be read: %s", strings.Join(unasked, "; ")) + } + return out, nil +} + +// probeStatus is D9: `status` answers in full within ten seconds, from a summary composed lately. +func probeStatus(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + started := time.Now() + stale := "" + if statusFrom != nil { + answer, err := statusFrom.answer(ctx) + if err != nil { + stale = err.Error() + } else if m, ok := answer.(map[string]any); ok { + if failed, _ := m["lastAttemptFailed"].(string); failed != "" { + stale = "its last composition failed: " + failed + } + if composed, err := time.Parse(time.RFC3339, fmt.Sprint(m["composed"])); err == nil && + time.Since(composed) > 3*statusEvery+statusComposeWithin { + stale = fmt.Sprintf("it answers a summary composed %s ago", time.Since(composed).Round(time.Second)) + } + } + } else if _, err := theThreeQuestions(ctx, d.open); err != nil { + stale = err.Error() + } + took := time.Since(started) + var out []conditions.Observation + if took > 10*time.Second || stale != "" { + why := stale + if why == "" { + why = fmt.Sprintf("it took %s", took.Round(time.Millisecond)) + } + out = append(out, conditions.Observation{Scope: conditions.ScopeCore, ID: "controller", Token: "status-slow", + Machine: d.host, Severity: conditions.Warning, + Summary: "status does not answer in full within ten seconds: " + why, Said: why}) + } + return out, nil +} + +// probeCoreBuilds is D10: every machine runs the node-engine and the node tools the mesh holds, or a +// plan is rolling one of them out. The node-engine says its build in each report; the node tools' is +// the build the machine was last sent, once it reported applying that send. +func probeCoreBuilds(ctx context.Context, d *doctor) ([]conditions.Observation, error) { + inv := d.open.inventory + current, err := inv.CurrentBuilds(ctx) + if err != nil { + return nil, err + } + plans, err := inv.OpenPlans(ctx) + if err != nil { + return nil, err + } + rolling := map[string]bool{} + for _, p := range plans { + for m := range p.Modules { + rolling[m] = true + } + } + nodes, err := inv.Nodes(ctx) + if err != nil { + return nil, err + } + reports, err := inv.LastReports(ctx) + if err != nil { + return nil, err + } + applied := map[string]bool{} + for _, r := range reports { + applied[r.Node] = r.Current + } + heard := heardMachines(d) + var out []conditions.Observation + for _, n := range nodes { + if !heard[n.Name] { + continue // a machine not heard from is S1's + } + var behind []string + host := current[hostModule].Commit + if host != "" && n.HostVersion != "" && !rolling[hostModule] && !sameCommit(n.HostVersion, host) { + behind = append(behind, fmt.Sprintf("the node-engine %s, the mesh holds %s", short(n.HostVersion), short(host))) + } + assigned, err := inv.Assigned(ctx, n.Name) + if err != nil { + return nil, err + } + tools := current[broker.RuntimeModule].Commit + if tools != "" && slices.Contains(assigned, broker.RuntimeModule) && !rolling[broker.RuntimeModule] { + sent, known, err := inv.SentBuilds(ctx, n.Name) + if err != nil { + return nil, err + } + switch { + case !known: + case !sameCommit(sent[broker.RuntimeModule], tools): + behind = append(behind, fmt.Sprintf("the node tools %s, the mesh holds %s", + short(orNotKnown(sent[broker.RuntimeModule])), short(tools))) + case !applied[n.Name]: + behind = append(behind, "the node tools it was last sent, not yet reported applied") + } + } + if len(behind) > 0 { + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: n.Name, Token: "core-behind", + Machine: n.Name, Severity: conditions.Warning, + Summary: fmt.Sprintf("%s runs %s, and no plan is rolling them out", n.Name, strings.Join(behind, "; ")), + Said: strings.Join(behind, "; ")}) + } + } + return out, nil +} + +// hostModule is the node-engine's module. +const hostModule = "mesh-host" + +// sameCommit says two commits are one, either written short. +func sameCommit(a, b string) bool { + if a == "" || b == "" { + return false + } + return strings.HasPrefix(a, b) || strings.HasPrefix(b, a) +} + +func orNotKnown(s string) string { + if s == "" { + return "(not known)" + } + return s +} + +// probeWatchdogs is DW: the watchdogs ran within three of their intervals. The doctor and the +// watchdogs watch each other: S10 is the other half. +func probeWatchdogs(_ context.Context, d *doctor) ([]conditions.Observation, error) { + if d.watchdogs == nil { + return nil, nil // a self-check run outside the serving controller has none to watch + } + ticked := d.watchdogs.lastTick() + since := ticked + if since.IsZero() { + since = d.watchdogs.started + } + if time.Since(since) <= 3*watchEvery { + return nil, nil + } + return []conditions.Observation{{Scope: conditions.ScopeCore, ID: "watchdogs", Token: "silent", + Machine: d.host, Severity: conditions.Urgent, + Summary: fmt.Sprintf("the watchdogs of the signals table have not run since %s: no late signal is being said", + since.UTC().Format("2006-01-02 15:04 MST")), + Said: fmt.Sprintf("no tick for %s", time.Since(since).Round(time.Second))}}, nil +} + +// askSeatTool asks one machine's holder of a node seat a verb and answers its result; the holder's +// own refusal is an error. +func askSeatTool(ctx context.Context, conn *nats.Conn, seat, verb, node string) (json.RawMessage, error) { + answer, err := link.AskSeatTool(ctx, conn, seat, verb, node, map[string]any{}, 10*time.Second) + if err != nil { + return nil, err + } + if answer.Error != "" { + return nil, fmt.Errorf("%s's %s.%s refused: %s", node, seat, verb, answer.Error) + } + return answer.Result, nil +} + +// oneLine is a message of several lines said on one, its runs of space made one. +func oneLine(s string) string { return strings.Join(strings.Fields(s), " ") } diff --git a/cmd/mesh-controller/push.go b/cmd/mesh-controller/push.go index eb5e56b..764bf93 100644 --- a/cmd/mesh-controller/push.go +++ b/cmd/mesh-controller/push.go @@ -8,6 +8,7 @@ import ( "errors" "flag" "fmt" + "github.com/novox/mesh-controller/internal/conditions" "io" "log" "os" @@ -142,7 +143,7 @@ func serve(ctx context.Context) error { } // And what providers say about consumers they keep failing, kept for `status` (novox/hq ADR // 0224): a provider's journal must not be the only place that says so. - if err := server.Watches(standings{inv}); err != nil { + if err := server.Watches(standings{keeper: func() *conditions.Keeper { return conditionsFrom }}); err != nil { return err } @@ -178,6 +179,13 @@ func serve(ctx context.Context) error { } else if err := link.Calls.Durably(ctx, keeper, controllerProcess(), said); err != nil { fmt.Printf("calls are kept on the bus from now on; the ones kept before could not be read: %v\n", err) } + // What is wrong, kept and said (novox/hq to-be 45 §2): the condition store, the watchdogs of the + // signals table, what the bus says about itself, and the self-check. A store that cannot be opened + // is said and the controller serves on: status then says the conditions cannot be read, and is + // not well — louder than not serving at all, and the push that repairs the bus still runs. + if stopWatching := watchTheMesh(ctx, open, server, bus); stopWatching != nil { + defer stopWatching() + } stopServing, err := bus.ServeSeatTools(catalogue.ControllerSeatName, handlers, log.New(os.Stdout, "", log.LstdFlags)) if err != nil { return err @@ -1150,30 +1158,12 @@ func raiseTheBus(ctx context.Context, inv *inventory.Inventory, address string) } } - nodes, err := inv.Nodes(ctx) + // The mesh's own streams and consumers, the seats' work queues and their workers, and how every + // machine hears its declaration — one derivation, which the self-check reads as well (D6, D7). + names, err := assertBusObjects(ctx, inv, js) if err != nil { return err } - names := make([]string, 0, len(nodes)) - for _, n := range nodes { - names = append(names, n.Name) - } - if err := broker.Raise(js, names); err != nil { - return err - } - // The work queues of the mesh's own roles (novox/hq ADR 0121). The queue before the holder, - // deliberately: work queues until somebody arrives to do it, so assigning a build machine a week - // after something started asking for builds flushes the backlog instead of having lost it. - // With the seats' holders, so each role's work queue gets the consumer its holder takes - // work from. Passed as nil until the first live raise, which left the build machine bound to a - // consumer nothing had created (2026-09-28). - holders, err := seatHolders(ctx, inv) - if err != nil { - return err - } - if err := broker.RaiseSeats(js, inventory.MeshSeats(), holders); err != nil { - return err - } // And each work queue's cancelled set (novox/hq ADR 0219), so a holder taking an ask can ask // whether it was cancelled the moment it took it. if err := broker.RaiseCancelledSets(js, inventory.MeshSeats()); err != nil { @@ -1199,25 +1189,11 @@ func raiseTheBus(ctx context.Context, inv *inventory.Inventory, address string) fmt.Printf("the bus holds state nothing declares any more, kept because it is data: %s — "+ "removing it is a person's act\n", strings.Join(undeclared, ", ")) } - // And how every module hears what it consumes. Derived from the same records the user list is - // composed from, so a module the mesh grants a consumer's subjects has that consumer waiting. - // Done on every raise, not only when a credential is issued: every module moved onto this bus - // by the rollout was issued on the old one, and came up with nothing to bind to (2026-09-28). - records, err := inv.BusRecords(ctx) + // And how every module hears what it consumes: asserted with the rest above, counted here. + hearing, err := moduleConsumerCount(ctx, inv) if err != nil { return err } - users, err := broker.Users(records) - if err != nil { - return err - } - hearing := 0 - for _, c := range broker.ConsumersOf(users) { - if err := js.EnsureConsumer(c.Consumer); err != nil { - return fmt.Errorf("how %s on %s hears what it consumes: %w", c.Module, c.Node, err) - } - hearing++ - } fmt.Printf("the bus at %s has its streams, %d machine(s) can hear a declaration, %d module(s) "+ "can hear what they consume, and %d bucket(s) of state\n", broker.BareAddress(address), len(names), hearing, len(buckets)) return nil diff --git a/cmd/mesh-controller/readable.go b/cmd/mesh-controller/readable.go index 0115c6c..d544e45 100644 --- a/cmd/mesh-controller/readable.go +++ b/cmd/mesh-controller/readable.go @@ -4,6 +4,7 @@ import ( "encoding/json" "fmt" "github.com/novox/mesh-controller/internal/catalogue" + "github.com/novox/mesh-controller/internal/conditions" "github.com/novox/mesh-controller/internal/inventory" "sort" "time" @@ -83,11 +84,16 @@ type meshStatus struct { // HandActsUnread says why when it could not be read, rather than reading as none. HandActsThisWeek *int `json:"handActsThisWeek,omitempty"` HandActsUnread string `json:"handActsUnread,omitempty"` - // Failing is every consumer a provider says it keeps failing, with the class of error, since - // when, and when it was last said (novox/hq ADR 0224). Absent when no provider says so. A - // document without this called the mesh well while the identity provider refused every consumer - // for a day (04-ISSUES/179). - Failing []inventory.ProviderStanding `json:"failing,omitempty"` + // Conditions is every open condition, urgent first and then oldest first (novox/hq to-be 45 §2): + // what is wrong, as the watchdogs, the self-check and the providers say it. Always present — an + // empty list is "none open" — unless they could not be read, which ConditionsUnread says. + Conditions []conditions.Condition `json:"conditions"` + ConditionsUnread string `json:"conditionsUnread,omitempty"` + // Failing is every consumer a provider says it keeps failing (novox/hq ADR 0224): the open + // conditions of that kind, carried here as well because ADR 0224 names this field. Absent when no + // provider says so. A document without it called the mesh well while the identity provider + // refused every consumer for a day (04-ISSUES/179). + Failing []conditions.Condition `json:"failing,omitempty"` // Overflowing is every module whose identity overflows the bound of a provision it requires, and // so is left out of its provider's grants (novox/hq ADR 0225). Absent when every identity fits. Overflowing []catalogue.Overflow `json:"overflowing,omitempty"` @@ -224,7 +230,11 @@ func statusAsJSON(asked answers) ([]byte, error) { } out.Unheld = asked.unheld out.HandActsThisWeek, out.HandActsUnread = asked.handActs, asked.handActsUnread - out.Failing = asked.failing + out.Conditions, out.ConditionsUnread = asked.conditions, asked.conditionsUnread + if out.Conditions == nil { + out.Conditions = []conditions.Condition{} + } + out.Failing = providerStandings(asked.conditions) out.Overflowing = asked.overflowing for name := range asked.refused { out.Unresolved = append(out.Unresolved, machineUnresolved{ diff --git a/cmd/mesh-controller/seatverbs.go b/cmd/mesh-controller/seatverbs.go index 0e0922b..a373f0d 100644 --- a/cmd/mesh-controller/seatverbs.go +++ b/cmd/mesh-controller/seatverbs.go @@ -416,6 +416,52 @@ func (a *verbArguments) commandLine() ([]string, error) { argv = append(argv, "--days", d) } return argv, nil + case "conditions": + // One verb, four shapes, as `plans` (novox/hq to-be 45 §2): a silence, one condition, the + // history, or the open ones filtered. + if key := str("silence"); key != "" { + if err := need("for", "why"); err != nil { + return nil, err + } + argv := []string{"conditions", "silence", key, "--for", str("for"), "--why", str("why")} + if c := str("cause"); c != "" { + argv = append(argv, "--cause", c) + } + return argv, nil + } + if on("history") { + argv := []string{"conditions", "history", "--json"} + if d := str("days"); d != "" { + argv = append(argv, "--days", d) + } + if k := str("key"); k != "" { + argv = append(argv, "--key", k) + } + return argv, nil + } + if k := str("key"); k != "" { + return []string{"conditions", "show", k, "--json"}, nil + } + argv := []string{"conditions", "--json"} + for _, filter := range []string{"scope", "severity", "machine"} { + if v := str(filter); v != "" { + argv = append(argv, "--"+filter, v) + } + } + return argv, nil + case "doctor": + which := 0 + argv := []string{"doctor"} + for _, sub := range []string{"run", "probes", "signals"} { + if on(sub) { + which++ + argv = append(argv, sub) + } + } + if which > 1 { + return nil, errors.New("doctor answers one of run, probes or signals at a time") + } + return append(argv, "--json"), nil case "rotate": if p := str("provision"); p != "" { argv := []string{"rotate", p} @@ -494,7 +540,7 @@ func (a *verbArguments) commandLine() ([]string, error) { // jsonVerbs are the verbs whose command speaks JSON, so the answer carries it as data as well. var jsonVerbs = map[string]bool{"status": true, "seats": true, "plan": true, "collection": true, - "hand-acts": true, "durations": true} + "hand-acts": true, "durations": true, "conditions": true, "doctor": true} // repairingCommand names a command line that repairs by hand, and so says why: a push, a plan stopped // or closed, a consumer re-made (novox/hq to-be 45 §7). Empty for any other. @@ -508,6 +554,8 @@ func repairingCommand(argv []string) string { return "broker consumer-reset" case argv[0] == "hand-act": return "hand-act record" + case argv[0] == "conditions" && len(argv) > 1 && argv[1] == "silence": + return "conditions silence" } return "" } @@ -584,6 +632,19 @@ func seatToolHandlers() (map[string]link.ToolHandler, []string, error) { if verb == "calls" { return callsAnswer(link.Calls, a.given["call"]) } + if verb == "doctor" { + // From the serving controller, which runs the self-check and hears the signals + // (novox/hq to-be 45 §4): the last verdict at once, or a run now. + argv, err := a.commandLine() + if err != nil { + return nil, err + } + sub := "" + if len(argv) > 2 { + sub = argv[1] + } + return doctorAnswer(ctx, sub) + } return seatTools(), nil } continue @@ -653,7 +714,7 @@ func actsOnAPlan(args map[string]any) bool { // inProcess are the verbs answered by this process rather than by a command it runs: `tools` from // the records, `calls` from what this process served. -var inProcess = map[string]bool{"tools": true, "calls": true} +var inProcess = map[string]bool{"tools": true, "calls": true, "doctor": true} // answersFirst is a command line whose caller is answered before it runs: a push, by its verb or // through `command`. A push sends the machine holding the bus first when its user list changed, the diff --git a/cmd/mesh-controller/seatverbs_schema_test.go b/cmd/mesh-controller/seatverbs_schema_test.go index ea666a3..bf5b907 100644 --- a/cmd/mesh-controller/seatverbs_schema_test.go +++ b/cmd/mesh-controller/seatverbs_schema_test.go @@ -272,7 +272,10 @@ var accountedFlags = map[string]map[string]string{ "json": "set by the verb: the answer is data", "all": "withheld: every measurement of a fortnight is more than a call should carry; `command` reaches it", }, - "hand-acts": {"json": "set by the verb: the answer is data"}, + "hand-acts": {"json": "set by the verb: the answer is data"}, + "conditions": {"json": "set by the verb: the answer is data"}, + "conditions history": {"json": "set by the verb: the answer is data"}, + "conditions show": {"json": "set by the verb: the answer is data"}, } // **Every flag of the command a verb runs is in the verb's schema, or accounted for here.** Derived diff --git a/cmd/mesh-controller/signals.go b/cmd/mesh-controller/signals.go new file mode 100644 index 0000000..48a3367 --- /dev/null +++ b/cmd/mesh-controller/signals.go @@ -0,0 +1,485 @@ +package main + +import ( + "fmt" + "strings" + "time" + + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/link" +) + +// The signals table (novox/hq to-be 45 §3, ADR 0227 rule 5), compiled in. +// +// **Every signal the core expects has a watchdog; its absence is a condition.** A row says what is +// expected, from whom, after what, within what bound, and what is raised when it does not come. One +// table, read three ways: by the watchdog loop (watchdogs.go), which runs every row's watch over the +// facts it gathered; by `doctor signals`, which says the age of every row's newest signal; and by the +// test generated from it (signals_test.go), which suppresses each signal in turn and asserts its +// condition — so a row added without a watch, or a watch that does not fire, fails the build. +// +// A row not watched yet says why, and in which phase it will be: a watchdog of a signal nothing emits +// would be a condition that can only cry wolf. Bounds marked provisional are set from what Phase 0 +// measured (`durations`) and corrected in Phase 1's first live week; a corrected bound is a change to +// this table, reviewed like code. + +// signalRow is one row of the table. +type signalRow struct { + Row string + Signal string + Emitter string + Trigger string + Bound string + Kind string + Severity conditions.Severity + // Phase is the phase of to-be 45 its watchdog is built in. + Phase int + // Deferred says why it is not watched yet; empty for a row that is. + Deferred string + // needs is the part of the facts the row reads: an error there is the row blind, which is + // itself said (probe-failed) rather than read as nothing wrong. + needs func(f *signalFacts) error + // watch is what is wrong now, from the facts. + watch func(f *signalFacts) []conditions.Observation + // newest is the time of the newest signal of this row, for `doctor signals`; zero when none. + newest func(f *signalFacts) time.Time +} + +// The bounds, provisional where to-be 45 says so. +const ( + // heartbeatEvery is the interval a node-engine or node tools that say none have always used. + heartbeatEvery = 60 * time.Second + // heartbeatsMissed is how many intervals may pass in silence (S1, S11). + heartbeatsMissed = 3 + // controlNodeUrgentAfter is how long the control node may be silent before it is urgent (S1). + controlNodeUrgentAfter = 30 * time.Minute + // reportAtLeast is the least a machine is given to report a send (S2). + reportAtLeast = 2 * time.Minute + // tierAtLeast is the least a plan's tier is given (S3), the bound `status` calls a plan late at. + tierAtLeast = planWaitBound + // loopDeafAfter is how long the event loop may take nothing while its consumers hold some (S4). + loopDeafAfter = 2 * time.Minute + // askAtLeast is the least a build ask is given, and askDefault the bound while nothing is + // measured (S6): the build seat declares no timeout of its own. + askAtLeast = 20 * time.Minute + askDefault = time.Hour + // callDefault is the bound of a verb that declares none (S7); push's and build's are longer. + callDefault = 10 * time.Minute + // advisoryQuiet is how long the bus must be quiet about a thing before its advisory clears (S9). + advisoryQuiet = time.Hour + // staleRefusalsAllowed in staleRefusalsWithin are what S13 lets pass from one writer. + staleRefusalsAllowed = 5 + staleRefusalsWithin = 5 * time.Minute +) + +// callBounds are the verbs that may run longer than callDefault, and how long (S7). +var callBounds = map[string]time.Duration{ + "push": 30 * time.Minute, "rotate": 30 * time.Minute, "assign": 15 * time.Minute, + "unassign": 15 * time.Minute, "command": 30 * time.Minute, "doctor": 3 * time.Minute, +} + +// callBound is a verb's bound. +func callBound(verb string) time.Duration { + if b, ok := callBounds[verb]; ok { + return b + } + return callDefault +} + +// signalsTable is the table, in to-be 45's order. +var signalsTable = []signalRow{ + {Row: "S1", Signal: "machine heartbeat", Emitter: "node-engine", Trigger: "its interval", + Bound: "3 × the interval it says (60 s when it says none), provisional; not raised while the machine " + + "said it is asleep or shutting down (ADR 0211); urgent after 30 min for a control node", + Kind: "silent", Severity: conditions.Warning, Phase: 1, + needs: func(f *signalFacts) error { return f.machinesErr }, watch: watchHeartbeats, + newest: func(f *signalFacts) time.Time { + return newestOf(f.machines, func(m machineFacts) time.Time { return m.lastHeard }) + }}, + {Row: "S2", Signal: "report after a send", Emitter: "node-engine", Trigger: "each declaration sent", + Bound: "max(2 min, 3 × that machine's last apply duration), provisional; not while the machine is silent or asleep", + Kind: "sent-not-reported", Severity: conditions.Warning, Phase: 1, + needs: func(f *signalFacts) error { return f.machinesErr }, watch: watchReports, + newest: func(f *signalFacts) time.Time { + return newestOf(f.machines, func(m machineFacts) time.Time { return m.reportedAt }) + }}, + {Row: "S3", Signal: "plan tier progress", Emitter: "controller's plan", Trigger: "each tier entered", + Bound: "max(30 min, 3 × the p90 of that repository's measured tiers), provisional; not while the " + + "build seat is paused under it", + Kind: "stalled", Severity: conditions.Warning, Phase: 1, + needs: func(f *signalFacts) error { return f.plansErr }, watch: watchPlans, + newest: func(f *signalFacts) time.Time { + return newestOf(f.plans, func(p planFacts) time.Time { return p.entered }) + }}, + {Row: "S4", Signal: "the controller's event loop takes a message", Emitter: "controller", + Trigger: "while its consumers have pending messages", Bound: "2 min", + Kind: "controller-deaf", Severity: conditions.Urgent, Phase: 1, + needs: func(f *signalFacts) error { return f.loopErr }, watch: watchLoop, + newest: func(f *signalFacts) time.Time { return f.loop.took }}, + {Row: "S5", Signal: "a merge announced becomes a plan, or nothing reads it", Emitter: "announcer → controller", + Trigger: "each merge", Bound: "10 min (the catch-up pass of issue 266)", + Kind: "merge-not-acted", Severity: conditions.Urgent, Phase: 1, + needs: func(f *signalFacts) error { return f.mergesErr }, watch: watchMerges, + newest: func(f *signalFacts) time.Time { return f.mergesPassed }}, + {Row: "S6", Signal: "a build asked → its outcome", Emitter: "build seat", Trigger: "each ask", + Bound: "max(20 min, 3 × the p90 of measured builds), 1 h while nothing is measured, provisional — the " + + "build seat declares no timeout; and an ask the queue gave up on (dead) at once", + Kind: "ask-lost", Severity: conditions.Warning, Phase: 1, + needs: func(f *signalFacts) error { return f.asksErr }, watch: watchAsks, + newest: func(f *signalFacts) time.Time { return newestOf(f.asks, func(a askFacts) time.Time { return a.since }) }}, + {Row: "S7", Signal: "a call running → finished", Emitter: "controller", Trigger: "each call", + Bound: "the verb's bound: push, rotate and command 30 min, assign and unassign 15 min, doctor 3 min, " + + "any other 10 min", + Kind: "call-hung", Severity: conditions.Warning, Phase: 1, + needs: func(*signalFacts) error { return nil }, watch: watchCalls, + newest: func(f *signalFacts) time.Time { + return newestOf(f.calls, func(c link.Call) time.Time { return c.Started }) + }}, + {Row: "S8", Signal: "a provider's failing word repeated", Emitter: "provider", + Trigger: "every 15 min while failing (ADR 0224)", Bound: "30 min", + Kind: kindProviderSilent, Severity: conditions.Warning, Phase: 1, + needs: func(f *signalFacts) error { return f.standingsErr }, watch: watchProviders, + newest: func(f *signalFacts) time.Time { + return newestOf(f.standings, func(c conditions.Condition) time.Time { return c.LastObserved }) + }}, + {Row: "S9", Signal: "bus advisories: maximum deliveries, consumer deleted; the controller's own slow " + + "consumer and refused subjects", Emitter: "bus server's advisory subjects; the controller's connection", + Trigger: "any", Bound: "any occurrence; clears after an hour without another, and a deleted consumer " + + "once it exists again or the mesh no longer expects it", + Kind: "slow-consumer, max-deliveries, refused, consumer-lost", Severity: conditions.Warning, Phase: 1, + needs: func(f *signalFacts) error { return f.advisoriesErr }, watch: watchAdvisories, + newest: func(f *signalFacts) time.Time { + return newestOf(f.advisories, func(a link.Advisory) time.Time { return a.Last }) + }}, + {Row: "S10", Signal: "the self-check's heartbeat", Emitter: "controller's doctor", Trigger: "every run", + Bound: "2 × its interval; watched from a second machine by mesh-watcher, and here as well", + Kind: "self-check-silent", Severity: conditions.Urgent, Phase: 1, + needs: func(*signalFacts) error { return nil }, watch: watchSelfCheck, + newest: func(f *signalFacts) time.Time { return f.selfCheck.last }}, + {Row: "S11", Signal: "node tools heartbeat", Emitter: "node tools", Trigger: "its interval", + Bound: "3 × the interval it says (60 s when it says none), provisional; only where node-tools is assigned", + Kind: "tools-silent", Severity: conditions.Warning, Phase: 1, + needs: func(f *signalFacts) error { return f.machinesErr }, watch: watchTools, + newest: func(f *signalFacts) time.Time { + return newestOf(f.machines, func(m machineFacts) time.Time { return m.toolsHeard }) + }}, + {Row: "S12", Signal: "the controller lease renewed", Emitter: "controller", Trigger: "every 5 s", + Bound: "15 s", Kind: "lease-lost", Severity: conditions.Urgent, Phase: 2, + Deferred: "the lease is built in Phase 2 (to-be 45 §6): there is nothing renewed to watch yet, and a " + + "second controller is caught today by its consumers being bound (standingBy)"}, + {Row: "S13", Signal: "stale refusals", Emitter: "every receiver (rule 2)", Trigger: "each refusal", + Bound: "more than 5 from one machine in 5 min", Kind: "stale-writer", Severity: conditions.Warning, Phase: 1, + needs: func(*signalFacts) error { return nil }, watch: watchStaleRefusals, + newest: func(f *signalFacts) time.Time { return time.Time{} }}, + {Row: "S14", Signal: "facts snapshot exported", Emitter: "controller", Trigger: "daily", + Bound: "2 days", Kind: "facts-stale", Severity: conditions.Warning, Phase: 5, + Deferred: "the facts snapshot is built in Phase 5 (to-be 45 §9): nothing exports one yet"}, + {Row: "S15", Signal: "a hand act with a cause already recorded", Emitter: "hand-act log", + Trigger: "each act", Bound: "the second within 14 days", Kind: "healer-wanted", + Severity: conditions.Warning, Phase: 3, + Deferred: "Phase 3 (to-be 45 §10): `hand-acts` lists repeated causes today; the condition comes with the healers"}, +} + +// newestOf is the newest time among things. +func newestOf[T any](list []T, at func(T) time.Time) time.Time { + var newest time.Time + for _, x := range list { + if t := at(x); t.After(newest) { + newest = t + } + } + return newest +} + +// ago is a duration as the summaries say it. +func ago(d time.Duration) string { + if d < time.Minute { + return d.Round(time.Second).String() + } + return d.Round(time.Minute).String() +} + +// heartbeatBound is a machine's S1 or S11 bound from the interval it says. +func heartbeatBound(every time.Duration) time.Duration { + if every <= 0 { + every = heartbeatEvery + } + return heartbeatsMissed * every +} + +func watchHeartbeats(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, m := range f.machines { + if m.lastHeard.IsZero() || m.asleep() { + // Never heard is a machine that has not joined, which status says; asleep is not lost. + continue + } + bound := heartbeatBound(m.every) + silent := f.now.Sub(m.lastHeard) + if silent <= bound { + continue + } + severity := conditions.Warning + if m.control && silent > controlNodeUrgentAfter { + severity = conditions.Urgent + } + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: m.name, Kind: "silent", + Machine: m.name, Severity: severity, + Summary: fmt.Sprintf("%s has not been heard from since %s (bound %s)", m.name, + m.lastHeard.UTC().Format("2006-01-02 15:04 MST"), bound), + Said: fmt.Sprintf("silent for %s", ago(silent))}) + } + return out +} + +func watchReports(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, m := range f.machines { + if m.sentAt.IsZero() || m.reportedCurrent || m.asleep() { + continue + } + if !m.lastHeard.IsZero() && f.now.Sub(m.lastHeard) > heartbeatBound(m.every) { + continue // silent: S1 says it, and a silent machine reports nothing + } + bound := max(reportAtLeast, 3*m.lastApply) + waited := f.now.Sub(m.sentAt) + if waited <= bound { + continue + } + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: m.name, + Kind: "sent-not-reported", Machine: m.name, Severity: conditions.Warning, + Summary: fmt.Sprintf("%s was sent a declaration at %s and has not reported applying it (bound %s)", + m.name, m.sentAt.UTC().Format("2006-01-02 15:04 MST"), ago(bound)), + Said: fmt.Sprintf("waiting %s for the report of the declaration sent", ago(waited))}) + } + return out +} + +func watchPlans(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, p := range f.plans { + if p.paused { + continue + } + in := f.now.Sub(p.entered) + if in <= p.bound { + continue + } + out = append(out, conditions.Observation{Scope: conditions.ScopePlan, ID: p.id, Kind: "stalled", + Severity: conditions.Warning, + Summary: fmt.Sprintf("the plan for %s %s has been at tier %d of %d since %s (bound %s): %s", + p.repository, short(p.commit), p.tier+1, p.tiers, p.entered.UTC().Format("2006-01-02 15:04 MST"), + ago(p.bound), p.waiting), + Said: fmt.Sprintf("at tier %d for %s: %s", p.tier+1, ago(in), p.waiting)}) + } + return out +} + +func watchLoop(f *signalFacts) []conditions.Observation { + if f.loop.pending == 0 { + return nil + } + since := f.loop.took + if since.IsZero() { + since = f.started + } + if f.now.Sub(since) <= loopDeafAfter { + return nil + } + return []conditions.Observation{{Scope: conditions.ScopeCore, ID: "controller", Kind: "controller-deaf", + Token: "deaf", Machine: f.host, Severity: conditions.Urgent, + Summary: fmt.Sprintf("the controller's event loop has taken nothing for %s while its consumers hold %d "+ + "message(s): reports, builds and merges are not being acted on", ago(f.now.Sub(since)), f.loop.pending), + Said: fmt.Sprintf("%d pending (%s), last taken %s", f.loop.pending, f.loop.where, since.UTC().Format(time.RFC3339))}} +} + +func watchMerges(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, m := range f.merges { + out = append(out, conditions.Observation{Scope: conditions.ScopeMerge, ID: m.Repo + "." + short(m.Commit), + Kind: "merge-not-acted", Token: "not-acted", Severity: conditions.Urgent, + Summary: fmt.Sprintf("%s/%s merged into %s (%s) was never handed to the controller by the bus; "+ + "acted on late by the catch-up", m.Owner, m.Repo, m.Base, short(m.Commit)), + Said: fmt.Sprintf("announced %s, %s behind it", m.At.UTC().Format(time.RFC3339), readableList(m.Modules))}) + } + return out +} + +func watchAsks(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, a := range f.asks { + var said string + switch { + case a.state == link.AskDead: + said = fmt.Sprintf("the %s queue handed it out as often as it may and it was never settled", a.seat) + case a.state == link.AskInFlight && f.now.Sub(a.since) > a.bound: + said = fmt.Sprintf("in flight on %s for %s (bound %s)", orSomewhere(a.on), ago(f.now.Sub(a.since)), ago(a.bound)) + default: + continue + } + out = append(out, conditions.Observation{Scope: conditions.ScopeBuild, ID: a.id, Kind: "ask-lost", + Token: "lost", Machine: a.on, Severity: conditions.Warning, + Summary: fmt.Sprintf("the build %s of %s has no outcome: %s", a.id, a.what, said), Said: said}) + } + return out +} + +func orSomewhere(node string) string { + if node == "" { + return "a machine that did not say which" + } + return node +} + +func watchCalls(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, c := range f.calls { + bound := callBound(c.Verb) + running := f.now.Sub(c.Started) + if running <= bound { + continue + } + out = append(out, conditions.Observation{Scope: conditions.ScopeCall, ID: c.ID, Kind: "call-hung", + Token: "hung", Machine: f.host, Severity: conditions.Warning, + Summary: fmt.Sprintf("%s.%s (call %s) has been running since %s, past its bound of %s", c.Seat, c.Verb, + c.ID, c.Started.UTC().Format("2006-01-02 15:04 MST"), ago(bound)), + Said: fmt.Sprintf("running %s, asked by %s", ago(running), orSomebody(c.Caller))}) + } + return out +} + +func orSomebody(caller string) string { + if caller == "" { + return "a caller the bus did not name" + } + return caller +} + +func watchProviders(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, c := range f.standings { + quiet := f.now.Sub(c.LastObserved) + if quiet <= providerSaysAgainWithin { + continue + } + module, node, consumer, ok := providerOf(c) + if !ok { + continue + } + out = append(out, conditions.Observation{Scope: conditions.ScopeProvider, ID: module + "." + node + "." + consumer, + Token: "silent", Kind: kindProviderSilent, Machine: node, Severity: conditions.Warning, + Summary: fmt.Sprintf("%s on %s said it keeps failing %s and has said nothing since %s: it stopped "+ + "saying anything, so its last word is all the mesh has", module, node, consumer, + c.LastObserved.UTC().Format("2006-01-02 15:04 MST")), + Said: fmt.Sprintf("not said again for %s", ago(quiet))}) + } + return out +} + +func watchAdvisories(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, a := range f.advisories { + if f.now.Sub(a.Last) > advisoryQuiet { + continue + } + if a.Kind == link.AdvisoryConsumerLost && !f.lostConsumers[a.Stream+"."+a.Consumer] { + continue // it exists again, or the mesh no longer expects it: a removal, not a loss + } + severity := conditions.Warning + times := "" + if a.Count > 1 { + times = fmt.Sprintf(" (%d times since %s)", a.Count, a.First.UTC().Format("15:04 MST")) + } + machine := "" + if a.ID == "controller" { + machine = f.host + } + out = append(out, conditions.Observation{Scope: conditions.ScopeBus, ID: a.ID, Kind: a.Kind, + Machine: machine, Severity: severity, Summary: a.Said + times, Said: a.Said}) + } + return out +} + +func watchSelfCheck(f *signalFacts) []conditions.Observation { + every := f.selfCheck.every + if every <= 0 { + every = doctorEvery + } + since := f.selfCheck.last + if since.IsZero() { + since = f.started + } + if f.now.Sub(since) <= 2*every { + return nil + } + return []conditions.Observation{{Scope: conditions.ScopeCore, ID: "doctor", Kind: "self-check-silent", + Machine: f.host, Severity: conditions.Urgent, + Summary: fmt.Sprintf("the self-check has not finished a run since %s (it runs every %s): the mesh's "+ + "invariants are not being checked", since.UTC().Format("2006-01-02 15:04 MST"), every), + Said: fmt.Sprintf("no run for %s", ago(f.now.Sub(since)))}} +} + +func watchTools(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for _, m := range f.machines { + if !m.tools || m.asleep() { + continue + } + bound := heartbeatBound(m.toolsEvery) + since := m.toolsHeard + if since.IsZero() { + // Not heard since this controller started: silent since then at the most. + since = f.toolsHeardFrom + } + silent := f.now.Sub(since) + if silent <= bound { + continue + } + heard := "not since this controller started at " + since.UTC().Format("2006-01-02 15:04 MST") + if !m.toolsHeard.IsZero() { + heard = "since " + m.toolsHeard.UTC().Format("2006-01-02 15:04 MST") + } + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: m.name, Kind: "tools-silent", + Machine: m.name, Severity: conditions.Warning, + Summary: fmt.Sprintf("the node tools on %s have not said they are there %s (bound %s): nothing can "+ + "ask that machine anything", m.name, heard, bound), + Said: fmt.Sprintf("silent for %s", ago(silent))}) + } + return out +} + +func watchStaleRefusals(f *signalFacts) []conditions.Observation { + var out []conditions.Observation + for node, n := range f.staleRefusals { + if n <= staleRefusalsAllowed { + continue + } + out = append(out, conditions.Observation{Scope: conditions.ScopeMachine, ID: node, Kind: "stale-writer", + Machine: node, Severity: conditions.Warning, + Summary: fmt.Sprintf("%s refused %d declarations in %s as older than the one it holds: a controller "+ + "is sending what it has moved past (which one is said once declarations carry an epoch, Phase 2)", + node, n, staleRefusalsWithin), + Said: fmt.Sprintf("%d stale refusals in %s", n, staleRefusalsWithin)}) + } + return out +} + +// watchedRows are the rows a watchdog runs for. +func watchedRows() []signalRow { + var out []signalRow + for _, r := range signalsTable { + if r.watch != nil { + out = append(out, r) + } + } + return out +} + +// kindsOf is a row's condition kinds, one or several. +func kindsOf(r signalRow) []string { + var out []string + for _, k := range strings.Split(r.Kind, ",") { + out = append(out, strings.TrimSpace(k)) + } + return out +} diff --git a/cmd/mesh-controller/signals_test.go b/cmd/mesh-controller/signals_test.go new file mode 100644 index 0000000..c53529e --- /dev/null +++ b/cmd/mesh-controller/signals_test.go @@ -0,0 +1,275 @@ +package main + +import ( + "context" + "errors" + "slices" + "strings" + "testing" + "time" + + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/link" +) + +// The test generated from the signals table (novox/hq to-be 45 §3, ADR 0227 rule 5, "how it is +// checked"): **every row is walked**. A watched row's signal is suppressed just inside its bound — +// nothing raised — and just past it — its condition raised, with its kind and severity — and restored, +// and the condition clears. A row that is not watched says why. A row added to the table without a +// suppression here fails, so the table cannot grow a watchdog nobody has seen fire. + +// calm is a mesh whose every signal is fresh: one control node heard ten seconds ago, its last send +// reported, a plan a minute into its tier, the loop taking, the merges read, nothing asked, no call +// running, the self-check a minute old. +func calm(now time.Time) *signalFacts { + return &signalFacts{now: now, started: now.Add(-time.Hour), host: "anchor", toolsHeardFrom: now.Add(-time.Hour), + machines: []machineFacts{{name: "anchor", control: true, lastHeard: now.Add(-10 * time.Second), + every: time.Minute, sentAt: now.Add(-time.Hour), reportedCurrent: true, reportedAt: now.Add(-59 * time.Minute), + lastApply: 20 * time.Second, tools: true, toolsHeard: now.Add(-10 * time.Second), toolsEvery: time.Minute}}, + plans: []planFacts{{id: "plan-1", repository: "novox/app", commit: "c0ffee00", tier: 0, tiers: 2, + entered: now.Add(-time.Minute), bound: 30 * time.Minute, waiting: "building"}}, + loop: loopFacts{took: now.Add(-time.Second), pending: 1}, + mergesPassed: now.Add(-time.Minute), + selfCheck: selfCheckFacts{last: now.Add(-time.Minute), every: 5 * time.Minute}, + lostConsumers: map[string]bool{}, staleRefusals: map[string]int{}, + } +} + +// suppression is one row's signal held back: inside its bound, and past it. +type suppression struct{ inside, past func(f *signalFacts) } + +// suppressions are every watched row's, by row. +var suppressions = map[string]suppression{ + "S1": { + inside: func(f *signalFacts) { f.machines[0].lastHeard = f.now.Add(-3*time.Minute + time.Second) }, + past: func(f *signalFacts) { f.machines[0].lastHeard = f.now.Add(-3*time.Minute - time.Second) }, + }, + "S2": { + inside: func(f *signalFacts) { + f.machines[0].sentAt, f.machines[0].reportedCurrent = f.now.Add(-110*time.Second), false + }, + past: func(f *signalFacts) { + f.machines[0].sentAt, f.machines[0].reportedCurrent = f.now.Add(-121*time.Second), false + }, + }, + "S3": { + inside: func(f *signalFacts) { f.plans[0].entered = f.now.Add(-29 * time.Minute) }, + past: func(f *signalFacts) { f.plans[0].entered = f.now.Add(-31 * time.Minute) }, + }, + "S4": { + inside: func(f *signalFacts) { f.loop.took = f.now.Add(-119 * time.Second) }, + past: func(f *signalFacts) { f.loop.took = f.now.Add(-121 * time.Second) }, + }, + "S5": { + inside: func(f *signalFacts) {}, + past: func(f *signalFacts) { + f.merges = []missedMerge{{Owner: "novox", Repo: "app", Base: "main", Commit: "c0ffee0011", At: f.now.Add(-11 * time.Minute)}} + }, + }, + "S6": { + inside: func(f *signalFacts) { + f.asks = []askFacts{{id: "build-1", seat: "node-build-agent", what: "novox/app", state: link.AskInFlight, + on: "anchor", since: f.now.Add(-59 * time.Minute), bound: time.Hour}} + }, + past: func(f *signalFacts) { + f.asks = []askFacts{{id: "build-1", seat: "node-build-agent", what: "novox/app", state: link.AskInFlight, + on: "anchor", since: f.now.Add(-61 * time.Minute), bound: time.Hour}} + }, + }, + "S7": { + inside: func(f *signalFacts) { + f.calls = []link.Call{{ID: "call-1", Seat: "mesh-controller", Verb: "push", Started: f.now.Add(-29 * time.Minute)}} + }, + past: func(f *signalFacts) { + f.calls = []link.Call{{ID: "call-1", Seat: "mesh-controller", Verb: "push", Started: f.now.Add(-31 * time.Minute)}} + }, + }, + "S8": { + inside: func(f *signalFacts) { f.standings = []conditions.Condition{standingSaid(f.now.Add(-29 * time.Minute))} }, + past: func(f *signalFacts) { f.standings = []conditions.Condition{standingSaid(f.now.Add(-31 * time.Minute))} }, + }, + "S9": { + inside: func(f *signalFacts) { + f.advisories = []link.Advisory{{Kind: link.AdvisoryMaxDeliveries, ID: "EVENTS.anchor_shop", Said: "gave up", + First: f.now.Add(-2 * time.Hour), Last: f.now.Add(-61 * time.Minute), Count: 1}} + }, + past: func(f *signalFacts) { + f.advisories = []link.Advisory{{Kind: link.AdvisoryMaxDeliveries, ID: "EVENTS.anchor_shop", Said: "gave up", + First: f.now.Add(-2 * time.Hour), Last: f.now.Add(-59 * time.Minute), Count: 1}} + }, + }, + "S10": { + inside: func(f *signalFacts) { f.selfCheck.last = f.now.Add(-9 * time.Minute) }, + past: func(f *signalFacts) { f.selfCheck.last = f.now.Add(-11 * time.Minute) }, + }, + "S11": { + inside: func(f *signalFacts) { f.machines[0].toolsHeard = f.now.Add(-179 * time.Second) }, + past: func(f *signalFacts) { f.machines[0].toolsHeard = f.now.Add(-181 * time.Second) }, + }, + "S13": { + inside: func(f *signalFacts) { f.staleRefusals = map[string]int{"anchor": 5} }, + past: func(f *signalFacts) { f.staleRefusals = map[string]int{"anchor": 6} }, + }, +} + +// standingSaid is a provider's failing word last said at a moment. +func standingSaid(at time.Time) conditions.Condition { + return conditions.Condition{Key: "provider.idp.anchor.app.failing", Kind: kindProviderFailing, LastObserved: at} +} + +func TestEveryRowOfTheSignalsTableIsWatchedRaisedAndCleared(t *testing.T) { + now := time.Date(2026, 10, 6, 12, 0, 0, 0, time.UTC) + seen := map[string]bool{} + for _, row := range signalsTable { + t.Run(row.Row, func(t *testing.T) { + if seen[row.Row] { + t.Fatalf("%s is in the table twice", row.Row) + } + seen[row.Row] = true + if row.Signal == "" || row.Emitter == "" || row.Trigger == "" || row.Bound == "" || row.Kind == "" || + (row.Severity != conditions.Urgent && row.Severity != conditions.Warning) { + t.Fatalf("%s does not say what it expects, from whom, within what, and what it raises: %+v", row.Row, row) + } + if row.Deferred != "" { + if row.watch != nil || row.Phase <= 1 { + t.Fatalf("%s is deferred and watched, or deferred out of Phase 1's own rows: %+v", row.Row, row) + } + if _, has := suppressions[row.Row]; has { + t.Fatalf("%s is deferred and has a suppression: one of the two is stale", row.Row) + } + return + } + if row.watch == nil || row.needs == nil || row.newest == nil { + t.Fatalf("%s is watched and lacks its watch, its needs or its newest", row.Row) + } + s, ok := suppressions[row.Row] + if !ok { + t.Fatalf("%s has no suppression in this test: a watchdog nobody has seen fire", row.Row) + } + if got := row.watch(calm(now)); len(got) != 0 { + t.Fatalf("%s raised on a calm mesh: %+v", row.Row, got) + } + inside := calm(now) + s.inside(inside) + if got := row.watch(inside); len(got) != 0 { + t.Fatalf("%s raised inside its bound: %+v", row.Row, got) + } + past := calm(now) + s.past(past) + got := row.watch(past) + if len(got) == 0 { + t.Fatalf("%s raised nothing past its bound", row.Row) + } + for _, o := range got { + if !slices.Contains(kindsOf(row), o.Kind) { + t.Errorf("%s raised %q, which is not its kind %q", row.Row, o.Kind, row.Kind) + } + if o.Severity != row.Severity { + t.Errorf("%s raised %s, the table says %s", row.Row, o.Severity, row.Severity) + } + if strings.TrimSpace(o.Summary) == "" { + t.Errorf("%s raised a condition that says nothing", row.Row) + } + } + + // Through the store: raised past the bound, cleared when the signal returns. + store := conditions.NewInMemory() + told := &conditions.Told{} + k := conditions.NewKeeper(t.Context(), conditions.Options{Store: store, History: store, Teller: told, + Now: func() time.Time { return now }}) + defer k.Close(context.Background()) + w := &watchdogs{keeper: k, started: now.Add(-time.Hour)} + w.see(t.Context(), past) + open, err := k.Open(t.Context()) + if err != nil || len(open) != len(got) { + t.Fatalf("%s past its bound left %d open (%v), want %d", row.Row, len(open), err, len(got)) + } + w.see(t.Context(), calm(now)) + if open, _ := k.Open(t.Context()); len(open) != 0 { + t.Fatalf("%s's condition stayed open after the signal returned: %+v", row.Row, open) + } + }) + } + for name := range suppressions { + if !seen[name] { + t.Errorf("a suppression for %s, which the table does not have", name) + } + } +} + +// **The control node silent for half an hour is urgent** (S1); any other machine stays a warning. +func TestTheControlNodeSilentIsUrgentAfterHalfAnHour(t *testing.T) { + now := time.Now() + f := calm(now) + f.machines[0].lastHeard = now.Add(-31 * time.Minute) + f.machines = append(f.machines, machineFacts{name: "laptop", lastHeard: now.Add(-31 * time.Minute)}) + got := watchHeartbeats(f) + if len(got) != 2 || got[0].Severity != conditions.Urgent || got[1].Severity != conditions.Warning { + t.Fatalf("%+v", got) + } +} + +// **A machine that said it sleeps is not silent** (ADR 0211), nor late to report; one that woke is. +func TestAMachineThatSaidItSleepsIsNotSilent(t *testing.T) { + now := time.Now() + f := calm(now) + f.machines[0].lastHeard = now.Add(-2 * time.Hour) + f.machines[0].sentAt, f.machines[0].reportedCurrent = now.Add(-time.Hour), false + f.machines[0].power = link.PowerState{State: "sleeping", At: now.Add(-2 * time.Hour)} + if got := append(watchHeartbeats(f), append(watchReports(f), watchTools(f)...)...); len(got) != 0 { + t.Fatalf("a sleeping machine raised %+v", got) + } + f.machines[0].power = link.PowerState{State: "woke", At: now.Add(-time.Hour)} + if got := watchHeartbeats(f); len(got) != 1 { + t.Fatalf("a woken machine silent past its bound raised %+v", got) + } +} + +// **A watchdog that cannot see says so, and clears nothing it raised** (ADR 0227 rule 4): the store +// unreadable is a probe-failed of its own, and the machine's silence stays open until it can see again. +func TestABlindWatchdogSaysSoAndClearsNothing(t *testing.T) { + now := time.Now() + store := conditions.NewInMemory() + k := conditions.NewKeeper(t.Context(), conditions.Options{Store: store, History: store}) + defer k.Close(context.Background()) + w := &watchdogs{keeper: k, started: now.Add(-time.Hour)} + silent := calm(now) + silent.machines[0].lastHeard = now.Add(-10 * time.Minute) + w.see(t.Context(), silent) + blind := calm(now) + blind.machines, blind.machinesErr = nil, errors.New("the store is away") + w.see(t.Context(), blind) + open, err := k.Open(t.Context()) + if err != nil { + t.Fatal(err) + } + var keys []string + for _, c := range open { + keys = append(keys, c.Key) + } + for _, want := range []string{"machine.anchor.silent", "probe.S1.failed", "probe.S2.failed", "probe.S11.failed"} { + if !slices.Contains(keys, want) { + t.Errorf("%s is not open while the machines cannot be read: %v", want, keys) + } + } + w.see(t.Context(), calm(now)) + if open, _ := k.Open(t.Context()); len(open) != 0 { + t.Fatalf("seeing again left open %+v", open) + } +} + +// **A controller standing by sees nothing and says nothing**: it hears no heartbeat, and would call +// every machine silent. +func TestAControllerStandingBySaysNothing(t *testing.T) { + store := conditions.NewInMemory() + k := conditions.NewKeeper(t.Context(), conditions.Options{Store: store, History: store}) + defer k.Close(context.Background()) + w := &watchdogs{keeper: k, started: time.Now(), acting: func() bool { return false }} + w.tick(t.Context()) + if w.lastTick().IsZero() { + t.Fatal("a tick standing by was not counted") + } + if open, _ := k.Open(t.Context()); len(open) != 0 { + t.Fatalf("%+v", open) + } +} diff --git a/cmd/mesh-controller/standing.go b/cmd/mesh-controller/standing.go index 24cd742..58df850 100644 --- a/cmd/mesh-controller/standing.go +++ b/cmd/mesh-controller/standing.go @@ -2,91 +2,153 @@ package main import ( "context" + "errors" "fmt" "strings" "time" + "github.com/novox/mesh-controller/internal/conditions" "github.com/novox/mesh-controller/internal/inventory" "github.com/novox/mesh-controller/internal/link" ) -// A provider that keeps failing a consumer is a problem the controller reports (novox/hq ADR 0224). +// A provider that keeps failing a consumer is a problem the controller reports (novox/hq ADR 0224) — +// **the condition store's first kind** (to-be 45 §2, ADR 0227). // // On 2026-10-05 the identity provider's provisioner failed every consumer from shortly after midnight // until it was fixed by hand that night — 31,000 refused logins after its database was moved and its // admin kept an older password — and `status` called the mesh well all day (novox/hq issue 179). A -// provider now announces a consumer it has failed for minutes; the controller keeps it until the -// provider says it recovered; and `status`, its JSON and `node show` name it, breaking "all well". +// provider announces a consumer it has failed for minutes; the controller keeps it until the provider +// says it recovered; and `status`, its JSON and `node show` name it, breaking "all well". Unchanged in +// what it says and when; kept as a condition, `provider....failing`, rather +// than a row of its own, so it is said outward like every other fault and silenced like one. -// standings keeps what providers say, in the inventory. -type standings struct{ inv *inventory.Inventory } +// Kinds of the provider standing. +const ( + kindProviderFailing = "provider-failing" + kindProviderSilent = "provider-silent" + // sourceProvisioner is what raised a standing: the provider's own event. + sourceProvisioner = "provisioner.failing" +) -func (s standings) Stood(ctx context.Context, st link.Standing) (bool, error) { - return s.inv.KeepStanding(ctx, st.Failing, inventory.ProviderStanding{ - Module: st.Module, ProviderNode: st.ProviderNode, Provision: st.Provider, - Consumer: st.Consumer, ConsumerNode: st.Node, - Class: st.Class, Error: st.Error, Since: st.Since, Attempts: st.Attempts, - }) +// providerSaysAgainWithin is how long a failing word stays current without being said again: twice +// the quarter of an hour a provider repeats it at (ADR 0224). Past it, S8. +const providerSaysAgainWithin = 30 * time.Minute + +// standings keeps what providers say, as conditions. +type standings struct { + keeper func() *conditions.Keeper } -// failingProviders is every consumer a provider still assigned where it ran says it keeps failing. -// -// **A provider no longer assigned is not asked about.** Its last word stays in the store, and is -// not a problem: nothing runs there to fail anybody. Assigned again, its first success for each -// consumer clears it. -func failingProviders(ctx context.Context, inv *inventory.Inventory) ([]inventory.ProviderStanding, error) { - all, err := inv.FailingProviders(ctx) - if err != nil { - return nil, fmt.Errorf("what providers say they keep failing cannot be read: %w", err) +// standingObservation is a provider's failing word as an observation: the provider, its machine and +// the consumer name it, so the same consumer failed again is the same condition. +func standingObservation(st link.Standing) conditions.Observation { + whom := st.Consumer + if st.Node != "" { + whom += " on " + st.Node } + summary := fmt.Sprintf("%s on %s keeps failing %s: %s, %d attempt(s) since %s", st.Module, st.ProviderNode, + whom, orUnclassed(st.Class), st.Attempts, st.Since.UTC().Format("2006-01-02 15:04 MST")) + said := orUnclassed(st.Class) + if e := firstLine(st.Error); e != "" { + said += ": " + e + } + if st.Provider != "" { + said += fmt.Sprintf(" (provision %s, %d attempts)", st.Provider, st.Attempts) + } + return conditions.Observation{Scope: conditions.ScopeProvider, + ID: st.Module + "." + st.ProviderNode + "." + st.Consumer, + Token: "failing", Kind: kindProviderFailing, Machine: st.ProviderNode, Also: alsoOn(st.Node, st.ProviderNode), + Severity: conditions.Warning, Summary: summary, Said: said, Source: sourceProvisioner} +} + +// Stood keeps a provider's newest word: failing raises or observes its condition, recovered clears +// it. An error is the store away, and the link holds the message to be asked again — a recovery is +// said once, and dropping it would leave a consumer named failing that is fine. +func (s standings) Stood(ctx context.Context, st link.Standing) (bool, error) { + k := s.keeper() + if k == nil { + return false, fmt.Errorf("the condition store is not open in this controller: %w", link.ErrTryAgain) + } + o := standingObservation(st) + if !st.Failing { + why := "the provider says it recovered" + if st.Why != "" { + why += ": " + st.Why + } + cleared, err := k.Clear(ctx, o.Key(), why) + return cleared, storeAway(err) + } + _, err := k.Observe(ctx, o) + return false, storeAway(err) +} + +// storeAway reads the condition store failing as the bus being away for the moment: the link holds the +// message and asks again, as it does for a store restarting (ADR 0083), rather than taking it unkept. +func storeAway(err error) error { + if err == nil { + return nil + } + return fmt.Errorf("%v: %w", err, link.ErrTryAgain) +} + +// providerStandings is every open provider-failing condition, from what is open. +func providerStandings(open []conditions.Condition) []conditions.Condition { + var out []conditions.Condition + for _, c := range open { + if c.Kind == kindProviderFailing { + out = append(out, c) + } + } + return out +} + +// providerOf reads a standing's provider module and machine back from its key. +func providerOf(c conditions.Condition) (module, node, consumer string, ok bool) { + parts := strings.Split(c.Key, ".") + if len(parts) != 5 || parts[0] != conditions.ScopeProvider { + return "", "", "", false + } + return parts[1], parts[2], parts[3], true +} + +// unassignedProviders clears the standing of every provider no longer assigned where it ran. +// +// **A provider no longer assigned is not asked about** (ADR 0224 §4): nothing runs there to fail +// anybody, and nothing there will ever say it recovered. The observation that resolves it is the +// assignment. Assigned again, its first failure raises it again. +func unassignedProviders(ctx context.Context, inv *inventory.Inventory, k *conditions.Keeper, + open []conditions.Condition) error { assigned := map[string]map[string]bool{} - var out []inventory.ProviderStanding - for _, s := range all { - on, asked := assigned[s.ProviderNode] + for _, c := range providerStandings(open) { + module, node, _, ok := providerOf(c) + if !ok { + continue + } + on, asked := assigned[node] if !asked { - modules, err := inv.Assigned(ctx, s.ProviderNode) + modules, err := inv.Assigned(ctx, node) if err != nil { - // A provider on a machine the mesh no longer knows has nothing running to fail anybody. - modules = nil + if errors.Is(err, inventory.ErrNoSuchNode) { + modules = nil // a machine the mesh no longer knows runs nothing + } else { + return fmt.Errorf("what %s is assigned cannot be read: %w", node, err) + } } on = map[string]bool{} for _, m := range modules { on[m] = true } - assigned[s.ProviderNode] = on + assigned[node] = on } - if on[s.Module] { - out = append(out, s) + if !on[module] { + if _, err := k.Clear(ctx, c.Key, module+" is no longer assigned to "+node+ + ": nothing runs there to fail anybody"); err != nil { + return err + } } } - return out, nil -} - -// failingLines is how status says them: one consumer per entry, the error under it, and a provider -// that stopped repeating itself said so. -func failingLines(list []inventory.ProviderStanding, now time.Time) []string { - var out []string - for _, s := range list { - where := s.Module - if s.ProviderNode != "" { - where += " on " + s.ProviderNode - } - whom := s.Consumer - if s.ConsumerNode != "" { - whom += " (" + s.ConsumerNode + ")" - } - out = append(out, fmt.Sprintf(" %-24s fails %s: %s, for %s (%d attempts since %s)", - where, whom, orUnclassed(s.Class), roughly(now.Sub(s.Since)), s.Attempts, - s.Since.Local().Format("2006-01-02 15:04"))) - if e := strings.TrimSpace(s.Error); e != "" { - out = append(out, fmt.Sprintf(" %-24s %s", "", firstLine(e))) - } - if s.Quiet(now) { - out = append(out, fmt.Sprintf(" %-24s not said again for %s — the provider has stopped "+ - "saying anything, so this is its last word", "", roughly(now.Sub(s.SaidAt)))) - } - } - return out + return nil } func orUnclassed(class string) string { @@ -96,25 +158,10 @@ func orUnclassed(class string) string { return class } -// printFailing is the status section, said when there is anything to say. -func printFailing(list []inventory.ProviderStanding, now time.Time) { - if len(list) == 0 { - return +// alsoOn is a consumer's machine, when it is not the provider's. +func alsoOn(consumerNode, providerNode string) []string { + if consumerNode == "" || consumerNode == providerNode { + return nil } - fmt.Printf("%d consumer(s) a provider keeps failing (ADR 0224):\n\n", len(list)) - for _, line := range failingLines(list, now) { - fmt.Println(line) - } - fmt.Printf("\n the provider's journal has every attempt; it says recovered on its next success\n\n") -} - -// failingOn is the standings that concern one machine: a provider running there, or a consumer. -func failingOn(list []inventory.ProviderStanding, node string) []inventory.ProviderStanding { - var out []inventory.ProviderStanding - for _, s := range list { - if s.ProviderNode == node || s.ConsumerNode == node { - out = append(out, s) - } - } - return out + return []string{consumerNode} } diff --git a/cmd/mesh-controller/standing_test.go b/cmd/mesh-controller/standing_test.go index 6a32972..e7fd312 100644 --- a/cmd/mesh-controller/standing_test.go +++ b/cmd/mesh-controller/standing_test.go @@ -7,13 +7,14 @@ import ( "time" "github.com/novox/mesh-controller/internal/catalogue" - "github.com/novox/mesh-controller/internal/inventory" + "github.com/novox/mesh-controller/internal/conditions" "github.com/novox/mesh-controller/internal/link" ) -// A provider that keeps failing a consumer is a problem `status` names (novox/hq ADR 0224). On -// 2026-10-05 the identity provider refused every consumer for a day and status called the mesh well -// (04-ISSUES/179): this is that day, told to the controller the way the provider now tells it. +// A provider that keeps failing a consumer is a problem `status` names (novox/hq ADR 0224), kept as +// the condition store's first kind (to-be 45 §2). On 2026-10-05 the identity provider refused every +// consumer for a day and status called the mesh well (04-ISSUES/179): this is that day, told to the +// controller the way the provider now tells it. func TestAProviderFailingAConsumerBreaksAllWellUntilItRecovers(t *testing.T) { open := aMesh(t) ctx := t.Context() @@ -22,7 +23,7 @@ func TestAProviderFailingAConsumerBreaksAllWellUntilItRecovers(t *testing.T) { if _, err := assign(ctx, open, "anchor", "idp"); err != nil { t.Fatal(err) } - kept := standings{open.inventory} + kept := standings{keeper: func() *conditions.Keeper { return conditionsFrom }} since := time.Now().Add(-23 * time.Hour) failing := link.Standing{Module: "idp", Failing: true, Provider: "oidc-client", ProviderNode: "anchor", Consumer: "mesh_laptop_dashboard", Node: "laptop", Class: "credentials-rejected", @@ -39,8 +40,8 @@ func TestAProviderFailingAConsumerBreaksAllWellUntilItRecovers(t *testing.T) { t.Fatal("a mesh whose identity provider fails a consumer reads as well") } said := printed(t, func() error { return printStatus(asked) }) - for _, want := range []string{"1 consumer(s) a provider keeps failing", "idp on anchor", - "mesh_laptop_dashboard (laptop)", "credentials-rejected", "31000 attempts", "invalid_grant"} { + for _, want := range []string{"1 open condition(s)", "provider.idp.anchor.mesh_laptop_dashboard.failing", + "idp on anchor keeps failing mesh_laptop_dashboard on laptop", "credentials-rejected", "31000 attempt(s)"} { if !strings.Contains(said, want) { t.Fatalf("status does not say %q:\n%s", want, said) } @@ -48,20 +49,25 @@ func TestAProviderFailingAConsumerBreaksAllWellUntilItRecovers(t *testing.T) { if strings.Contains(said, "all doing what they were told") { t.Fatalf("status said all well beside a failing provider:\n%s", said) } + if !strings.HasPrefix(said, "1 open condition(s)") { + t.Fatalf("status does not lead with what is open:\n%s", said) + } body, err := statusAsJSON(asked) if err != nil { t.Fatal(err) } var doc struct { - Failing []inventory.ProviderStanding `json:"failing"` + Conditions []conditions.Condition `json:"conditions"` + Failing []conditions.Condition `json:"failing"` } - if err := json.Unmarshal(body, &doc); err != nil || len(doc.Failing) != 1 || doc.Failing[0].Consumer != "mesh_laptop_dashboard" { + if err := json.Unmarshal(body, &doc); err != nil || len(doc.Failing) != 1 || len(doc.Conditions) != 1 || + !strings.Contains(doc.Failing[0].Evidence[0].Said, "invalid_grant") { t.Fatalf("the document does not carry it: %v\n%s", err, body) } // Both machines' `node show` name it: where the provider runs, and where the consumer is. for _, node := range []string{"anchor", "laptop"} { shown := printed(t, func() error { return showNode(ctx, open.inventory, node) }) - if !strings.Contains(shown, "a provider keeps failing") || !strings.Contains(shown, "mesh_laptop_dashboard") { + if !strings.Contains(shown, "open condition(s) about this machine") || !strings.Contains(shown, "mesh_laptop_dashboard") { t.Fatalf("node show %s does not name it:\n%s", node, shown) } } @@ -75,41 +81,38 @@ func TestAProviderFailingAConsumerBreaksAllWellUntilItRecovers(t *testing.T) { if err != nil { t.Fatal(err) } - if len(asked.failing) != 0 { - t.Fatalf("a recovered consumer is still named: %+v", asked.failing) + if len(asked.conditions) != 0 { + t.Fatalf("a recovered consumer is still named: %+v", asked.conditions) } } // A provider no longer assigned where it ran has nothing running to fail anybody: its last word is -// not a problem. -func TestAnUnassignedProvidersLastWordIsNotAProblem(t *testing.T) { +// cleared on the next look, said as resolved by the assignment. +func TestAnUnassignedProvidersLastWordIsCleared(t *testing.T) { open := aMesh(t) ctx := t.Context() - if _, err := (standings{open.inventory}).Stood(ctx, link.Standing{Module: "gone", Failing: true, + kept := standings{keeper: func() *conditions.Keeper { return conditionsFrom }} + if _, err := kept.Stood(ctx, link.Standing{Module: "gone", Failing: true, ProviderNode: "anchor", Consumer: "x", Since: time.Now()}); err != nil { t.Fatal(err) } - asked, err := theThreeQuestions(ctx, open) - if err != nil { + all, err := conditionsFrom.Open(ctx) + if err != nil || len(all) != 1 { + t.Fatalf("%+v %v", all, err) + } + if err := unassignedProviders(ctx, open.inventory, conditionsFrom, all); err != nil { t.Fatal(err) } - if len(asked.failing) != 0 { - t.Fatalf("%+v", asked.failing) + if all, _ := conditionsFrom.Open(ctx); len(all) != 0 { + t.Fatalf("%+v", all) } } -func TestAProviderThatStoppedRepeatingItselfIsSaidToHaveGoneQuiet(t *testing.T) { - now := time.Now() - lines := strings.Join(failingLines([]inventory.ProviderStanding{{ - Module: "idp", ProviderNode: "anchor", Consumer: "c", Class: "unreachable", Error: "connection refused\nmore", - Since: now.Add(-3 * time.Hour), SaidAt: now.Add(-2 * time.Hour), Attempts: 9, - }}, now), "\n") - for _, want := range []string{"unreachable, for 3h", "connection refused", "not said again for 2h"} { - if !strings.Contains(lines, want) { - t.Fatalf("%q not in:\n%s", want, lines) - } - } - if strings.Contains(lines, "more") { - t.Fatalf("more than the first line of an error:\n%s", lines) +// **The store away holds a recovery** (ADR 0224 §3): a standing that cannot be kept is asked again. +func TestAStandingTheStoreCannotKeepIsAskedAgain(t *testing.T) { + kept := standings{keeper: func() *conditions.Keeper { return nil }} + if _, err := kept.Stood(t.Context(), link.Standing{Module: "idp", ProviderNode: "anchor", Consumer: "x"}); err == nil || + !strings.Contains(err.Error(), link.ErrTryAgain.Error()) { + t.Fatalf("answered %v", err) } } diff --git a/cmd/mesh-controller/status.go b/cmd/mesh-controller/status.go index 4d0afe5..a7c732f 100644 --- a/cmd/mesh-controller/status.go +++ b/cmd/mesh-controller/status.go @@ -82,8 +82,12 @@ func printStatus(asked answers) error { wrong, nodes, quiet := asked.wrong, asked.nodes, asked.quiet behind, sources := asked.behind, asked.sources + // **What is wrong leads** (novox/hq to-be 45 §2): every open condition, urgent first, oldest + // first, silenced ones with when their silence ends. + printConditions(asked.conditions, asked.conditionsUnread, time.Now()) + if len(asked.refused) > 0 { - // First, above everything else. A machine that cannot be worked out is not running an old + // First of what follows. A machine that cannot be worked out is not running an old // declaration — it has no declaration, and nothing below this line is about it. var names []string for name := range asked.refused { @@ -130,10 +134,6 @@ func printStatus(asked answers) error { fmt.Println() } - // A provider failing a consumer, beside machines failing what they were told: both are something - // not working now (novox/hq ADR 0224). - printFailing(asked.failing, time.Now()) - if len(quiet) > 0 { var said []string for _, n := range quiet { @@ -335,8 +335,9 @@ func printStatus(asked answers) error { if asked.well() { // Said plainly. "Nothing to report" and "nothing was checked" must never look the same, - // and getting here means every question was asked and answered. - fmt.Printf("%d machine(s), all doing what they were told, all heard from, running what "+ + // and getting here means every question was asked and answered. **No open conditions first** + // (novox/hq to-be 45 §2): it is what the sentence means now, silenced ones included. + fmt.Printf("no open conditions; %d machine(s), all doing what they were told, all heard from, running what "+ "the mesh would send them, and every module current with its source\n", len(nodes)) // **And what that sentence does not cover**, because for eleven hours it was true of a mesh // in which no module could reach another (novox/hq 04-ISSUES/145). Every question above is @@ -450,11 +451,11 @@ func theThreeQuestions(ctx context.Context, open *stores) (answers, error) { // resolution, as the provider's composition judges it. out.overflowing = append(out.overflowing, plan.Overflowing()...) } - // And every consumer a provider says it keeps failing (novox/hq ADR 0224). Read from what the - // providers announced: nothing else in the mesh knows whether a provision is being made. - out.failing, err = failingProviders(ctx, inv) - if err != nil { - return answers{}, err + // And every open condition (novox/hq to-be 45 §2): what the watchdogs, the self-check and the + // providers' own words say is wrong — a provider failing a consumer among them (ADR 0224). Kept on + // the bus; a process that cannot read them says so, and the mesh is then not called well. + if out.conditions, err = openConditions(ctx); err != nil { + out.conditionsUnread = err.Error() } out.plans, err = inv.RecentPlans(ctx, 5) if err != nil { @@ -578,7 +579,8 @@ func untakenModules(ctx context.Context, inv *inventory.Inventory, nodes []inven func (a answers) well() bool { return len(a.wrong) == 0 && len(a.quiet) == 0 && len(a.behind) == 0 && len(a.waiting) == 0 && len(a.refused) == 0 && a.network == "" && len(a.untaken) == 0 && - len(a.filtered) == 0 && len(a.unheld) == 0 && len(a.failing) == 0 && len(a.overflowing) == 0 + len(a.filtered) == 0 && len(a.unheld) == 0 && len(a.overflowing) == 0 && + len(a.conditions) == 0 && a.conditionsUnread == "" } // hostSplit is which machines report which host version, for every version more than one machine diff --git a/cmd/mesh-controller/status_summary.go b/cmd/mesh-controller/status_summary.go index b814cf5..fc13a7c 100644 --- a/cmd/mesh-controller/status_summary.go +++ b/cmd/mesh-controller/status_summary.go @@ -171,6 +171,7 @@ func composeStatus(open *stores) func(context.Context) ([]byte, error) { var readingVerbs = map[string]bool{ "tools": true, "calls": true, "status": true, "nodes": true, "node": true, "modules": true, "seats": true, "builds": true, "plan": true, "queue": true, "durations": true, "hand-acts": true, + "doctor": true, "conditions": true, } // nudgingListener is the enrolment, nudging the summary when a machine said something new. @@ -180,6 +181,10 @@ type nudgingListener struct { } func (l nudgingListener) Heard(ctx context.Context, report link.Report) (bool, error) { + // A declaration refused as older than the one the machine holds is counted (novox/hq to-be 45 S13). + if link.IsStaleRefusal(report.Refused) { + link.StaleRefusals.Refused(report.Node, time.Now()) + } news, err := l.Enrolment.Heard(ctx, report) if news { l.summary.nudge() diff --git a/cmd/mesh-controller/watchdogs.go b/cmd/mesh-controller/watchdogs.go new file mode 100644 index 0000000..0510715 --- /dev/null +++ b/cmd/mesh-controller/watchdogs.go @@ -0,0 +1,549 @@ +package main + +import ( + "context" + "errors" + "fmt" + "os" + "slices" + "sort" + "sync" + "time" + + "github.com/nats-io/nats.go" + + "github.com/novox/mesh-controller/internal/broker" + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/inventory" + "github.com/novox/mesh-controller/internal/link" +) + +// The watchdogs (novox/hq to-be 45 §3): every row of the signals table, run over what the serving +// controller knows, every half minute. +// +// **One loop, one gathering, every row.** The facts are gathered once a tick — the store's machines, +// plans and durations, the bus's queue and consumers, what this process heard — and each row's watch +// is a pure reading of them, which is what lets the test generated from the table suppress a signal by +// changing a fact. A part that cannot be gathered makes the rows that read it blind: each says so as +// a condition of its own (`probe..failed`) and keeps what it raised before, because a watchdog +// that cannot see must not read as one that sees nothing wrong (ADR 0227 rule 4). +// +// **The watchdogs are themselves watched.** Each tick is recorded; the self-check (doctor.go) fails +// its probe DW when the ticks stop, and the watchdogs raise S10 when the self-check stops — two loops +// watching each other, and mesh-watcher on a second machine watching the self-check's heartbeat for +// the case both stop with the process. + +// watchEvery is how often the watchdogs run. +var watchEvery = 30 * time.Second + +// signalFacts is what one tick of the watchdogs reads. +type signalFacts struct { + now time.Time + started time.Time + // host is the machine this controller runs on, as the mesh names it, for a condition about itself. + host string + + machines []machineFacts + machinesErr error + // toolsHeardFrom is when this process began hearing node tools: one not heard since is silent + // since then at the most. + toolsHeardFrom time.Time + + plans []planFacts + plansErr error + + loop loopFacts + loopErr error + + merges []missedMerge + mergesPassed time.Time + mergesErr error + + asks []askFacts + asksErr error + + calls []link.Call + + standings []conditions.Condition + standingsErr error + + advisories []link.Advisory + lostConsumers map[string]bool + advisoriesErr error + + selfCheck selfCheckFacts + + staleRefusals map[string]int +} + +type machineFacts struct { + name string + control bool + // lastHeard is the store's last word from it, any word; zero when never. + lastHeard time.Time + // every is the heartbeat interval it said; zero when it said none. + every time.Duration + power link.PowerState + // sentAt is when it was last sent a declaration; reportedCurrent whether it has reported that one. + sentAt time.Time + reportedCurrent bool + reportedAt time.Time + // lastApply is its newest measured apply. + lastApply time.Duration + // tools is whether node-tools is assigned there; toolsHeard and toolsEvery its heartbeat. + tools bool + toolsHeard time.Time + toolsEvery time.Duration +} + +// asleep says the machine said it would be away and has not said it is back (ADR 0211). +func (m machineFacts) asleep() bool { return m.power.Away() } + +type planFacts struct { + id, repository, commit string + tier, tiers int + entered time.Time + bound time.Duration + waiting string + paused bool +} + +type loopFacts struct { + took time.Time + pending uint64 + where string +} + +type askFacts struct { + id, seat, what, state, on string + since time.Time + bound time.Duration +} + +type selfCheckFacts struct { + last time.Time + every time.Duration +} + +// watchdogs is the loop and what it needs. +type watchdogs struct { + open *stores + server *link.Server + js *broker.JetStream + keeper *conditions.Keeper + doctor *doctor + + started time.Time + // acting says this controller is the one acting, not one standing by (link.Holding): a controller + // standing by hears no heartbeat and would call every machine silent. + acting func() bool + + mu sync.Mutex + ticked time.Time + last *signalFacts + failed string +} + +// lastTick is when the watchdogs last finished a tick. +func (w *watchdogs) lastTick() time.Time { + w.mu.Lock() + defer w.mu.Unlock() + return w.ticked +} + +// lastFacts is the facts of the newest tick, for `doctor signals`; nil before the first. +func (w *watchdogs) lastFacts() *signalFacts { + w.mu.Lock() + defer w.mu.Unlock() + return w.last +} + +// keep runs the watchdogs until ctx ends. +func (w *watchdogs) keep(ctx context.Context) { + tick := time.NewTicker(watchEvery) + defer tick.Stop() + for { + w.tick(ctx) + select { + case <-ctx.Done(): + return + case <-tick.C: + } + } +} + +// tick is one run of every row. +func (w *watchdogs) tick(ctx context.Context) { + if w.acting != nil && !w.acting() { + // Standing by: nothing seen, nothing said, and the tick counted — this process's self-check + // is not the one that matters while another acts. + w.mu.Lock() + w.ticked = time.Now() + w.mu.Unlock() + return + } + running, cancel := context.WithTimeout(ctx, watchEvery) + defer cancel() + w.see(running, w.gather(running)) +} + +// see runs every watched row over one gathering, keeps what each found, and records the tick. +func (w *watchdogs) see(running context.Context, f *signalFacts) { + var problems []string + var blind []conditions.Observation + for _, row := range watchedRows() { + if err := row.needs(f); err != nil { + blind = append(blind, blindRow(row, err)) + continue + } + if err := w.keeper.Reconcile(running, row.Row, row.watch(f)); err != nil { + problems = append(problems, row.Row+": "+err.Error()) + } + } + // The rows that could not see, said; the ones that see again, cleared. + if err := w.keeper.Reconcile(running, sourceWatchdogs, blind); err != nil { + problems = append(problems, err.Error()) + } + // A provider no longer assigned where it ran: its standing is resolved by the assignment. + if f.standingsErr == nil && w.open != nil { + if err := unassignedProviders(running, w.open.inventory, w.keeper, f.standings); err != nil { + problems = append(problems, "S8: "+err.Error()) + } + } + if err := w.keeper.EndSilences(running); err != nil { + problems = append(problems, err.Error()) + } + failed := "" + if len(problems) > 0 { + failed = fmt.Sprintf("%v", problems) + } + w.mu.Lock() + said := w.failed + w.ticked, w.last, w.failed = time.Now(), f, failed + w.mu.Unlock() + if failed != said { + if failed != "" { + fmt.Printf("the watchdogs could not keep what they saw: %s\n", failed) + } else if said != "" { + fmt.Println("the watchdogs keep what they see again") + } + } +} + +// sourceWatchdogs is what raises a blind row's condition. +const sourceWatchdogs = "watchdogs" + +// blindRow is a row whose facts could not be gathered, as a condition of its own. +func blindRow(row signalRow, err error) conditions.Observation { + return conditions.Observation{Scope: conditions.ScopeProbe, ID: row.Row, Kind: "probe-failed", Token: "failed", + Severity: conditions.Warning, + Summary: fmt.Sprintf("the watchdog of %s (%s) cannot see: what it reads could not be read, so nothing "+ + "it would raise can be — and nothing it raised before is cleared", row.Row, row.Signal), + Said: firstLine(err.Error())} +} + +// gather reads every fact a tick needs. Each part's failure is kept beside it, never an empty part. +func (w *watchdogs) gather(ctx context.Context) *signalFacts { + now := time.Now() + f := &signalFacts{now: now, started: w.started, toolsHeardFrom: link.ToolsBeats.Started(), calls: link.Calls.Running(), + staleRefusals: link.StaleRefusals.Within(now.Add(-staleRefusalsWithin)), lostConsumers: map[string]bool{}} + if w.doctor != nil { + f.selfCheck = selfCheckFacts{last: w.doctor.lastRunEnded(), every: doctorEvery} + } + inv := w.open.inventory + f.host = controlHost(ctx, inv) + f.machines, f.machinesErr = w.gatherMachines(ctx, inv, now) + f.plans, f.plansErr = gatherPlans(ctx, inv, now) + f.loop, f.loopErr = w.gatherLoop() + f.mergesPassed, f.merges, f.mergesErr = watchedMerges.last() + if f.mergesErr == nil && !f.mergesPassed.IsZero() && now.Sub(f.mergesPassed) > 3*mergeCatchUpEvery { + f.mergesErr = fmt.Errorf("the catch-up of merges has not passed since %s", f.mergesPassed.UTC().Format(time.RFC3339)) + } + f.asks, f.asksErr = w.gatherAsks(ctx, inv) + if open, err := w.keeper.Open(ctx); err != nil { + f.standingsErr = err + } else { + f.standings = providerStandings(open) + } + f.advisories = link.Advisories.Since(now.Add(-advisoryQuiet)) + f.lostConsumers, f.advisoriesErr = w.lostConsumers(ctx, f.advisories) + return f +} + +// controlHost is the machine running the controller, as the mesh names it: the one the controller +// module is assigned to, or this process's host name where that is not one machine. +func controlHost(ctx context.Context, inv *inventory.Inventory) string { + if on, err := inv.Running(ctx, "mesh-controller"); err == nil && len(on) == 1 { + return on[0] + } + host, _ := os.Hostname() + return host +} + +func (w *watchdogs) gatherMachines(ctx context.Context, inv *inventory.Inventory, now time.Time) ([]machineFacts, error) { + nodes, err := inv.Nodes(ctx) + if err != nil { + return nil, fmt.Errorf("the machines cannot be read: %w", err) + } + reports, err := inv.LastReports(ctx) + if err != nil { + return nil, fmt.Errorf("what each machine last reported cannot be read: %w", err) + } + reported := map[string]inventory.Reported{} + for _, r := range reports { + reported[r.Node] = r + } + control, err := inv.Running(ctx, "mesh-controller") + if err != nil { + return nil, fmt.Errorf("where the controller runs cannot be read: %w", err) + } + tooled, err := inv.Running(ctx, broker.RuntimeModule) + if err != nil { + return nil, fmt.Errorf("where the node tools run cannot be read: %w", err) + } + applies, err := inv.Durations(ctx, inventory.DurationApply, now.Add(-7*24*time.Hour)) + if err != nil { + return nil, fmt.Errorf("the measured applies cannot be read: %w", err) + } + lastApply := map[string]time.Duration{} + for _, d := range applies { // oldest first: the last one read is the newest + lastApply[d.Node] = d.Took + } + var out []machineFacts + anyPast := false + for _, n := range nodes { + m := machineFacts{name: n.Name, control: slices.Contains(control, n.Name), lastHeard: n.LastSeen, + lastApply: lastApply[n.Name], tools: slices.Contains(tooled, n.Name)} + if beat, ok := link.HostBeats.Of(n.Name); ok { + m.every = beat.Every + } + if beat, ok := link.ToolsBeats.Of(n.Name); ok { + m.toolsHeard, m.toolsEvery = beat.At, beat.Every + } + if r, ok := reported[n.Name]; ok { + if r.Sent != nil { + m.sentAt = *r.Sent + } + if r.At != nil { + m.reportedAt = *r.At + } + m.reportedCurrent = r.Current + } + if !m.lastHeard.IsZero() && now.Sub(m.lastHeard) > heartbeatBound(m.every) { + anyPast = true + } + if m.tools && now.Sub(later(m.toolsHeard, link.ToolsBeats.Started())) > heartbeatBound(m.toolsEvery) { + anyPast = true + } + out = append(out, m) + } + // What a machine past its bound last said of its power, read only then: a machine that said it + // is asleep is not lost (ADR 0211). Unreadable is said: a sleeping laptop is then called silent, + // which is the louder mistake and the right one to make. + if anyPast && w.server != nil { + states, err := w.server.PowerStates(ctx, now.Add(-7*24*time.Hour)) + if err != nil { + fmt.Printf("what machines said of their power cannot be read, so a sleeping one is called silent: %v\n", err) + } + for i := range out { + out[i].power = states[out[i].name] + } + } + return out, nil +} + +// gatherPlans is every open plan, its tier's bound from what was measured, and what it waits on. +func gatherPlans(ctx context.Context, inv *inventory.Inventory, now time.Time) ([]planFacts, error) { + plans, err := inv.OpenPlans(ctx) + if err != nil { + return nil, fmt.Errorf("the open plans cannot be read: %w", err) + } + if len(plans) == 0 { + return nil, nil + } + tiers, err := inv.Durations(ctx, inventory.DurationPlanTier, now.Add(-14*24*time.Hour)) + if err != nil { + return nil, fmt.Errorf("the measured plan tiers cannot be read: %w", err) + } + measured := map[string][]time.Duration{} + for _, d := range tiers { + measured[d.Subject] = append(measured[d.Subject], d.Took) + } + pause := buildSeatPause(ctx, inv, plans) + var out []planFacts + for _, p := range plans { + _, paused := pausedWaiting(p, pause, now) + out = append(out, planFacts{id: p.ID, repository: p.Repository, commit: p.Commit, tier: p.Tier, + tiers: len(p.Tiers), entered: p.TierEntered, bound: max(tierAtLeast, 3*p90(measured[p.Repository])), + waiting: planLineWith(p, now, pause), paused: paused}) + } + return out, nil +} + +// p90 is the ninetieth percentile of measurements; zero for none. +func p90(took []time.Duration) time.Duration { + if len(took) == 0 { + return 0 + } + sorted := append([]time.Duration(nil), took...) + sort.Slice(sorted, func(i, j int) bool { return sorted[i] < sorted[j] }) + return sorted[int(0.9*float64(len(sorted)-1))] +} + +// gatherLoop is when the event loop last took a message and what its consumers hold. +func (w *watchdogs) gatherLoop() (loopFacts, error) { + f := loopFacts{took: link.Loop.Last()} + if w.js == nil { + return f, errors.New("this controller is not on the bus") + } + var where []string + for _, c := range broker.MeshConsumers() { + info, err := w.js.Context().ConsumerInfo(c.Stream, c.Name) + if err != nil { + return f, fmt.Errorf("the controller's consumer on %s cannot be read: %w", c.Stream, err) + } + if held := info.NumPending + uint64(info.NumAckPending); held > 0 { + f.pending += held + where = append(where, fmt.Sprintf("%d on %s", held, c.Stream)) + } + } + f.where = fmt.Sprint(where) + return f, nil +} + +// gatherAsks is every ask in the build seat's queue that is in flight or dead, with its bound. +func (w *watchdogs) gatherAsks(ctx context.Context, inv *inventory.Inventory) ([]askFacts, error) { + if w.js == nil { + return nil, errors.New("this controller is not on the bus") + } + entries, err := inv.Catalogued(ctx) + if err != nil { + return nil, fmt.Errorf("the catalogue cannot be read: %w", err) + } + seat := buildSeatAmong(entries) + q, err := link.ReadQueue(ctx, w.js, seat) + if err != nil { + return nil, err + } + builds, err := inv.Durations(ctx, inventory.DurationBuild, time.Now().Add(-14*24*time.Hour)) + if err != nil { + return nil, fmt.Errorf("the measured builds cannot be read: %w", err) + } + var took []time.Duration + for _, d := range builds { + took = append(took, d.Took) + } + bound := askDefault + if len(took) > 0 { + bound = max(askAtLeast, 3*p90(took)) + } + var out []askFacts + for _, a := range q.Asks { + if a.State != link.AskInFlight && a.State != link.AskDead { + continue + } + since := a.Started + if since.IsZero() { + since = a.AskedAt + } + what := a.Repository + if a.Path != "" { + what += " " + a.Path + } + out = append(out, askFacts{id: a.ID, seat: seat, what: what, state: a.State, on: a.On, since: since, bound: bound}) + } + return out, nil +} + +// lostConsumers is, of the consumers the bus said were deleted, each that is still missing and that +// the mesh expects: a consumer removed because its module was unassigned is not lost. +func (w *watchdogs) lostConsumers(ctx context.Context, heard []link.Advisory) (map[string]bool, error) { + out := map[string]bool{} + var deleted []link.Advisory + for _, a := range heard { + if a.Kind == link.AdvisoryConsumerLost { + deleted = append(deleted, a) + } + } + if len(deleted) == 0 { + return out, nil + } + if w.js == nil { + return nil, errors.New("this controller is not on the bus") + } + _, expected, err := expectedBusObjects(ctx, w.open.inventory) + if err != nil { + return nil, err + } + want := map[string]bool{} + for _, c := range expected { + want[c.Stream+"."+c.Name] = true + } + for _, a := range deleted { + _, err := w.js.Context().ConsumerInfo(a.Stream, a.Consumer) + switch { + case errors.Is(err, nats.ErrConsumerNotFound): + out[a.Stream+"."+a.Consumer] = want[a.Stream+"."+a.Consumer] + case err != nil: + return nil, fmt.Errorf("whether %s exists cannot be read: %w", link.ConsumerInWords(a.Stream, a.Consumer), err) + } + } + return out, nil +} + +// later is the later of two moments. +func later(a, b time.Time) time.Time { + if a.After(b) { + return a + } + return b +} + +// watchTheMesh opens the condition store and starts the watchdogs, the bus's advisories and the +// self-check, for the serving controller; the returned function stops them. Nil when the store could +// not be opened, which is said. +func watchTheMesh(ctx context.Context, open *stores, server *link.Server, bus link.OverNATS) func() { + keeper, err := keeperOn(ctx, bus.Conn) + if err != nil { + fmt.Printf("the condition store could NOT be opened, so nothing that goes wrong is kept or said, and "+ + "status says the conditions cannot be read: %v\n", err) + return nil + } + conditionsFrom = keeper + logf := func(format string, args ...any) { fmt.Printf(format+"\n", args...) } + stopHearing, err := server.HearAdvisories(logf) + if err != nil { + fmt.Printf("what the bus says about itself cannot be heard (S9 is blind): %v\n", err) + stopHearing = func() {} + } + host := controlHost(ctx, open.inventory) + w := &watchdogs{open: open, server: server, js: server.JetStream(), keeper: keeper, started: time.Now(), + acting: link.Holding} + d := &doctor{open: open, js: server.JetStream(), keeper: keeper, teller: bus, watchdogs: w, host: host} + w.doctor = d + doctorFrom = d + watching, stop := context.WithCancel(ctx) + go w.keep(watching) + go d.keep(watching) + fmt.Printf("watching the mesh: %d signal(s) every %s, %d probe(s) every %s; what is wrong is kept in %s "+ + "and said as %s events\n", len(watchedRows()), watchEvery, len(runnableProbes()), doctorEvery, + broker.ConditionsBucket, conditions.Seat) + return func() { + stop() + stopHearing() + flushing, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + keeper.Close(flushing) + } +} + +// runnableProbes are the probes the registry runs. +func runnableProbes() []probe { + var out []probe + for _, p := range probeRegistry { + if p.run != nil { + out = append(out, p) + } + } + return out +} diff --git a/go.mod b/go.mod index ac7fec7..3e253af 100644 --- a/go.mod +++ b/go.mod @@ -5,7 +5,9 @@ go 1.26.0 require ( github.com/jackc/pgx/v5 v5.10.0 github.com/nats-io/nats.go v1.54.0 + github.com/novox/mesh-host v0.0.0 golang.org/x/crypto v0.57.0 + golang.org/x/net v0.58.0 ) require ( @@ -15,8 +17,12 @@ require ( github.com/klauspost/compress v1.20.0 // indirect github.com/nats-io/nkeys v0.4.16 // indirect github.com/nats-io/nuid v1.0.1 // indirect - golang.org/x/net v0.58.0 // indirect golang.org/x/sync v0.23.0 // indirect golang.org/x/sys v0.48.0 // indirect golang.org/x/text v0.42.0 // indirect ) + +// The node-engine's own validator (mesh-host/validate, novox/hq to-be 45 D1): one validator, the host's. +// The host's module path names no forge a build can fetch from, so it is fetched from the one that +// holds it; the commit is the host's, and moves when its validator does. +replace github.com/novox/mesh-host => git.novox.be/novox/mesh-host v0.0.0-20261006081854-6953b5bafdb2 diff --git a/go.sum b/go.sum index 7edc48e..5eaa821 100644 --- a/go.sum +++ b/go.sum @@ -1,3 +1,5 @@ +git.novox.be/novox/mesh-host v0.0.0-20261006081854-6953b5bafdb2 h1:b4+F4tTfrPkuJTST+rkwIHpEb4mkVJR9158hr6nnc4g= +git.novox.be/novox/mesh-host v0.0.0-20261006081854-6953b5bafdb2/go.mod h1:VlilMCRZ5yyNXg7SNigNBLr0Gt32jrGw5KSNq5JAVYs= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= diff --git a/internal/broker/controller_buckets.go b/internal/broker/controller_buckets.go index 4b18354..e863767 100644 --- a/internal/broker/controller_buckets.go +++ b/internal/broker/controller_buckets.go @@ -19,10 +19,18 @@ import ( // like the streams, so a bus raised from nothing has them before the first call is served. // CallsBucket keeps every call of the mesh's own verbs and what came of it; HandActsBucket every act -// a person did by hand, with why. +// a person did by hand, with why; ConditionsBucket every condition open now (to-be 45 §2), one key +// each, and ConditionHistoryBucket every transition of one — raised, changed, silenced, cleared — +// for ninety days. +// +// **The history is a bucket of its own** because its keys expire and an open condition's must not: +// a bucket has one age for every key, and a condition open longer than the history is kept would +// otherwise vanish from the store while still true. var ( - CallsBucket = BucketName(ControllerSeat, "calls") - HandActsBucket = BucketName(ControllerSeat, "hand-acts") + CallsBucket = BucketName(ControllerSeat, "calls") + HandActsBucket = BucketName(ControllerSeat, "hand-acts") + ConditionsBucket = BucketName(ControllerSeat, "conditions") + ConditionHistoryBucket = BucketName(ControllerSeat, "condition-history") ) // The bounds to-be 45 §6 sets for calls: the last thousand, or fourteen days, whichever is fewer. @@ -37,11 +45,19 @@ const ( // HandActsKeptFor is as long as a condition's history (to-be 45 §2): an act by hand is read // back beside what it addressed. HandActsKeptFor = 90 * 24 * time.Hour + // ConditionHistoryKeptFor is how long a condition's transitions are kept (to-be 45 §2). + ConditionHistoryKeptFor = 90 * 24 * time.Hour ) // IsControllerBucket says a bucket is the controller's own, not a module's state nothing declares. func IsControllerBucket(bucket string) bool { - return bucket == CallsBucket || bucket == HandActsBucket + return bucket == CallsBucket || bucket == HandActsBucket || bucket == ConditionsBucket || + bucket == ConditionHistoryBucket +} + +// ControllerBuckets are the controller's own buckets, in the order they are asserted. +func ControllerBuckets() []string { + return []string{CallsBucket, HandActsBucket, ConditionsBucket, ConditionHistoryBucket} } // ControllerBucketsAsserter is what raising the controller's buckets needs of a connection. @@ -98,5 +114,30 @@ func (j *JetStream) EnsureControllerBuckets() error { }); err != nil { return fmt.Errorf("asserting bucket %s: %w", HandActsBucket, err) } + // **No age on the open conditions.** A condition is removed when observation clears it and at no + // other moment: one that expired would be a fault the store forgot while it was still true. + if _, err := js.CreateOrUpdateKeyValue(ctx, jetstream.KeyValueConfig{ + Bucket: ConditionsBucket, + Description: "every condition open now, one key each (novox/hq to-be 45 §2): written by the " + + "controller alone, raised and cleared by observation, read through `conditions`", + History: 1, + MaxValueSize: 64 << 10, + MaxBytes: 64 << 20, + Storage: jetstream.FileStorage, + }); err != nil { + return fmt.Errorf("asserting bucket %s: %w", ConditionsBucket, err) + } + if _, err := js.CreateOrUpdateKeyValue(ctx, jetstream.KeyValueConfig{ + Bucket: ConditionHistoryBucket, + Description: "every transition of a condition — raised, changed, silenced, cleared — kept ninety " + + "days (novox/hq to-be 45 §2): written by the controller alone, read through `conditions history`", + History: 1, + TTL: ConditionHistoryKeptFor, + MaxValueSize: 64 << 10, + MaxBytes: 256 << 20, + Storage: jetstream.FileStorage, + }); err != nil { + return fmt.Errorf("asserting bucket %s: %w", ConditionHistoryBucket, err) + } return nil } diff --git a/internal/broker/controller_buckets_test.go b/internal/broker/controller_buckets_test.go index bb9008d..9696547 100644 --- a/internal/broker/controller_buckets_test.go +++ b/internal/broker/controller_buckets_test.go @@ -2,6 +2,7 @@ package broker import ( "slices" + "strings" "testing" ) @@ -29,3 +30,32 @@ func TestTheControllerMayWriteEveryBucketItWrites(t *testing.T) { t.Error("the controller may write any bucket, a module's state included") } } + +// **A machine's node tools may say they are there, as that machine and no other** (novox/hq to-be 45 +// S11), and the controller may hear the bus's advisories and ask who answers — read-only, named. +func TestTheWatchedSignalsMayBeSaidAndHeard(t *testing.T) { + tools, err := PermissionsFor(Principal{Kind: KindNodeTools, Node: "anchor", Module: RuntimeModule, PasswordHash: "x"}) + if err != nil { + t.Fatal(err) + } + if !slices.Contains(tools.Publish, "mesh.control.anchor.tools-alive") { + t.Error("the node tools may not say they are there") + } + for _, s := range tools.Publish { + if strings.Contains(s, "tools-alive") && s != "mesh.control.anchor.tools-alive" { + t.Errorf("the node tools may say %s", s) + } + } + controller, err := PermissionsFor(Principal{Kind: KindController, PasswordHash: "x"}) + if err != nil { + t.Fatal(err) + } + for _, s := range BusAdvisories { + if !slices.Contains(controller.Subscribe, s) { + t.Errorf("the controller may not hear %s", s) + } + } + if !slices.Contains(controller.Publish, "$SRV.INFO") || slices.Contains(controller.Subscribe, "$JS.EVENT.>") { + t.Error("the controller may not ask who answers, or hears every API call") + } +} diff --git a/internal/broker/nats.go b/internal/broker/nats.go index 112f8eb..3fb374a 100644 --- a/internal/broker/nats.go +++ b/internal/broker/nats.go @@ -266,6 +266,9 @@ func PermissionsFor(p Principal) (Permissions, error) { sub = append(sub, "mesh.seat."+ControllerSeat+".tool.>") // And says so (novox/hq ADR 0197): it answers discovery for the seat it serves. sub = append(sub, announcing(ControllerSeat)...) + // And asks who answers (novox/hq to-be 45 §4, D3): the self-check finds every seat's holder by + // the same discovery the console reads. The question only; the answers come to its own inbox. + pub = append(pub, "$SRV.INFO") // The events it reacts to, and its ack subject on the stream they arrive from // (streams.go). **Each named, not a pattern**: `mesh.mod.*.event.>` would make the @@ -297,7 +300,14 @@ func PermissionsFor(p Principal) (Permissions, error) { // **And its own buckets** (novox/hq to-be 45 §1): the calls it served and the acts done by // hand, which it alone writes. A put is a publish to the bucket's subject, which `$JS.API.>` // does not cover; each bucket named, not `$KV.>`, which would let it write any module's state. - pub = append(pub, "$KV."+CallsBucket+".>", "$KV."+HandActsBucket+".>") + for _, bucket := range ControllerBuckets() { + pub = append(pub, "$KV."+bucket+".>") + } + // **And what the bus says about itself, read-only** (novox/hq to-be 45 §3, S9): a durable + // consumer that gave up on a message, or one that was deleted. The server already publishes + // both in the mesh's own account; the controller says each as a condition in the mesh's words. + // Named, not `$JS.EVENT.>`: the other advisories are every API call the mesh makes. + sub = append(sub, BusAdvisories...) case KindPerson: // Tools, and nothing else. Every subject a person may publish is a tool call; a person @@ -510,6 +520,9 @@ func PermissionsFor(p Principal) (Permissions, error) { // that varies is the module, so the pattern is the machine's own assignments. sub = append(sub, "mesh.assignment."+p.Node+".*") pub = append(pub, "$JS.API.DIRECT.GET."+AssignmentsStream+".mesh.assignment."+p.Node+".*") + // And that it is there (novox/hq to-be 45 §3, S11): its own heartbeat, under its machine's + // name and no other's, on core NATS like the host's. + pub = append(pub, "mesh.control."+p.Node+".tools-alive") // And every tool on the mesh (ADR 0175, decision 5): any node may call any tool on any // node, as the console already could — the runtime is the console's serving mode. invoked, err := invokedSubjects([]string{"*"}) diff --git a/internal/broker/states_agreement_test.go b/internal/broker/states_agreement_test.go index afd132f..e7162b4 100644 --- a/internal/broker/states_agreement_test.go +++ b/internal/broker/states_agreement_test.go @@ -6,6 +6,7 @@ import ( "github.com/novox/mesh-controller/internal/broker" "github.com/novox/mesh-controller/internal/catalogue" + "github.com/novox/mesh-controller/internal/conditions" "github.com/novox/mesh-controller/internal/link" ) @@ -20,12 +21,15 @@ func TestTheFactsTheGrantPermitsAreTheFactsTheMeshStates(t *testing.T) { t.Fatalf("the grant is written for the %q seat and the mesh states its facts under %q", broker.ControllerSeat, link.MeshControllerSeat) } - for _, event := range []string{link.KeyApplied, link.KeyRefused, link.KeyBuiltBefore} { + // And what is wrong, as it changes, and the self-check's heartbeat (novox/hq to-be 45 §2, §4). + states := append([]string{link.KeyApplied, link.KeyRefused, link.KeyBuiltBefore}, conditions.Events...) + states = append(states, conditions.HeartbeatEvent) + for _, event := range states { if !slices.Contains(broker.ControllerStates, event) { t.Errorf("the mesh states %q and its account may not publish it", event) } } - if len(broker.ControllerStates) != 3 { + if len(broker.ControllerStates) != len(states) { t.Errorf("the grant permits %v, which is more than the mesh states", broker.ControllerStates) } // **And the seat says it.** A seat carries the protocol of its role (novox/hq ADR 0129), so the diff --git a/internal/broker/streams.go b/internal/broker/streams.go index cfd7e52..b314df8 100644 --- a/internal/broker/streams.go +++ b/internal/broker/streams.go @@ -201,7 +201,23 @@ const ControllerName = "controller" // something to say. const ControllerSeat = "mesh-controller" -var ControllerStates = []string{"applied", "refused", "built-before"} +var ControllerStates = []string{"applied", "refused", "built-before", + // What is wrong, said as it changes (novox/hq to-be 45 §2): a condition raised, changed in + // severity, resolver or silence, and cleared. The operator-channel's holder and any other surface + // consume them; the controller tells nobody itself. + "condition-raised", "condition-changed", "condition-cleared", + // And the self-check's heartbeat, at the end of every run (to-be 45 §4, S10): watched from a + // machine that is not the control node, so the controller going quiet is itself said. + "doctor-heartbeat"} + +// BusAdvisories are what the bus server says about the mesh's own account that the controller +// reads (novox/hq to-be 45 §3, S9): a durable consumer that handed a message over as often as it +// may and gave up on it, and one that was deleted. Read-only: an advisory is the server's to +// publish, and the controller's subscription changes nothing on the bus. +var BusAdvisories = []string{ + "$JS.EVENT.ADVISORY.CONSUMER.MAX_DELIVERIES.>", + "$JS.EVENT.ADVISORY.CONSUMER.DELETED.>", +} // ControllerFollows are the events the controller reacts to: the catalogue saying a module's // current version moved, and a catalogue that has just started saying it may have missed builds. diff --git a/internal/broker/testdata/composed.conf b/internal/broker/testdata/composed.conf index 93395ba..344f363 100644 --- a/internal/broker/testdata/composed.conf +++ b/internal/broker/testdata/composed.conf @@ -24,8 +24,8 @@ accounts { jetstream: enabled users = [ { user: "controller", password: "$2a$11$cccccccccccccccccccccc", permissions: { - publish: { allow: ["$JS.ACK.CONTROL.controller.>", "$JS.ACK.EVENTS.controller.>", "$JS.API.>", "$KV.SEAT_MESH_BUILD_MACHINE_cancelled.>", "$KV.SEAT_NODE_BUILD_AGENT_cancelled.>", "$KV.mesh-controller_calls.>", "$KV.mesh-controller_hand-acts.>", "_INBOX.enrol.>", "mesh.assignment.>", "mesh.control.>", "mesh.mod.*.tool.>", "mesh.node.>", "mesh.seat.mesh-build-machine.accept.>", "mesh.seat.mesh-build-machine.tool.>", "mesh.seat.mesh-controller.event.applied", "mesh.seat.mesh-controller.event.built-before", "mesh.seat.mesh-controller.event.refused", "mesh.seat.node-build-agent.accept.>", "mesh.seat.node-build-agent.tool.>"] } - subscribe: { allow: ["$JS.API.>", "$SRV.INFO", "$SRV.INFO.mesh-controller", "$SRV.INFO.mesh-controller.>", "$SRV.PING", "$SRV.PING.mesh-controller", "$SRV.PING.mesh-controller.>", "$SRV.STATS", "$SRV.STATS.mesh-controller", "$SRV.STATS.mesh-controller.>", "_DELIVER.controller", "_DELIVER.controller.>", "_INBOX.controller.>", "mesh.control.>", "mesh.mod.*.event.provisioner.failing", "mesh.mod.*.event.provisioner.recovered", "mesh.mod.gitea.event.pull.merged", "mesh.mod.mesh-catalog.event.catching-up", "mesh.mod.mesh-catalog.event.upgraded", "mesh.seat.mesh-build-machine.event.built", "mesh.seat.mesh-controller.tool.>", "mesh.seat.node-build-agent.event.built"] } + publish: { allow: ["$JS.ACK.CONTROL.controller.>", "$JS.ACK.EVENTS.controller.>", "$JS.API.>", "$KV.SEAT_MESH_BUILD_MACHINE_cancelled.>", "$KV.SEAT_NODE_BUILD_AGENT_cancelled.>", "$KV.mesh-controller_calls.>", "$KV.mesh-controller_condition-history.>", "$KV.mesh-controller_conditions.>", "$KV.mesh-controller_hand-acts.>", "$SRV.INFO", "_INBOX.enrol.>", "mesh.assignment.>", "mesh.control.>", "mesh.mod.*.tool.>", "mesh.node.>", "mesh.seat.mesh-build-machine.accept.>", "mesh.seat.mesh-build-machine.tool.>", "mesh.seat.mesh-controller.event.applied", "mesh.seat.mesh-controller.event.built-before", "mesh.seat.mesh-controller.event.condition-changed", "mesh.seat.mesh-controller.event.condition-cleared", "mesh.seat.mesh-controller.event.condition-raised", "mesh.seat.mesh-controller.event.doctor-heartbeat", "mesh.seat.mesh-controller.event.refused", "mesh.seat.node-build-agent.accept.>", "mesh.seat.node-build-agent.tool.>"] } + subscribe: { allow: ["$JS.API.>", "$JS.EVENT.ADVISORY.CONSUMER.DELETED.>", "$JS.EVENT.ADVISORY.CONSUMER.MAX_DELIVERIES.>", "$SRV.INFO", "$SRV.INFO.mesh-controller", "$SRV.INFO.mesh-controller.>", "$SRV.PING", "$SRV.PING.mesh-controller", "$SRV.PING.mesh-controller.>", "$SRV.STATS", "$SRV.STATS.mesh-controller", "$SRV.STATS.mesh-controller.>", "_DELIVER.controller", "_DELIVER.controller.>", "_INBOX.controller.>", "mesh.control.>", "mesh.mod.*.event.provisioner.failing", "mesh.mod.*.event.provisioner.recovered", "mesh.mod.gitea.event.pull.merged", "mesh.mod.mesh-catalog.event.catching-up", "mesh.mod.mesh-catalog.event.upgraded", "mesh.seat.mesh-build-machine.event.built", "mesh.seat.mesh-controller.tool.>", "mesh.seat.node-build-agent.event.built"] } allow_responses: { max: 1, ttl: "1m" } } } { user: "enrol.one", password: "$2a$11$eeeeeeeeeeeeeeeeeeeeee", permissions: { diff --git a/internal/catalogue/seats.go b/internal/catalogue/seats.go index 8177582..2fa3c70 100644 --- a/internal/catalogue/seats.go +++ b/internal/catalogue/seats.go @@ -83,7 +83,9 @@ var defaultSeats = append([]Seat{ // `assign` and the rest are a role's interface, not a container's, and stay addressable while // the control plane is replaced. {Name: ControllerSeatName, Scope: ScopeMesh, Decision: "novox/hq ADR 0079", - Emits: []string{"applied", "refused", "built-before"}, + // And what is wrong, as it changes, and the self-check's heartbeat (novox/hq to-be 45 §2, §4). + Emits: []string{"applied", "refused", "built-before", + "condition-raised", "condition-changed", "condition-cleared", "doctor-heartbeat"}, Serves: ControllerVerbs}, // The store's first verbs (novox/hq ADR 0159): the smallest set that makes the store askable, // served by whichever module holds the seat with tools of these names. diff --git a/internal/catalogue/verbs.go b/internal/catalogue/verbs.go index 6ab9fd2..657814d 100644 --- a/internal/catalogue/verbs.go +++ b/internal/catalogue/verbs.go @@ -231,6 +231,33 @@ var ControllerVerbs = []Verb{ "kind": "one kind: apply, heartbeat-gap, plan-tier or build; every kind when absent", "days": "how many days back (default 14)", }, nil)}, + // What is wrong, and the self-check (novox/hq to-be 45 §2, §4). + {Name: "conditions", Description: "What is wrong with the mesh now: every open condition, urgent first, " + + "then oldest — raised by the watchdogs of the signals table, the self-check's probes and the providers' " + + "own words, and cleared when observation says it is resolved, never by hand. Given a key, that one " + + "whole with its evidence; with history, every transition lately; with silence, stop one's messages " + + "for a while — a hand act, which says why (novox/hq to-be 45 §2).", + Input: schema(map[string]string{ + "key": "a condition's key: that one whole; with history, only its transitions", + "scope": "only this scope: machine, plan, call, build, merge, provider, seat, bus, core, probe or mesh", + "severity": "only urgent, or only warning", + "machine": "only those about this machine", + "history": "\"true\": every raising, change, silence and clearing lately, oldest first", + "days": "with history: how many days back (default 7, at most 90)", + "silence": "a condition's key: send no message for it for a while; it stays open and in status", + "for": "with silence: how long — 30m, 4h, 2d; at most 7d", + "why": "with silence: why — required, and recorded in the hand-act log", + "cause": "with silence: the cause in a word (the condition's kind when absent)", + }, nil, "history")}, + {Name: "doctor", Description: "The self-check (novox/hq to-be 45 §4): the last run's verdict at once — " + + "each probe of the design's live invariants passed, failed or could not run, and how long ago. With " + + "run, a run now; with probes, the registry; with signals, every row of the signals table and the age " + + "of its newest signal. Runs every five minutes on its own; each failure is an open condition.", + Input: schema(map[string]string{ + "run": "\"true\": run every probe now and answer the verdict", + "probes": "\"true\": the registry — what each probe asserts, and the condition it raises", + "signals": "\"true\": the signals table, each row with the age of its newest signal", + }, nil, "run", "probes", "signals")}, {Name: "build", Description: "Have the build machine build a repository. Answers at once with the build's id: " + "`builds` with that id follows it line by line, and the module is registered when the outcome comes.", Input: schema(map[string]string{ diff --git a/internal/conditions/bus.go b/internal/conditions/bus.go new file mode 100644 index 0000000..8d14df8 --- /dev/null +++ b/internal/conditions/bus.go @@ -0,0 +1,159 @@ +package conditions + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "sort" + "strconv" + "sync/atomic" + "time" + + "github.com/nats-io/nats.go" + "github.com/nats-io/nats.go/jetstream" + + "github.com/novox/mesh-controller/internal/broker" +) + +// The condition store on the bus (to-be 45 §2, ADR 0201): the controller's two buckets, asserted at +// its start like its calls and its hand-act log. + +// OnTheBus opens the store and its history on a connection. +func OnTheBus(ctx context.Context, conn *nats.Conn) (Backend, History, error) { + api, err := jetstream.New(conn) + if err != nil { + return nil, nil, err + } + open, err := api.KeyValue(ctx, broker.ConditionsBucket) + if err != nil { + return nil, nil, fmt.Errorf("the condition store %s is not on the bus — the controller asserts it at "+ + "its start, so one older than this has not: %w", broker.ConditionsBucket, err) + } + history, err := api.KeyValue(ctx, broker.ConditionHistoryBucket) + if err != nil { + return nil, nil, fmt.Errorf("the condition history %s is not on the bus — the controller asserts it "+ + "at its start, so one older than this has not: %w", broker.ConditionHistoryBucket, err) + } + return busStore{open}, &busHistory{api: api, kv: history}, nil +} + +type busStore struct{ kv jetstream.KeyValue } + +func (b busStore) Get(ctx context.Context, key string) (Entry, bool, error) { + e, err := b.kv.Get(ctx, key) + if errors.Is(err, jetstream.ErrKeyNotFound) { + return Entry{}, false, nil + } + if err != nil { + return Entry{}, false, err + } + return Entry{Value: e.Value(), Revision: e.Revision()}, true, nil +} + +func (b busStore) Create(ctx context.Context, key string, value []byte) error { + _, err := b.kv.Create(ctx, key, value) + if errors.Is(err, jetstream.ErrKeyExists) { + return ErrMoved + } + return err +} + +func (b busStore) Update(ctx context.Context, key string, value []byte, revision uint64) error { + _, err := b.kv.Update(ctx, key, value, revision) + return moved(err) +} + +func (b busStore) Delete(ctx context.Context, key string, revision uint64) error { + return moved(b.kv.Delete(ctx, key, jetstream.LastRevision(revision))) +} + +// moved reads the server's refusal of a compare-and-set as what it is. +func moved(err error) error { + var apiErr *jetstream.APIError + if errors.As(err, &apiErr) && apiErr.ErrorCode == jetstream.JSErrCodeStreamWrongLastSequence { + return ErrMoved + } + return err +} + +// All is every key, read through a watch that hands over each current value and then says it has. +func (b busStore) All(ctx context.Context) (map[string]Entry, error) { + w, err := b.kv.WatchAll(ctx, jetstream.IgnoreDeletes()) + if err != nil { + return nil, err + } + defer func() { _ = w.Stop() }() + out := map[string]Entry{} + for { + select { + case <-ctx.Done(): + return nil, fmt.Errorf("reading the condition store: %w", ctx.Err()) + case e := <-w.Updates(): + if e == nil { + return out, nil + } + out[e.Key()] = Entry{Value: e.Value(), Revision: e.Revision()} + } + } +} + +// busHistory keeps each transition under a key of its time and a sequence, and reads them back +// from a moment through the stream under the bucket — by time, so a read of the last ten minutes +// does not read ninety days. +type busHistory struct { + api jetstream.JetStream + kv jetstream.KeyValue + seq atomic.Uint64 +} + +func (h *busHistory) Append(ctx context.Context, e Event) error { + body, err := json.Marshal(e) + if err != nil { + return err + } + key := strconv.FormatInt(e.At.UnixNano(), 10) + "-" + strconv.FormatUint(h.seq.Add(1), 10) + _, err = h.kv.Put(ctx, key, body) + return err +} + +// historyQuiet is how long a read of the history waits for one more transition before it takes the +// stream as read to its end; it answers at once while it holds something. +const historyQuiet = 2 * time.Second + +func (h *busHistory) Since(ctx context.Context, since time.Time) ([]Event, error) { + start := since + consumer, err := h.api.OrderedConsumer(ctx, "KV_"+broker.ConditionHistoryBucket, jetstream.OrderedConsumerConfig{ + DeliverPolicy: jetstream.DeliverByStartTimePolicy, OptStartTime: &start, + }) + if err != nil { + return nil, fmt.Errorf("reading the condition history: %w", err) + } + info, err := consumer.Info(ctx) + if err != nil { + return nil, fmt.Errorf("reading the condition history: %w", err) + } + var out []Event + pending := info.NumPending + for pending > 0 { + msg, err := consumer.Next(jetstream.FetchMaxWait(historyQuiet)) + if err != nil { + if ctx.Err() != nil { + return nil, ctx.Err() + } + // Nothing more within the quiet wait: read to its end. + break + } + meta, err := msg.Metadata() + if err != nil { + break + } + pending = meta.NumPending + var e Event + if len(msg.Data()) > 0 && json.Unmarshal(msg.Data(), &e) == nil && e.Key != "" { + out = append(out, e) + } + } + sort.SliceStable(out, func(i, j int) bool { return out[i].At.Before(out[j].At) }) + return out, nil +} diff --git a/internal/conditions/bus_test.go b/internal/conditions/bus_test.go new file mode 100644 index 0000000..ad3e12f --- /dev/null +++ b/internal/conditions/bus_test.go @@ -0,0 +1,117 @@ +package conditions + +import ( + "context" + "os" + "testing" + "time" + + "github.com/nats-io/nats.go/jetstream" + + "github.com/novox/mesh-controller/internal/broker" +) + +// The condition store against a real server: compare-and-set, an unreadable store refused, and the +// history read back by time are claims about what the bus does. + +func busStoreForTest(t *testing.T) (*broker.JetStream, Backend, History) { + t.Helper() + url := os.Getenv("MESH_TEST_NATS") + if url == "" { + t.Skip("MESH_TEST_NATS unset") + } + js, err := broker.Dial(url) + if err != nil { + t.Fatal(err) + } + t.Cleanup(js.Close) + api, err := jetstream.New(js.Conn()) + if err != nil { + t.Fatal(err) + } + _ = api.DeleteKeyValue(t.Context(), broker.ConditionsBucket) + _ = api.DeleteKeyValue(t.Context(), broker.ConditionHistoryBucket) + if err := js.EnsureControllerBuckets(); err != nil { + t.Fatal(err) + } + store, history, err := OnTheBus(t.Context(), js.Conn()) + if err != nil { + t.Fatal(err) + } + return js, store, history +} + +// **A condition outlives the controller that raised it**, and two writers on the bus cannot lose each +// other's word: a stale revision is refused as moved. +func TestNatsTheStoreKeepsConditionsByCompareAndSet(t *testing.T) { + _, store, history := busStoreForTest(t) + ctx := t.Context() + told := &Told{} + k := NewKeeper(ctx, Options{Store: store, History: history, Teller: told}) + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + k.Close(context.Background()) + + again := NewKeeper(ctx, Options{Store: store, History: history}) + defer again.Close(context.Background()) + open, err := again.Open(ctx) + if err != nil { + t.Fatal(err) + } + if len(open) != 1 || open[0].Observations != 2 { + t.Fatalf("a new keeper read %+v", open) + } + e, _, err := store.Get(ctx, "machine.ace.silent") + if err != nil { + t.Fatal(err) + } + if err := store.Update(ctx, "machine.ace.silent", []byte(`{}`), e.Revision-1); err != ErrMoved { + t.Fatalf("a write at a stale revision answered %v", err) + } + if err := store.Create(ctx, "machine.ace.silent", []byte(`{}`)); err != ErrMoved { + t.Fatalf("creating an open condition answered %v", err) + } + if err := store.Delete(ctx, "machine.ace.silent", e.Revision-1); err != ErrMoved { + t.Fatalf("a delete at a stale revision answered %v", err) + } + if cleared, err := again.Clear(ctx, "machine.ace.silent", "heard"); err != nil || !cleared { + t.Fatalf("cleared %v: %v", cleared, err) + } + // Raised again at once: the store takes a key whose last word was a delete. + if _, err := again.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + got, _, _ := again.Get(ctx, "machine.ace.silent") + if got.Count != 2 { + t.Fatalf("raised again after its clearing as %+v", got) + } +} + +// **The history is read back from a moment, oldest first**, through the stream under its bucket. +func TestNatsTheHistoryIsReadByTime(t *testing.T) { + _, store, history := busStoreForTest(t) + ctx := t.Context() + k := NewKeeper(ctx, Options{Store: store, History: history}) + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + if _, err := k.Clear(ctx, "machine.ace.silent", "heard"); err != nil { + t.Fatal(err) + } + k.Close(context.Background()) + all, err := history.Since(ctx, time.Now().Add(-time.Hour)) + if err != nil { + t.Fatal(err) + } + if len(all) != 2 || all[0].Change != ChangeRaised || all[1].Change != ChangeCleared { + t.Fatalf("history %+v", all) + } + none, err := history.Since(ctx, time.Now().Add(time.Hour)) + if err != nil || len(none) != 0 { + t.Fatalf("history from the future: %+v %v", none, err) + } +} diff --git a/internal/conditions/condition.go b/internal/conditions/condition.go new file mode 100644 index 0000000..a09301a --- /dev/null +++ b/internal/conditions/condition.go @@ -0,0 +1,232 @@ +// Package conditions is the condition store (novox/hq to-be 45 §2, ADR 0227 rules 5 and 6). +// +// **A condition is a durable fact about something the mesh owns that is wrong.** Until this, every +// one of the forty-eight core failures of research 031 was noticed because a person or an agent +// looked: the mesh's own answers carried the fact for whoever asked, and told nobody. A condition is +// raised when an observation says something is wrong past its bound, kept with since-when, evidence +// and who can resolve it, said on the bus as it changes, and cleared when an observation says it is +// resolved — never by hand. +// +// The controller is the store's only writer (to-be 45 §1). Two of its processes may write at once — +// the serving controller's watchdogs, and a command a person runs to silence one — so every write +// is a compare-and-set on the key's revision, and a write that lost the race reads again and redoes +// itself rather than overwriting what the other said. +package conditions + +import ( + "fmt" + "regexp" + "sort" + "strings" + "time" +) + +// Severity is how soon the operator is needed: two levels, no more (to-be 45 §2). +type Severity string + +const ( + // Urgent needs the operator now. + Urgent Severity = "urgent" + // Warning needs the operator when they can. + Warning Severity = "warning" +) + +// The scopes a condition's key starts with: what kind of thing is wrong. +const ( + ScopeMachine = "machine" + ScopePlan = "plan" + ScopeCall = "call" + ScopeBuild = "build" + ScopeMerge = "merge" + ScopeProvider = "provider" + ScopeSeat = "seat" + ScopeBus = "bus" + ScopeCore = "core" + ScopeProbe = "probe" + ScopeMesh = "mesh" +) + +// Scopes is every scope, in the order a person reads them. +var Scopes = []string{ScopeMachine, ScopePlan, ScopeCall, ScopeBuild, ScopeMerge, ScopeProvider, + ScopeSeat, ScopeBus, ScopeCore, ScopeProbe, ScopeMesh} + +// Who resolves a condition. +const ( + // ResolverSelf clears on observation: the signal returns, the probe passes. + ResolverSelf = "self" + // ResolverOperator needs a person: a healer's budget spent, or a repair that could only destroy. + ResolverOperator = "operator" + // ResolverAgent is work handed to an agent (research 017; not raised by anything yet). + ResolverAgent = "agent" +) + +// ResolverHealer is the resolver of a condition a registered healer works on (Phase 3). +func ResolverHealer(name string) string { return "healer:" + name } + +// Subject is what the condition is about: its scope, its id within the scope, and the machine it +// concerns when there is one. +type Subject struct { + Scope string `json:"scope"` + ID string `json:"id"` + Machine string `json:"machine,omitempty"` + // Also are the other machines it concerns: a consumer's, for a provider failing it. + Also []string `json:"also,omitempty"` +} + +// Evidence is one observation, as it was said. +type Evidence struct { + At time.Time `json:"at"` + Said string `json:"said"` +} + +// Attempt is one healer's try at a condition (to-be 45 §7; written from Phase 3). +type Attempt struct { + At time.Time `json:"at"` + What string `json:"what"` + Outcome string `json:"outcome"` +} + +// Silence is a person saying they know: no messages until it ends (to-be 45 §2). Recorded as a hand +// act; the condition stays open, and `status` still says it. +type Silence struct { + Until time.Time `json:"until"` + By string `json:"by"` + Why string `json:"why"` + Since time.Time `json:"since"` +} + +// KeptEvidence is how many observations a condition keeps, newest first. +const KeptEvidence = 10 + +// MaxSilence is the longest a condition may be silenced at once: past it, a person says so again. +const MaxSilence = 7 * 24 * time.Hour + +// ReopenWithin is how soon after it cleared a condition raised again is the same one again, with its +// count increased, rather than news (to-be 45 §2). +const ReopenWithin = 10 * time.Minute + +// Condition is one open condition, as the store keeps it and its events carry it. +type Condition struct { + Key string `json:"key"` + // Kind is the condition kind: from the signals table, the probe registry or an event kind. + Kind string `json:"kind"` + Subject Subject `json:"subject"` + Severity Severity `json:"severity"` + // Summary is one line in the mesh's words. + Summary string `json:"summary"` + // Evidence is the newest observations, at most KeptEvidence, newest first. + Evidence []Evidence `json:"evidence"` + // Source is the signals-table row, probe or event that raised it: `S1`, `D3`, `provisioner.failing`. + Source string `json:"source"` + // Raised is when it was first observed this time; LastObserved the newest observation. + Raised time.Time `json:"raised"` + LastObserved time.Time `json:"last-observed"` + // Observations is how many times it was observed since raised. + Observations int `json:"observations"` + // Count is how many times it has been raised, a reopening within ReopenWithin counted. + Count int `json:"count"` + Tried []Attempt `json:"tried,omitempty"` + Resolver string `json:"resolver"` + // Silenced is null when no silence is in force: said, not left out, so a reader need not guess. + Silenced *Silence `json:"silenced"` + // Epoch is the controller lease epoch that last wrote it. Zero until the lease exists (to-be 45 + // Phase 2): no controller holds an epoch yet, and a number invented here would be one nobody + // could compare. + Epoch uint64 `json:"epoch"` +} + +// SilencedAt says whether a person's silence is in force at a moment. +func (c Condition) SilencedAt(now time.Time) bool { + return c.Silenced != nil && now.Before(c.Silenced.Until) +} + +// Show is the verb that shows more about a condition, as a message carries it. +func (c Condition) Show() string { return "mesh-controller.conditions key=" + c.Key } + +// Observation is one watchdog, probe or event saying something is wrong now. +type Observation struct { + Scope string + // ID is the thing within the scope; several tokens joined by dots where the thing is named by + // several (a provider's module, its machine and the consumer). + ID string + // Token is the last part of the key, short for the kind: `silent` for a machine, `failing` for a + // provider. Kind's own word when empty. + Token string + Kind string + Machine string + // Also are the other machines it concerns. + Also []string + Severity Severity + Summary string + // Said is this observation's evidence, in the mesh's words; Summary when empty. + Said string + Source string + Resolver string +} + +// Key is where the observation's condition is kept: `..`, so the same fault said +// again is the same condition. +func (o Observation) Key() string { + token := o.Token + if token == "" { + token = o.Kind + } + return Key(o.Scope, o.ID, token) +} + +// unsafeKey is anything a key may not hold: the bus takes letters, digits and `-_/=` in a key's +// tokens, and a `*` or `>` would make one a wildcard. +var unsafeKey = regexp.MustCompile(`[^A-Za-z0-9_=/-]`) + +// Key composes a condition's key from its parts, each token made safe for the bus: a character the +// bus would refuse becomes `_`, so a key is never refused for the name of the thing it is about. +func Key(scope, id, token string) string { + var parts []string + for _, p := range append(append([]string{scope}, strings.Split(id, ".")...), token) { + p = unsafeKey.ReplaceAllString(strings.TrimSpace(p), "_") + if p == "" { + p = "_" + } + parts = append(parts, p) + } + return strings.Join(parts, ".") +} + +// check refuses an observation that could not be said: a condition with no kind, no scope the mesh +// knows, or no severity is one nobody could route. +func (o Observation) check() error { + known := false + for _, s := range Scopes { + if s == o.Scope { + known = true + } + } + switch { + case !known: + return fmt.Errorf("a condition's scope is one of %s, not %q", strings.Join(Scopes, ", "), o.Scope) + case strings.TrimSpace(o.ID) == "": + return fmt.Errorf("a %s condition names what it is about", o.Scope) + case strings.TrimSpace(o.Kind) == "": + return fmt.Errorf("the condition %s has no kind", o.Key()) + case o.Severity != Urgent && o.Severity != Warning: + return fmt.Errorf("the condition %s is urgent or a warning, not %q", o.Key(), o.Severity) + case strings.TrimSpace(o.Summary) == "": + return fmt.Errorf("the condition %s says nothing", o.Key()) + case strings.TrimSpace(o.Source) == "": + return fmt.Errorf("the condition %s does not say what raised it", o.Key()) + } + return nil +} + +// Order sorts conditions as `status` says them: urgent before warning, then oldest first. +func Order(list []Condition) { + sort.SliceStable(list, func(i, j int) bool { + if list[i].Severity != list[j].Severity { + return list[i].Severity == Urgent + } + if !list[i].Raised.Equal(list[j].Raised) { + return list[i].Raised.Before(list[j].Raised) + } + return list[i].Key < list[j].Key + }) +} diff --git a/internal/conditions/events.go b/internal/conditions/events.go new file mode 100644 index 0000000..053177e --- /dev/null +++ b/internal/conditions/events.go @@ -0,0 +1,73 @@ +package conditions + +import "time" + +// The events a condition's life emits (to-be 45 §2), as the mesh-controller seat's own: published on +// `mesh.seat.mesh-controller.event.`, on the events stream, so a consumer that was away catches +// up. **This is a contract**: the operator-channel's holder is written against these names and the +// shape of Event, and the controller learns nothing about telling. +const ( + // EventRaised: a condition was raised — new, or the same fault again within ReopenWithin of its + // clearing (Change says which). A reopened condition is not news: its key is the one the + // first message was about. + EventRaised = "condition-raised" + // EventChanged: its severity, its resolver or its silence changed. Not every observation: a + // condition observed again is written, and says nothing. + EventChanged = "condition-changed" + // EventCleared: an observation says it is resolved. The condition is removed from the store and + // the transition kept in its history. + EventCleared = "condition-cleared" +) + +// Events is every event a condition's life emits. +var Events = []string{EventRaised, EventChanged, EventCleared} + +// HeartbeatEvent is the self-check's heartbeat (to-be 45 §4, S10), said under the same seat at the end +// of every run: `{run, at, interval-seconds, counts: {passed, failed, failed-to-run, deferred}, probes, +// controller, why}`. mesh-watcher, on a machine that is not the control node, listens for it. +const HeartbeatEvent = "doctor-heartbeat" + +// What changed, as an event's Change and a history entry's says it. +const ( + ChangeRaised = "raised" + ChangeReopened = "reopened" + ChangeSeverity = "severity" + ChangeResolver = "resolver" + ChangeSilenced = "silenced" + ChangeUnsilenced = "silence-ended" + ChangeCleared = "cleared" +) + +// Event is the body of every condition event, and the shape a history entry keeps: **the condition +// itself, at the top level** — key, kind, subject, severity, summary, source, raised, last-observed, +// observations, resolver, silenced (null when not), epoch, and the evidence — with what happened to +// it beside. One object a consumer reads the same way whichever of the three it is. +type Event struct { + // Condition is the condition after the transition — as it was last held, for a clearing. + Condition + // Event is the event's own name, so a body read without its subject still says what it is. + Event string `json:"event"` + // At is when the transition happened. + At time.Time `json:"at"` + // Change is what happened: raised, reopened, severity, resolver, silenced, silence-ended, cleared. + Change string `json:"change"` + // Was is the value before, for a severity or resolver change. + Was string `json:"was,omitempty"` + // Why says why it cleared, or why it was silenced. + Why string `json:"why,omitempty"` + // Cleared is when it cleared, on a clearing. + Cleared *time.Time `json:"cleared,omitempty"` + // Show is the verb that shows more. + Show string `json:"show"` +} + +// eventFor is the event a change is said under. +func eventFor(change string) string { + switch change { + case ChangeRaised, ChangeReopened: + return EventRaised + case ChangeCleared: + return EventCleared + } + return EventChanged +} diff --git a/internal/conditions/memory.go b/internal/conditions/memory.go new file mode 100644 index 0000000..1e23ee2 --- /dev/null +++ b/internal/conditions/memory.go @@ -0,0 +1,147 @@ +package conditions + +import ( + "context" + "encoding/json" + "errors" + "sort" + "sync" + "time" +) + +// InMemory is a store and a history held in this process: for tests, and for nothing else — a +// condition kept here is forgotten by a restart, which is the fault the store exists to remove. +type InMemory struct { + mu sync.Mutex + values map[string]Entry + revision uint64 + events []Event + // Fail, when set, is what every read and write answers: a store that is away. + Fail error +} + +// NewInMemory is an empty store. +func NewInMemory() *InMemory { return &InMemory{values: map[string]Entry{}} } + +func (m *InMemory) Get(_ context.Context, key string) (Entry, bool, error) { + m.mu.Lock() + defer m.mu.Unlock() + if m.Fail != nil { + return Entry{}, false, m.Fail + } + e, ok := m.values[key] + return e, ok, nil +} + +func (m *InMemory) Create(_ context.Context, key string, value []byte) error { + m.mu.Lock() + defer m.mu.Unlock() + if m.Fail != nil { + return m.Fail + } + if _, ok := m.values[key]; ok { + return ErrMoved + } + m.revision++ + m.values[key] = Entry{Value: value, Revision: m.revision} + return nil +} + +func (m *InMemory) Update(_ context.Context, key string, value []byte, revision uint64) error { + m.mu.Lock() + defer m.mu.Unlock() + if m.Fail != nil { + return m.Fail + } + if e, ok := m.values[key]; !ok || e.Revision != revision { + return ErrMoved + } + m.revision++ + m.values[key] = Entry{Value: value, Revision: m.revision} + return nil +} + +func (m *InMemory) Delete(_ context.Context, key string, revision uint64) error { + m.mu.Lock() + defer m.mu.Unlock() + if m.Fail != nil { + return m.Fail + } + if e, ok := m.values[key]; !ok || e.Revision != revision { + return ErrMoved + } + delete(m.values, key) + return nil +} + +func (m *InMemory) All(context.Context) (map[string]Entry, error) { + m.mu.Lock() + defer m.mu.Unlock() + if m.Fail != nil { + return nil, m.Fail + } + out := make(map[string]Entry, len(m.values)) + for k, v := range m.values { + out[k] = v + } + return out, nil +} + +func (m *InMemory) Append(_ context.Context, e Event) error { + m.mu.Lock() + defer m.mu.Unlock() + if m.Fail != nil { + return m.Fail + } + m.events = append(m.events, e) + return nil +} + +func (m *InMemory) Since(_ context.Context, since time.Time) ([]Event, error) { + m.mu.Lock() + defer m.mu.Unlock() + if m.Fail != nil { + return nil, m.Fail + } + var out []Event + for _, e := range m.events { + if !e.At.Before(since) { + out = append(out, e) + } + } + sort.SliceStable(out, func(i, j int) bool { return out[i].At.Before(out[j].At) }) + return out, nil +} + +// Told is a teller that remembers what it was told, for tests. +type Told struct { + mu sync.Mutex + Events []Event + Names []string + Fail error +} + +func (t *Told) PublishSeatEvent(_ context.Context, seat, event string, body []byte) error { + t.mu.Lock() + defer t.mu.Unlock() + if t.Fail != nil { + return t.Fail + } + if seat != Seat { + return errors.New("told under the wrong seat: " + seat) + } + var e Event + if err := json.Unmarshal(body, &e); err != nil { + return err + } + t.Events = append(t.Events, e) + t.Names = append(t.Names, event) + return nil +} + +// Said is a copy of what was told so far. +func (t *Told) Said() []Event { + t.mu.Lock() + defer t.mu.Unlock() + return append([]Event(nil), t.Events...) +} diff --git a/internal/conditions/store.go b/internal/conditions/store.go new file mode 100644 index 0000000..77aff2d --- /dev/null +++ b/internal/conditions/store.go @@ -0,0 +1,502 @@ +package conditions + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "strings" + "sync" + "time" +) + +// Backend is where the open conditions are kept: one value per key, written by compare-and-set. +type Backend interface { + // Get is one key's value and revision; false when it holds none. + Get(ctx context.Context, key string) (Entry, bool, error) + // Create writes a key that holds nothing, and fails with ErrMoved when it holds something. + Create(ctx context.Context, key string, value []byte) error + // Update writes a key at the revision it was read at, and fails with ErrMoved when it moved. + Update(ctx context.Context, key string, value []byte, revision uint64) error + // Delete removes a key at the revision it was read at, and fails with ErrMoved when it moved. + Delete(ctx context.Context, key string, revision uint64) error + // All is every key's value. An error is an error: never an empty store (ADR 0227 rule 4). + All(ctx context.Context) (map[string]Entry, error) +} + +// Entry is one key's value, at a revision. +type Entry struct { + Value []byte + Revision uint64 +} + +// ErrMoved is a compare-and-set that lost: somebody wrote the key since it was read. +var ErrMoved = errors.New("the condition was written by somebody else since it was read") + +// History keeps every transition (to-be 45 §2): appended, read back from a moment. +type History interface { + Append(ctx context.Context, e Event) error + // Since is every transition from a moment, oldest first. + Since(ctx context.Context, since time.Time) ([]Event, error) +} + +// Teller says a transition on the bus, as the mesh-controller seat's event. The link's bus is one. +type Teller interface { + PublishSeatEvent(ctx context.Context, seat, event string, body []byte) error +} + +// Seat is the role the events are said under (novox/hq ADR 0134): the control plane's. +const Seat = "mesh-controller" + +// Keeper raises, observes, silences and clears conditions, and says each transition. +type Keeper struct { + store Backend + history History + teller Teller + now func() time.Time + say func(format string, args ...any) + changed func() + + mu sync.Mutex + // cleared is when each recently cleared condition cleared and how often it had been raised, so + // one raised again within ReopenWithin is the same one again. + cleared map[string]clearing + + // out is the transitions still to be said and kept, in order: said by one goroutine, so a + // condition's events arrive in the order they happened, and offered again while the bus is away. + out chan Event + drained chan struct{} + closing sync.Once + // Unsaid counts the transitions given up on, for the self-check to say. + unsaid int +} + +type clearing struct { + at time.Time + count int + silenced *Silence +} + +// Options are what a Keeper is made with. +type Options struct { + Store Backend + History History + // Teller says the transitions; nil says nothing (a test, or a command run with no bus to say on). + Teller Teller + Now func() time.Time + // Say is where a transition that could not be said or kept is said instead. + Say func(format string, args ...any) + // Changed is told of every transition, at once — for `status`, which leads with what is open. + Changed func() +} + +// TellFor is how long one transition is offered to the bus before it is said lost. +var TellFor = 10 * time.Minute + +// NewKeeper is a keeper over a store. It reads what cleared lately from the history, so a condition +// that cleared just before this controller started and is raised again now is a reopening. +func NewKeeper(ctx context.Context, o Options) *Keeper { + k := &Keeper{store: o.Store, history: o.History, teller: o.Teller, now: o.Now, say: o.Say, changed: o.Changed, + cleared: map[string]clearing{}, out: make(chan Event, 1024), drained: make(chan struct{})} + if k.now == nil { + k.now = time.Now + } + if k.say == nil { + k.say = func(string, ...any) {} + } + if k.history != nil { + if recent, err := k.history.Since(ctx, k.now().Add(-ReopenWithin)); err == nil { + for _, e := range recent { + if e.Change == ChangeCleared { + k.cleared[e.Key] = clearing{at: e.At, count: e.Condition.Count, silenced: e.Condition.Silenced} + } + } + } else { + k.say("what cleared lately could not be read from the condition history, so a condition "+ + "raised again now is said as new rather than reopened: %v", err) + } + } + go k.telling() + return k +} + +// Close says what is still to be said, waiting at most until ctx ends. +func (k *Keeper) Close(ctx context.Context) { + k.closing.Do(func() { close(k.out) }) + select { + case <-k.drained: + case <-ctx.Done(): + k.say("%d condition transition(s) were not yet said when this process ended", len(k.out)) + } +} + +// Unsaid is how many transitions were given up on since this keeper started. +func (k *Keeper) Unsaid() int { + k.mu.Lock() + defer k.mu.Unlock() + return k.unsaid +} + +// tries bounds one compare-and-set: two writers rarely race more than once. +const tries = 8 + +// Observe records one observation: raises the condition if it is not open, and otherwise adds the +// evidence. Says a raising, a reopening, and a change of severity or resolver; an observation that +// changes neither is written and said nowhere. +func (k *Keeper) Observe(ctx context.Context, o Observation) (Condition, error) { + if err := o.check(); err != nil { + return Condition{}, err + } + key := o.Key() + for i := 0; i < tries; i++ { + now := k.now().UTC() + said := o.Said + if said == "" { + said = o.Summary + } + entry, found, err := k.store.Get(ctx, key) + if err != nil { + return Condition{}, fmt.Errorf("reading the condition %s: %w", key, err) + } + if !found { + c := Condition{Key: key, Kind: o.Kind, Subject: Subject{Scope: o.Scope, ID: o.ID, Machine: o.Machine, Also: o.Also}, + Severity: o.Severity, Summary: o.Summary, Evidence: []Evidence{{At: now, Said: said}}, + Source: o.Source, Raised: now, LastObserved: now, Observations: 1, Count: 1, + Resolver: orSelf(o.Resolver)} + change := ChangeRaised + k.mu.Lock() + if before, ok := k.cleared[key]; ok && now.Sub(before.at) <= ReopenWithin { + c.Count, change = before.count+1, ChangeReopened + // A silence a person gave the condition before it cleared still holds: they said + // they knew, and the same fault again ten minutes later is what they knew about. + if before.silenced != nil && now.Before(before.silenced.Until) { + c.Silenced = before.silenced + } + } + k.mu.Unlock() + body, err := json.Marshal(c) + if err != nil { + return Condition{}, err + } + if err := k.store.Create(ctx, key, body); errors.Is(err, ErrMoved) { + continue + } else if err != nil { + return Condition{}, fmt.Errorf("raising the condition %s: %w", key, err) + } + k.mu.Lock() + delete(k.cleared, key) + k.mu.Unlock() + k.tell(Event{Condition: c, At: now, Change: change}) + return c, nil + } + var c Condition + if err := json.Unmarshal(entry.Value, &c); err != nil { + return Condition{}, fmt.Errorf("the condition %s on the bus cannot be read: %w", key, err) + } + var changes []Event + if o.Severity != c.Severity { + changes = append(changes, Event{Change: ChangeSeverity, Was: string(c.Severity)}) + c.Severity = o.Severity + } + if r := orSelf(o.Resolver); o.Resolver != "" && r != c.Resolver { + changes = append(changes, Event{Change: ChangeResolver, Was: c.Resolver}) + c.Resolver = r + } + c.Summary, c.Source, c.LastObserved = o.Summary, o.Source, now + if o.Machine != "" { + c.Subject.Machine = o.Machine + } + if len(o.Also) > 0 { + c.Subject.Also = o.Also + } + c.Observations++ + c.Evidence = append([]Evidence{{At: now, Said: said}}, c.Evidence...) + if len(c.Evidence) > KeptEvidence { + c.Evidence = c.Evidence[:KeptEvidence] + } + body, err := json.Marshal(c) + if err != nil { + return Condition{}, err + } + if err := k.store.Update(ctx, key, body, entry.Revision); errors.Is(err, ErrMoved) { + continue + } else if err != nil { + return Condition{}, fmt.Errorf("observing the condition %s: %w", key, err) + } + for _, e := range changes { + e.At, e.Condition = now, c + k.tell(e) + } + return c, nil + } + return Condition{}, fmt.Errorf("the condition %s kept moving under this write; %d tries", key, tries) +} + +// Clear removes a condition an observation says is resolved, and says so. False when none was open. +func (k *Keeper) Clear(ctx context.Context, key, why string) (bool, error) { + for i := 0; i < tries; i++ { + entry, found, err := k.store.Get(ctx, key) + if err != nil { + return false, fmt.Errorf("reading the condition %s: %w", key, err) + } + if !found { + return false, nil + } + var c Condition + if err := json.Unmarshal(entry.Value, &c); err != nil { + // Unreadable is not resolved: kept, and said, rather than removed unread. + return false, fmt.Errorf("the condition %s on the bus cannot be read, so it is not cleared: %w", key, err) + } + if err := k.store.Delete(ctx, key, entry.Revision); errors.Is(err, ErrMoved) { + continue + } else if err != nil { + return false, fmt.Errorf("clearing the condition %s: %w", key, err) + } + now := k.now().UTC() + k.mu.Lock() + k.cleared[key] = clearing{at: now, count: c.Count, silenced: c.Silenced} + k.mu.Unlock() + k.tell(Event{Condition: c, At: now, Change: ChangeCleared, Why: why, Cleared: &now}) + return true, nil + } + return false, fmt.Errorf("the condition %s kept moving under this clearing; %d tries", key, tries) +} + +// Reconcile is one source's whole observation: every condition it observes is observed, and every +// condition it raised before and no longer observes is cleared — the observation says it is +// resolved. A source that could not observe must not call this: an empty observation clears all it +// raised, which is exactly the fault of saying "none" for "I could not tell" (ADR 0227 rule 4). +func (k *Keeper) Reconcile(ctx context.Context, source string, observed []Observation) error { + all, err := k.Open(ctx) + if err != nil { + return err + } + seen := map[string]bool{} + var problems []string + for _, o := range observed { + o.Source = source + seen[o.Key()] = true + if _, err := k.Observe(ctx, o); err != nil { + problems = append(problems, err.Error()) + } + } + for _, c := range all { + if c.Source != source || seen[c.Key] { + continue + } + if _, err := k.Clear(ctx, c.Key, source+" no longer observes it"); err != nil { + problems = append(problems, err.Error()) + } + } + if len(problems) > 0 { + return errors.New(strings.Join(problems, "; ")) + } + return nil +} + +// Silence stops a condition's messages for a while, with a reason, by somebody (to-be 45 §2). The +// condition stays open and `status` still says it; recording the act in the hand-act log is the +// caller's, which knows who acted. +func (k *Keeper) Silence(ctx context.Context, key string, d time.Duration, by, why string) (Condition, error) { + if strings.TrimSpace(why) == "" { + return Condition{}, errors.New("a silence says why: --why ") + } + if d <= 0 || d > MaxSilence { + return Condition{}, fmt.Errorf("a condition is silenced for a while, at most %s — not %s", MaxSilence, d) + } + for i := 0; i < tries; i++ { + entry, found, err := k.store.Get(ctx, key) + if err != nil { + return Condition{}, fmt.Errorf("reading the condition %s: %w", key, err) + } + if !found { + return Condition{}, fmt.Errorf("no condition %s is open — `conditions` lists them", key) + } + var c Condition + if err := json.Unmarshal(entry.Value, &c); err != nil { + return Condition{}, fmt.Errorf("the condition %s on the bus cannot be read: %w", key, err) + } + now := k.now().UTC() + c.Silenced = &Silence{Until: now.Add(d), By: by, Why: strings.TrimSpace(why), Since: now} + body, err := json.Marshal(c) + if err != nil { + return Condition{}, err + } + if err := k.store.Update(ctx, key, body, entry.Revision); errors.Is(err, ErrMoved) { + continue + } else if err != nil { + return Condition{}, fmt.Errorf("silencing the condition %s: %w", key, err) + } + k.tell(Event{Condition: c, At: now, Change: ChangeSilenced, Why: c.Silenced.Why}) + return c, nil + } + return Condition{}, fmt.Errorf("the condition %s kept moving under this silence; %d tries", key, tries) +} + +// EndSilences ends every silence that has run out, and says each: the condition is still open, and +// its messages start again. +func (k *Keeper) EndSilences(ctx context.Context) error { + all, err := k.Open(ctx) + if err != nil { + return err + } + now := k.now().UTC() + for _, c := range all { + if c.Silenced == nil || now.Before(c.Silenced.Until) { + continue + } + for i := 0; i < tries; i++ { + entry, found, err := k.store.Get(ctx, c.Key) + if err != nil { + return err + } + if !found { + break + } + var held Condition + if err := json.Unmarshal(entry.Value, &held); err != nil { + return fmt.Errorf("the condition %s on the bus cannot be read: %w", c.Key, err) + } + if held.Silenced == nil || now.Before(held.Silenced.Until) { + break + } + was := held.Silenced.Why + held.Silenced = nil + body, err := json.Marshal(held) + if err != nil { + return err + } + if err := k.store.Update(ctx, c.Key, body, entry.Revision); errors.Is(err, ErrMoved) { + continue + } else if err != nil { + return err + } + k.tell(Event{Condition: held, At: now, Change: ChangeUnsilenced, Why: was}) + break + } + } + return nil +} + +// Open is every open condition, urgent first and then oldest first. +func (k *Keeper) Open(ctx context.Context) ([]Condition, error) { + return Read(ctx, k.store) +} + +// Get is one open condition. +func (k *Keeper) Get(ctx context.Context, key string) (Condition, bool, error) { + return ReadOne(ctx, k.store, key) +} + +// HistorySince is every transition from a moment, oldest first. +func (k *Keeper) HistorySince(ctx context.Context, since time.Time) ([]Event, error) { + if k.history == nil { + return nil, errors.New("this keeper has no history to read") + } + return k.history.Since(ctx, since) +} + +// Read is every open condition in a store, in the order status says them. A value that cannot be +// read is an error naming its key, never a condition left out (ADR 0227 rule 4). +func Read(ctx context.Context, store Backend) ([]Condition, error) { + all, err := store.All(ctx) + if err != nil { + return nil, fmt.Errorf("the open conditions cannot be read: %w", err) + } + out := make([]Condition, 0, len(all)) + for key, e := range all { + var c Condition + if err := json.Unmarshal(e.Value, &c); err != nil { + return nil, fmt.Errorf("the condition %s cannot be read: %w", key, err) + } + out = append(out, c) + } + Order(out) + return out, nil +} + +// ReadOne is one open condition from a store. +func ReadOne(ctx context.Context, store Backend, key string) (Condition, bool, error) { + e, found, err := store.Get(ctx, key) + if err != nil || !found { + return Condition{}, found, err + } + var c Condition + if err := json.Unmarshal(e.Value, &c); err != nil { + return Condition{}, false, fmt.Errorf("the condition %s cannot be read: %w", key, err) + } + return c, true, nil +} + +// tell queues a transition to be kept and said. Never blocks the caller for long: a queue that is +// full is a bus away for a long time, and the transition is said lost rather than holding a watchdog. +func (k *Keeper) tell(e Event) { + e.Event = eventFor(e.Change) + e.Show = e.Condition.Show() + if k.changed != nil { + k.changed() + } + defer func() { + // A keeper closed while a write was in flight: said, not a panic. + if recover() != nil { + k.lost(e, errors.New("the keeper was closed")) + } + }() + select { + case k.out <- e: + default: + k.lost(e, errors.New("too many transitions are waiting to be said")) + } +} + +func (k *Keeper) lost(e Event, err error) { + k.mu.Lock() + k.unsaid++ + k.mu.Unlock() + k.say("the condition %s was %s and that could NOT be said or kept: %v", e.Key, e.Change, err) +} + +// telling keeps and says every transition in order, offering each again while the bus is away. +func (k *Keeper) telling() { + defer close(k.drained) + for e := range k.out { + body, err := json.Marshal(e) + if err != nil { + k.lost(e, err) + continue + } + deadline := time.Now().Add(TellFor) + wait := 200 * time.Millisecond + kept, said := k.history == nil, k.teller == nil + for { + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + if !kept { + kept = k.history.Append(ctx, e) == nil + } + if !said { + said = k.teller.PublishSeatEvent(ctx, Seat, e.Event, body) == nil + } + cancel() + if kept && said { + break + } + if time.Now().After(deadline) { + what := "said" + if !kept { + what = "kept in the history" + } + k.lost(e, fmt.Errorf("not %s within %s", what, TellFor)) + break + } + time.Sleep(wait) + wait = min(2*wait, 10*time.Second) + } + } +} + +func orSelf(resolver string) string { + if resolver == "" { + return ResolverSelf + } + return resolver +} diff --git a/internal/conditions/store_test.go b/internal/conditions/store_test.go new file mode 100644 index 0000000..2d571ab --- /dev/null +++ b/internal/conditions/store_test.go @@ -0,0 +1,379 @@ +package conditions + +import ( + "context" + "encoding/json" + "errors" + "strings" + "testing" + "time" +) + +// clock is a time a test moves by hand. +type clock struct{ at time.Time } + +func (c *clock) now() time.Time { return c.at } +func (c *clock) pass(d time.Duration) { c.at = c.at.Add(d) } +func newClock() *clock { return &clock{at: time.Date(2026, 10, 6, 12, 0, 0, 0, time.UTC)} } +func keeper(t *testing.T) (*Keeper, *InMemory, *Told, *clock) { + t.Helper() + store, told, c := NewInMemory(), &Told{}, newClock() + k := NewKeeper(t.Context(), Options{Store: store, History: store, Teller: told, Now: c.now, + Say: func(f string, a ...any) { t.Logf(f, a...) }}) + t.Cleanup(func() { k.Close(context.Background()) }) + return k, store, told, c +} + +// settled waits until the teller has been told n events. +func settled(t *testing.T, told *Told, n int) []Event { + t.Helper() + deadline := time.Now().Add(5 * time.Second) + for { + said := told.Said() + if len(said) >= n { + return said + } + if time.Now().After(deadline) { + t.Fatalf("told %d event(s), want %d: %+v", len(said), n, said) + } + time.Sleep(5 * time.Millisecond) + } +} + +func silent(node string) Observation { + return Observation{Scope: ScopeMachine, ID: node, Kind: "silent", Machine: node, Severity: Warning, + Summary: node + " has not been heard from", Source: "S1"} +} + +// **A condition is raised once, observed many times, and said on the bus only when it changes** +// (to-be 45 §2): an observation that changes nothing is written and said nowhere, or the operator's +// channel would hear the same fault every thirty seconds. +func TestAConditionIsSaidWhenItChangesNotWhenItIsSeenAgain(t *testing.T) { + k, _, told, c := keeper(t) + ctx := t.Context() + for i := 0; i < 3; i++ { + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + c.pass(time.Minute) + } + urgent := silent("ace") + urgent.Severity = Urgent + got, err := k.Observe(ctx, urgent) + if err != nil { + t.Fatal(err) + } + if got.Key != "machine.ace.silent" || got.Observations != 4 || got.Count != 1 || got.Severity != Urgent { + t.Fatalf("held %+v", got) + } + if len(got.Evidence) != 4 || !got.Evidence[0].At.Equal(c.at) { + t.Fatalf("evidence is not newest first: %+v", got.Evidence) + } + said := settled(t, told, 2) + if said[0].Event != EventRaised || said[0].Change != ChangeRaised || said[1].Event != EventChanged || + said[1].Change != ChangeSeverity || said[1].Was != string(Warning) { + t.Fatalf("said %+v", said) + } + time.Sleep(50 * time.Millisecond) + if n := len(told.Said()); n != 2 { + t.Fatalf("said %d events for one raising and one change", n) + } + for i, name := range told.Names { + if name != told.Events[i].Event { + t.Errorf("event %d published as %s and says it is %s", i, name, told.Events[i].Event) + } + } +} + +// **Evidence is bounded**: a condition open for a week keeps its newest ten observations, not all. +func TestEvidenceKeepsTheNewestTen(t *testing.T) { + k, _, _, c := keeper(t) + var got Condition + for i := 0; i < 25; i++ { + var err error + if got, err = k.Observe(t.Context(), silent("ace")); err != nil { + t.Fatal(err) + } + c.pass(time.Minute) + } + if len(got.Evidence) != KeptEvidence || got.Observations != 25 { + t.Fatalf("kept %d evidence of %d observations", len(got.Evidence), got.Observations) + } +} + +// **Cleared and raised again within ten minutes is the same condition again** (to-be 45 §2): its +// count goes up and it is said as reopened, not as news; a person's silence of it still holds. +func TestRaisedAgainSoonAfterClearingReopens(t *testing.T) { + k, store, told, c := keeper(t) + ctx := t.Context() + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + if _, err := k.Silence(ctx, "machine.ace.silent", time.Hour, "jochen", "the laptop is on the train"); err != nil { + t.Fatal(err) + } + if cleared, err := k.Clear(ctx, "machine.ace.silent", "heard again"); err != nil || !cleared { + t.Fatalf("cleared %v: %v", cleared, err) + } + c.pass(5 * time.Minute) + again, err := k.Observe(ctx, silent("ace")) + if err != nil { + t.Fatal(err) + } + if again.Count != 2 || again.Silenced == nil { + t.Fatalf("reopened as %+v", again) + } + said := settled(t, told, 4) + if said[3].Event != EventRaised || said[3].Change != ChangeReopened { + t.Fatalf("the reopening was said as %+v", said[3]) + } + // And from a new keeper — the controller restarted between — reading what cleared from history. + if _, err := k.Clear(ctx, "machine.ace.silent", "heard again"); err != nil { + t.Fatal(err) + } + settled(t, told, 5) + k.Close(context.Background()) + next := NewKeeper(ctx, Options{Store: store, History: store, Now: c.now}) + defer next.Close(context.Background()) + c.pass(time.Minute) + third, err := next.Observe(ctx, silent("ace")) + if err != nil { + t.Fatal(err) + } + if third.Count != 3 { + t.Fatalf("a controller restarted between cleared and raised said it as new: %+v", third) + } + // Past the window it is news. + if _, err := next.Clear(ctx, "machine.ace.silent", "heard again"); err != nil { + t.Fatal(err) + } + c.pass(ReopenWithin + time.Minute) + fourth, err := next.Observe(ctx, silent("ace")) + if err != nil { + t.Fatal(err) + } + if fourth.Count != 1 || fourth.Silenced != nil { + t.Fatalf("raised past the window as %+v", fourth) + } +} + +// **A source's whole observation clears what it no longer observes, and only its own.** A watchdog +// that stops seeing a fault says it is resolved; it does not clear what another raised. +func TestReconcileClearsOnlyTheSourcesOwn(t *testing.T) { + k, _, told, _ := keeper(t) + ctx := t.Context() + other := Observation{Scope: ScopeProbe, ID: "D3", Kind: "probe-failed", Token: "failed", Severity: Warning, + Summary: "D3 did not answer", Source: "doctor"} + if _, err := k.Observe(ctx, other); err != nil { + t.Fatal(err) + } + if err := k.Reconcile(ctx, "S1", []Observation{silent("ace"), silent("g14")}); err != nil { + t.Fatal(err) + } + if err := k.Reconcile(ctx, "S1", []Observation{silent("g14")}); err != nil { + t.Fatal(err) + } + open, err := k.Open(ctx) + if err != nil { + t.Fatal(err) + } + var keys []string + for _, c := range open { + keys = append(keys, c.Key) + } + if strings.Join(keys, ",") != "machine.g14.silent,probe.D3.failed" { + t.Fatalf("open after the second observation: %v", keys) + } + said := settled(t, told, 4) + last := said[3] + if last.Event != EventCleared || last.Key != "machine.ace.silent" || last.Why == "" { + t.Fatalf("the clearing was said as %+v", last) + } +} + +// **A store that cannot be read is never an empty one** (ADR 0227 rule 4): reconciling against it +// clears nothing and says why. +func TestAnUnreadableStoreClearsNothing(t *testing.T) { + k, store, _, _ := keeper(t) + ctx := t.Context() + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + store.Fail = errors.New("the bus is away") + if err := k.Reconcile(ctx, "S1", nil); err == nil { + t.Fatal("reconciled against a store it could not read") + } + if _, err := k.Open(ctx); err == nil { + t.Fatal("an unreadable store answered as read") + } + store.Fail = nil + store.values["machine.g14.silent"] = Entry{Value: []byte("{not a condition"), Revision: 99} + if _, err := k.Open(ctx); err == nil || !strings.Contains(err.Error(), "machine.g14.silent") { + t.Fatalf("an unreadable condition was left out rather than said: %v", err) + } + if cleared, err := k.Clear(ctx, "machine.g14.silent", "x"); err == nil || cleared { + t.Fatal("an unreadable condition was cleared unread") + } +} + +// **A silence is bounded, says why, and ends on its own** (to-be 45 §2): the condition stays open +// through it, and its messages start again when it ends. +func TestASilenceIsBoundedAndEnds(t *testing.T) { + k, _, told, c := keeper(t) + ctx := t.Context() + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + if _, err := k.Silence(ctx, "machine.ace.silent", 8*24*time.Hour, "jochen", "away"); err == nil { + t.Fatal("silenced for longer than a week") + } + if _, err := k.Silence(ctx, "machine.ace.silent", time.Hour, "jochen", " "); err == nil { + t.Fatal("silenced without a reason") + } + if _, err := k.Silence(ctx, "machine.nothing.silent", time.Hour, "jochen", "x"); err == nil { + t.Fatal("silenced a condition that is not open") + } + held, err := k.Silence(ctx, "machine.ace.silent", time.Hour, "jochen", "on the train") + if err != nil { + t.Fatal(err) + } + if !held.SilencedAt(c.at) || held.Silenced.By != "jochen" { + t.Fatalf("silenced as %+v", held.Silenced) + } + c.pass(30 * time.Minute) + if err := k.EndSilences(ctx); err != nil { + t.Fatal(err) + } + c.pass(31 * time.Minute) + if err := k.EndSilences(ctx); err != nil { + t.Fatal(err) + } + got, _, _ := k.Get(ctx, "machine.ace.silent") + if got.Silenced != nil { + t.Fatalf("a silence past its end still held: %+v", got.Silenced) + } + said := settled(t, told, 3) + if said[1].Change != ChangeSilenced || said[2].Change != ChangeUnsilenced || said[2].Event != EventChanged { + t.Fatalf("said %+v", said) + } +} + +// **Two writers never lose each other's word.** The serving controller observes while a person's +// command silences: the write that lost the compare-and-set reads again and redoes itself. +func TestAWriteThatLostTheRaceRedoesItself(t *testing.T) { + k, store, _, _ := keeper(t) + ctx := t.Context() + if _, err := k.Observe(ctx, silent("ace")); err != nil { + t.Fatal(err) + } + racing := &racingStore{InMemory: store, before: func() { + // Another process silences between this keeper's read and its write. + other := NewKeeper(ctx, Options{Store: store}) + defer other.Close(context.Background()) + if _, err := other.Silence(ctx, "machine.ace.silent", time.Hour, "jochen", "known"); err != nil { + t.Error(err) + } + }} + k.store = racing + got, err := k.Observe(ctx, silent("ace")) + if err != nil { + t.Fatal(err) + } + if got.Silenced == nil || got.Observations != 2 { + t.Fatalf("the observation overwrote the silence: %+v", got) + } +} + +// racingStore lets another writer in once, between a read and the write after it. +type racingStore struct { + *InMemory + before func() + done bool +} + +func (r *racingStore) Update(ctx context.Context, key string, value []byte, revision uint64) error { + if !r.done { + r.done = true + r.before() + } + return r.InMemory.Update(ctx, key, value, revision) +} + +// **An observation that could not be routed is refused**, naming what it lacks. +func TestAnObservationSaysWhatItIs(t *testing.T) { + k, _, _, _ := keeper(t) + for _, o := range []Observation{ + {Scope: "elsewhere", ID: "x", Kind: "k", Severity: Warning, Summary: "s", Source: "S1"}, + {Scope: ScopeMachine, ID: "x", Kind: "k", Severity: "loud", Summary: "s", Source: "S1"}, + {Scope: ScopeMachine, ID: "x", Kind: "k", Severity: Warning, Source: "S1"}, + {Scope: ScopeMachine, ID: "x", Kind: "k", Severity: Warning, Summary: "s"}, + } { + if _, err := k.Observe(t.Context(), o); err == nil { + t.Errorf("observed %+v", o) + } + } +} + +// **A key holds nothing the bus would refuse or read as a wildcard**, whatever the thing is called. +func TestAKeyIsSafeForTheBus(t *testing.T) { + if got := Key(ScopeProvider, "keycloak.novox.my app*", "failing"); got != "provider.keycloak.novox.my_app_.failing" { + t.Fatalf("key %q", got) + } + if got := Key(ScopeBus, "EVENTS.>", "consumer-lost"); got != "bus.EVENTS._.consumer-lost" { + t.Fatalf("key %q", got) + } +} + +// **The event's shape is a contract** (to-be 45 §2): the operator-channel's holder is written against +// these field names. A rename here is a channel that reads nothing, so they are held still. +func TestTheEventShapeIsTheContract(t *testing.T) { + k, _, told, _ := keeper(t) + if _, err := k.Observe(t.Context(), silent("ace")); err != nil { + t.Fatal(err) + } + said := settled(t, told, 1) + body, err := json.Marshal(said[0]) + if err != nil { + t.Fatal(err) + } + var shape map[string]any + if err := json.Unmarshal(body, &shape); err != nil { + t.Fatal(err) + } + // The condition at the top level, kebab-case, beside what happened to it. + for _, field := range []string{"event", "at", "change", "show", "key", "kind", "subject", "severity", + "summary", "evidence", "source", "raised", "last-observed", "observations", "count", "resolver", + "silenced", "epoch"} { + if _, ok := shape[field]; !ok { + t.Errorf("the event carries no %q: %s", field, body) + } + } + if shape["silenced"] != nil { + t.Errorf("an unsilenced condition says silenced %v, not null", shape["silenced"]) + } + subject, _ := shape["subject"].(map[string]any) + if subject["scope"] != "machine" || subject["id"] != "ace" || subject["machine"] != "ace" { + t.Errorf("subject %v", shape["subject"]) + } + if said[0].Show != "mesh-controller.conditions key=machine.ace.silent" { + t.Errorf("show is %q", said[0].Show) + } +} + +// **A transition the bus will not take is offered again**, and said lost only after TellFor. +func TestATransitionIsOfferedAgainWhileTheBusIsAway(t *testing.T) { + store, told, c := NewInMemory(), &Told{Fail: errors.New("no responders")}, newClock() + k := NewKeeper(t.Context(), Options{Store: store, History: store, Teller: told, Now: c.now}) + defer k.Close(context.Background()) + if _, err := k.Observe(t.Context(), silent("ace")); err != nil { + t.Fatal(err) + } + time.Sleep(300 * time.Millisecond) + told.mu.Lock() + told.Fail = nil + told.mu.Unlock() + said := settled(t, told, 1) + if said[0].Key != "machine.ace.silent" || k.Unsaid() != 0 { + t.Fatalf("said %+v, unsaid %d", said, k.Unsaid()) + } +} diff --git a/internal/inventory/plans.go b/internal/inventory/plans.go index cb8d875..0d63308 100644 --- a/internal/inventory/plans.go +++ b/internal/inventory/plans.go @@ -28,6 +28,10 @@ type Plan struct { Tiers [][]string `json:"tiers"` Modules map[string]*PlanModule `json:"modules"` Note string `json:"note,omitempty"` + // TierEntered is when the plan entered the tier it is at (novox/hq to-be 45 Phase 0), read and + // never written from here: a save measures the tier it leaves and stamps the next. What the + // watchdog of a plan's progress (S3) reads. + TierEntered time.Time `json:"tier_entered,omitempty"` } // PlanModule is one module's state within a plan. @@ -129,7 +133,8 @@ func (i *Inventory) PlanByID(ctx context.Context, id string) (Plan, error) { func (i *Inventory) plans(ctx context.Context, tail string) ([]Plan, error) { rows, err := i.store.Pool().Query(ctx, - `select id, repository, commit_hash, created, updated, state, tier, tiers, modules, note, branch + `select id, repository, commit_hash, created, updated, state, tier, tiers, modules, note, branch, + coalesce(tier_entered, created) from release_plan `+tail) if err != nil { return nil, err @@ -140,7 +145,7 @@ func (i *Inventory) plans(ctx context.Context, tail string) ([]Plan, error) { var p Plan var tiers, modules []byte if err := rows.Scan(&p.ID, &p.Repository, &p.Commit, &p.Created, &p.Updated, &p.State, - &p.Tier, &tiers, &modules, &p.Note, &p.Branch); err != nil { + &p.Tier, &tiers, &modules, &p.Note, &p.Branch, &p.TierEntered); err != nil { return nil, err } if err := json.Unmarshal(tiers, &p.Tiers); err != nil { diff --git a/internal/inventory/standing.go b/internal/inventory/standing.go deleted file mode 100644 index 8e29369..0000000 --- a/internal/inventory/standing.go +++ /dev/null @@ -1,76 +0,0 @@ -package inventory - -import ( - "context" - "time" -) - -// ProviderStanding is a consumer a provider says it keeps failing (novox/hq ADR 0224). -type ProviderStanding struct { - // Module is the provider's module, and ProviderNode the machine it runs on. - Module string `json:"module"` - ProviderNode string `json:"provider-node"` - // Provision is the interface it provides, e.g. `oidc-client`. - Provision string `json:"provision"` - // Consumer is the identity the mesh derived for the consumer, ConsumerNode its machine. - Consumer string `json:"consumer"` - ConsumerNode string `json:"consumer-node"` - // Class is what kind of failure: credentials-rejected, unreachable, secret-unreadable, refused. - Class string `json:"class"` - Error string `json:"error"` - // Since is when the unbroken run of failures began; Attempts how many it has been. - Since time.Time `json:"since"` - Attempts int `json:"attempts"` - // SaidAt is when the controller last heard it. A provider says it again every quarter of an hour - // while it lasts, so an old one is a provider that stopped saying anything. - SaidAt time.Time `json:"said-at"` -} - -// SayAgainWithin is how long a failing standing stays current without being said again: twice the -// quarter of an hour a provider repeats it at. Older, and status says the provider has gone quiet. -const SayAgainWithin = 30 * time.Minute - -// Quiet says the provider has not repeated this standing for longer than it would while it lasts. -func (s ProviderStanding) Quiet(now time.Time) bool { return now.Sub(s.SaidAt) > SayAgainWithin } - -// KeepStanding records a provider's newest word: failing keeps it, recovered removes it, and says -// whether a recovery removed anything. -func (i *Inventory) KeepStanding(ctx context.Context, failing bool, s ProviderStanding) (bool, error) { - if !failing { - tag, err := i.store.Pool().Exec(ctx, - `delete from provider_standing where module = $1 and provider_node = $2 and consumer = $3`, - s.Module, s.ProviderNode, s.Consumer) - return err == nil && tag.RowsAffected() > 0, err - } - _, err := i.store.Pool().Exec(ctx, ` - insert into provider_standing - (module, provider_node, consumer, consumer_node, provision, class, error, since, attempts, said_at) - values ($1, $2, $3, $4, $5, $6, $7, $8, $9, now()) - on conflict (module, provider_node, consumer) do update set - consumer_node = excluded.consumer_node, provision = excluded.provision, - class = excluded.class, error = excluded.error, since = excluded.since, - attempts = excluded.attempts, said_at = excluded.said_at`, - s.Module, s.ProviderNode, s.Consumer, s.ConsumerNode, s.Provision, s.Class, s.Error, s.Since, s.Attempts) - return false, err -} - -// FailingProviders is every consumer a provider last said it keeps failing, oldest run first. -func (i *Inventory) FailingProviders(ctx context.Context) ([]ProviderStanding, error) { - rows, err := i.store.Pool().Query(ctx, ` - select module, provider_node, provision, consumer, consumer_node, class, error, since, attempts, said_at - from provider_standing order by since, module, consumer`) - if err != nil { - return nil, err - } - defer rows.Close() - var out []ProviderStanding - for rows.Next() { - var s ProviderStanding - if err := rows.Scan(&s.Module, &s.ProviderNode, &s.Provision, &s.Consumer, &s.ConsumerNode, - &s.Class, &s.Error, &s.Since, &s.Attempts, &s.SaidAt); err != nil { - return nil, err - } - out = append(out, s) - } - return out, rows.Err() -} diff --git a/internal/inventory/standing_test.go b/internal/inventory/standing_test.go deleted file mode 100644 index fe5fa3f..0000000 --- a/internal/inventory/standing_test.go +++ /dev/null @@ -1,130 +0,0 @@ -package inventory - -import ( - "slices" - "testing" - "time" - - "github.com/novox/mesh-controller/internal/broker" - "github.com/novox/mesh-controller/internal/catalogue" -) - -// A provider's standing (novox/hq ADR 0224), from the grant that lets it say so to the row status -// reads. - -// The broker spells the events itself because it cannot import the catalogue; the two agree. -func TestTheBrokerAndTheCatalogueNameTheSameStandingEvents(t *testing.T) { - if broker.ProvisionerFailing != catalogue.ProvisionerFailing || - broker.ProvisionerRecovered != catalogue.ProvisionerRecovered { - t.Fatal("the broker and the catalogue disagree about what a provider's standing is called") - } -} - -// **Every provider may say it, whatever its manifest lists**: a provider whose manifest forgot the -// events would have its announcement refused by the bus, and fail its consumers as silently as on -// 2026-10-05 (issue 179). A module that receives no contributions provides nothing and is given -// nothing. -func TestEveryProviderIsGrantedItsStandingAndNothingElseIs(t *testing.T) { - provider := catalogue.Manifest{Module: "keycloak", Version: "1", - Emits: []string{"client.created"}, Receives: map[string]string{"oidc-client": "/x/mesh.json"}} - consumer := catalogue.Manifest{Module: "grafana", Version: "1", Emits: []string{"dashboard.saved"}} - - d := declaredFor(provider, nil) - for _, e := range []string{"client.created", catalogue.ProvisionerFailing, catalogue.ProvisionerRecovered} { - if !slices.Contains(d.Emits, e) { - t.Fatalf("a provider is not granted %s: %v", e, d.Emits) - } - } - perms, err := broker.PermissionsFor(broker.Principal{Kind: broker.KindModule, Node: "anchor", - Module: "keycloak", Emits: d.Emits}) - if err != nil { - t.Fatal(err) - } - if !slices.Contains(perms.Publish, "mesh.mod.keycloak.event.provisioner.failing") { - t.Fatalf("the bus would refuse a provider's standing: %v", perms.Publish) - } - - if got := declaredFor(consumer, nil).Emits; slices.Contains(got, catalogue.ProvisionerFailing) { - t.Fatalf("a module that provides nothing was granted a provider's standing: %v", got) - } - // Declared by hand as well: said once. - provider.Emits = append(provider.Emits, catalogue.ProvisionerFailing) - n := 0 - for _, e := range provider.EmitsAll() { - if e == catalogue.ProvisionerFailing { - n++ - } - } - if n != 1 { - t.Fatalf("%v", provider.EmitsAll()) - } -} - -// And the controller may hear it from every provider, and only those two events. -func TestTheControllerHearsEveryProvidersStanding(t *testing.T) { - perms, err := broker.PermissionsFor(broker.Principal{Kind: broker.KindController}) - if err != nil { - t.Fatal(err) - } - for _, want := range []string{"mesh.mod.*.event.provisioner.failing", "mesh.mod.*.event.provisioner.recovered"} { - if !slices.Contains(perms.Subscribe, want) { - t.Fatalf("the controller may not hear %s: %v", want, perms.Subscribe) - } - } - if slices.Contains(perms.Subscribe, "mesh.mod.*.event.>") { - t.Fatal("the controller hears every event in the mesh") - } -} - -func TestAFailingStandingIsKeptUntilItRecovers(t *testing.T) { - inv := ForTest(t) - ctx := t.Context() - since := time.Date(2026, 10, 5, 0, 49, 0, 0, time.UTC) - s := ProviderStanding{Module: "keycloak", ProviderNode: "anchor", Provision: "oidc-client", - Consumer: "mesh_home_grafana", ConsumerNode: "home-server", Class: "credentials-rejected", - Error: "401 invalid_grant", Since: since, Attempts: 60} - if _, err := inv.KeepStanding(ctx, true, s); err != nil { - t.Fatal(err) - } - // Said again: one row, the newest word. - s.Attempts = 31000 - if _, err := inv.KeepStanding(ctx, true, s); err != nil { - t.Fatal(err) - } - got, err := inv.FailingProviders(ctx) - if err != nil { - t.Fatal(err) - } - if len(got) != 1 || got[0].Attempts != 31000 || !got[0].Since.Equal(since) || got[0].ConsumerNode != "home-server" || - got[0].Class != "credentials-rejected" || got[0].SaidAt.IsZero() { - t.Fatalf("%+v", got) - } - if got[0].Quiet(time.Now()) { - t.Fatal("a standing just said reads as quiet") - } - if !got[0].Quiet(time.Now().Add(SayAgainWithin + time.Minute)) { - t.Fatal("a standing not said again for longer than a provider repeats it does not read as quiet") - } - - // The same consumer from another machine's provider is its own row. - other := s - other.ProviderNode = "laptop" - if _, err := inv.KeepStanding(ctx, true, other); err != nil { - t.Fatal(err) - } - cleared, err := inv.KeepStanding(ctx, false, s) - if err != nil || !cleared { - t.Fatalf("recovered cleared nothing: %v %v", cleared, err) - } - cleared, err = inv.KeepStanding(ctx, false, s) - if err != nil || cleared { - t.Fatalf("a recovery for nothing kept said it cleared something: %v %v", cleared, err) - } - got, err = inv.FailingProviders(ctx) - if err != nil { - t.Fatal(err) - } - if len(got) != 1 || got[0].ProviderNode != "laptop" { - t.Fatalf("%+v", got) - } -} diff --git a/internal/link/advisories.go b/internal/link/advisories.go new file mode 100644 index 0000000..f14f3ad --- /dev/null +++ b/internal/link/advisories.go @@ -0,0 +1,227 @@ +package link + +import ( + "encoding/json" + "errors" + "fmt" + "strings" + "sync" + "time" + + "github.com/nats-io/nats.go" + + "github.com/novox/mesh-controller/internal/broker" +) + +// What the bus says about itself, in the mesh's words (novox/hq to-be 45 §3, S9). +// +// **The server already says it; nothing listened.** A durable consumer that hands a message over as +// often as it may gives up on it and says so on `$JS.EVENT.ADVISORY.CONSUMER.MAX_DELIVERIES`; one +// deleted says so on `…CONSUMER.DELETED`. The controller's own connection is told when it falls behind +// (a slow consumer: the client library dropped messages — issue 184, the controller deaf for 24 +// minutes) and when the bus refuses it a subject (a permissions violation — issues 183, 217, 265, +// days each as a line in a client library's output). Each is recorded here, named in the mesh's words — +// which consumer of whose, which subject — for the watchdog to say as a condition, as the refused +// reply of issue 265 is said today. +// +// What the bus says about **other** principals' connections — a module's slow consumer, a module +// refused a subject — the server publishes only to a system account, which the mesh's bus does not +// have; that half is not heard yet (to-be 45 S9, recorded as deferred). + +// The advisory kinds, as conditions name them. +const ( + AdvisorySlowConsumer = "slow-consumer" + AdvisoryMaxDeliveries = "max-deliveries" + AdvisoryRefused = "refused" + AdvisoryConsumerLost = "consumer-lost" +) + +// Advisory is one thing the bus said, kept as its newest word and how often it was said. +type Advisory struct { + Kind string + // ID names what it is about, for the condition's key: `.`, or `controller`. + ID string + // Stream and Consumer are the consumer it is about, when it is about one. + Stream, Consumer string + // Said is the newest saying, in the mesh's words. + Said string + First, Last time.Time + Count int +} + +// AdvisoryLog keeps what the bus said lately. +type AdvisoryLog struct { + mu sync.Mutex + seen map[string]*Advisory +} + +// Advisories is this process's log. +var Advisories = &AdvisoryLog{seen: map[string]*Advisory{}} + +// Heard records one advisory. +func (l *AdvisoryLog) Heard(a Advisory, at time.Time) { + l.mu.Lock() + defer l.mu.Unlock() + key := a.Kind + "/" + a.ID + if had, ok := l.seen[key]; ok { + had.Last, had.Said, had.Count = at, a.Said, had.Count+1 + return + } + a.First, a.Last, a.Count = at, at, 1 + l.seen[key] = &a +} + +// Since is every advisory said at or after a moment, and forgets the older ones. +func (l *AdvisoryLog) Since(since time.Time) []Advisory { + l.mu.Lock() + defer l.mu.Unlock() + var out []Advisory + for key, a := range l.seen { + if a.Last.Before(since) { + delete(l.seen, key) + continue + } + out = append(out, *a) + } + return out +} + +// jsAdvisory is the part of a JetStream advisory the mesh reads. +type jsAdvisory struct { + Type string `json:"type"` + Stream string `json:"stream"` + Consumer string `json:"consumer"` + StreamSeq uint64 `json:"stream_seq"` + Deliveries uint64 `json:"deliveries"` + Action string `json:"action"` +} + +// ReadAdvisory is one JetStream advisory as the mesh says it; false for one it does not watch. +func ReadAdvisory(subject string, body []byte) (Advisory, bool) { + var a jsAdvisory + if err := json.Unmarshal(body, &a); err != nil || a.Stream == "" || a.Consumer == "" { + return Advisory{}, false + } + who := ConsumerInWords(a.Stream, a.Consumer) + id := a.Stream + "." + a.Consumer + switch { + case strings.HasPrefix(subject, "$JS.EVENT.ADVISORY.CONSUMER.MAX_DELIVERIES."): + return Advisory{Kind: AdvisoryMaxDeliveries, ID: id, Stream: a.Stream, Consumer: a.Consumer, + Said: fmt.Sprintf("%s handed message %d over %d times and gave up on it: it will not be delivered "+ + "again, and what it asked for was not done", who, a.StreamSeq, a.Deliveries)}, true + case strings.HasPrefix(subject, "$JS.EVENT.ADVISORY.CONSUMER.DELETED."): + if !MeshNamed(a.Stream, a.Consumer) { + // A reader's own consumer, gone when it finished — every watch of a bucket and every + // read-back of a stream makes one, many a minute: not something the mesh defines. + return Advisory{}, false + } + return Advisory{Kind: AdvisoryConsumerLost, ID: id, Stream: a.Stream, Consumer: a.Consumer, + Said: fmt.Sprintf("%s was deleted from the bus", who)}, true + } + return Advisory{}, false +} + +// MeshNamed says a consumer is one of the durable consumers the mesh defines, by its name's shape: +// the controller's own, a machine's declaration consumer, a module's (`_`), a seat's +// worker. Every other consumer is a reader's own — an ordered consumer, a bucket's watcher — named at +// random by the client library, deleted when the read is done, and not the mesh's to say anything of. +func MeshNamed(stream, name string) bool { + switch { + case strings.HasPrefix(stream, "KV_") || stream == broker.AssignmentsStream: + return false // the mesh defines no durable consumer on a bucket's stream, or the memberships' + case stream == "NODES": + return true + case strings.HasPrefix(stream, "SEAT_"): + return strings.HasSuffix(name, "_worker") + case name == broker.ControllerName: + return true + case stream == broker.EventsStream: + return strings.Contains(name, "_") + } + return false +} + +// ConsumerInWords is a durable consumer as the mesh says it: whose, and for what. +func ConsumerInWords(stream, name string) string { + switch { + case name == broker.ControllerName: + return "the controller's consumer on " + stream + case stream == "NODES": + return "how " + name + " hears what it should be (its declaration consumer)" + case strings.HasPrefix(stream, "SEAT_") && strings.HasSuffix(name, "_worker"): + seat := strings.ToLower(strings.ReplaceAll(strings.TrimPrefix(stream, "SEAT_"), "_", "-")) + return "the worker every holder of " + seat + " takes its asks from" + case stream == broker.EventsStream: + if node, module, ok := strings.Cut(name, "_"); ok { + return "how " + module + " on " + node + " hears what it consumes" + } + } + return "the consumer " + name + " on " + stream +} + +// HearAdvisories subscribes what the bus says about the mesh's account, and listens for what it +// tells this connection, until the returned function is called. Read-only: nothing is published. +func (s *Server) HearAdvisories(logf func(string, ...any)) (func(), error) { + if s.js == nil { + return nil, errors.New("this control plane is not on the bus, so it cannot hear what the bus says") + } + conn := s.js.Conn() + var subs []*nats.Subscription + stop := func() { + for _, sub := range subs { + _ = sub.Unsubscribe() + } + } + for _, subject := range broker.BusAdvisories { + sub, err := conn.Subscribe(subject, func(m *nats.Msg) { + if a, ok := ReadAdvisory(m.Subject, m.Data); ok { + Advisories.Heard(a, time.Now()) + logf("the bus says: %s", a.Said) + } + }) + if err != nil { + stop() + return nil, fmt.Errorf("listening to what the bus says (%s): %w", subject, err) + } + subs = append(subs, sub) + } + WatchConnection(conn, logf) + return stop, nil +} + +// WatchConnection records what the bus tells this connection about itself: it fell behind, or a +// subject was refused it. Chained before whatever handler the connection had, which still runs. A +// refused answer to a call is the call log's to say (issue 265), and is not said twice. +func WatchConnection(conn *nats.Conn, logf func(string, ...any)) { + before := conn.ErrorHandler() + conn.SetErrorHandler(func(c *nats.Conn, sub *nats.Subscription, err error) { + if a, ok := connectionAdvisory(sub, err); ok { + Advisories.Heard(a, time.Now()) + logf("the bus says: %s", a.Said) + } + if before != nil { + before(c, sub, err) + } + }) +} + +// connectionAdvisory is an error the bus handed the controller's connection, as an advisory. +func connectionAdvisory(sub *nats.Subscription, err error) (Advisory, bool) { + switch { + case errors.Is(err, nats.ErrSlowConsumer): + subject := "a subscription" + if sub != nil { + subject = sub.Subject + } + return Advisory{Kind: AdvisorySlowConsumer, ID: "controller", + Said: fmt.Sprintf("the controller fell behind on %s and the client dropped messages it was sent", subject)}, true + case errors.Is(err, nats.ErrPermissionViolation): + if m := refusedPublish.FindStringSubmatch(err.Error()); m != nil && strings.HasPrefix(m[1], "_INBOX.") && + !strings.HasPrefix(m[1], "_INBOX.enrol.") { + return Advisory{}, false // a refused answer to a call, which the call log says against its call + } + return Advisory{Kind: AdvisoryRefused, ID: "controller", + Said: "the bus refused the controller: " + err.Error()}, true + } + return Advisory{}, false +} diff --git a/internal/link/advisories_test.go b/internal/link/advisories_test.go new file mode 100644 index 0000000..e3a5359 --- /dev/null +++ b/internal/link/advisories_test.go @@ -0,0 +1,33 @@ +package link + +import "testing" + +// **A reader's own consumer gone is not a consumer lost**: every bucket watch and stream read-back +// makes and deletes one, many a minute, and the bus says so each time (found running the controller +// against a real bus: five a tick). +func TestOnlyTheMeshsOwnConsumersAreSaidLost(t *testing.T) { + deleted := func(stream, consumer string) bool { + _, ok := ReadAdvisory("$JS.EVENT.ADVISORY.CONSUMER.DELETED."+stream+"."+consumer, + []byte(`{"type":"io.nats.jetstream.advisory.v1.consumer_action","stream":"`+stream+`","consumer":"`+consumer+`","action":"delete"}`)) + return ok + } + for _, c := range [][2]string{{"EVENTS", "controller"}, {"CONTROL", "controller"}, {"NODES", "anchor"}, + {"EVENTS", "anchor_shop"}, {"SEAT_NODE_BUILD_AGENT", "SEAT_NODE_BUILD_AGENT_worker"}} { + if !deleted(c[0], c[1]) { + t.Errorf("%s on %s deleted is not said", c[1], c[0]) + } + } + for _, c := range [][2]string{{"KV_mesh-controller_conditions", "381UWW5Y"}, {"EVENTS", "E7vVYoe6"}, + {"SEAT_NODE_BUILD_AGENT", "Rcnt6jla"}, {"ASSIGNMENTS", "x"}} { + if deleted(c[0], c[1]) { + t.Errorf("a reader's own consumer %s on %s is said lost", c[1], c[0]) + } + } + a, ok := ReadAdvisory("$JS.EVENT.ADVISORY.CONSUMER.MAX_DELIVERIES.EVENTS.anchor_shop", + []byte(`{"stream":"EVENTS","consumer":"anchor_shop","stream_seq":7,"deliveries":5}`)) + if !ok || a.Kind != AdvisoryMaxDeliveries || a.ID != "EVENTS.anchor_shop" || + a.Said != "how shop on anchor hears what it consumes handed message 7 over 5 times and gave up on it: "+ + "it will not be delivered again, and what it asked for was not done" { + t.Fatalf("%+v", a) + } +} diff --git a/internal/link/bus.go b/internal/link/bus.go index cc0ead6..e03c8e8 100644 --- a/internal/link/bus.go +++ b/internal/link/bus.go @@ -71,6 +71,10 @@ const ( // next heartbeat, and a stream of them is the mesh's least valuable message competing for // retention with its most valuable (design 25 §3). AliveSubjects = "mesh.control.*.alive" + + // ToolsAliveSubjects is every machine's node tools saying they are there (novox/hq to-be 45 §3, + // S11): core NATS like the host's, for the same reason. + ToolsAliveSubjects = "mesh.control.*.tools-alive" ) // ReportSubject is where one node says what it did. On the CONTROL stream, because it is the @@ -80,6 +84,9 @@ func ReportSubject(node string) string { return "mesh.control." + node + ".repor // AliveSubject is one node's heartbeat. func AliveSubject(node string) string { return "mesh.control." + node + ".alive" } +// ToolsAliveSubject is one machine's node tools' heartbeat. +func ToolsAliveSubject(node string) string { return "mesh.control." + node + ".tools-alive" } + // EventSubject is where a module's event lands. Derived from the emitter, never taken from the // caller: a source that could differ from the subject is an envelope that can lie about its // origin, and on NATS the account's permissions make the subject the authority (design 29 §2). diff --git a/internal/link/calls.go b/internal/link/calls.go index 51f996f..5926843 100644 --- a/internal/link/calls.go +++ b/internal/link/calls.go @@ -271,6 +271,23 @@ func (l *CallLog) finish(c *Call, answer []byte, failed, answeredAlready bool) { // kept durably, every other the bus holds — a call a controller before this one served included. // Memory wins for a call in both, being the newer word on it. A bus that cannot be read is said in // the error beside what memory holds, never answered as no calls. +// Running is every call this process is serving that has not finished, oldest first, without +// answers: what the watchdog of a call's bound (novox/hq to-be 45 S7) reads. This process's own, +// because a call another controller left running is said abandoned when this one starts. +func (l *CallLog) Running() []Call { + l.mu.Lock() + defer l.mu.Unlock() + var out []Call + for _, c := range l.calls { + if c.State == CallRunning { + running := *c + running.Answer = nil + out = append(out, running) + } + } + return out +} + func (l *CallLog) Recent() ([]Call, error) { l.mu.Lock() out := make([]Call, 0, len(l.calls)) diff --git a/internal/link/protocol.go b/internal/link/protocol.go index 38348c4..3a08390 100644 --- a/internal/link/protocol.go +++ b/internal/link/protocol.go @@ -138,6 +138,20 @@ type Signed struct { // is current. type Alive struct { Node string `json:"node"` + // IntervalSeconds is how often the node says it is there (novox/hq to-be 45 §3, S1): the + // watchdog's bound is three of them. Zero from a host older than that, which is read as the + // interval hosts have always used. + IntervalSeconds int `json:"interval_seconds,omitempty"` +} + +// ToolsAlive is a machine's node tools saying they are there (novox/hq to-be 45 §3, S11): the +// runtime every module's tools and every held seat's verbs are served by. Its own word, apart from the +// host's, because a host heard and a runtime gone is a machine nobody can ask anything. +type ToolsAlive struct { + Node string `json:"node"` + IntervalSeconds int `json:"interval_seconds,omitempty"` + // Version is the runtime's build, as it says it. + Version string `json:"version,omitempty"` } // Report is what a node states after applying. It states; the owning context writes. diff --git a/internal/link/receive.go b/internal/link/receive.go index 98447b7..bdd0acd 100644 --- a/internal/link/receive.go +++ b/internal/link/receive.go @@ -25,11 +25,13 @@ import ( // on the wire: the wire is the transport's business, and a kind that travelled would be a third // name for the same thing. const ( - KindEnrolment = "enrolment" - KindReport = "report" - KindHeartbeat = "heartbeat" - KindBuilt = "built" - KindModuleMoved = "module-moved" + KindEnrolment = "enrolment" + KindReport = "report" + KindHeartbeat = "heartbeat" + // KindToolsHeartbeat is a machine's node tools saying they are there (novox/hq to-be 45 S11). + KindToolsHeartbeat = "tools-heartbeat" + KindBuilt = "built" + KindModuleMoved = "module-moved" // KindSourceMoved is the forge announcing a merge: a source moved, and what it produces is // built without anybody telling the mesh (novox/hq 04-ISSUES/131). KindSourceMoved = "source-moved" diff --git a/internal/link/receive_nats.go b/internal/link/receive_nats.go index d4f67fa..cace2dc 100644 --- a/internal/link/receive_nats.go +++ b/internal/link/receive_nats.go @@ -89,6 +89,10 @@ func (n *natsInbound) Receive(ctx context.Context, act func(context.Context, Con return nil // stopped while standing by } defer func() { _ = said.Unsubscribe() }() + // This controller is the one acting now: its watchdogs and self-check may say what they see + // (novox/hq to-be 45 §3). One standing by hears nothing, and would call every machine silent. + holding.Store(true) + defer holding.Store(false) // Heartbeats, on core NATS and off any stream (design 25 §3). Their own subscription because // they are their own guarantee: a lost one is the next one. @@ -98,6 +102,12 @@ func (n *natsInbound) Receive(ctx context.Context, act func(context.Context, Con return fmt.Errorf("subscribing to heartbeats: %w", err) } defer func() { _ = alive.Unsubscribe() }() + // And each machine's node tools, on the same channel: as cheap, and lost the same way. + toolsAlive, err := conn.ChanSubscribe(ToolsAliveSubjects, beats) + if err != nil { + return fmt.Errorf("subscribing to the node tools' heartbeats: %w", err) + } + defer func() { _ = toolsAlive.Unsubscribe() }() // The events the controller follows, when something is listening for them. var events chan *nats.Msg @@ -159,6 +169,8 @@ func (n *natsInbound) deliver(ctx context.Context, act func(context.Context, Con } m := &natsControl{kind: kind, msg: msg, on: n} if streamed { + // The event loop took one: what S4 watches (novox/hq to-be 45 §3). + Loop.Took(time.Now()) // A message with no metadata is not from a stream, whatever it was delivered on, and the // window has nothing to hold it by. Said by leaving the sequence at zero. if meta, err := msg.Metadata(); err == nil { @@ -225,6 +237,8 @@ func kindOfSubject(subject string) (string, bool) { return KindReport, true case "alive": return KindHeartbeat, true + case "tools-alive": + return KindToolsHeartbeat, true } } switch subject { diff --git a/internal/link/serve.go b/internal/link/serve.go index 920d6bf..e63f02f 100644 --- a/internal/link/serve.go +++ b/internal/link/serve.go @@ -170,6 +170,8 @@ func (s *Server) act(ctx context.Context, m Control) { s.reported(ctx, m) case KindHeartbeat: s.heartbeat(m) + case KindToolsHeartbeat: + s.toolsHeartbeat(m) case KindBuilt: s.wasBuilt(ctx, m) case KindModuleMoved: @@ -268,6 +270,8 @@ func (s *Server) heartbeat(m Control) { _ = m.Drop() return } + // The interval it says, for the watchdog's bound (novox/hq to-be 45 S1). + HostBeats.Heard(alive.Node, time.Now(), time.Duration(alive.IntervalSeconds)*time.Second, "") if s.listener != nil { if _, err := s.listener.Heard(context.Background(), Report{Node: alive.Node}); err != nil { s.log.Printf("could not record that %s is here: %v", alive.Node, err) @@ -276,6 +280,22 @@ func (s *Server) heartbeat(m Control) { _ = m.Took() } +// toolsHeartbeat records that a machine's node tools were heard from (novox/hq to-be 45 S11), and +// nothing else: in this process's memory, for the watchdog — the next one is a minute away. +func (s *Server) toolsHeartbeat(m Control) { + var alive ToolsAlive + if err := json.Unmarshal(m.Body(), &alive); err != nil || alive.Node == "" { + _ = m.Drop() + return + } + // The machine is the one in the subject the bus let the runtime publish on, never the body's. + if node, ok := nodeOfToolsAlive(m.Subject()); ok { + alive.Node = node + } + ToolsBeats.Heard(alive.Node, time.Now(), time.Duration(alive.IntervalSeconds)*time.Second, alive.Version) + _ = m.Took() +} + // reported records what a node says it did. // // A node states; nothing here writes anything the node claimed about itself beyond that it was diff --git a/internal/link/watched.go b/internal/link/watched.go new file mode 100644 index 0000000..f93a680 --- /dev/null +++ b/internal/link/watched.go @@ -0,0 +1,227 @@ +package link + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "strings" + "sync" + "sync/atomic" + "time" + + "github.com/nats-io/nats.go" + + "github.com/novox/mesh-controller/internal/broker" +) + +// What the serving controller hears that its watchdogs read (novox/hq to-be 45 §3). +// +// **In memory, on purpose.** A heartbeat is the least valuable message the mesh sends — the next one +// is a minute away — and what a watchdog needs of it is the newest moment and the interval it said. +// A machine's last word is kept in the store as well (`last_seen`), which is what S1 reads; these are +// what the store does not keep: the interval, the node tools' word, and when the event loop last took +// a message. + +// Beat is one emitter's newest heartbeat. +type Beat struct { + At time.Time + // Every is the interval it said; zero when it said none. + Every time.Duration + Version string +} + +// Beats is the newest heartbeat of each machine, for one kind of emitter. +type Beats struct { + mu sync.Mutex + started time.Time + heard map[string]Beat +} + +// NewBeats is an empty record, started now. +func NewBeats() *Beats { return &Beats{started: time.Now(), heard: map[string]Beat{}} } + +// HostBeats are the node-engines' heartbeats (S1); ToolsBeats the node tools' (S11). +var ( + HostBeats = NewBeats() + ToolsBeats = NewBeats() +) + +// Heard records one heartbeat. +func (b *Beats) Heard(node string, at time.Time, every time.Duration, version string) { + b.mu.Lock() + defer b.mu.Unlock() + b.heard[node] = Beat{At: at, Every: every, Version: version} +} + +// Of is one machine's newest heartbeat; false when none was heard since this process started. +func (b *Beats) Of(node string) (Beat, bool) { + b.mu.Lock() + defer b.mu.Unlock() + beat, ok := b.heard[node] + return beat, ok +} + +// Started is when this record began: a machine not heard since is silent since then at the most. +func (b *Beats) Started() time.Time { + b.mu.Lock() + defer b.mu.Unlock() + return b.started +} + +// nodeOfToolsAlive is the machine a node tools' heartbeat names in its subject. +func nodeOfToolsAlive(subject string) (string, bool) { + rest, ok := strings.CutPrefix(subject, "mesh.control.") + if !ok { + return "", false + } + node, kind, ok := strings.Cut(rest, ".") + if !ok || kind != "tools-alive" || node == "" { + return "", false + } + return node, true +} + +// LoopActivity is when the controller's event loop last took a message from a stream (S4). +type LoopActivity struct { + mu sync.Mutex + took time.Time +} + +// Loop is this process's event loop. +var Loop = &LoopActivity{} + +// Took records that the loop was handed a message. +func (l *LoopActivity) Took(at time.Time) { + l.mu.Lock() + defer l.mu.Unlock() + l.took = at +} + +// Last is when the loop last took one; zero when it has not since this process started. +func (l *LoopActivity) Last() time.Time { + l.mu.Lock() + defer l.mu.Unlock() + return l.took +} + +// PowerState is what a machine last said about its power (novox/hq ADR 0211): `sleeping` or +// `shutting-down` until it says `booted` or `woke`. +type PowerState struct { + State string + At time.Time +} + +// PowerModule is the module whose events say a machine's power (ADR 0211), and PowerEvents its +// events that say whether the machine is about to be away or is back. +const PowerModule = "power" + +var PowerEvents = map[string]bool{"sleeping": true, "shutting-down": true, "booted": true, "woke": true} + +// PowerStates is each machine's newest word about its power since a moment, read back from the +// events stream on a consumer of its own that acknowledges nothing (as AnnouncedMerges reads). The +// machine is the one the runtime stamped on the event (`x-node`); an event without one names none. +func (s *Server) PowerStates(ctx context.Context, since time.Time) (map[string]PowerState, error) { + if s.js == nil { + return nil, errors.New("this control plane is not on the bus, so it cannot read what machines said of their power") + } + sub, err := s.js.Context().SubscribeSync(EventSubject(PowerModule, ">"), nats.OrderedConsumer(), nats.StartTime(since)) + if err != nil { + return nil, fmt.Errorf("reading what machines said of their power: %w", err) + } + defer func() { _ = sub.Unsubscribe() }() + out := map[string]PowerState{} + for { + wait, cancel := context.WithTimeout(ctx, readQuiet) + msg, err := sub.NextMsgWithContext(wait) + cancel() + if err != nil { + if ctx.Err() != nil { + return nil, ctx.Err() + } + break + } + meta, err := msg.Metadata() + if err != nil { + continue + } + state := strings.TrimPrefix(msg.Subject, "mesh.mod."+PowerModule+".event.") + node := msg.Header.Get("x-node") + if PowerEvents[state] && node != "" { + at := meta.Timestamp + var body struct { + At time.Time `json:"at"` + } + if json.Unmarshal(msg.Data, &body) == nil && !body.At.IsZero() { + at = body.At + } + if before, ok := out[node]; !ok || !at.Before(before.At) { + out[node] = PowerState{State: state, At: at} + } + } + if meta.NumPending == 0 { + break + } + } + return out, nil +} + +// Away says whether a power state is a machine that said it would be away. +func (p PowerState) Away() bool { return p.State == "sleeping" || p.State == "shutting-down" } + +// StaleRefusal is the node-engine's words for a declaration it refused because it is older than the +// one it holds (mesh-host `refuseOlder`, novox/hq issue 107): the receiver's refusal S13 counts. +const StaleRefusal = "is older than what the mesh last said to this node" + +// IsStaleRefusal says a report's refusal is the node-engine refusing a declaration older than it holds. +func IsStaleRefusal(refused string) bool { return strings.Contains(refused, StaleRefusal) } + +// RefusalCount keeps when each machine refused a stale declaration, for S13 (novox/hq to-be 45 §3): +// more than five from one writer in five minutes is a writer sending what it has moved past. +type RefusalCount struct { + mu sync.Mutex + per map[string][]time.Time +} + +// StaleRefusals is this process's count. +var StaleRefusals = &RefusalCount{per: map[string][]time.Time{}} + +// Refused records one refusal by a machine. +func (r *RefusalCount) Refused(node string, at time.Time) { + r.mu.Lock() + defer r.mu.Unlock() + r.per[node] = append(r.per[node], at) +} + +// Within is how many refusals each machine made since a moment; older ones are forgotten. +func (r *RefusalCount) Within(since time.Time) map[string]int { + r.mu.Lock() + defer r.mu.Unlock() + out := map[string]int{} + for node, times := range r.per { + var kept []time.Time + for _, t := range times { + if !t.Before(since) { + kept = append(kept, t) + } + } + if len(kept) == 0 { + delete(r.per, node) + continue + } + r.per[node] = kept + out[node] = len(kept) + } + return out +} + +// holding is whether this process holds the controller's consumer of what nodes say: the controller +// acting, not one standing by for another (issue 213). Until the lease (to-be 45 §6) it is how a +// watchdog knows it is the one that hears. +var holding atomic.Bool + +// Holding says this process is the controller acting now. +func Holding() bool { return holding.Load() } + +// JetStream is the connection the server consumes on. +func (s *Server) JetStream() *broker.JetStream { return s.js }