Watchman: a module is unhealthy when its have still says failed a minute after it first did (issue 1952)

A have that turned failed once and stayed unchanged was written once, so the old count of two writes never fired and the
finding was never written (fail2ban on novox). Confirm by time, with a signal, also at a restart.
Quick: raise the count to one write (loses the confirmation). Thorough, chosen: confirm by a time bound, as ADR 0564 s4's
signals are keys that expire, so no write count is needed.

Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL
This commit is contained in:
2026-10-31 21:59:46 +01:00
parent f83835b4b6
commit fb8d2386b9
2 changed files with 31 additions and 13 deletions
@@ -143,18 +143,25 @@ func TestTheWatchmansFindings(t *testing.T) {
w.Provisioned(ProvReport{Node: "g14", Module: "web", Status: ProvFailed, Reason: "x", At: t0.Add(-10 * time.Minute)})
w.Provisioned(ProvReport{Node: "ace", Module: "web", Status: "applied", At: t0})
}, map[string]string{}},
{"WM3: unhealthy only at the second write in a row, urgent after four hours", func(t *testing.T, w *Watchman, o *fakeOut, c *clock) {
{"WM3: unhealthy once a failed have is confirmed after a minute (written once and steady); recovered within it none; urgent after four hours", func(t *testing.T, w *Watchman, o *fakeOut, c *clock) {
w.Have("ace.web", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "the unit failed"), Put)
if len(o.findings) != 0 {
t.Fatalf("one write raised %v", o.findings)
t.Fatalf("raised before its bound: %v", o.findings)
}
w.Have("ace.web", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "the unit failed"), Put)
if o.findings["module.web.ace.unhealthy"].Severity != Warning {
w.Have("ace.quick", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "blip"), Put)
w.Have("ace.quick", haveOf(t, delivery.PhaseRunning, delivery.HealthOK, ""), Put) // recovered within the bound
expire(w, c, signalKey("unhealthy-confirm", "quick.ace"), UnhealthyConfirmAfter)
expire(w, c, signalKey("unhealthy-confirm", "web.ace"), UnhealthyConfirmAfter) // the one write, never repeated
if o.findings["module.web.ace.unhealthy"].Severity != Warning || len(o.findings) != 1 {
t.Fatalf("findings = %v", o.findings)
}
expire(w, c, signalKey("unhealthy", "web.ace"), UnhealthyUrgentAfter)
w.Have("ace.mail", haveOf(t, delivery.PhaseRunning, delivery.HealthWaits, "a part waits for the secret token"), Put) // needs-operator is not observed here
}, map[string]string{"module.web.ace.unhealthy": Urgent}},
{"WM3: a restart replays a have already failed: it is confirmed after a minute like a new one", func(t *testing.T, w *Watchman, o *fakeOut, c *clock) {
w.Have("novox.fail2ban", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "down since 19:40"), Put)
expire(w, c, signalKey("unhealthy-confirm", "fail2ban.novox"), UnhealthyConfirmAfter)
}, map[string]string{"module.fail2ban.novox.unhealthy": Warning}},
{"1954/D2: a provision in waits is its consumer's needs-operator; provided, it ends", func(t *testing.T, w *Watchman, o *fakeOut, c *clock) {
enc := func(state, why string) []byte {
b, err := provisions.Encode(provisions.Provision{Provision: "oidc", Consumer: provisions.End{Module: "photos", Node: "ace"},
@@ -267,7 +274,7 @@ func TestTheWatchmansFindings(t *testing.T) {
}, map[string]string{}},
{"WM3: a have removed ends its findings", func(t *testing.T, w *Watchman, o *fakeOut, c *clock) {
w.Have("ace.mail", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "x"), Put)
w.Have("ace.mail", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "x"), Put)
expire(w, c, signalKey("unhealthy-confirm", "mail.ace"), UnhealthyConfirmAfter)
w.Have("ace.mail", haveOf(t, delivery.PhaseRemoved, delivery.HealthUnknown, ""), Put)
}, map[string]string{}},
{"WM2 S1: a control node silent is urgent after half an hour", func(t *testing.T, w *Watchman, o *fakeOut, c *clock) {
@@ -314,7 +321,7 @@ func TestTheWatchmansFindings(t *testing.T) {
}, map[string]string{}},
{"WM4: resync after a cleared bucket writes the same findings", func(t *testing.T, w *Watchman, o *fakeOut, c *clock) {
w.Have("ace.mail", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "x"), Put)
w.Have("ace.mail", haveOf(t, delivery.PhaseRunning, delivery.HealthFailed, "x"), Put)
expire(w, c, signalKey("unhealthy-confirm", "mail.ace"), UnhealthyConfirmAfter)
o.findings = map[string]Finding{}
if n := w.Rewrite(); n != 1 {
t.Fatalf("rewrote %d", n)
@@ -27,7 +27,7 @@ import (
// - S11, a machine's tool runner heartbeat on `mesh.control.<node>.tools-alive`: a pulse of three intervals;
// - S21, a module's have failed: a pulse of one apply interval from the first failure, whose expiry while it still fails
// is the finding `apply-failing`;
// - a module's have unhealthy in two writes in a row, `unhealthy`, urgent after four hours; and a have that waits for
// - a module's have still failed a minute after it first said so, `unhealthy`, urgent after four hours; and a have that waits for
// the operator, `needs-operator` (ADR 0240 §12, §17).
// The bounds of the rows.
@@ -43,6 +43,8 @@ const (
HeartbeatEvery = 60 * time.Second
// ApplyEvery is one apply interval (S21): a failure still there after it is not one the next apply clears.
ApplyEvery = 5 * time.Minute
// UnhealthyConfirmAfter is how long a have must keep saying failed before the module is said unhealthy.
UnhealthyConfirmAfter = time.Minute
// UnhealthyUrgentAfter is how long a module stays unhealthy before it is urgent.
UnhealthyUrgentAfter = 4 * time.Hour
// SilentBound is the bound S1 says, three of the intervals a machine has always used, and ControlNodeUrgentAfter
@@ -471,6 +473,7 @@ func (w *Watchman) haveFindings(key string, node, module string, h *delivery.Hav
delete(w.haveState, key)
delete(w.unhealthy, key)
delete(w.failedSince, key)
w.unsignal("unhealthy-confirm", module+"."+node)
w.unsignal("unhealthy", module+"."+node)
w.unfind(unhealthyKey)
w.applyCheck(node)
@@ -489,21 +492,29 @@ func (w *Watchman) haveFindings(key string, node, module string, h *delivery.Hav
}
w.applyCheck(node)
// unhealthy: two writes in a row that say it failed.
// unhealthy: a have that says failed and still says it after UnhealthyConfirmAfter (ADR 0564 §4's confirmation, by time:
// a have written once and then unchanged never gets a second write). The confirm signal's expiry writes the warning; a
// signal already standing (kept across a restart) is not renewed, so a steady have does not push its own expiry out.
if h.Health == delivery.HealthFailed {
w.unhealthy[key]++
if w.unhealthy[key] == 2 {
if w.unhealthy[key] == 0 {
w.unhealthy[key] = 1
f := Finding{Scope: ScopeModule, ID: module + "." + node, Token: "unhealthy", Kind: KindUnhealthy, Machine: node,
Severity: Warning, Source: "health", Since: now,
Summary: fmt.Sprintf("%s on %s is not healthy: %s", module, node, orWords(h.Detail, "its check failed")),
Said: firstLine(orWords(h.Detail, "failed")),
Headline: fmt.Sprintf("%s not working on %s", module, node)}
w.find(f)
f.Severity = Urgent
w.signal("unhealthy", module+"."+node, UnhealthyUrgentAfter, signalDue{Do: dueFind, While: key, Finding: f})
id := module + "." + node
if _, ok := w.signals[signalKey("unhealthy-confirm", id)]; !ok {
w.signal("unhealthy-confirm", id, UnhealthyConfirmAfter, signalDue{Do: dueFind, While: key, Finding: f})
}
if _, ok := w.signals[signalKey("unhealthy", id)]; !ok {
f.Severity = Urgent
w.signal("unhealthy", id, UnhealthyUrgentAfter, signalDue{Do: dueFind, While: key, Finding: f})
}
}
} else {
delete(w.unhealthy, key)
w.unsignal("unhealthy-confirm", module+"."+node)
w.unsignal("unhealthy", module+"."+node)
w.unfind(unhealthyKey)
}