Merge pull request 'A bus refusal is counted by what the bus said, not by the controller's looks (issue 402)' (#212) from fix/402-a-refusal-is-counted-once into main
This commit was merged in pull request #212.
This commit is contained in:
@@ -0,0 +1,95 @@
|
|||||||
|
package main
|
||||||
|
|
||||||
|
import (
|
||||||
|
"strings"
|
||||||
|
"testing"
|
||||||
|
"time"
|
||||||
|
|
||||||
|
"github.com/novox/mesh-controller/internal/conditions"
|
||||||
|
"github.com/novox/mesh-controller/internal/link"
|
||||||
|
)
|
||||||
|
|
||||||
|
// **A refusal the bus said once is counted once** (novox/hq issue 402). The bus refused the controller
|
||||||
|
// one publish at 18:52:59 UTC on 2026-10-10 and never again, yet S9 looked at the one remembered
|
||||||
|
// advisory every half minute for the hour it is kept, and the condition said "observed 15 time(s), last
|
||||||
|
// 13s ago" with a refusal in its evidence every 30 seconds: two of us read it as a refusal going on and
|
||||||
|
// went looking for a missing grant. The condition counts what the bus said, with when it last said it,
|
||||||
|
// never how often the controller looked.
|
||||||
|
func TestARefusalSaidOnceIsCountedOnceHoweverOftenItIsLookedAt(t *testing.T) {
|
||||||
|
refused := time.Date(2026, 10, 10, 18, 52, 59, 0, time.UTC)
|
||||||
|
now := refused.Add(10 * time.Second)
|
||||||
|
store := conditions.NewInMemory()
|
||||||
|
k := conditions.NewKeeper(t.Context(), conditions.Options{Store: store, History: store,
|
||||||
|
Teller: &conditions.Told{}, Now: func() time.Time { return now }})
|
||||||
|
t.Cleanup(func() { k.Close(t.Context()) })
|
||||||
|
|
||||||
|
// The words the live condition bus.controller.refused carried on 2026-10-10.
|
||||||
|
said := "the bus refused the controller: nats: permissions violation: Permissions Violation for " +
|
||||||
|
`Publish to "mesh.seat.mesh-delivery.tool.times"`
|
||||||
|
advisory := link.Advisory{Kind: link.AdvisoryRefused, ID: "controller", Said: said,
|
||||||
|
First: refused, Last: refused, Count: 1}
|
||||||
|
look := func() conditions.Condition {
|
||||||
|
t.Helper()
|
||||||
|
f := &signalFacts{now: now, host: "novox", advisories: []link.Advisory{advisory}}
|
||||||
|
if err := k.Reconcile(t.Context(), "S9", watchAdvisories(f)); err != nil {
|
||||||
|
t.Fatal(err)
|
||||||
|
}
|
||||||
|
c, found, err := conditions.ReadOne(t.Context(), store, "bus.controller.refused")
|
||||||
|
if err != nil || !found {
|
||||||
|
t.Fatalf("bus.controller.refused: found %v, %v", found, err)
|
||||||
|
}
|
||||||
|
return c
|
||||||
|
}
|
||||||
|
|
||||||
|
var c conditions.Condition
|
||||||
|
for range 15 {
|
||||||
|
c = look()
|
||||||
|
now = now.Add(30 * time.Second)
|
||||||
|
}
|
||||||
|
if c.Observations != 1 || len(c.Evidence) != 1 {
|
||||||
|
t.Fatalf("one refusal, looked at 15 times, reads as observed %d time(s) with %d evidence lines: %+v",
|
||||||
|
c.Observations, len(c.Evidence), c.Evidence)
|
||||||
|
}
|
||||||
|
if !c.LastObserved.Equal(refused) || !c.Evidence[0].At.Equal(refused) {
|
||||||
|
t.Fatalf("last observed %s, evidence at %s: the refusal was at %s", c.LastObserved, c.Evidence[0].At, refused)
|
||||||
|
}
|
||||||
|
|
||||||
|
// The bus refuses it three times more between two looks: the condition counts four refusals, says
|
||||||
|
// the newest, and adds one line of evidence for the look that saw them.
|
||||||
|
again := now.Add(-5 * time.Second)
|
||||||
|
advisory.Last, advisory.Count = again, 4
|
||||||
|
c = look()
|
||||||
|
if c.Observations != 4 || len(c.Evidence) != 2 || !c.LastObserved.Equal(again) || !c.Evidence[0].At.Equal(again) {
|
||||||
|
t.Fatalf("four refusals read as observed %d time(s), last %s, evidence %+v", c.Observations, c.LastObserved, c.Evidence)
|
||||||
|
}
|
||||||
|
if !strings.Contains(c.Summary, "(4 times since 18:52 UTC)") {
|
||||||
|
t.Fatalf("summary %q", c.Summary)
|
||||||
|
}
|
||||||
|
now = now.Add(30 * time.Second)
|
||||||
|
if c = look(); c.Observations != 4 || len(c.Evidence) != 2 {
|
||||||
|
t.Fatalf("a look with nothing new counted: observed %d time(s), evidence %+v", c.Observations, c.Evidence)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// **A condition that looks at the present still counts its looks** (novox/hq issue 402 changes only
|
||||||
|
// what reads a record): a machine silent for three looks was observed three times, and says so.
|
||||||
|
func TestAConditionOfThePresentCountsItsLooks(t *testing.T) {
|
||||||
|
now := time.Date(2026, 10, 10, 19, 0, 0, 0, time.UTC)
|
||||||
|
store := conditions.NewInMemory()
|
||||||
|
k := conditions.NewKeeper(t.Context(), conditions.Options{Store: store, History: store,
|
||||||
|
Teller: &conditions.Told{}, Now: func() time.Time { return now }})
|
||||||
|
t.Cleanup(func() { k.Close(t.Context()) })
|
||||||
|
var c conditions.Condition
|
||||||
|
for range 3 {
|
||||||
|
var err error
|
||||||
|
if c, err = k.Observe(t.Context(), conditions.Observation{Scope: conditions.ScopeMachine, ID: "ace",
|
||||||
|
Kind: "silent", Machine: "ace", Severity: conditions.Warning, Summary: "ace has not been heard from",
|
||||||
|
Source: "S1"}); err != nil {
|
||||||
|
t.Fatal(err)
|
||||||
|
}
|
||||||
|
now = now.Add(30 * time.Second)
|
||||||
|
}
|
||||||
|
if c.Observations != 3 || len(c.Evidence) != 3 || !c.LastObserved.Equal(now.Add(-30*time.Second)) {
|
||||||
|
t.Fatalf("observed %d time(s), %d evidence lines, last %s", c.Observations, len(c.Evidence), c.LastObserved)
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -533,7 +533,10 @@ func watchAdvisories(f *signalFacts) []conditions.Observation {
|
|||||||
machine = f.host
|
machine = f.host
|
||||||
}
|
}
|
||||||
o := conditions.Observation{Scope: conditions.ScopeBus, ID: a.ID, Kind: a.Kind, Token: a.Token,
|
o := conditions.Observation{Scope: conditions.ScopeBus, ID: a.ID, Kind: a.Kind, Token: a.Token,
|
||||||
Machine: machine, Severity: severity, Summary: a.Said + times, Said: a.Said}
|
Machine: machine, Severity: severity, Summary: a.Said + times, Said: a.Said,
|
||||||
|
// The advisory is remembered and read again on every look for an hour: the condition counts
|
||||||
|
// what the bus said and when, not the looks (novox/hq issue 402).
|
||||||
|
Happened: a.Last, Times: a.Count}
|
||||||
if a.Kind == link.AdvisoryMaxDeliveries && a.Token == link.AdvisoryNotKept {
|
if a.Kind == link.AdvisoryMaxDeliveries && a.Token == link.AdvisoryNotKept {
|
||||||
o.Machine = consumerMachine(a.Stream, a.Consumer)
|
o.Machine = consumerMachine(a.Stream, a.Consumer)
|
||||||
o.Headline = clip(conditions.Capital(fmt.Sprintf("%s gave up on a message, not kept",
|
o.Headline = clip(conditions.Capital(fmt.Sprintf("%s gave up on a message, not kept",
|
||||||
|
|||||||
@@ -152,7 +152,9 @@ type Condition struct {
|
|||||||
// reopened after a send was there at the send unless the send fell in one of its gaps.
|
// reopened after a send was there at the send unless the send fell in one of its gaps.
|
||||||
First time.Time `json:"first,omitzero"`
|
First time.Time `json:"first,omitzero"`
|
||||||
Gaps []Gap `json:"gaps,omitempty"`
|
Gaps []Gap `json:"gaps,omitempty"`
|
||||||
// Observations is how many times it was observed since raised.
|
// Observations is how many times it was observed since raised: a look that sees it, for a source
|
||||||
|
// that looks at the present; for one that reads a record of what happened (Observation.Happened),
|
||||||
|
// how many times it happened, and LastObserved when it last did (novox/hq issue 402).
|
||||||
Observations int `json:"observations"`
|
Observations int `json:"observations"`
|
||||||
// Count is how many times it has been raised, a reopening within ReopenWithin counted.
|
// Count is how many times it has been raised, a reopening within ReopenWithin counted.
|
||||||
Count int `json:"count"`
|
Count int `json:"count"`
|
||||||
@@ -208,6 +210,15 @@ type Observation struct {
|
|||||||
Said string
|
Said string
|
||||||
Source string
|
Source string
|
||||||
Resolver string
|
Resolver string
|
||||||
|
// Happened is set by a source that reads a record of what happened rather than looking at the
|
||||||
|
// present — a bus advisory, remembered for an hour and read again on every look — to when it last
|
||||||
|
// happened; Times is how many times the record counts it. The condition then counts what happened,
|
||||||
|
// not the looks (novox/hq issue 402): one refusal looked at every half minute read as "observed 15
|
||||||
|
// time(s)", with a line of evidence every 30 seconds, and was taken for a refusal going on. A look
|
||||||
|
// that brings nothing newer than the condition's last observation adds no observation and no
|
||||||
|
// evidence. Zero for a source that looks at the present, whose every look is an observation.
|
||||||
|
Happened time.Time
|
||||||
|
Times int
|
||||||
// Confirm says a single look can be wrong about this finding — a question over the network that
|
// Confirm says a single look can be wrong about this finding — a question over the network that
|
||||||
// went unanswered, a time measured once on a loaded machine. The keeper does not read it: the
|
// went unanswered, a time measured once on a loaded machine. The keeper does not read it: the
|
||||||
// source that looks again does, and raises it only when the next look sees it too, or while it is
|
// source that looks again does, and raises it only when the next look sees it too, or while it is
|
||||||
|
|||||||
@@ -191,11 +191,16 @@ func (k *Keeper) Observe(ctx context.Context, o Observation) (Condition, error)
|
|||||||
if err != nil {
|
if err != nil {
|
||||||
return Condition{}, fmt.Errorf("reading the condition %s: %w", key, err)
|
return Condition{}, fmt.Errorf("reading the condition %s: %w", key, err)
|
||||||
}
|
}
|
||||||
|
// What was observed and when: the look, or what the record says happened (novox/hq issue 402).
|
||||||
|
at, observations := now, 1
|
||||||
|
if !o.Happened.IsZero() {
|
||||||
|
at, observations = o.Happened.UTC(), max(1, o.Times)
|
||||||
|
}
|
||||||
if !found {
|
if !found {
|
||||||
c := Condition{Key: key, Kind: o.Kind, Subject: Subject{Scope: o.Scope, ID: o.ID, Machine: o.Machine, Also: o.Also},
|
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, Headline: o.Headline, Explanation: o.Explanation,
|
Severity: o.Severity, Summary: o.Summary, Headline: o.Headline, Explanation: o.Explanation,
|
||||||
Resolved: o.Resolved, Needs: o.Needs, Actions: o.Actions, Evidence: []Evidence{{At: now, Said: said}},
|
Resolved: o.Resolved, Needs: o.Needs, Actions: o.Actions, Evidence: []Evidence{{At: at, Said: said}},
|
||||||
Source: o.Source, Raised: now, LastObserved: now, Observations: 1, Count: 1,
|
Source: o.Source, Raised: now, LastObserved: at, Observations: observations, Count: 1,
|
||||||
Resolver: orSelf(o.Resolver)}
|
Resolver: orSelf(o.Resolver)}
|
||||||
change := ChangeRaised
|
change := ChangeRaised
|
||||||
k.mu.Lock()
|
k.mu.Lock()
|
||||||
@@ -244,7 +249,10 @@ func (k *Keeper) Observe(ctx context.Context, o Observation) (Condition, error)
|
|||||||
}
|
}
|
||||||
// The kind as the source says it now: a source that gave the same key a kind of its own since
|
// The kind as the source says it now: a source that gave the same key a kind of its own since
|
||||||
// (a probe's finding split out for a healer) is read by that kind from its next observation.
|
// (a probe's finding split out for a healer) is read by that kind from its next observation.
|
||||||
c.Kind, c.Summary, c.Source, c.LastObserved = o.Kind, o.Summary, o.Source, now
|
// A record read again with nothing newer in it is not observed again: its words are refreshed,
|
||||||
|
// its count, evidence and last observation stay (novox/hq issue 402).
|
||||||
|
fresh := o.Happened.IsZero() || at.After(c.LastObserved)
|
||||||
|
c.Kind, c.Summary, c.Source = o.Kind, o.Summary, o.Source
|
||||||
wasNeeds, wasActions := c.Needs, c.Actions
|
wasNeeds, wasActions := c.Needs, c.Actions
|
||||||
c.Headline, c.Explanation, c.Resolved, c.Needs, c.Actions = o.Headline, o.Explanation, o.Resolved, o.Needs, o.Actions
|
c.Headline, c.Explanation, c.Resolved, c.Needs, c.Actions = o.Headline, o.Explanation, o.Resolved, o.Needs, o.Actions
|
||||||
escalatedWords(&c)
|
escalatedWords(&c)
|
||||||
@@ -257,10 +265,15 @@ func (k *Keeper) Observe(ctx context.Context, o Observation) (Condition, error)
|
|||||||
if len(o.Also) > 0 {
|
if len(o.Also) > 0 {
|
||||||
c.Subject.Also = o.Also
|
c.Subject.Also = o.Also
|
||||||
}
|
}
|
||||||
c.Observations++
|
if fresh {
|
||||||
c.Evidence = append([]Evidence{{At: now, Said: said}}, c.Evidence...)
|
// A record counts what happened since it began; the condition never counts down, so a
|
||||||
if len(c.Evidence) > KeptEvidence {
|
// record begun again (a controller restarted) still adds the one it shows.
|
||||||
c.Evidence = c.Evidence[:KeptEvidence]
|
c.Observations = max(c.Observations+1, o.Times)
|
||||||
|
c.LastObserved = at
|
||||||
|
c.Evidence = append([]Evidence{{At: at, Said: said}}, c.Evidence...)
|
||||||
|
if len(c.Evidence) > KeptEvidence {
|
||||||
|
c.Evidence = c.Evidence[:KeptEvidence]
|
||||||
|
}
|
||||||
}
|
}
|
||||||
if err := k.stamp(&c); err != nil {
|
if err := k.stamp(&c); err != nil {
|
||||||
return Condition{}, err
|
return Condition{}, err
|
||||||
|
|||||||
Reference in New Issue
Block a user