From 0560684b358f4f07eb8db8cad84baa0f2dbc7b7b Mon Sep 17 00:00:00 2001 From: claude Date: Wed, 5 Aug 2026 02:27:22 +0400 Subject: [PATCH] kuma: a monitor must stay down before it wakes him (V-536) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Technitium read down on one poll and up on the next, sixty seconds apart, and the sev4 arrived after the service was already back. mavpoll writes a service_down fact only when the state changes, so the fact's timestamp IS the moment the monitor went down and its age is how long it has stayed there. The debounce is that age against MinDownAge, 90s — one poll interval plus jitter. No history to keep and no counter to persist. It bounds the alarm and not the truth: DownServices still reports a monitor the instant it goes down, because /dash showing a fresh outage is right even when phoning him about it is not. Existing fixtures that seeded a one-minute-old down fact now seed five, which is what they always meant. --- cmd/mavend/alarm_stop_test.go | 8 ++-- cmd/mavend/tick_test.go | 4 +- internal/loop/explain_test.go | 4 +- internal/loop/gate_test.go | 2 +- internal/loop/gather_test.go | 4 +- internal/loop/loop_test.go | 6 +-- internal/loop/rules.go | 52 +++++++++++++++++++----- internal/loop/rules_test.go | 74 +++++++++++++++++++++++++++-------- 8 files changed, 115 insertions(+), 39 deletions(-) diff --git a/cmd/mavend/alarm_stop_test.go b/cmd/mavend/alarm_stop_test.go index 81d9242..cc57d7f 100644 --- a/cmd/mavend/alarm_stop_test.go +++ b/cmd/mavend/alarm_stop_test.go @@ -72,7 +72,7 @@ func TestAlarmStopsWhenTheServiceComesBackUp(t *testing.T) { st := newTestStore(t) ctx := context.Background() now := refNow() - seedDown(t, st, ctx, "down", now) + seedDown(t, st, ctx, "down", now.Add(-5*time.Minute)) sink := &fakeSink{} tl := newAlarmTickLoop(t, st, sink) @@ -101,7 +101,7 @@ func TestAlarmStopsAtTheAgeCapWhileStillDown(t *testing.T) { st := newTestStore(t) ctx := context.Background() now := refNow() - seedDown(t, st, ctx, "down", now) + seedDown(t, st, ctx, "down", now.Add(-5*time.Minute)) sink := &fakeSink{} tl := newAlarmTickLoop(t, st, sink) @@ -132,7 +132,7 @@ func TestAFlapRaisesAFreshAlarmRatherThanReviveTheClosedOne(t *testing.T) { st := newTestStore(t) ctx := context.Background() now := refNow() - seedDown(t, st, ctx, "down", now) + seedDown(t, st, ctx, "down", now.Add(-5*time.Minute)) sink := &fakeSink{} tl := newAlarmTickLoop(t, st, sink) @@ -145,7 +145,7 @@ func TestAFlapRaisesAFreshAlarmRatherThanReviveTheClosedOne(t *testing.T) { t.Fatalf("closing the run changed the row count: %d → %d", first, len(got)) } - seedDown(t, st, ctx, "down", now.Add(30*time.Minute)) + seedDown(t, st, ctx, "down", now.Add(25*time.Minute)) sink.sends = nil tl.tick(ctx, now.Add(31*time.Minute)) diff --git a/cmd/mavend/tick_test.go b/cmd/mavend/tick_test.go index c2c4ac9..43646ee 100644 --- a/cmd/mavend/tick_test.go +++ b/cmd/mavend/tick_test.go @@ -584,7 +584,9 @@ func TestDigestSev4BypassesQueue(t *testing.T) { ctx := context.Background() now := refNow() markPresent(t, st, ctx, now) - if _, err := st.SetValue(ctx, store.KindSelf, "service_down:db", "poll:uptimekuma", "down", now); err != nil { + // Older than loop.MinDownAge, so this tests the digest bypass and not the + // flap debounce (Vikunja #536). + if _, err := st.SetValue(ctx, store.KindSelf, "service_down:db", "poll:uptimekuma", "down", now.Add(-5*time.Minute)); err != nil { t.Fatalf("seed service_down: %v", err) } sink := &fakeSink{} diff --git a/internal/loop/explain_test.go b/internal/loop/explain_test.go index 1110106..603e238 100644 --- a/internal/loop/explain_test.go +++ b/internal/loop/explain_test.go @@ -103,7 +103,7 @@ func TestExplainGate_PresenceAway(t *testing.T) { func TestExplainGate_PresenceAwayOpsBypass(t *testing.T) { now := refTime() s := State{Now: now, Presence: store.Away, - Facts: map[string]store.Fact{"service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-1*time.Minute))}, + Facts: map[string]store.Fact{"service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-5*time.Minute))}, } r := ServiceDownRule() // Sev4 ops passed, blocked, d := ExplainGate(s, r) @@ -260,7 +260,7 @@ func TestExplainTick_WinnerRecorded(t *testing.T) { Presence: store.Present, Facts: map[string]store.Fact{ "water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour)), - "service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-1*time.Minute)), + "service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-5*time.Minute)), }, } cand, trace := ExplainTick(s, DefaultRules()) diff --git a/internal/loop/gate_test.go b/internal/loop/gate_test.go index 4ad6e90..c8195ed 100644 --- a/internal/loop/gate_test.go +++ b/internal/loop/gate_test.go @@ -202,7 +202,7 @@ func TestTickNeverDogpilesAndPicksLoudest(t *testing.T) { "meal": ago("meal", "voice", `"lunch"`, 8*time.Hour), "desk_active": ago("desk_active", "infer:hyprland", "1", 30*time.Second), "break": ago("break", "voice", `"walk"`, 3*time.Hour), - "service_down:db": ago("service_down:db", "poll:uptimekuma", `"down"`, time.Minute), + "service_down:db": ago("service_down:db", "poll:uptimekuma", `"down"`, 5*time.Minute), "netdata_alarm": ago("netdata_alarm", "poll:netdata", `"critical"`, time.Minute), }, } diff --git a/internal/loop/gather_test.go b/internal/loop/gather_test.go index c854eba..b4bc97c 100644 --- a/internal/loop/gather_test.go +++ b/internal/loop/gather_test.go @@ -25,7 +25,9 @@ func TestGatherStateLoadsPrefixFamilies(t *testing.T) { "service_down:db": "down", "service_down:web": "up", } { - if _, err := s.SetValue(ctx, store.KindEnv, key, ServiceDownSource, val, now.Add(-time.Minute)); err != nil { + // Older than MinDownAge, so this tests the gather path and not the + // flap debounce. + if _, err := s.SetValue(ctx, store.KindEnv, key, ServiceDownSource, val, now.Add(-5*time.Minute)); err != nil { t.Fatalf("SetValue %s: %v", key, err) } } diff --git a/internal/loop/loop_test.go b/internal/loop/loop_test.go index 0f5cf1a..14d3451 100644 --- a/internal/loop/loop_test.go +++ b/internal/loop/loop_test.go @@ -82,7 +82,7 @@ func TestTickOpsHardSurvivesAwayAndQuiet(t *testing.T) { Presence: store.Away, QuietHours: true, Facts: map[string]store.Fact{ - "service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-1*time.Minute)), + "service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-5*time.Minute)), }, } got := Tick(s, DefaultRules()) @@ -99,7 +99,7 @@ func TestTickServiceSourceTrustRefusesForgedTrigger(t *testing.T) { Now: now, Presence: store.Present, Facts: map[string]store.Fact{ - "service_down:db": factAt("service_down:db", "ambient", `"down"`, now.Add(-1*time.Minute)), + "service_down:db": factAt("service_down:db", "ambient", `"down"`, now.Add(-5*time.Minute)), }, } if got := Tick(s, DefaultRules()); got != nil { @@ -116,7 +116,7 @@ func TestTickOneNudgePerTickMaxSeverityWins(t *testing.T) { Presence: store.Present, Facts: map[string]store.Fact{ "water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour)), - "service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-1*time.Minute)), + "service_down:db": factAt("service_down:db", "poll:uptimekuma", `"down"`, now.Add(-5*time.Minute)), }, } got := Tick(s, DefaultRules()) diff --git a/internal/loop/rules.go b/internal/loop/rules.go index e062df6..aa6ed21 100644 --- a/internal/loop/rules.go +++ b/internal/loop/rules.go @@ -144,6 +144,44 @@ func DownServices(s State) []string { return out } +// MinDownAge — how long a monitor must have read "down" before it is worth +// waking him (Vikunja #536). +// +// Technitium read down on one kuma poll and up on the next, sixty seconds +// apart, and the alarm arrived after the service was already back. mavpoll +// writes a service_down fact only when the state CHANGES, so the fact's +// timestamp is the instant the monitor went down and its age is how long it +// has stayed there. That is the whole debounce: no history to keep, no counter +// to persist. +// +// Ninety seconds is one poll interval plus room for jitter, so a monitor must +// survive at least one further poll as down. The cost is up to ninety seconds +// of alarm latency on a real outage, against never being paged for a blip. +// +// It bounds the alarm, not the truth: DownServices still reports a monitor the +// instant it goes down, because /dash showing a fresh outage is right even +// when phoning him about it is not. +const MinDownAge = 90 * time.Second + +// downLongEnough — the newest down fact that has aged past MinDownAge, or the +// zero time when no monitor has. The rule fires off this and not off the +// newest down fact outright. +func downLongEnough(s State, now time.Time) time.Time { + var newest time.Time + for _, f := range s.FactsUnder(ServiceDownPrefix) { + if f.Source != ServiceDownSource || f.Value != `"down"` { + continue + } + if now.Sub(f.Ts) < MinDownAge { + continue + } + if f.Ts.After(newest) { + newest = f.Ts + } + } + return newest +} + // ServiceDownRule — sev4 ops hard: at least one kuma monitor reads "down". // // It used to read one aggregate `service_down` fact, which is why it was @@ -160,17 +198,11 @@ func ServiceDownRule() Rule { Cooldown: Cooldown{Base: 15 * time.Minute, Min: 5 * time.Minute, Max: 1 * time.Hour}, WantPrefixes: []string{ServiceDownPrefix}, Predicate: func(s State) bool { - var newest time.Time - for _, f := range s.FactsUnder(ServiceDownPrefix) { - if f.Source != ServiceDownSource || f.Value != `"down"` { - continue - } - if f.Ts.After(newest) { - newest = f.Ts - } - } + newest := downLongEnough(s, s.Now) if newest.IsZero() { - return false // nothing down, or no data at all → shut up + // Nothing down, no data at all, or nothing down long enough + // to be more than a flap → shut up. See MinDownAge. + return false } return !s.NudgedSince("service_down", newest) }, diff --git a/internal/loop/rules_test.go b/internal/loop/rules_test.go index 70cc11c..0c081bc 100644 --- a/internal/loop/rules_test.go +++ b/internal/loop/rules_test.go @@ -193,13 +193,13 @@ func TestOpsRulePredicates(t *testing.T) { { name: "service_down fires on a kuma down fact", rule: ServiceDownRule(), - facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma", `"down"`, time.Minute)}, + facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma", `"down"`, 5*time.Minute)}, want: true, }, { name: "service_down quiet when kuma says up", rule: ServiceDownRule(), - facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma", `"up"`, time.Minute)}, + facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma", `"up"`, 5*time.Minute)}, want: false, }, { @@ -218,31 +218,31 @@ func TestOpsRulePredicates(t *testing.T) { { name: "service_down refuses a forgery from the netdata poller", rule: ServiceDownRule(), - facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:netdata", `"down"`, time.Minute)}, + facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:netdata", `"down"`, 5*time.Minute)}, want: false, }, { name: "service_down refuses a forgery from ambient audio", rule: ServiceDownRule(), - facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "ambient:other", `"down"`, time.Minute)}, + facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "ambient:other", `"down"`, 5*time.Minute)}, want: false, }, { name: "service_down refuses a forgery from the user's own voice", rule: ServiceDownRule(), - facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "voice", `"down"`, time.Minute)}, + facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "voice", `"down"`, 5*time.Minute)}, want: false, }, { name: "service_down refuses a source that only looks like kuma", rule: ServiceDownRule(), - facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma-staging", `"down"`, time.Minute)}, + facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma-staging", `"down"`, 5*time.Minute)}, want: false, }, { name: "service_down refuses an unquoted down value", rule: ServiceDownRule(), - facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma", `down`, time.Minute)}, + facts: map[string]store.Fact{"service_down:db": ago("service_down:db", "poll:uptimekuma", `down`, 5*time.Minute)}, want: false, }, @@ -383,7 +383,7 @@ func TestPredicatesArePure(t *testing.T) { "meal": ago("meal", "voice", `"lunch"`, 7*time.Hour), "desk_active": ago("desk_active", "infer:hyprland", "1", 30*time.Second), "break": ago("break", "voice", `"walk"`, 2*time.Hour), - "service_down:db": ago("service_down:db", "poll:uptimekuma", `"down"`, time.Minute), + "service_down:db": ago("service_down:db", "poll:uptimekuma", `"down"`, 5*time.Minute), }) for _, r := range DefaultRules() { first := r.Predicate(s) @@ -445,12 +445,12 @@ func TestDownServicesNamesOnlyTheDownOnes(t *testing.T) { s := State{ Now: refTime(), Facts: map[string]store.Fact{ - "service_down:web": ago("service_down:web", ServiceDownSource, `"up"`, time.Minute), - "service_down:db": ago("service_down:db", ServiceDownSource, `"down"`, time.Minute), - "service_down:vault": ago("service_down:vault", ServiceDownSource, `"down"`, time.Minute), - "service_down:paused": ago("service_down:paused", ServiceDownSource, `"maintenance"`, time.Minute), - "service_down:forged": ago("service_down:forged", "voice", `"down"`, time.Minute), - "service_down:missing": ago("service_down:missing", ServiceDownSource, `"unknown"`, time.Minute), + "service_down:web": ago("service_down:web", ServiceDownSource, `"up"`, 5*time.Minute), + "service_down:db": ago("service_down:db", ServiceDownSource, `"down"`, 5*time.Minute), + "service_down:vault": ago("service_down:vault", ServiceDownSource, `"down"`, 5*time.Minute), + "service_down:paused": ago("service_down:paused", ServiceDownSource, `"maintenance"`, 5*time.Minute), + "service_down:forged": ago("service_down:forged", "voice", `"down"`, 5*time.Minute), + "service_down:missing": ago("service_down:missing", ServiceDownSource, `"unknown"`, 5*time.Minute), }, } got := DownServices(s) @@ -469,8 +469,8 @@ func TestDownServicesNamesOnlyTheDownOnes(t *testing.T) { // the aggregate stayed "down" and pausing achieved nothing. func TestPausedMonitorSilencesOnlyItself(t *testing.T) { base := map[string]store.Fact{ - "service_down:db": ago("service_down:db", ServiceDownSource, `"maintenance"`, time.Minute), - "service_down:web": ago("service_down:web", ServiceDownSource, `"down"`, time.Minute), + "service_down:db": ago("service_down:db", ServiceDownSource, `"maintenance"`, 5*time.Minute), + "service_down:web": ago("service_down:web", ServiceDownSource, `"down"`, 5*time.Minute), } if !ServiceDownRule().Predicate(State{Now: refTime(), Facts: base}) { t.Fatal("web is still down, the rule must fire") @@ -494,8 +494,48 @@ func TestServiceDownFiresOncePerTransition(t *testing.T) { t.Fatal("already told about this transition, must be quiet") } // A second service goes down after that nudge — a new edge, so it fires. - s.Facts["service_down:web"] = ago("service_down:web", ServiceDownSource, `"down"`, time.Minute) + s.Facts["service_down:web"] = ago("service_down:web", ServiceDownSource, `"down"`, 5*time.Minute) if !ServiceDownRule().Predicate(s) { t.Fatal("a later transition must fire again") } } + +// A monitor that reads down on one poll and up on the next raises nothing +// (Vikunja #536). Technitium did exactly that at 01:27:59 on 05-08-2026, and +// the alarm arrived after the service was already back. +func TestAFlappingMonitorRaisesNothing(t *testing.T) { + fresh := ago("service_down:dns", ServiceDownSource, `"down"`, 10*time.Second) + s := State{Now: refTime(), Facts: map[string]store.Fact{"service_down:dns": fresh}} + if ServiceDownRule().Predicate(s) { + t.Fatal("a monitor down for ten seconds must not wake him") + } + // It stays down. mavpoll writes only on change, so the fact does not move + // and its age is how long the outage has run. + s.Now = fresh.Ts.Add(MinDownAge) + if !ServiceDownRule().Predicate(s) { + t.Fatal("past MinDownAge this is a real outage and must fire") + } +} + +// The debounce bounds the alarm, not the truth. /dash reads DownServices and +// showing a fresh outage there is right even when phoning him about it is not. +func TestDownServicesReportsAFreshOutage(t *testing.T) { + s := State{ + Now: refTime(), + Facts: map[string]store.Fact{"service_down:dns": ago("service_down:dns", ServiceDownSource, `"down"`, 10*time.Second)}, + } + if got := DownServices(s); len(got) != 1 || got[0] != "dns" { + t.Fatalf("DownServices = %v, want [dns]", got) + } +} + +// One monitor flapping must not hide another that has been down for an hour. +func TestAFlapDoesNotMaskARealOutage(t *testing.T) { + s := State{Now: refTime(), Facts: map[string]store.Fact{ + "service_down:dns": ago("service_down:dns", ServiceDownSource, `"down"`, 10*time.Second), + "service_down:db": ago("service_down:db", ServiceDownSource, `"down"`, time.Hour), + }} + if !ServiceDownRule().Predicate(s) { + t.Fatal("db has been down an hour, the rule must fire") + } +}