Say on a failed provisioning report when the failure began, kept while only its words change (issue 774)

The client dated each report with the time it was said, and says a failure again whenever its words change, so the controller's apply-failing alarm, which reads that time, saw a new failure: on novox the vault's refusal replaced a bus refusal at 16:56 and the alarm cleared for five minutes while every module still failed. Quick fix: the controller keeps a raised alarm while any failure stands (done there). Thorough fix: the report says failing-since, kept from the module's last report (this run's, else the applied bucket's) while it stays failed, whatever its reason says; any other status ends it. Chose both: the controller can now judge the failure's age rather than its newest words, which is its change to make.
2026-10-30 18:32:30 +01:00
parent f3b13de20d
commit 3aae6c0890
2 changed files with 76 additions and 0 deletions
@@ -80,6 +80,26 @@ type Report struct {
 	// Items are the collections the module's items are recorded in on this node (design 57 L1).
 	Items []string  `json:"items,omitempty"`
 	At    time.Time `json:"at"`
+	// FailingSince is, on a failed report, when the module's standing failure began: kept while it stays failed, however
+	// its reason's words change, so the controller's apply-failing alarm judges the failure's age, not its newest words
+	// (the sweep of 2026-10-30, issue 774). Empty on any other status.
+	FailingSince time.Time `json:"failing-since,omitzero"`
+}
+
+// failingSince is when the failure r says began: before's when the module's last report was a failure too, whatever
+// its words; else now. Zero when r is no failure.
+func failingSince(r Report, before *Report, now time.Time) time.Time {
+	switch {
+	case r.Status != StatusFailed:
+		return time.Time{}
+	case before == nil || before.Status != StatusFailed:
+		return now
+	case !before.FailingSince.IsZero():
+		return before.FailingSince
+	case !before.At.IsZero():
+		return before.At // a report from before the field: its time is the oldest known
+	}
+	return now
 }

 // FileApplied is one file as the node-engine wrote it.
@@ -139,6 +159,7 @@ type state struct {
 	config                        map[string]map[string]json.RawMessage
 	applied                       map[string]bool       // module → a report is kept
 	reported                      map[string][]byte     // module → the last report said, undated
+	last                          map[string]Report     // module → the last report said, dated
 	secrets                       map[string]heldSecret // the vault's name → what this run holds of it; never written anywhere
 	// items is every item recorded for this node, by collection and contributor: what a collector is filled from.
 	items map[string]map[string]itemValue
@@ -940,6 +961,7 @@ func (c *Client) report(ctx context.Context, kvs map[string]jetstream.KeyValue,
 		return
 	}
 	r.At = c.now()
+	r.FailingSince = failingSince(r, c.lastReport(ctx, kvs, s, r.Module), r.At)
 	body, err := json.Marshal(r)
 	if err != nil {
 		logf("[provisioner-client] the report of %s: %v", r.Module, err)
@@ -952,6 +974,10 @@ func (c *Client) report(ctx context.Context, kvs map[string]jetstream.KeyValue,
 	}
 	c.publish(r)
 	s.reported[r.Module] = undated
+	if s.last == nil {
+		s.last = map[string]Report{}
+	}
+	s.last[r.Module] = r
 	switch r.Status {
 	case StatusFailed:
 		logf("[provisioner-client] %s failed: %s", r.Module, r.Reason)
@@ -960,6 +986,27 @@ func (c *Client) report(ctx context.Context, kvs map[string]jetstream.KeyValue,
 	}
 }

+// lastReport is the module's last report: this run's, else the one kept in the applied bucket by a run before; nil when
+// none can be read.
+func (c *Client) lastReport(ctx context.Context, kvs map[string]jetstream.KeyValue, s *state, module string) *Report {
+	if r, ok := s.last[module]; ok {
+		return &r
+	}
+	kv := kvs[AppliedBucket]
+	if kv == nil {
+		return nil
+	}
+	e, err := kv.Get(ctx, c.Node+"."+module)
+	if err != nil {
+		return nil
+	}
+	var r Report
+	if json.Unmarshal(e.Value(), &r) != nil {
+		return nil
+	}
+	return &r
+}
+
 func (c *Client) publish(r Report) {
 	body, err := json.Marshal(r)
 	if err != nil {
@@ -826,3 +826,32 @@ func planned(assignment string) ([]byte, bool) {
 	raw, _ := json.Marshal(map[string]any{"v": 1, "node": a.Node, "module": a.Module, "plan": a.Provisioning})
 	return raw, true
 }
+
+// A standing failure keeps when it began while only its words change, so the controller's apply-failing alarm judges
+// its age (the sweep of 2026-10-30, issue 774: novox's reason changed at 16:56 and the alarm cleared for five minutes
+// while every module still failed); it begins anew after any other status, and a report from before the field gives
+// its time.
+func TestAFailureKeepsWhenItBeganWhileItsWordsChange(t *testing.T) {
+	t0 := time.Date(2026, 10, 30, 15, 0, 0, 0, time.UTC)
+	now := t0.Add(time.Hour)
+	failed := func(why string, since time.Time) *Report {
+		return &Report{Status: StatusFailed, Reason: why, At: since.Add(time.Minute), FailingSince: since}
+	}
+	for _, row := range []struct {
+		name   string
+		r      Report
+		before *Report
+		want   time.Time
+	}{
+		{"a first failure", Report{Status: StatusFailed, Reason: "a"}, nil, now},
+		{"the same failure in other words", Report{Status: StatusFailed, Reason: "the vault refused it"}, failed("bus refused", t0), t0},
+		{"a failure after an apply", Report{Status: StatusFailed, Reason: "a"}, &Report{Status: StatusApplied, At: t0}, now},
+		{"a failure after waiting", Report{Status: StatusFailed, Reason: "a"}, &Report{Status: StatusWaiting, At: t0}, now},
+		{"a report from before the field", Report{Status: StatusFailed, Reason: "b"}, &Report{Status: StatusFailed, Reason: "a", At: t0}, t0},
+		{"an apply", Report{Status: StatusApplied}, failed("a", t0), time.Time{}},
+	} {
+		if got := failingSince(row.r, row.before, now); !got.Equal(row.want) {
+			t.Errorf("%s: failing since %v, want %v", row.name, got, row.want)
+		}
+	}
+}