From 077ddf0eb885bea74aca0b29cd05b195e06ec780 Mon Sep 17 00:00:00 2001 From: jochen Date: Fri, 9 Oct 2026 13:30:18 +0200 Subject: [PATCH 1/5] Judge a send by when a fault began, not when it was last raised (hq issue 348) On 2026-10-09 the control node's resolver refused from 10:57:57 UTC. A node-engine restarted by the 10:59:34 send said its names undecided, that statement cleared the network condition, the next look raised it again after the send, and the gate put back two builds for a fault older than them. - A condition keeps First across a reopening; the gate reads Began. - An undecided network statement (unknown, starting) clears nothing. - D10 counts what a release's tier names as rolling, so a walked node-engine is not core-behind on its own first machine. - D2 raises a resolver that refuses every try at once: a refusal is an answer, not a loaded resolver (issue 277). --- cmd/mesh-controller/gate.go | 7 +- cmd/mesh-controller/issue348_test.go | 212 +++++++++++++++++++++++++ cmd/mesh-controller/machine_network.go | 33 +++- cmd/mesh-controller/probes.go | 51 +++++- internal/conditions/condition.go | 16 ++ internal/conditions/store.go | 15 +- internal/conditions/store_test.go | 53 +++++++ 7 files changed, 370 insertions(+), 17 deletions(-) create mode 100644 cmd/mesh-controller/issue348_test.go diff --git a/cmd/mesh-controller/gate.go b/cmd/mesh-controller/gate.go index f47929cf..7e3a8631 100644 --- a/cmd/mesh-controller/gate.go +++ b/cmd/mesh-controller/gate.go @@ -209,7 +209,8 @@ func judgeHealth(module, component string, m catalogue.Manifest, machine string, return healthNotYet, fmt.Sprintf("%s reported %q", machine, r.Outcome) } // **No new condition about it**: about the machine itself, or naming the module on that machine, - // raised since the judging began. The gate's own are not evidence about the build. + // raised since the judging began. The gate's own are not evidence about the build. A fault reopened + // since, that began before the send, is not new (Began, novox/hq issue 348). if f.judged { if f.openErr != nil { return healthNotYet, "what is wrong cannot be read, so whether the build made anything wrong is not known: " + @@ -219,7 +220,7 @@ func judgeHealth(module, component string, m catalogue.Manifest, machine string, // A wait for a person's new login, or for a directory used as found to be handed over, is the module's // reading, not a fault raised since the send: the gate reads it from the statement below (ADR 0254, // novox/hq issue 339). - if c.Source == gateProbe || c.Raised.Before(since) || c.Kind == kindReloginNeeded || c.Kind == kindUsedAsFound { + if c.Source == gateProbe || c.Began().Before(since) || c.Kind == kindReloginNeeded || c.Kind == kindUsedAsFound { continue } onIt := c.Subject.Machine == machine || slices.Contains(c.Subject.Also, machine) || @@ -331,7 +332,7 @@ func aboutTheMachine(machine string, moved []string, since time.Time, f gateFact aboutIt := c.Subject.Scope == conditions.ScopeMachine && (c.Subject.ID == machine || c.Subject.Machine == machine || slices.Contains(c.Subject.Also, machine)) // A directory used as found waits for a person, whatever the send did (novox/hq issue 339). - if !aboutIt || c.Source == gateProbe || c.Raised.Before(since) || c.Kind == kindUsedAsFound { + if !aboutIt || c.Source == gateProbe || c.Began().Before(since) || c.Kind == kindUsedAsFound { kept = append(kept, c) continue } diff --git a/cmd/mesh-controller/issue348_test.go b/cmd/mesh-controller/issue348_test.go new file mode 100644 index 00000000..39275326 --- /dev/null +++ b/cmd/mesh-controller/issue348_test.go @@ -0,0 +1,212 @@ +package main + +import ( + "errors" + "net" + "os" + "strings" + "syscall" + "testing" + "time" + + "github.com/novox/mesh-controller/internal/catalogue" + "github.com/novox/mesh-controller/internal/conditions" + "github.com/novox/mesh-controller/internal/inventory" + "github.com/novox/mesh-controller/internal/lease" + "github.com/novox/mesh-controller/internal/link" +) + +// novox/hq issue 348: on 2026-10-09 the control node's resolver stopped answering on its private address +// at 10:57:57 UTC; the machine's network condition was raised at 10:58:45. The node-engine and the +// controller were sent at 10:59:34. The new node-engine's first statement judged the names once — unknown, +// "one look failed; a second decides" — and that statement cleared the condition, though its last evidence +// still said "connection refused". The next look raised it again at 11:00:23, after the send, and both +// builds failed their gate at 11:10 with "raised since it was sent" and were put back, for a fault that +// began before they were sent. + +// namesRefused is the control node's names part as its node-engine said it in the outage: its own +// resolver, at its own address, refusing. +func namesRefused(state string, streak int) link.NetworkPart { + p := link.NetworkPart{Part: link.PartNames, State: state, Since: h0, Streak: streak} + if state == link.StateUnhealthy { + p.Reason = "1 of its 2 resolvers do not answer as the mesh's do" + p.Said = "10.77.0.1 — anchor.internal (IPv4): read udp 10.77.0.1:35244->10.77.0.1:53: read: connection refused" + p.Toward = []string{"10.77.0.1"} + } + return p +} + +func networkSaying(parts ...link.NetworkPart) *link.NetworkHealth { + state := link.StateHealthy + for _, p := range parts { + switch { + case p.State == link.StateUnhealthy: + state = link.StateUnhealthy + case p.State == link.StateUnknown && state == link.StateHealthy: + state = link.StateUnknown + } + } + return &link.NetworkHealth{State: state, Since: h0, Parts: parts} +} + +// TestReplay348 replays the statements of the outage: the condition raised before the send is not +// cleared by the restarted engine's first, undecided statement, and the gate does not count it against +// the builds sent after it began. +func TestReplay348(t *testing.T) { + open := aMesh(t) + ctx := t.Context() + inv, k := open.inventory, conditionsFrom + say := func(at time.Time, n *link.NetworkHealth) { + t.Helper() + if err := stateHealth(ctx, inv, k, "anchor", link.Health{Contract: link.ReadinessContract, At: at, Network: n}, at); err != nil { + t.Fatal(err) + } + } + network := func() (conditions.Condition, bool) { + t.Helper() + list, err := k.Open(ctx) + if err != nil { + t.Fatal(err) + } + for _, c := range list { + if c.Key == "machine.anchor.network" { + return c, true + } + } + return conditions.Condition{}, false + } + + // 10:58:45 — the second failing look: raised. + say(h0, networkSaying(namesRefused(link.StateUnhealthy, 2))) + raised, ok := network() + if !ok { + t.Fatal("the resolver refusing on the control node raised nothing") + } + time.Sleep(5 * time.Millisecond) + sent := time.Now().UTC() + time.Sleep(5 * time.Millisecond) + + // 10:59:42 — the restarted engine's first statement: one look failed, a second decides. + say(h0.Add(time.Minute), networkSaying(namesRefused(link.StateUnknown, 1))) + if _, ok := network(); !ok { + t.Fatal("a statement that judged nothing yet cleared the condition: the restarted engine's first look " + + "said the fault was gone while it still refused") + } + // 11:00:23 — its second look: unhealthy again, the same raising. + say(h0.Add(2*time.Minute), networkSaying(namesRefused(link.StateUnhealthy, 2))) + again, ok := network() + if !ok || !again.Began().Equal(raised.Raised) { + t.Fatalf("the same fault was said as one that began at %s (raised first at %s)", again.Began(), raised.Raised) + } + + // The gate on the control node, for a build sent after the fault began. + open2, err := k.Open(ctx) + if err != nil { + t.Fatal(err) + } + f := gateFacts{judged: true, open: open2} + if w := aboutTheMachine("anchor", []string{"mesh-host"}, sent, f); w.whole != "" || len(w.on) != 0 { + t.Fatalf("a fault from before the send held the build: %+v", w) + } + + // Decided healthy: cleared. + say(h0.Add(3*time.Minute), networkSaying(link.NetworkPart{Part: link.PartNames, State: link.StateHealthy, Since: h0})) + if c, ok := network(); ok { + t.Fatalf("a statement that decides the names healthy left %s open", c.Key) + } +} + +// A reopening is the same fault: it began when it was first raised, and the gate reads when it began. The +// controller that cleared it on an undecided statement — or any clearing and raising within ReopenWithin — +// no longer makes a fault from before a send into one raised since it. +func TestAReopenedFaultFromBeforeTheSendIsNotRaisedSinceIt(t *testing.T) { + since := h0 + c := conditions.Condition{Key: "machine.anchor.network", Kind: kindMachineNetwork, + Subject: conditions.Subject{Scope: conditions.ScopeMachine, ID: "anchor", Machine: "anchor"}, + Summary: "anchor's network is not healthy", Source: sourceNetwork, Count: 2, + First: since.Add(-time.Minute), Raised: since.Add(time.Minute)} + f := gateFacts{judged: true, open: []conditions.Condition{c}} + if w := aboutTheMachine("anchor", []string{"mesh-controller"}, since, f); w.whole != "" || len(w.on) != 0 { + t.Fatalf("a fault reopened after the send, first raised before it, held the machine: %+v", w) + } + // The same raised first after the send is the send's to answer for. + c.First = since.Add(30 * time.Second) + f.open = []conditions.Condition{c} + if w := aboutTheMachine("anchor", []string{"mesh-controller"}, since, f); w.whole == "" { + t.Fatalf("a fault that began after the send held nothing: %+v", w) + } + // And a module's own: judgeHealth reads it the same way. + at := since.Add(2 * time.Minute) + g := gateFacts{judged: true, now: at, reports: map[string]inventory.Reported{"anchor": {Node: "anchor", + Outcome: inventory.OutcomeApplied, At: &at, Current: true}}, engines: map[string]string{}, + served: map[string]served{}, rolledBack: map[string][]lease.Rollback{}, + open: []conditions.Condition{{Key: "provider.app.anchor.x.failing", Subject: conditions.Subject{ + Scope: conditions.ScopeProvider, ID: "app.anchor.x", Machine: "anchor"}, Summary: "failing", + First: since.Add(-time.Hour), Raised: since.Add(time.Minute)}}} + if h, why := judgeHealth("app", "", catalogue.Manifest{Module: "app"}, "anchor", since, g); strings.HasPrefix(why, "raised since it was sent") { + t.Fatalf("a module's own fault, reopened after its send and first raised before it: %v (%s)", h, why) + } + g.open[0].First = time.Time{} + if _, why := judgeHealth("app", "", catalogue.Manifest{Module: "app"}, "anchor", since, g); !strings.HasPrefix(why, "raised since it was sent") { + t.Fatalf("a module's own fault raised after its send was not counted: %s", why) + } +} + +// An undecided statement — unknown or starting — keeps the machine's network conditions; a decided one +// does not. Pure. +func TestAnUndecidedStatementKeepsTheMachinesNetworkConditions(t *testing.T) { + f := netFacts(map[string]*inventory.NetworkHealth{ + "anchor": aNetwork(link.StateUnknown, inventory.NetworkPart{Part: link.PartNames, State: link.StateUnknown, Streak: 1}), + "laptop": aNetwork(link.StateHealthy, inventory.NetworkPart{Part: link.PartNames, State: link.StateHealthy}), + "spare": aNetwork(link.StateUnhealthy, noRoute), + }) + got := undecidedMachines(f) + if !got["anchor"] || got["laptop"] || got["spare"] || len(got) != 1 { + t.Fatalf("undecided: %v", got) + } +} + +// A release walks its modules without a record per module: D10 counts what its tier names as rolling, +// so the node-engine a release walks is not "behind, and no plan is rolling it out" on its first machine. +func TestAReleaseRollsOutWhatItsTierNames(t *testing.T) { + plans := []inventory.Plan{ + {ID: "release-1", State: inventory.PlanRolling, Tiers: [][]string{{"mesh-host"}}, Modules: map[string]*inventory.PlanModule{}}, + {ID: "plan-2", State: inventory.PlanRolling, Modules: map[string]*inventory.PlanModule{"letta": {}}}, + } + got := rollingModules(plans) + if !got["mesh-host"] || !got["letta"] || len(got) != 2 { + t.Fatalf("rolling: %v", got) + } +} + +// A resolver that refuses every try — nothing listens on its port — is said at once, not held for the +// next run five minutes later: a refusal is the machine's answer, not a loaded resolver (issue 277). +func TestAResolverThatRefusesEveryTryIsSaidAtOnce(t *testing.T) { + conn, err := net.ListenPacket("udp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + _, port, _ := net.SplitHostPort(conn.LocalAddr().String()) + _ = conn.Close() // nothing listens there now: every question is refused + quickResolvers(t, port) + got := askEveryResolver(t.Context(), map[string]string{"anchor.internal": "127.0.0.1"}, anchorOnTheNetwork, "internal") + if len(got) != 1 { + t.Fatalf("%+v", got) + } + if got[0].Confirm || !strings.Contains(got[0].Said, "refused") { + t.Fatalf("a resolver refusing every try was held for the next run: %+v", got[0]) + } +} + +func TestOnlyARefusalOnEveryTryIsAllRefused(t *testing.T) { + refused := &net.OpError{Op: "read", Net: "udp", Err: os.NewSyscallError("read", syscall.ECONNREFUSED)} + if !(resolverAsked{errs: []error{refused, refused}}).allRefused() { + t.Fatal("refused on every try is not all refused") + } + if (resolverAsked{errs: []error{refused, errors.New("i/o timeout")}}).allRefused() { + t.Fatal("a timeout among the tries is all refused") + } + if (resolverAsked{answered: true, errs: []error{refused}}).allRefused() || (resolverAsked{}).allRefused() { + t.Fatal("an answered question, or one never asked, is all refused") + } +} diff --git a/cmd/mesh-controller/machine_network.go b/cmd/mesh-controller/machine_network.go index 8fe0ce18..fcb081cf 100644 --- a/cmd/mesh-controller/machine_network.go +++ b/cmd/mesh-controller/machine_network.go @@ -98,8 +98,9 @@ func judgeNetworks(ctx context.Context, inv *inventory.Inventory, k *conditions. problems = append(problems, err.Error()) } } + undecided := undecidedMachines(f) for _, c := range open { - if !slices.Contains(networkKinds, c.Kind) || said[c.Key] { + if !slices.Contains(networkKinds, c.Kind) || said[c.Key] || undecided[c.Subject.Machine] { continue } why := "no machine says it any more" @@ -116,6 +117,36 @@ func judgeNetworks(ctx context.Context, inv *inventory.Inventory, k *conditions. return nil } +// undecidedMachines is every machine whose newest statement has a part not yet judged: starting, or +// unknown — one look failed and a second decides (novox/hq issue 348). Such a statement does not say a +// fault is gone, so an open network condition about that machine is kept until a statement decides. +// +// On 2026-10-09 the control node's resolver refused every question from 10:58 to 11:18 UTC. A build of +// the node-engine sent at 10:59:34 restarted it; its first statement after the restart judged the names +// once (unknown, "one look failed; a second decides"), and that statement cleared the control node's +// network condition while its last evidence still said "connection refused". The second look raised it +// again forty seconds later — after the send — and the gate failed the build for a fault from before it. +// Pure. +func undecidedMachines(f networkFacts) map[string]bool { + out := map[string]bool{} + for m, h := range f.healths { + if h.Network == nil { + continue + } + if h.Network.State == link.StateUnknown || h.Network.State == link.StateStarting { + out[m] = true + continue + } + for _, p := range h.Network.Parts { + if p.State == link.StateUnknown || p.State == link.StateStarting { + out[m] = true + break + } + } + } + return out +} + // pointed is one machine's failing part that points at another machine. type pointed struct { from string diff --git a/cmd/mesh-controller/probes.go b/cmd/mesh-controller/probes.go index 6e034d07..f236a0ac 100644 --- a/cmd/mesh-controller/probes.go +++ b/cmd/mesh-controller/probes.go @@ -11,6 +11,7 @@ import ( "sort" "strings" "sync" + "syscall" "time" "github.com/nats-io/nats.go" @@ -216,6 +217,8 @@ func askEveryResolver(ctx context.Context, resolvers map[string]string, places [ type verdict struct { wrong, unanswered, said []string asked int + // refused says every try of every unanswered question was refused (nothing listens there). + refused bool } byHolder := map[string]*verdict{} for _, q := range questions { @@ -232,6 +235,7 @@ func askEveryResolver(ctx context.Context, resolvers map[string]string, places [ v.wrong = append(v.wrong, words) v.said = append(v.said, said) default: + v.refused = (len(v.unanswered) == 0 || v.refused) && q.asked.allRefused() v.unanswered = append(v.unanswered, words) v.said = append(v.said, said) } @@ -251,8 +255,11 @@ func askEveryResolver(ctx context.Context, resolvers map[string]string, places [ o.Summary = fmt.Sprintf("the mesh's resolver on %s does not answer machine names as it must: %s%s", node, v.wrong[0], andMore(len(v.wrong)-1)) } else { - // Nothing but silence: held for the next run, which raises it if the resolver is still silent. - o.Confirm = true + // Nothing but silence: held for the next run, which raises it if the resolver is still silent — + // unless every try of every question was refused. A refusal is an answer from the machine: + // nothing listens there. It is not a loaded resolver slow to answer (issue 277), and holding it + // for the next run cost the control node's resolver five minutes on 2026-10-09 (issue 348). + o.Confirm = !v.refused o.Summary = fmt.Sprintf("the mesh's resolver on %s does not answer: %d of the %d question(s) about the "+ "machines' names went unanswered, each asked %d times — the first, %s", node, len(v.unanswered), v.asked, resolverTries, v.unanswered[0]) @@ -341,6 +348,19 @@ type resolverAsked struct { errs []error } +// allRefused says every try was refused: the resolver's machine said nothing listens on its port. +func (a resolverAsked) allRefused() bool { + if a.answered || len(a.errs) == 0 { + return false + } + for _, err := range a.errs { + if !errors.Is(err, syscall.ECONNREFUSED) { + return false + } + } + return true +} + // askResolverPatiently asks one question until it is answered as right says, at most resolverTries // times. A wrong answer is asked again too — a resolver restarting may say NXDOMAIN for a moment — and // stands if no try answers rightly. @@ -1040,12 +1060,7 @@ func probeCoreBuilds(ctx context.Context, d *doctor) ([]conditions.Observation, return nil, err } hostVersions := deliveredVersions(shelf[hostModule]) - rolling := map[string]bool{} - for _, p := range plans { - for m := range p.Modules { - rolling[m] = true - } - } + rolling := rollingModules(plans) nodes, err := inv.Nodes(ctx) if err != nil { return nil, err @@ -1103,6 +1118,26 @@ func probeCoreBuilds(ctx context.Context, d *doctor) ([]conditions.Observation, return out, nil } +// rollingModules is every module an open plan is rolling out: those it keeps a record of, and those its +// tiers name. **A release keeps no record per module** — its walk is per machine, its modules only in its +// tier — so reading the records alone, D10 said "no plan is rolling them out" about the node-engine while +// a release walked it, and the gate on that release's first machine waited on what its own send causes +// (novox/hq issue 348). Pure. +func rollingModules(plans []inventory.Plan) map[string]bool { + rolling := map[string]bool{} + for _, p := range plans { + for m := range p.Modules { + rolling[m] = true + } + for _, tier := range p.Tiers { + for _, m := range tier { + rolling[m] = true + } + } + } + return rolling +} + // deliveredVersions are the versions a module's registered build is delivered as: the last element // of every resource path under a `versions/` directory, which registration filled from the artifact's // digest (catalogue `${version}`). The node-engine names itself by that directory. diff --git a/internal/conditions/condition.go b/internal/conditions/condition.go index cc253a6a..ce408349 100644 --- a/internal/conditions/condition.go +++ b/internal/conditions/condition.go @@ -145,6 +145,11 @@ type Condition struct { // Raised is when it was first observed this time; LastObserved the newest observation. Raised time.Time `json:"raised"` LastObserved time.Time `json:"last-observed"` + // First is when this fault was first raised, a reopening within ReopenWithin counted as the same + // fault: Raised of the first raising. Absent on one written before it was kept, and on a first + // raising, where it is Raised (Began). A reopening is the same fault, so what asks when a fault began + // — the gate, asking whether it began after a send — reads Began, never Raised (novox/hq issue 348). + First time.Time `json:"first,omitzero"` // 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. @@ -274,3 +279,14 @@ func Order(list []Condition) { return list[i].Key < list[j].Key }) } + +// Began is when this fault began as the mesh knows it: its first raising, a reopening within +// ReopenWithin being the same fault again (novox/hq issue 348). A condition that cleared on a statement +// that judged nothing yet — a node-engine just restarted — and was raised again a minute later began +// when it was first raised, not at the reopening. +func (c Condition) Began() time.Time { + if !c.First.IsZero() && c.First.Before(c.Raised) { + return c.First + } + return c.Raised +} diff --git a/internal/conditions/store.go b/internal/conditions/store.go index cf016f4a..f4935d7d 100644 --- a/internal/conditions/store.go +++ b/internal/conditions/store.go @@ -77,8 +77,10 @@ type Keeper struct { } type clearing struct { - at time.Time - count int + at time.Time + count int + // began is when the fault that cleared began, so its reopening keeps it (Condition.Began). + began time.Time silenced *Silence // tried is what healers tried before it cleared: a reopening is the same fault, and what was // tried on it is still what was tried. @@ -120,8 +122,8 @@ func NewKeeper(ctx context.Context, o Options) *Keeper { 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, - tried: e.Condition.Tried} + k.cleared[e.Key] = clearing{at: e.At, count: e.Condition.Count, began: e.Condition.Began(), + silenced: e.Condition.Silenced, tried: e.Condition.Tried} } } } else { @@ -197,6 +199,9 @@ func (k *Keeper) Observe(ctx context.Context, o Observation) (Condition, error) k.mu.Lock() if before, ok := k.cleared[key]; ok && now.Sub(before.at) <= ReopenWithin { c.Count, change = before.count+1, ChangeReopened + if !before.began.IsZero() && before.began.Before(now) { + c.First = before.began + } // 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) { @@ -313,7 +318,7 @@ func (k *Keeper) ClearSaying(ctx context.Context, key, why, resolved string) (bo } now := k.now().UTC() k.mu.Lock() - k.cleared[key] = clearing{at: now, count: c.Count, silenced: c.Silenced, tried: c.Tried} + k.cleared[key] = clearing{at: now, count: c.Count, began: c.Began(), silenced: c.Silenced, tried: c.Tried} k.mu.Unlock() k.tell(Event{Condition: c, At: now, Change: ChangeCleared, Why: why, Cleared: &now}) return true, nil diff --git a/internal/conditions/store_test.go b/internal/conditions/store_test.go index 91d1fbba..ab2fe986 100644 --- a/internal/conditions/store_test.go +++ b/internal/conditions/store_test.go @@ -378,3 +378,56 @@ func TestATransitionIsOfferedAgainWhileTheBusIsAway(t *testing.T) { t.Fatalf("said %+v, unsaid %d", said, k.Unsaid()) } } + +// **A reopening keeps when the fault began** (novox/hq issue 348): Raised is the reopening, Began the +// first raising — also from a keeper that read what cleared from the history — and past the window a +// raising is a new fault that begins then. +func TestAReopeningKeepsWhenTheFaultBegan(t *testing.T) { + k, store, told, c := keeper(t) + ctx := t.Context() + first, err := k.Observe(ctx, silent("ace")) + if err != nil { + t.Fatal(err) + } + if !first.Began().Equal(first.Raised) || !first.First.IsZero() { + t.Fatalf("a first raising began at %s, raised %s, first %s", first.Began(), first.Raised, first.First) + } + if _, err := k.Clear(ctx, "machine.ace.silent", "heard again"); err != nil { + t.Fatal(err) + } + c.pass(time.Minute) + again, err := k.Observe(ctx, silent("ace")) + if err != nil { + t.Fatal(err) + } + if !again.Raised.After(first.Raised) || !again.Began().Equal(first.Raised) { + t.Fatalf("reopened: raised %s, began %s; first raised %s", again.Raised, again.Began(), first.Raised) + } + // Through a restarted controller, reading the clearing from the history. + if _, err := k.Clear(ctx, "machine.ace.silent", "heard again"); err != nil { + t.Fatal(err) + } + settled(t, told, 4) + 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.Began().Equal(first.Raised) { + t.Fatalf("after a restart the reopening began at %s, not %s", third.Began(), first.Raised) + } + 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.Began().Equal(fourth.Raised) { + t.Fatalf("past the window the fault began at %s, raised %s", fourth.Began(), fourth.Raised) + } +} From 997a4925b04d2ef6e2f4122e4470ec2424dcf7e6 Mon Sep 17 00:00:00 2001 From: jochen Date: Fri, 9 Oct 2026 14:04:39 +0200 Subject: [PATCH 2/5] Order a branch's plans by its merges, and build the newest commit (hq issue 349) A merge acted on late by the catch-up made its plan after the plan of the merge that followed it, superseded it by creation time, and folded its unbuilt modules into a plan at the older commit: on 2026-10-09 the forge's security fix (a082615b) was superseded by 8ff8197a. A plan now keeps its merge time (migration 0086), supersession follows it, and a merge older than an open plan of its branch is planned at that plan's commit, which contains it. --- cmd/mesh-controller/issue349_test.go | 93 +++++++++++++++++++ cmd/mesh-controller/release_plan.go | 45 ++++++++- cmd/mesh-controller/upgrades.go | 14 +++ ...6-a-plan-keeps-when-its-merge-was-made.sql | 10 ++ internal/inventory/plans.go | 30 ++++-- 5 files changed, 184 insertions(+), 8 deletions(-) create mode 100644 cmd/mesh-controller/issue349_test.go create mode 100644 internal/inventory/migrations/0086-a-plan-keeps-when-its-merge-was-made.sql diff --git a/cmd/mesh-controller/issue349_test.go b/cmd/mesh-controller/issue349_test.go new file mode 100644 index 00000000..ff2d3ba7 --- /dev/null +++ b/cmd/mesh-controller/issue349_test.go @@ -0,0 +1,93 @@ +package main + +import ( + "strings" + "testing" + "time" + + "github.com/novox/mesh-controller/internal/catalogue" + "github.com/novox/mesh-controller/internal/inventory" + "github.com/novox/mesh-controller/internal/link" +) + +// novox/hq issue 349: on 2026-10-09 the plan of mesh-catalog at a082615b (the merge of a security fix to the +// forge's module) was "superseded at tier 0 by" the plan at 8ff8197a, the merge before it, which the +// catch-up acted on late; what the later plan had not built was folded into a plan at the commit before the +// fix. Plans of one branch are ordered by when the forge made their merges, and a merge older than an open +// plan of its branch is planned at that plan's commit. + +// TestTwoMergesActedOnInReverseOrderBuildTheNewerCommit replays it: the later merge acted on first, the +// earlier one second (the catch-up). One plan is left open, at the later commit, and it builds both. +func TestTwoMergesActedOnInReverseOrderBuildTheNewerCommit(t *testing.T) { + open := aCatalogueMesh(t) + ctx := t.Context() + asksWithPaths(t) + for _, m := range []string{"gitea", "notes"} { + if err := open.inventory.RegisterModule(ctx, catalogue.Manifest{Module: m, Version: "1"}, + inventory.Source{Repository: "novox/mesh-catalog", Seat: "git", Path: "modules/" + m, Ref: "main", + BuiltFrom: "c0", Head: "c0"}); err != nil { + t.Fatal(err) + } + } + at := time.Now().UTC().Add(-20 * time.Minute).Truncate(time.Second) + fix := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "a082615bfix", + MergedAt: at.Add(2 * time.Minute).Format(time.RFC3339), + Paths: []string{"modules/gitea/module.json"}, ModuleDirs: []string{"modules/gitea"}, ModuleDirsSaid: true} + before := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "8ff8197abefore", + MergedAt: at.Format(time.RFC3339), + Paths: []string{"modules/notes/module.json"}, ModuleDirs: []string{"modules/notes"}, ModuleDirsSaid: true} + for _, m := range []link.SourceMoved{fix, before} { + if err := (following{open: open}).SourceMoved(ctx, m); err != nil { + t.Fatal(err) + } + } + plans, err := open.inventory.OpenPlans(ctx) + if err != nil { + t.Fatal(err) + } + if len(plans) != 1 { + var said []string + for _, p := range plans { + said = append(said, p.ID+" "+p.Commit+" "+p.Note) + } + t.Fatalf("open plans: %s", strings.Join(said, "; ")) + } + p := plans[0] + if p.Commit != fix.Commit { + t.Fatalf("the open plan builds %s, not the newer commit %s", p.Commit, fix.Commit) + } + for _, m := range []string{"gitea", "notes"} { + if _, has := p.Modules[m]; !has { + t.Fatalf("the open plan at the newer commit does not build %s: %v", m, p.Modules) + } + } +} + +// Pure: the branch's order is the merges', where both plans know it; and a merge older than an open plan +// of its branch finds it. +func TestTheBranchOrderIsTheMerges(t *testing.T) { + t0 := time.Date(2026, 10, 9, 10, 0, 0, 0, time.UTC) + newerMerge := inventory.Plan{ID: "plan-1", Repository: "novox/mesh-catalog", Branch: "main", Commit: "a082615b", + Merged: t0.Add(time.Minute), Created: t0.Add(2 * time.Minute), State: inventory.PlanRolling} + olderMerge := inventory.Plan{ID: "plan-2", Repository: "novox/mesh-catalog", Branch: "main", Commit: "8ff8197a", + Merged: t0, Created: t0.Add(10 * time.Minute), State: inventory.PlanBuilding} + if earlierOnTheBranch(newerMerge, olderMerge) || !earlierOnTheBranch(olderMerge, newerMerge) { + t.Fatal("ordered by when the plans were made, not by when the merges were") + } + if _, closed := supersededBy(olderMerge, []inventory.Plan{newerMerge}, func(string) bool { return true }); len(closed) != 0 { + t.Fatalf("the plan of an older merge superseded a newer one: %s", closed[0].Note) + } + unknown := newerMerge + unknown.Merged = time.Time{} + if !earlierOnTheBranch(unknown, olderMerge) { + t.Fatal("without a merge time the plans' own order does not stand") + } + m := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "8ff8197a", MergedAt: t0.Format(time.RFC3339)} + if p, ok := newestOnTheBranch(m, []inventory.Plan{newerMerge}); !ok || p.ID != "plan-1" { + t.Fatalf("the newer open plan of the branch was not found: %v %+v", ok, p) + } + m.Base = "release" + if _, ok := newestOnTheBranch(m, []inventory.Plan{newerMerge}); ok { + t.Fatal("another branch's plan was taken") + } +} diff --git a/cmd/mesh-controller/release_plan.go b/cmd/mesh-controller/release_plan.go index b2bd68e7..ae66a31b 100644 --- a/cmd/mesh-controller/release_plan.go +++ b/cmd/mesh-controller/release_plan.go @@ -188,11 +188,13 @@ func planOfMerge(m link.SourceMoved, moved []string, edges []inventory.Edge) inv for _, name := range set { modules[name] = &inventory.PlanModule{} } + merged, _ := time.Parse(time.RFC3339, m.MergedAt) return inventory.Plan{ ID: fmt.Sprintf("plan-%d", time.Now().UnixNano()), Repository: m.Owner + "/" + m.Repo, Branch: m.Base, Commit: m.Commit, + Merged: merged.UTC(), Created: time.Now().UTC(), State: inventory.PlanBuilding, Tiers: tiers, @@ -220,12 +222,20 @@ func planOfMerge(m link.SourceMoved, moved []string, edges []inventory.Edge) inv // // A plan with no branch recorded is from before branches were kept, and is superseded by the next // plan of its repository: what it had not built is folded in, so nothing is lost by it. +// +// **Newer is the branch's order, not the plans'** (novox/hq issue 349). A merge the bus did not hand +// over is acted on late, by the catch-up, so its plan is made after the plan of a merge that came after +// it — and that later-made plan of the earlier commit superseded the later merge's, and built what it +// folded in from the commit before the later merge: twice on 2026-10-09, once a security fix. So where +// both plans know when their merge was made, that decides; only where one does not do the plans' own +// times. A merge older than an open plan of its branch never reaches here at its own commit: it is +// planned at the newest open plan's commit, which contains it (newestOnTheBranch). func supersededBy(newer inventory.Plan, open []inventory.Plan, rollsOut func(string) bool) ([]string, []inventory.Plan) { folded := map[string]bool{} var closed []inventory.Plan for _, old := range open { if old.ID == newer.ID || !old.Open() || !strings.EqualFold(old.Repository, newer.Repository) || - (old.Branch != "" && old.Branch != newer.Branch) || !old.Created.Before(newer.Created) { + (old.Branch != "" && old.Branch != newer.Branch) || !earlierOnTheBranch(old, newer) { continue } var took []string @@ -254,6 +264,39 @@ func supersededBy(newer inventory.Plan, open []inventory.Plan, rollsOut func(str return out, closed } +// earlierOnTheBranch says plan a answers a merge made before b's: by when the forge made each merge where +// both are known, else by when each plan was made. A merge's own plan made again at the same commit +// (the same merge time) is ordered by when it was made. Pure. +func earlierOnTheBranch(a, b inventory.Plan) bool { + if !a.Merged.IsZero() && !b.Merged.IsZero() && !a.Merged.Equal(b.Merged) { + return a.Merged.Before(b.Merged) + } + return a.Created.Before(b.Created) +} + +// newestOnTheBranch is the open plan of m's repository and branch whose merge was made after m's, the +// newest of them; false when none was. Merges into one branch are made one on the other, so that plan's +// commit contains m's change: m is planned there, and the newest commit of the branch is what is built +// (novox/hq issue 349). Pure. +func newestOnTheBranch(m link.SourceMoved, open []inventory.Plan) (inventory.Plan, bool) { + merged, err := time.Parse(time.RFC3339, m.MergedAt) + if err != nil { + return inventory.Plan{}, false + } + var newest inventory.Plan + found := false + for _, p := range open { + if !p.Open() || p.Release != nil || p.Merged.IsZero() || !strings.EqualFold(p.Repository, m.Owner+"/"+m.Repo) || + p.Branch != m.Base || !p.Merged.After(merged) { + continue + } + if !found || p.Merged.After(newest.Merged) { + newest, found = p, true + } + } + return newest, found +} + // gates is what the next tier needs running from this one: a module of the tier that a later // tier is built by — the runtime dependency — and whose policy rolls it out, must be applied by // the machines running it before the next tier is asked. A base an image stands on need only be diff --git a/cmd/mesh-controller/upgrades.go b/cmd/mesh-controller/upgrades.go index 86b08215..5a639aa1 100644 --- a/cmd/mesh-controller/upgrades.go +++ b/cmd/mesh-controller/upgrades.go @@ -345,6 +345,20 @@ func (f following) SourceMoved(ctx context.Context, m link.SourceMoved) error { e.Manifest.Module, m.Owner, m.Repo, e.Source.Ref, m.Base) } } + // **A merge older than an open plan of its branch is planned at that plan's commit** (novox/hq issue + // 349): the catch-up acts on a merge the bus did not hand over after the merges that came after it, + // and planned at its own commit it built what the later merge had fixed from the commit before the fix. + // The later commit contains this merge's change, so what this merge moved is built from there, and the + // plan made here supersedes that one as any newer plan does. + if open, err := inv.OpenPlans(ctx); err == nil { + if newest, later := newestOnTheBranch(m, open); later { + fmt.Printf(" %s/%s %.8s was merged before %.8s, which %s is planning: what it moved is built "+ + "from %.8s, which contains it\n", m.Owner, m.Repo, m.Commit, newest.Commit, newest.ID, newest.Commit) + m.Commit, m.MergedAt = newest.Commit, newest.Merged.Format(time.RFC3339) + } + } else { + return notNow(err) + } touched, added, _ := touchedBy(from, entries, m) // **A module the merge deleted is not built** (novox/hq ADR 0236): its manifest is gone, so the build // seat finds nothing saying what it is, and the plan failed on it (`has no module.json at …`) with diff --git a/internal/inventory/migrations/0086-a-plan-keeps-when-its-merge-was-made.sql b/internal/inventory/migrations/0086-a-plan-keeps-when-its-merge-was-made.sql new file mode 100644 index 00000000..de593714 --- /dev/null +++ b/internal/inventory/migrations/0086-a-plan-keeps-when-its-merge-was-made.sql @@ -0,0 +1,10 @@ +-- A plan keeps when the forge made the merge it answers (novox/hq issue 349). +-- +-- A newer plan of a repository's branch supersedes the older open ones, and "newer" was read from when each +-- plan was made. A merge the bus did not hand over is acted on late, by the catch-up, so its plan is made +-- after the plan of a merge that came after it — and superseded it, folding its unbuilt modules into a plan +-- at the older commit. On 2026-10-09 a security fix to the forge's module would have been built from the +-- commit before it. Merges into one branch are made one after another, each on the one before, so the +-- forge's merge time is the branch's order. Null for a plan kept before this column, and for a plan no merge +-- made (a release); then the plans' own order stands, as before. +alter table release_plan add column merged_at timestamptz; diff --git a/internal/inventory/plans.go b/internal/inventory/plans.go index 00842dd4..348cf15d 100644 --- a/internal/inventory/plans.go +++ b/internal/inventory/plans.go @@ -19,8 +19,12 @@ type Plan struct { Repository string `json:"repository"` // Branch is the branch the merge went into (novox/hq issue 254): a newer plan supersedes the open // ones of the same repository and branch. Empty for a plan from before it was kept. - Branch string `json:"branch,omitempty"` - Commit string `json:"commit"` + Branch string `json:"branch,omitempty"` + Commit string `json:"commit"` + // Merged is when the forge made the merge this plan answers (novox/hq issue 349): the order of a + // branch's merges, which is not the order their plans were made in when one was acted on late. Zero + // for a release, and for a plan kept before it was. + Merged time.Time `json:"merged,omitzero"` Created time.Time `json:"created"` Updated time.Time `json:"updated"` State string `json:"state"` @@ -249,8 +253,8 @@ func (i *Inventory) SavePlan(ctx context.Context, p *Plan) error { var revision int64 err = tx.QueryRow(ctx, `insert into release_plan (id, repository, commit_hash, created, updated, state, tier, tiers, modules, note, - branch, tier_entered, revision, epoch, release, delivery) - values ($1, $2, $3, $4, now(), $5, $6, $7, $8, $9, $10, $11, 1, $13, $14, $15) + branch, tier_entered, revision, epoch, release, delivery, merged_at) + values ($1, $2, $3, $4, now(), $5, $6, $7, $8, $9, $10, $11, 1, $13, $14, $15, $16) on conflict (id) do update set updated = now(), state = excluded.state, tier = excluded.tier, tiers = excluded.tiers, modules = excluded.modules, note = excluded.note, branch = excluded.branch, tier_entered = excluded.tier_entered, revision = release_plan.revision + 1, epoch = excluded.epoch, @@ -258,7 +262,7 @@ func (i *Inventory) SavePlan(ctx context.Context, p *Plan) error { where release_plan.revision = $12 returning revision`, p.ID, p.Repository, p.Commit, p.Created, p.State, p.Tier, tiers, modules, p.Note, p.Branch, entered, - p.Revision, epoch, release, delivery).Scan(&revision) + p.Revision, epoch, release, delivery, mergedAt(p.Merged)).Scan(&revision) if errors.Is(err, pgx.ErrNoRows) { // The row is there and at another revision — moved since this was read, or there already // when this one is new: either way not this writer's to overwrite. (A plan saved before plans @@ -291,6 +295,14 @@ func short(commit string) string { return commit } +// mergedAt is a plan's merge time as the store keeps it: null when not known. +func mergedAt(t time.Time) *time.Time { + if t.IsZero() { + return nil + } + return &t +} + // OpenPlans is every plan still being worked, oldest first. func (i *Inventory) OpenPlans(ctx context.Context) ([]Plan, error) { return i.plans(ctx, `where state in ('building', 'rolling') order by created`) @@ -316,7 +328,7 @@ 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, - coalesce(tier_entered, created), revision, coalesce(epoch, 0), release, delivery + coalesce(tier_entered, created), revision, coalesce(epoch, 0), release, delivery, merged_at from release_plan `+tail) if err != nil { return nil, err @@ -327,11 +339,15 @@ func (i *Inventory) plans(ctx context.Context, tail string) ([]Plan, error) { var p Plan var tiers, modules, release, delivery []byte var epoch int64 + var merged *time.Time if err := rows.Scan(&p.ID, &p.Repository, &p.Commit, &p.Created, &p.Updated, &p.State, &p.Tier, &tiers, &modules, &p.Note, &p.Branch, &p.TierEntered, &p.Revision, &epoch, &release, - &delivery); err != nil { + &delivery, &merged); err != nil { return nil, err } + if merged != nil { + p.Merged = merged.UTC() + } if len(release) > 0 { if err := json.Unmarshal(release, &p.Release); err != nil { return nil, err From 63b87b6f7bc649d329fd103dcaa7b4e7c681cb46 Mon Sep 17 00:00:00 2001 From: jochen Date: Fri, 9 Oct 2026 14:07:16 +0200 Subject: [PATCH 3/5] Hold the resolver to bind-interfaces, as mesh-catalog PR 161 makes it (hq issue 348) --- internal/catalogue/resolver_manifests_test.go | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/internal/catalogue/resolver_manifests_test.go b/internal/catalogue/resolver_manifests_test.go index 32415c6a..8825615c 100644 --- a/internal/catalogue/resolver_manifests_test.go +++ b/internal/catalogue/resolver_manifests_test.go @@ -51,7 +51,10 @@ func TestTheResolverForwardsToFixedUpstreamsAndNeverReadsResolvConf(t *testing.T "\nno-resolv\n", "\nserver=1.1.1.1\n", "\nserver=8.8.8.8\n", // The private address and loopback, never a LAN's (novox/hq ADR 0194): a device that is not a // member cannot reach what the mesh's names point at. - "\nlisten-address=127.0.0.1\n", "\nlisten-address=${machine:address}\n", "\nbind-dynamic\n", + "\nlisten-address=127.0.0.1\n", "\nlisten-address=${machine:address}\n", + // Each address bound once, at start, never closed (novox/hq issue 348, with mesh-catalog PR 161): + // bind-dynamic closed the private address's listener when a bridge teardown failed its re-read. + "\nbind-interfaces\n", // No hosts file and no operator's files: the mesh's resolver answers every node (ADR 0199). "\nno-hosts\n", "\nconf-file=" + m.Facts["zones"].Path + "\n", @@ -62,6 +65,9 @@ func TestTheResolverForwardsToFixedUpstreamsAndNeverReadsResolvConf(t *testing.T t.Errorf("the resolver's configuration lacks %q:\n%s", strings.TrimSpace(want), config) } } + if strings.Contains(config, "\nbind-dynamic\n") { + t.Error("the resolver binds dynamically, and closes a listener whenever a re-read of the addresses fails (issue 348)") + } // By address and never by interface: dnsmasq admits a query by the interface it arrives on // when told one, and a container's query to the private address arrives on the runtime's // bridge — `interface=mesh0` dropped every such query, silently (novox/hq issue 110). From c3c56a69e25485839cfb65b5a8859d082c9236e1 Mon Sep 17 00:00:00 2001 From: jochen Date: Fri, 9 Oct 2026 14:22:11 +0200 Subject: [PATCH 4/5] Take either binding until the catalogue's main binds once (hq issue 348) The test reads the catalogue beside it, which the build seat checks out at main; mesh-catalog PR 161 changes the binding, so the two land in either order. --- internal/catalogue/resolver_manifests_test.go | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/internal/catalogue/resolver_manifests_test.go b/internal/catalogue/resolver_manifests_test.go index 8825615c..8ea3e32b 100644 --- a/internal/catalogue/resolver_manifests_test.go +++ b/internal/catalogue/resolver_manifests_test.go @@ -52,9 +52,7 @@ func TestTheResolverForwardsToFixedUpstreamsAndNeverReadsResolvConf(t *testing.T // The private address and loopback, never a LAN's (novox/hq ADR 0194): a device that is not a // member cannot reach what the mesh's names point at. "\nlisten-address=127.0.0.1\n", "\nlisten-address=${machine:address}\n", - // Each address bound once, at start, never closed (novox/hq issue 348, with mesh-catalog PR 161): - // bind-dynamic closed the private address's listener when a bridge teardown failed its re-read. - "\nbind-interfaces\n", + // No hosts file and no operator's files: the mesh's resolver answers every node (ADR 0199). "\nno-hosts\n", "\nconf-file=" + m.Facts["zones"].Path + "\n", @@ -65,8 +63,13 @@ func TestTheResolverForwardsToFixedUpstreamsAndNeverReadsResolvConf(t *testing.T t.Errorf("the resolver's configuration lacks %q:\n%s", strings.TrimSpace(want), config) } } - if strings.Contains(config, "\nbind-dynamic\n") { - t.Error("the resolver binds dynamically, and closes a listener whenever a re-read of the addresses fails (issue 348)") + // Bound to its addresses, one way or the other. mesh-catalog PR 161 (novox/hq issue 348) moves it from + // bind-dynamic, which closed the private address's listener when a bridge teardown failed its re-read + // of the machine's addresses, to bind-interfaces. This test reads the catalogue beside it, which may be + // on either side of that merge, so it takes both; once the catalogue's main has it, bind-dynamic is + // refused here. + if !strings.Contains(config, "\nbind-interfaces\n") && !strings.Contains(config, "\nbind-dynamic\n") { + t.Errorf("the resolver's configuration binds neither by bind-interfaces nor by bind-dynamic:\n%s", config) } // By address and never by interface: dnsmasq admits a query by the interface it arrives on // when told one, and a container's query to the private address arrives on the runtime's From 58cb586c37f8217972a64f323f0d315323870a6a Mon Sep 17 00:00:00 2001 From: jochen Date: Fri, 9 Oct 2026 14:58:23 +0200 Subject: [PATCH 5/5] Answer the review of hq issues 348 and 349: gaps, parts, the newest merge in any state - A reopened fault keeps its gaps: it was there at a send unless the send fell in one, so a send that breaks a machine recovered before it still fails its gate (A2). - An undecided part holds only the conditions that name it (A4). - D2 holds a silent resolver for the next run again, refused or not: a burst of refusals is also a restart (A3). - A late merge is planned at the newest planned merge of its branch in any state, not only an open one (A1); merge times to the nanosecond (A5). --- cmd/mesh-controller/gate.go | 9 +- cmd/mesh-controller/issue348_test.go | 145 +++++++++++++------------ cmd/mesh-controller/issue349_test.go | 100 +++++++++++++++-- cmd/mesh-controller/machine_network.go | 59 +++++++--- cmd/mesh-controller/probes.go | 28 +---- cmd/mesh-controller/release_plan.go | 37 +++---- cmd/mesh-controller/upgrades.go | 29 ++--- internal/conditions/condition.go | 51 ++++++++- internal/conditions/store.go | 12 +- internal/conditions/store_test.go | 40 ++++++- internal/inventory/plans.go | 16 ++- 11 files changed, 347 insertions(+), 179 deletions(-) diff --git a/cmd/mesh-controller/gate.go b/cmd/mesh-controller/gate.go index 7e3a8631..d2282170 100644 --- a/cmd/mesh-controller/gate.go +++ b/cmd/mesh-controller/gate.go @@ -209,8 +209,9 @@ func judgeHealth(module, component string, m catalogue.Manifest, machine string, return healthNotYet, fmt.Sprintf("%s reported %q", machine, r.Outcome) } // **No new condition about it**: about the machine itself, or naming the module on that machine, - // raised since the judging began. The gate's own are not evidence about the build. A fault reopened - // since, that began before the send, is not new (Began, novox/hq issue 348). + // raised since the judging began. The gate's own are not evidence about the build. A fault that was + // there at the send and reopened since is not new; one that had cleared before the send and came back + // after it is (OpenAt, novox/hq issue 348). if f.judged { if f.openErr != nil { return healthNotYet, "what is wrong cannot be read, so whether the build made anything wrong is not known: " + @@ -220,7 +221,7 @@ func judgeHealth(module, component string, m catalogue.Manifest, machine string, // A wait for a person's new login, or for a directory used as found to be handed over, is the module's // reading, not a fault raised since the send: the gate reads it from the statement below (ADR 0254, // novox/hq issue 339). - if c.Source == gateProbe || c.Began().Before(since) || c.Kind == kindReloginNeeded || c.Kind == kindUsedAsFound { + if c.Source == gateProbe || c.OpenAt(since) || c.Kind == kindReloginNeeded || c.Kind == kindUsedAsFound { continue } onIt := c.Subject.Machine == machine || slices.Contains(c.Subject.Also, machine) || @@ -332,7 +333,7 @@ func aboutTheMachine(machine string, moved []string, since time.Time, f gateFact aboutIt := c.Subject.Scope == conditions.ScopeMachine && (c.Subject.ID == machine || c.Subject.Machine == machine || slices.Contains(c.Subject.Also, machine)) // A directory used as found waits for a person, whatever the send did (novox/hq issue 339). - if !aboutIt || c.Source == gateProbe || c.Began().Before(since) || c.Kind == kindUsedAsFound { + if !aboutIt || c.Source == gateProbe || c.OpenAt(since) || c.Kind == kindUsedAsFound { kept = append(kept, c) continue } diff --git a/cmd/mesh-controller/issue348_test.go b/cmd/mesh-controller/issue348_test.go index 39275326..7c0bd4a7 100644 --- a/cmd/mesh-controller/issue348_test.go +++ b/cmd/mesh-controller/issue348_test.go @@ -1,11 +1,7 @@ package main import ( - "errors" - "net" - "os" "strings" - "syscall" "testing" "time" @@ -95,8 +91,8 @@ func TestReplay348(t *testing.T) { // 11:00:23 — its second look: unhealthy again, the same raising. say(h0.Add(2*time.Minute), networkSaying(namesRefused(link.StateUnhealthy, 2))) again, ok := network() - if !ok || !again.Began().Equal(raised.Raised) { - t.Fatalf("the same fault was said as one that began at %s (raised first at %s)", again.Began(), raised.Raised) + if !ok || !again.Raised.Equal(raised.Raised) || again.Count != 1 { + t.Fatalf("the same raising was not kept: raised %s (first %s), count %d", again.Raised, raised.Raised, again.Count) } // The gate on the control node, for a build sent after the fault began. @@ -116,53 +112,98 @@ func TestReplay348(t *testing.T) { } } -// A reopening is the same fault: it began when it was first raised, and the gate reads when it began. The -// controller that cleared it on an undecided statement — or any clearing and raising within ReopenWithin — -// no longer makes a fault from before a send into one raised since it. -func TestAReopenedFaultFromBeforeTheSendIsNotRaisedSinceIt(t *testing.T) { +// A fault there at the send, cleared and reopened after it, is not raised since the send; one that cleared +// before the send and came back after it is — a send that breaks a recovered machine fails its gate (review +// of mesh-controller PR 179, A2). Read through OpenAt, by both of the gate's readings. +func TestAFaultThatFlappedAfterTheSendIsNotTheSendsAndOneThatRecoveredBeforeItIs(t *testing.T) { since := h0 - c := conditions.Condition{Key: "machine.anchor.network", Kind: kindMachineNetwork, - Subject: conditions.Subject{Scope: conditions.ScopeMachine, ID: "anchor", Machine: "anchor"}, - Summary: "anchor's network is not healthy", Source: sourceNetwork, Count: 2, - First: since.Add(-time.Minute), Raised: since.Add(time.Minute)} - f := gateFacts{judged: true, open: []conditions.Condition{c}} - if w := aboutTheMachine("anchor", []string{"mesh-controller"}, since, f); w.whole != "" || len(w.on) != 0 { - t.Fatalf("a fault reopened after the send, first raised before it, held the machine: %+v", w) + network := func(first time.Time, gaps ...conditions.Gap) conditions.Condition { + raised := since.Add(time.Minute) + if len(gaps) > 0 { + raised = gaps[len(gaps)-1].Reopened + } + return conditions.Condition{Key: "machine.anchor.network", Kind: kindMachineNetwork, + Subject: conditions.Subject{Scope: conditions.ScopeMachine, ID: "anchor", Machine: "anchor"}, + Summary: "anchor's network is not healthy", Source: sourceNetwork, First: first, Gaps: gaps, Raised: raised} } - // The same raised first after the send is the send's to answer for. - c.First = since.Add(30 * time.Second) - f.open = []conditions.Condition{c} - if w := aboutTheMachine("anchor", []string{"mesh-controller"}, since, f); w.whole == "" { - t.Fatalf("a fault that began after the send held nothing: %+v", w) + held := func(c conditions.Condition) bool { + return aboutTheMachine("anchor", []string{"mesh-controller"}, since, gateFacts{judged: true, + open: []conditions.Condition{c}}).whole != "" } - // And a module's own: judgeHealth reads it the same way. + // The day's case: raised before the send, cleared 8 s after it, reopened 49 s after it. + flapped := network(since.Add(-49*time.Second), + conditions.Gap{Cleared: since.Add(8 * time.Second), Reopened: since.Add(49 * time.Second)}) + if held(flapped) { + t.Fatal("a fault there at the send, flapping after it, held the machine") + } + // Recovered before the send, broken again after it: the send's. + recovered := network(since.Add(-time.Hour), + conditions.Gap{Cleared: since.Add(-30 * time.Second), Reopened: since.Add(20 * time.Second)}) + if !held(recovered) { + t.Fatal("a machine recovered at the send and broken after it passed the gate") + } + // An older gap, before the send, and the fault there at the send: not the send's. + twice := network(since.Add(-time.Hour), + conditions.Gap{Cleared: since.Add(-50 * time.Minute), Reopened: since.Add(-45 * time.Minute)}, + conditions.Gap{Cleared: since.Add(10 * time.Second), Reopened: since.Add(30 * time.Second)}) + if held(twice) { + t.Fatal("a fault there at the send, with an older gap, held the machine") + } + // Raised after the send, never cleared: the send's. + if !held(network(time.Time{})) { + t.Fatal("a fault raised after the send held nothing") + } + // And a module's own, through judgeHealth. at := since.Add(2 * time.Minute) g := gateFacts{judged: true, now: at, reports: map[string]inventory.Reported{"anchor": {Node: "anchor", Outcome: inventory.OutcomeApplied, At: &at, Current: true}}, engines: map[string]string{}, served: map[string]served{}, rolledBack: map[string][]lease.Rollback{}, open: []conditions.Condition{{Key: "provider.app.anchor.x.failing", Subject: conditions.Subject{ Scope: conditions.ScopeProvider, ID: "app.anchor.x", Machine: "anchor"}, Summary: "failing", - First: since.Add(-time.Hour), Raised: since.Add(time.Minute)}}} - if h, why := judgeHealth("app", "", catalogue.Manifest{Module: "app"}, "anchor", since, g); strings.HasPrefix(why, "raised since it was sent") { - t.Fatalf("a module's own fault, reopened after its send and first raised before it: %v (%s)", h, why) + First: since.Add(-time.Hour), Raised: since.Add(time.Minute), + Gaps: []conditions.Gap{{Cleared: since.Add(5 * time.Second), Reopened: since.Add(time.Minute)}}}}} + if _, why := judgeHealth("app", "", catalogue.Manifest{Module: "app"}, "anchor", since, g); strings.HasPrefix(why, "raised since it was sent") { + t.Fatalf("a module's own fault there at the send: %s", why) } - g.open[0].First = time.Time{} + g.open[0].Gaps[0].Cleared = since.Add(-5 * time.Second) if _, why := judgeHealth("app", "", catalogue.Manifest{Module: "app"}, "anchor", since, g); !strings.HasPrefix(why, "raised since it was sent") { - t.Fatalf("a module's own fault raised after its send was not counted: %s", why) + t.Fatalf("a module's own fault, recovered at the send and back after it, was not counted: %s", why) } } -// An undecided statement — unknown or starting — keeps the machine's network conditions; a decided one -// does not. Pure. -func TestAnUndecidedStatementKeepsTheMachinesNetworkConditions(t *testing.T) { +// Only an undecided part holds a condition that names it; a condition about another part clears, and a +// statement unknown as a whole holds every part (review of PR 179, A4). Pure. +func TestAnUndecidedPartHoldsOnlyWhatNamesIt(t *testing.T) { f := netFacts(map[string]*inventory.NetworkHealth{ - "anchor": aNetwork(link.StateUnknown, inventory.NetworkPart{Part: link.PartNames, State: link.StateUnknown, Streak: 1}), + "anchor": aNetwork(link.StateUnknown, inventory.NetworkPart{Part: link.PartNames, State: link.StateUnknown, Streak: 1}, + inventory.NetworkPart{Part: link.PartRoute, State: link.StateHealthy}), "laptop": aNetwork(link.StateHealthy, inventory.NetworkPart{Part: link.PartNames, State: link.StateHealthy}), - "spare": aNetwork(link.StateUnhealthy, noRoute), + "spare": aNetwork(link.StateStarting, inventory.NetworkPart{Part: link.PartTunnel, State: link.StateHealthy}), + "other": aNetwork(link.StateStarting, inventory.NetworkPart{Part: link.PartTunnel, State: link.StateStarting}), }) - got := undecidedMachines(f) - if !got["anchor"] || got["laptop"] || got["spare"] || len(got) != 1 { - t.Fatalf("undecided: %v", got) + u := undecidedParts(f) + if !u["anchor"][link.PartNames] || u["anchor"][link.PartRoute] || u["laptop"] != nil || !u["spare"]["*"] || + !u["other"][link.PartTunnel] || u["other"]["*"] { + t.Fatalf("undecided: %v", u) + } + about := func(machine, said string, also ...string) conditions.Condition { + return conditions.Condition{Subject: conditions.Subject{Scope: conditions.ScopeMachine, ID: machine, + Machine: machine, Also: also}, Evidence: []conditions.Evidence{{Said: said}}} + } + for _, c := range []struct { + c conditions.Condition + held bool + }{ + {about("anchor", "names since 2026-10-09 10:58:45 UTC: 10.77.0.1 — refused"), true}, + {about("anchor", "route since 2026-10-09 10:58:45 UTC: no default route"), false}, + {about("laptop", "names since 2026-10-09 10:58:45 UTC: refused"), false}, + {about("spare", "route since …: no default route"), true}, + {about("hub", "anchor: names: refused", "anchor"), true}, + {about("hub", "anchor: tunnel: no handshake", "anchor"), false}, + } { + if got := heldUndecided(c.c, u); got != c.held { + t.Errorf("%s %q held %v, want %v", c.c.Subject.Machine, c.c.Evidence[0].Said, got, c.held) + } } } @@ -178,35 +219,3 @@ func TestAReleaseRollsOutWhatItsTierNames(t *testing.T) { t.Fatalf("rolling: %v", got) } } - -// A resolver that refuses every try — nothing listens on its port — is said at once, not held for the -// next run five minutes later: a refusal is the machine's answer, not a loaded resolver (issue 277). -func TestAResolverThatRefusesEveryTryIsSaidAtOnce(t *testing.T) { - conn, err := net.ListenPacket("udp", "127.0.0.1:0") - if err != nil { - t.Fatal(err) - } - _, port, _ := net.SplitHostPort(conn.LocalAddr().String()) - _ = conn.Close() // nothing listens there now: every question is refused - quickResolvers(t, port) - got := askEveryResolver(t.Context(), map[string]string{"anchor.internal": "127.0.0.1"}, anchorOnTheNetwork, "internal") - if len(got) != 1 { - t.Fatalf("%+v", got) - } - if got[0].Confirm || !strings.Contains(got[0].Said, "refused") { - t.Fatalf("a resolver refusing every try was held for the next run: %+v", got[0]) - } -} - -func TestOnlyARefusalOnEveryTryIsAllRefused(t *testing.T) { - refused := &net.OpError{Op: "read", Net: "udp", Err: os.NewSyscallError("read", syscall.ECONNREFUSED)} - if !(resolverAsked{errs: []error{refused, refused}}).allRefused() { - t.Fatal("refused on every try is not all refused") - } - if (resolverAsked{errs: []error{refused, errors.New("i/o timeout")}}).allRefused() { - t.Fatal("a timeout among the tries is all refused") - } - if (resolverAsked{answered: true, errs: []error{refused}}).allRefused() || (resolverAsked{}).allRefused() { - t.Fatal("an answered question, or one never asked, is all refused") - } -} diff --git a/cmd/mesh-controller/issue349_test.go b/cmd/mesh-controller/issue349_test.go index ff2d3ba7..29ff7a75 100644 --- a/cmd/mesh-controller/issue349_test.go +++ b/cmd/mesh-controller/issue349_test.go @@ -31,10 +31,10 @@ func TestTwoMergesActedOnInReverseOrderBuildTheNewerCommit(t *testing.T) { } at := time.Now().UTC().Add(-20 * time.Minute).Truncate(time.Second) fix := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "a082615bfix", - MergedAt: at.Add(2 * time.Minute).Format(time.RFC3339), + MergedAt: at.Add(2 * time.Minute).Format(time.RFC3339Nano), Paths: []string{"modules/gitea/module.json"}, ModuleDirs: []string{"modules/gitea"}, ModuleDirsSaid: true} before := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "8ff8197abefore", - MergedAt: at.Format(time.RFC3339), + MergedAt: at.Format(time.RFC3339Nano), Paths: []string{"modules/notes/module.json"}, ModuleDirs: []string{"modules/notes"}, ModuleDirsSaid: true} for _, m := range []link.SourceMoved{fix, before} { if err := (following{open: open}).SourceMoved(ctx, m); err != nil { @@ -63,8 +63,63 @@ func TestTwoMergesActedOnInReverseOrderBuildTheNewerCommit(t *testing.T) { } } -// Pure: the branch's order is the merges', where both plans know it; and a merge older than an open plan -// of its branch finds it. +// A late older merge after the newer plan is done (review of PR 179, A1): what it moved is built from the +// newer commit, and what the newer merge already looked at is not built again at the older one. +func TestALateMergeAfterTheNewerPlanEndedBuildsTheNewerCommit(t *testing.T) { + open := aCatalogueMesh(t) + ctx := t.Context() + asksWithPaths(t) + for _, m := range []string{"gitea", "notes"} { + if err := open.inventory.RegisterModule(ctx, catalogue.Manifest{Module: m, Version: "1"}, + inventory.Source{Repository: "novox/mesh-catalog", Seat: "git", Path: "modules/" + m, Ref: "main", + BuiltFrom: "c0", Head: "c0"}); err != nil { + t.Fatal(err) + } + } + at := time.Now().UTC().Add(-20 * time.Minute).Truncate(time.Second) + fix := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "a082615bfix", + MergedAt: at.Add(2*time.Minute + 500*time.Millisecond).Format(time.RFC3339Nano), + Paths: []string{"modules/gitea/module.json"}, ModuleDirs: []string{"modules/gitea"}, ModuleDirsSaid: true} + if err := (following{open: open}).SourceMoved(ctx, fix); err != nil { + t.Fatal(err) + } + plans, err := open.inventory.OpenPlans(ctx) + if err != nil || len(plans) != 1 { + t.Fatalf("%v %v", plans, err) + } + done := plans[0] + done.State = inventory.PlanDone + if err := open.inventory.SavePlan(ctx, &done); err != nil { + t.Fatal(err) + } + if got, err := open.inventory.PlanByID(ctx, done.ID); err != nil || !got.Merged.Equal(at.Add(2*time.Minute+500*time.Millisecond)) { + t.Fatalf("the merge time kept is %s, not to the nanosecond (%v)", got.Merged, err) + } + before := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "8ff8197abefore", + MergedAt: at.Format(time.RFC3339Nano), + Paths: []string{"modules/notes/module.json", "modules/gitea/module.json"}, + ModuleDirs: []string{"modules/notes", "modules/gitea"}, ModuleDirsSaid: true} + if err := (following{open: open}).SourceMoved(ctx, before); err != nil { + t.Fatal(err) + } + plans, err = open.inventory.OpenPlans(ctx) + if err != nil || len(plans) != 1 { + t.Fatalf("open plans after the late merge: %+v %v", plans, err) + } + p := plans[0] + if p.Commit != fix.Commit { + t.Fatalf("the late merge was planned at %s, not the newer commit %s", p.Commit, fix.Commit) + } + if _, has := p.Modules["notes"]; !has { + t.Fatalf("what only the late merge moved is not built: %v", p.Modules) + } + if _, has := p.Modules["gitea"]; has { + t.Fatalf("what the newer merge already built is built again: %v", p.Modules) + } +} + +// Pure: the branch's order is the merges', where both plans know it; and a later merge of the branch is +// found in any state, never a release's, another repository's or another branch's. func TestTheBranchOrderIsTheMerges(t *testing.T) { t0 := time.Date(2026, 10, 9, 10, 0, 0, 0, time.UTC) newerMerge := inventory.Plan{ID: "plan-1", Repository: "novox/mesh-catalog", Branch: "main", Commit: "a082615b", @@ -82,12 +137,37 @@ func TestTheBranchOrderIsTheMerges(t *testing.T) { if !earlierOnTheBranch(unknown, olderMerge) { t.Fatal("without a merge time the plans' own order does not stand") } - m := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "8ff8197a", MergedAt: t0.Format(time.RFC3339)} - if p, ok := newestOnTheBranch(m, []inventory.Plan{newerMerge}); !ok || p.ID != "plan-1" { - t.Fatalf("the newer open plan of the branch was not found: %v %+v", ok, p) + same := olderMerge + same.Merged = newerMerge.Merged + if !earlierOnTheBranch(newerMerge, same) || earlierOnTheBranch(same, newerMerge) { + t.Fatal("one merge time: the plans' own order does not stand") } - m.Base = "release" - if _, ok := newestOnTheBranch(m, []inventory.Plan{newerMerge}); ok { - t.Fatal("another branch's plan was taken") + m := link.SourceMoved{Owner: "novox", Repo: "mesh-catalog", Base: "main", Commit: "8ff8197a", + MergedAt: t0.Add(500 * time.Millisecond).Format(time.RFC3339Nano)} + newerMerge.State = inventory.PlanDone + if !laterOnTheBranch(m, newerMerge) { + t.Fatal("a later merge of the branch, its plan done, was not found") + } + for name, change := range map[string]func(p *inventory.Plan, m *link.SourceMoved){ + "another branch": func(_ *inventory.Plan, m *link.SourceMoved) { m.Base = "release" }, + "another repository": func(p *inventory.Plan, _ *link.SourceMoved) { p.Repository = "novox/mesh-controller" }, + "a release": func(p *inventory.Plan, _ *link.SourceMoved) { p.Release = &inventory.PlanRelease{} }, + "no merge time": func(p *inventory.Plan, _ *link.SourceMoved) { p.Merged = time.Time{} }, + "the same commit": func(p *inventory.Plan, m *link.SourceMoved) { m.Commit = p.Commit }, + "an older merge": func(p *inventory.Plan, _ *link.SourceMoved) { p.Merged = t0 }, + "the same moment": func(p *inventory.Plan, _ *link.SourceMoved) { p.Merged = t0.Add(500 * time.Millisecond) }, + "an unreadable time": func(_ *inventory.Plan, m *link.SourceMoved) { m.MergedAt = "yesterday" }, + } { + p, mm := newerMerge, m + change(&p, &mm) + if laterOnTheBranch(mm, p) { + t.Errorf("%s was taken as a later merge of the branch", name) + } + } + // To the nanosecond: two merges within a second keep their order. + m.MergedAt = t0.Add(time.Minute + 200*time.Millisecond).Format(time.RFC3339Nano) + if !laterOnTheBranch(m, inventory.Plan{Repository: "novox/mesh-catalog", Branch: "main", Commit: "x", + Merged: t0.Add(time.Minute + 700*time.Millisecond)}) { + t.Fatal("merges within one second lost their order") } } diff --git a/cmd/mesh-controller/machine_network.go b/cmd/mesh-controller/machine_network.go index fcb081cf..667456c8 100644 --- a/cmd/mesh-controller/machine_network.go +++ b/cmd/mesh-controller/machine_network.go @@ -98,9 +98,9 @@ func judgeNetworks(ctx context.Context, inv *inventory.Inventory, k *conditions. problems = append(problems, err.Error()) } } - undecided := undecidedMachines(f) + undecided := undecidedParts(f) for _, c := range open { - if !slices.Contains(networkKinds, c.Kind) || said[c.Key] || undecided[c.Subject.Machine] { + if !slices.Contains(networkKinds, c.Kind) || said[c.Key] || heldUndecided(c, undecided) { continue } why := "no machine says it any more" @@ -117,36 +117,59 @@ func judgeNetworks(ctx context.Context, inv *inventory.Inventory, k *conditions. return nil } -// undecidedMachines is every machine whose newest statement has a part not yet judged: starting, or -// unknown — one look failed and a second decides (novox/hq issue 348). Such a statement does not say a -// fault is gone, so an open network condition about that machine is kept until a statement decides. +// undecidedParts is, per machine, every part of its newest statement not yet judged: starting, or unknown +// — one look failed and a second decides (novox/hq issue 348). Such a part does not say its fault is gone. +// A statement whose parts are all decided but whose whole is unknown or starting holds every part. Pure. // // On 2026-10-09 the control node's resolver refused every question from 10:58 to 11:18 UTC. A build of -// the node-engine sent at 10:59:34 restarted it; its first statement after the restart judged the names -// once (unknown, "one look failed; a second decides"), and that statement cleared the control node's -// network condition while its last evidence still said "connection refused". The second look raised it -// again forty seconds later — after the send — and the gate failed the build for a fault from before it. -// Pure. -func undecidedMachines(f networkFacts) map[string]bool { - out := map[string]bool{} +// the node-engine sent at 10:59:34 restarted it; its first statement judged the names once (unknown, "one +// look failed; a second decides"), and that statement cleared the control node's network condition while +// its last evidence still said "connection refused". The second look raised it again forty seconds later — +// after the send — and the gate failed the build for a fault from before it. +func undecidedParts(f networkFacts) map[string]map[string]bool { + out := map[string]map[string]bool{} for m, h := range f.healths { if h.Network == nil { continue } - if h.Network.State == link.StateUnknown || h.Network.State == link.StateStarting { - out[m] = true - continue - } + parts := map[string]bool{} for _, p := range h.Network.Parts { if p.State == link.StateUnknown || p.State == link.StateStarting { - out[m] = true - break + parts[p.Part] = true } } + if len(parts) == 0 && (h.Network.State == link.StateUnknown || h.Network.State == link.StateStarting) { + parts["*"] = true + } + if len(parts) > 0 { + out[m] = parts + } } return out } +// heldUndecided says an open network condition is kept rather than cleared: a part its newest evidence +// names is undecided in the newest statement of a machine it is about. A condition about other parts +// clears as before. Pure. +func heldUndecided(c conditions.Condition, undecided map[string]map[string]bool) bool { + said := "" + if len(c.Evidence) > 0 { + said = c.Evidence[0].Said + } + for _, m := range append([]string{c.Subject.Machine}, c.Subject.Also...) { + parts := undecided[m] + if parts["*"] { + return true + } + for part := range parts { + if strings.Contains(said, part+" since ") || strings.Contains(said, part+": ") { + return true + } + } + } + return false +} + // pointed is one machine's failing part that points at another machine. type pointed struct { from string diff --git a/cmd/mesh-controller/probes.go b/cmd/mesh-controller/probes.go index f236a0ac..2f8380ae 100644 --- a/cmd/mesh-controller/probes.go +++ b/cmd/mesh-controller/probes.go @@ -11,7 +11,6 @@ import ( "sort" "strings" "sync" - "syscall" "time" "github.com/nats-io/nats.go" @@ -217,8 +216,6 @@ func askEveryResolver(ctx context.Context, resolvers map[string]string, places [ type verdict struct { wrong, unanswered, said []string asked int - // refused says every try of every unanswered question was refused (nothing listens there). - refused bool } byHolder := map[string]*verdict{} for _, q := range questions { @@ -235,7 +232,6 @@ func askEveryResolver(ctx context.Context, resolvers map[string]string, places [ v.wrong = append(v.wrong, words) v.said = append(v.said, said) default: - v.refused = (len(v.unanswered) == 0 || v.refused) && q.asked.allRefused() v.unanswered = append(v.unanswered, words) v.said = append(v.said, said) } @@ -255,11 +251,12 @@ func askEveryResolver(ctx context.Context, resolvers map[string]string, places [ o.Summary = fmt.Sprintf("the mesh's resolver on %s does not answer machine names as it must: %s%s", node, v.wrong[0], andMore(len(v.wrong)-1)) } else { - // Nothing but silence: held for the next run, which raises it if the resolver is still silent — - // unless every try of every question was refused. A refusal is an answer from the machine: - // nothing listens there. It is not a loaded resolver slow to answer (issue 277), and holding it - // for the next run cost the control node's resolver five minutes on 2026-10-09 (issue 348). - o.Confirm = !v.refused + // Nothing but silence: held for the next run, which raises it if the resolver is still silent. + // Refused on every try too: a few hundred milliseconds of refusals is a resolver restarting as + // well as one that stopped, and the two looks a finding needs are this run and the next + // (novox/hq issue 348). The machine's own node-engine is the fast detector: its names check + // raised the control node's resolver within a minute on 2026-10-09. + o.Confirm = true o.Summary = fmt.Sprintf("the mesh's resolver on %s does not answer: %d of the %d question(s) about the "+ "machines' names went unanswered, each asked %d times — the first, %s", node, len(v.unanswered), v.asked, resolverTries, v.unanswered[0]) @@ -348,19 +345,6 @@ type resolverAsked struct { errs []error } -// allRefused says every try was refused: the resolver's machine said nothing listens on its port. -func (a resolverAsked) allRefused() bool { - if a.answered || len(a.errs) == 0 { - return false - } - for _, err := range a.errs { - if !errors.Is(err, syscall.ECONNREFUSED) { - return false - } - } - return true -} - // askResolverPatiently asks one question until it is answered as right says, at most resolverTries // times. A wrong answer is asked again too — a resolver restarting may say NXDOMAIN for a moment — and // stands if no try answers rightly. diff --git a/cmd/mesh-controller/release_plan.go b/cmd/mesh-controller/release_plan.go index ae66a31b..c6b5dfb1 100644 --- a/cmd/mesh-controller/release_plan.go +++ b/cmd/mesh-controller/release_plan.go @@ -188,7 +188,7 @@ func planOfMerge(m link.SourceMoved, moved []string, edges []inventory.Edge) inv for _, name := range set { modules[name] = &inventory.PlanModule{} } - merged, _ := time.Parse(time.RFC3339, m.MergedAt) + merged, _ := time.Parse(time.RFC3339Nano, m.MergedAt) return inventory.Plan{ ID: fmt.Sprintf("plan-%d", time.Now().UnixNano()), Repository: m.Owner + "/" + m.Repo, @@ -228,8 +228,8 @@ func planOfMerge(m link.SourceMoved, moved []string, edges []inventory.Edge) inv // it — and that later-made plan of the earlier commit superseded the later merge's, and built what it // folded in from the commit before the later merge: twice on 2026-10-09, once a security fix. So where // both plans know when their merge was made, that decides; only where one does not do the plans' own -// times. A merge older than an open plan of its branch never reaches here at its own commit: it is -// planned at the newest open plan's commit, which contains it (newestOnTheBranch). +// times. A merge older than the newest planned merge of its branch never reaches here at its own commit: +// it is planned at that merge's commit, which contains it (laterOnTheBranch). func supersededBy(newer inventory.Plan, open []inventory.Plan, rollsOut func(string) bool) ([]string, []inventory.Plan) { folded := map[string]bool{} var closed []inventory.Plan @@ -274,27 +274,18 @@ func earlierOnTheBranch(a, b inventory.Plan) bool { return a.Created.Before(b.Created) } -// newestOnTheBranch is the open plan of m's repository and branch whose merge was made after m's, the -// newest of them; false when none was. Merges into one branch are made one on the other, so that plan's -// commit contains m's change: m is planned there, and the newest commit of the branch is what is built -// (novox/hq issue 349). Pure. -func newestOnTheBranch(m link.SourceMoved, open []inventory.Plan) (inventory.Plan, bool) { - merged, err := time.Parse(time.RFC3339, m.MergedAt) - if err != nil { - return inventory.Plan{}, false +// laterOnTheBranch says the plan newest answers a merge into m's branch made after m: then newest's commit +// contains m's change, and m is planned there, so the newest commit of the branch is what is built (novox/hq +// issue 349). newest is the newest merge's plan of the branch in any state: a later plan already done +// built what it moved at its commit, and m planned at its own would build m's dependents back at the older +// one. Pure. +func laterOnTheBranch(m link.SourceMoved, newest inventory.Plan) bool { + merged, err := time.Parse(time.RFC3339Nano, m.MergedAt) + if err != nil || newest.Release != nil || newest.Commit == m.Commit { + return false } - var newest inventory.Plan - found := false - for _, p := range open { - if !p.Open() || p.Release != nil || p.Merged.IsZero() || !strings.EqualFold(p.Repository, m.Owner+"/"+m.Repo) || - p.Branch != m.Base || !p.Merged.After(merged) { - continue - } - if !found || p.Merged.After(newest.Merged) { - newest, found = p, true - } - } - return newest, found + return strings.EqualFold(newest.Repository, m.Owner+"/"+m.Repo) && newest.Branch == m.Base && + newest.Merged.After(merged) } // gates is what the next tier needs running from this one: a module of the tier that a later diff --git a/cmd/mesh-controller/upgrades.go b/cmd/mesh-controller/upgrades.go index 5a639aa1..d0c2215c 100644 --- a/cmd/mesh-controller/upgrades.go +++ b/cmd/mesh-controller/upgrades.go @@ -318,6 +318,21 @@ func (f following) SourceMoved(ctx context.Context, m link.SourceMoved) error { return notNow(err) } + // **A merge older than the newest planned merge of its branch is planned at that merge's commit** + // (novox/hq issue 349): the catch-up acts on a merge the bus did not hand over after the merges that + // came after it, and planned at its own commit it built what a later merge had fixed — the forge's + // security fix, on 2026-10-09 — from the commit before it, dependents and all. The later commit contains + // this merge's change. Planned there, with that merge's time, a module the later merge already looked at + // reads as history and is not built again; the rest are built from the newest commit. + newest, known, err := inv.NewestMergeOf(ctx, m.Owner+"/"+m.Repo, m.Base) + if err != nil { + return notNow(err) + } + if known && laterOnTheBranch(m, newest) { + fmt.Printf(" %s/%s %.8s was merged before %.8s (%s, %s): what it moved is built from %.8s, which "+ + "contains it\n", m.Owner, m.Repo, m.Commit, newest.Commit, newest.ID, newest.State, newest.Commit) + m.Commit, m.MergedAt = newest.Commit, newest.Merged.Format(time.RFC3339Nano) + } from, packaging, already := mergeCandidates(m, entries, read) if len(from) == 0 && len(packaging) == 0 { // "Already built from it" and "nothing reads it" are different facts, and reading the first @@ -345,20 +360,6 @@ func (f following) SourceMoved(ctx context.Context, m link.SourceMoved) error { e.Manifest.Module, m.Owner, m.Repo, e.Source.Ref, m.Base) } } - // **A merge older than an open plan of its branch is planned at that plan's commit** (novox/hq issue - // 349): the catch-up acts on a merge the bus did not hand over after the merges that came after it, - // and planned at its own commit it built what the later merge had fixed from the commit before the fix. - // The later commit contains this merge's change, so what this merge moved is built from there, and the - // plan made here supersedes that one as any newer plan does. - if open, err := inv.OpenPlans(ctx); err == nil { - if newest, later := newestOnTheBranch(m, open); later { - fmt.Printf(" %s/%s %.8s was merged before %.8s, which %s is planning: what it moved is built "+ - "from %.8s, which contains it\n", m.Owner, m.Repo, m.Commit, newest.Commit, newest.ID, newest.Commit) - m.Commit, m.MergedAt = newest.Commit, newest.Merged.Format(time.RFC3339) - } - } else { - return notNow(err) - } touched, added, _ := touchedBy(from, entries, m) // **A module the merge deleted is not built** (novox/hq ADR 0236): its manifest is gone, so the build // seat finds nothing saying what it is, and the plan failed on it (`has no module.json at …`) with diff --git a/internal/conditions/condition.go b/internal/conditions/condition.go index ce408349..d8932dab 100644 --- a/internal/conditions/condition.go +++ b/internal/conditions/condition.go @@ -146,10 +146,12 @@ type Condition struct { Raised time.Time `json:"raised"` LastObserved time.Time `json:"last-observed"` // First is when this fault was first raised, a reopening within ReopenWithin counted as the same - // fault: Raised of the first raising. Absent on one written before it was kept, and on a first - // raising, where it is Raised (Began). A reopening is the same fault, so what asks when a fault began - // — the gate, asking whether it began after a send — reads Began, never Raised (novox/hq issue 348). + // fault; Gaps are the stretches between, each from a clearing to the reopening after it. Absent on a + // first raising, and on one written before they were kept. What asks whether the fault was there at a + // moment — the gate, at a send — reads OpenAt, never Raised (novox/hq issue 348): a fault cleared and + // reopened after a send was there at the send unless the send fell in one of its gaps. First time.Time `json:"first,omitzero"` + Gaps []Gap `json:"gaps,omitempty"` // 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. @@ -280,13 +282,50 @@ func Order(list []Condition) { }) } +// Gap is a stretch in which a fault was cleared, between its clearing and its reopening. +type Gap struct { + Cleared time.Time `json:"cleared"` + Reopened time.Time `json:"reopened"` +} + +// KeptGaps is how many gaps a condition keeps. Past it the oldest go, and the fault is said to have begun +// at the reopening after the newest of them: earlier history forgotten, never a fault said older than known. +const KeptGaps = 8 + // Began is when this fault began as the mesh knows it: its first raising, a reopening within -// ReopenWithin being the same fault again (novox/hq issue 348). A condition that cleared on a statement -// that judged nothing yet — a node-engine just restarted — and was raised again a minute later began -// when it was first raised, not at the reopening. +// ReopenWithin being the same fault again (novox/hq issue 348). func (c Condition) Began() time.Time { if !c.First.IsZero() && c.First.Before(c.Raised) { return c.First } return c.Raised } + +// OpenAt says the fault was there at t: it began at or before t, and t fell in none of its gaps. A fault +// that cleared before a send and came back after it was not there at the send — that is the send's to +// answer for — while one that flapped after the send was (novox/hq issue 348). +func (c Condition) OpenAt(t time.Time) bool { + if t.Before(c.Began()) { + return false + } + for _, g := range c.Gaps { + if !t.Before(g.Cleared) && t.Before(g.Reopened) { + return false + } + } + return true +} + +// reopen is c raised again at now after a clearing at cleared, of a fault that began at first with gaps: +// the same fault, with one more gap. +func (c *Condition) reopen(first time.Time, gaps []Gap, cleared, now time.Time) { + if first.IsZero() || !first.Before(now) { + return + } + c.First = first + c.Gaps = append(append([]Gap(nil), gaps...), Gap{Cleared: cleared, Reopened: now}) + if over := len(c.Gaps) - KeptGaps; over > 0 { + c.First = c.Gaps[over-1].Reopened + c.Gaps = c.Gaps[over:] + } +} diff --git a/internal/conditions/store.go b/internal/conditions/store.go index f4935d7d..caca3c02 100644 --- a/internal/conditions/store.go +++ b/internal/conditions/store.go @@ -79,8 +79,10 @@ type Keeper struct { type clearing struct { at time.Time count int - // began is when the fault that cleared began, so its reopening keeps it (Condition.Began). + // began is when the fault that cleared began, and gaps its earlier gaps, so its reopening keeps + // them (Condition.OpenAt). began time.Time + gaps []Gap silenced *Silence // tried is what healers tried before it cleared: a reopening is the same fault, and what was // tried on it is still what was tried. @@ -122,7 +124,7 @@ func NewKeeper(ctx context.Context, o Options) *Keeper { 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, began: e.Condition.Began(), + k.cleared[e.Key] = clearing{at: e.At, count: e.Condition.Count, began: e.Condition.Began(), gaps: e.Condition.Gaps, silenced: e.Condition.Silenced, tried: e.Condition.Tried} } } @@ -199,9 +201,7 @@ func (k *Keeper) Observe(ctx context.Context, o Observation) (Condition, error) k.mu.Lock() if before, ok := k.cleared[key]; ok && now.Sub(before.at) <= ReopenWithin { c.Count, change = before.count+1, ChangeReopened - if !before.began.IsZero() && before.began.Before(now) { - c.First = before.began - } + c.reopen(before.began, before.gaps, before.at, now) // 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) { @@ -318,7 +318,7 @@ func (k *Keeper) ClearSaying(ctx context.Context, key, why, resolved string) (bo } now := k.now().UTC() k.mu.Lock() - k.cleared[key] = clearing{at: now, count: c.Count, began: c.Began(), silenced: c.Silenced, tried: c.Tried} + k.cleared[key] = clearing{at: now, count: c.Count, began: c.Began(), gaps: c.Gaps, silenced: c.Silenced, tried: c.Tried} k.mu.Unlock() k.tell(Event{Condition: c, At: now, Change: ChangeCleared, Why: why, Cleared: &now}) return true, nil diff --git a/internal/conditions/store_test.go b/internal/conditions/store_test.go index ab2fe986..f460e0d8 100644 --- a/internal/conditions/store_test.go +++ b/internal/conditions/store_test.go @@ -392,6 +392,7 @@ func TestAReopeningKeepsWhenTheFaultBegan(t *testing.T) { if !first.Began().Equal(first.Raised) || !first.First.IsZero() { t.Fatalf("a first raising began at %s, raised %s, first %s", first.Began(), first.Raised, first.First) } + c.pass(30 * time.Second) if _, err := k.Clear(ctx, "machine.ace.silent", "heard again"); err != nil { t.Fatal(err) } @@ -400,8 +401,13 @@ func TestAReopeningKeepsWhenTheFaultBegan(t *testing.T) { if err != nil { t.Fatal(err) } - if !again.Raised.After(first.Raised) || !again.Began().Equal(first.Raised) { - t.Fatalf("reopened: raised %s, began %s; first raised %s", again.Raised, again.Began(), first.Raised) + if !again.Raised.After(first.Raised) || !again.Began().Equal(first.Raised) || len(again.Gaps) != 1 || + !again.Gaps[0].Reopened.Equal(again.Raised) || !again.Gaps[0].Cleared.Before(again.Raised) { + t.Fatalf("reopened: raised %s, began %s, gaps %+v; first raised %s", again.Raised, again.Began(), again.Gaps, first.Raised) + } + if !again.OpenAt(first.Raised) || again.OpenAt(again.Gaps[0].Cleared) || !again.OpenAt(again.Raised) || + again.OpenAt(first.Raised.Add(-time.Second)) { + t.Fatalf("open at the wrong moments: %+v", again) } // Through a restarted controller, reading the clearing from the history. if _, err := k.Clear(ctx, "machine.ace.silent", "heard again"); err != nil { @@ -416,8 +422,8 @@ func TestAReopeningKeepsWhenTheFaultBegan(t *testing.T) { if err != nil { t.Fatal(err) } - if !third.Began().Equal(first.Raised) { - t.Fatalf("after a restart the reopening began at %s, not %s", third.Began(), first.Raised) + if !third.Began().Equal(first.Raised) || len(third.Gaps) != 2 { + t.Fatalf("after a restart the reopening began at %s, not %s, with gaps %+v", third.Began(), first.Raised, third.Gaps) } if _, err := next.Clear(ctx, "machine.ace.silent", "heard again"); err != nil { t.Fatal(err) @@ -427,7 +433,29 @@ func TestAReopeningKeepsWhenTheFaultBegan(t *testing.T) { if err != nil { t.Fatal(err) } - if !fourth.Began().Equal(fourth.Raised) { - t.Fatalf("past the window the fault began at %s, raised %s", fourth.Began(), fourth.Raised) + if !fourth.Began().Equal(fourth.Raised) || len(fourth.Gaps) != 0 { + t.Fatalf("past the window the fault began at %s, raised %s, gaps %+v", fourth.Began(), fourth.Raised, fourth.Gaps) + } +} + +// Past KeptGaps the oldest gaps go, and the fault is said to have begun after them, never before. +func TestAFaultKeepsItsNewestGapsAndForgetsWhatWasBefore(t *testing.T) { + t0 := time.Date(2026, 10, 9, 10, 0, 0, 0, time.UTC) + c := Condition{Raised: t0} + first, gaps := t0, []Gap(nil) + for i := 1; i <= KeptGaps+2; i++ { + cleared, now := t0.Add(time.Duration(2*i)*time.Minute), t0.Add(time.Duration(2*i+1)*time.Minute) + c = Condition{Raised: now} + c.reopen(first, gaps, cleared, now) + first, gaps = c.Began(), c.Gaps + } + if len(c.Gaps) != KeptGaps || !c.Began().Equal(t0.Add(5*time.Minute)) || c.OpenAt(t0.Add(time.Minute)) { + t.Fatalf("after %d gaps: began %s, %d gaps", KeptGaps+2, c.Began(), len(c.Gaps)) + } + // A first time not before the reopening is no earlier fault. + d := Condition{Raised: t0} + d.reopen(t0, nil, t0.Add(-time.Minute), t0) + if !d.First.IsZero() || len(d.Gaps) != 0 { + t.Fatalf("a fault reopened at its own first raising: %+v", d) } } diff --git a/internal/inventory/plans.go b/internal/inventory/plans.go index 348cf15d..bf1d1532 100644 --- a/internal/inventory/plans.go +++ b/internal/inventory/plans.go @@ -313,6 +313,18 @@ func (i *Inventory) RecentPlans(ctx context.Context, limit int) ([]Plan, error) return i.plans(ctx, fmt.Sprintf(`order by created desc limit %d`, limit)) } +// NewestMergeOf is the plan, in any state, of the newest merge into a repository's branch that the mesh +// planned: the branch's newest commit the mesh knows of (novox/hq issue 349). False when no plan of it +// recorded when its merge was made. +func (i *Inventory) NewestMergeOf(ctx context.Context, repository, branch string) (Plan, bool, error) { + plans, err := i.plans(ctx, `where lower(repository) = lower($1) and branch = $2 and merged_at is not null + and release is null order by merged_at desc, created desc limit 1`, repository, branch) + if err != nil || len(plans) == 0 { + return Plan{}, false, err + } + return plans[0], true, nil +} + // PlanByID is one plan. func (i *Inventory) PlanByID(ctx context.Context, id string) (Plan, error) { plans, err := i.plans(ctx, `where id = '`+id+`'`) @@ -325,11 +337,11 @@ func (i *Inventory) PlanByID(ctx context.Context, id string) (Plan, error) { return plans[0], nil } -func (i *Inventory) plans(ctx context.Context, tail string) ([]Plan, error) { +func (i *Inventory) plans(ctx context.Context, tail string, args ...any) ([]Plan, error) { rows, err := i.store.Pool().Query(ctx, `select id, repository, commit_hash, created, updated, state, tier, tiers, modules, note, branch, coalesce(tier_entered, created), revision, coalesce(epoch, 0), release, delivery, merged_at - from release_plan `+tail) + from release_plan `+tail, args...) if err != nil { return nil, err }