diff --git a/cmd/mavend/alarm_stop_test.go b/cmd/mavend/alarm_stop_test.go new file mode 100644 index 0000000..81d9242 --- /dev/null +++ b/cmd/mavend/alarm_stop_test.go @@ -0,0 +1,186 @@ +package main + +import ( + "context" + "testing" + "time" + + "github.com/kami/maven/internal/delivery" + "github.com/kami/maven/internal/loop" + "github.com/kami/maven/internal/phraser" + "github.com/kami/maven/internal/store" +) + +// The sev4 repeat path had no off switch (Vikunja #535): it re-sent every +// pending telegram nudge every repeat_interval, and nothing in the tree could +// ever mark one acked. None of what follows can be reproduced by hand without +// sitting in front of the box for hours, so it is covered here or nowhere. + +// seedDown writes one kuma monitor fact at ts. value is "down" or "up". +func seedDown(t *testing.T, st *store.Store, ctx context.Context, value string, ts time.Time) { + t.Helper() + if _, err := st.SetValue(ctx, store.KindSelf, "service_down:db", "poll:uptimekuma", value, ts); err != nil { + t.Fatalf("seed service_down:db=%s: %v", value, err) + } +} + +// newAlarmTickLoop — like newTestTickLoop but with the ack tracker wired, which +// the shared helper leaves nil. Without it RepeatUnacked returns early and the +// repeat these tests are about never happens. The daemon wires it (main.go). +func newAlarmTickLoop(t *testing.T, st *store.Store, sink delivery.Sink) *tickLoop { + t.Helper() + rules := loop.DefaultRules() + g := loop.NewGatherer(st, rules) + d := delivery.NewDispatcher(delivery.Config{ + Voice: sink, Ntfy: sink, Telegram: sink, + Ack: st, Nudges: st, Reminders: st, + }) + return newTickLoop(st, g, d, phraser.NewStub(), rules, time.Second, 5*time.Minute, 0, nil, nil, nil, nil) +} + +// telegramSends counts sends that went out on the telegram reach. +func telegramSends(sink *fakeSink, rule string) int { + n := 0 + for _, s := range sink.sends { + if s.RuleName == rule { + n++ + } + } + return n +} + +// outcomes returns the outcome of every nudge row for a rule, newest first. +func outcomes(t *testing.T, st *store.Store, ctx context.Context, rule string) []string { + t.Helper() + rows, err := st.RecentNudges(ctx, 50) + if err != nil { + t.Fatalf("recent nudges: %v", err) + } + var out []string + for _, n := range rows { + if n.Rule == rule { + out = append(out, n.Outcome) + } + } + return out +} + +func TestAlarmStopsWhenTheServiceComesBackUp(t *testing.T) { + // The condition clearing is the ending that should happen. StillTrue reads + // the same DownServices helper the phraser reads, so the repeat stops on + // exactly the monitor he was told about. + st := newTestStore(t) + ctx := context.Background() + now := refNow() + seedDown(t, st, ctx, "down", now) + + sink := &fakeSink{} + tl := newAlarmTickLoop(t, st, sink) + tl.tick(ctx, now) + if telegramSends(sink, "service_down") == 0 { + t.Fatal("the alarm never went out; the rest of this test proves nothing") + } + + seedDown(t, st, ctx, "up", now.Add(time.Minute)) + sink.sends = nil + tl.tick(ctx, now.Add(6*time.Minute)) // past repeat_interval + + if n := telegramSends(sink, "service_down"); n != 0 { + t.Fatalf("repeated %d time(s) after the service came back up; want 0", n) + } + for _, o := range outcomes(t, st, ctx, "service_down") { + if o != store.NudgeResolved { + t.Fatalf("nudge outcome = %q, want %q", o, store.NudgeResolved) + } + } +} + +func TestAlarmStopsAtTheAgeCapWhileStillDown(t *testing.T) { + // Still down, still un-acked, and nobody has answered in two hours. That is + // not one more repeat away from being answered. + st := newTestStore(t) + ctx := context.Background() + now := refNow() + seedDown(t, st, ctx, "down", now) + + sink := &fakeSink{} + tl := newAlarmTickLoop(t, st, sink) + tl.tick(ctx, now) + + sink.sends = nil + tl.tick(ctx, now.Add(6*time.Minute)) + if n := telegramSends(sink, "service_down"); n == 0 { + t.Fatal("no repeat inside the cap; the cap is not what stopped it later") + } + + sink.sends = nil + tl.tick(ctx, now.Add(maxAlarmAge+time.Minute)) + if n := telegramSends(sink, "service_down"); n != 0 { + t.Fatalf("repeated %d time(s) past the %s cap; want 0", n, maxAlarmAge) + } + // Ignored, not resolved: nothing says the service got better. + for _, o := range outcomes(t, st, ctx, "service_down") { + if o != store.NudgeIgnored { + t.Fatalf("nudge outcome = %q, want %q", o, store.NudgeIgnored) + } + } +} + +func TestAFlapRaisesAFreshAlarmRatherThanReviveTheClosedOne(t *testing.T) { + // Down, up, down again. Closing the first run must not make the second run + // unreportable, and must not silently reopen the closed rows either. + st := newTestStore(t) + ctx := context.Background() + now := refNow() + seedDown(t, st, ctx, "down", now) + + sink := &fakeSink{} + tl := newAlarmTickLoop(t, st, sink) + tl.tick(ctx, now) + first := len(outcomes(t, st, ctx, "service_down")) + + seedDown(t, st, ctx, "up", now.Add(time.Minute)) + tl.tick(ctx, now.Add(2*time.Minute)) + if got := outcomes(t, st, ctx, "service_down"); len(got) != first { + t.Fatalf("closing the run changed the row count: %d → %d", first, len(got)) + } + + seedDown(t, st, ctx, "down", now.Add(30*time.Minute)) + sink.sends = nil + tl.tick(ctx, now.Add(31*time.Minute)) + + if n := telegramSends(sink, "service_down"); n == 0 { + t.Fatal("the second outage said nothing; the first alarm's ending swallowed it") + } + got := outcomes(t, st, ctx, "service_down") + if len(got) <= first { + t.Fatalf("no new nudge row for the second outage (%d rows, was %d)", len(got), first) + } +} + +func TestARuleThatSaysNothingAboutItsConditionOnlyStopsOnAge(t *testing.T) { + // StillTrue == nil means "I cannot tell you", never "it cleared". A rule + // that says nothing must keep its alarm until the age cap, or a rule author + // silences their own alarm by omission. + st := newTestStore(t) + ctx := context.Background() + now := refNow() + + sink := &fakeSink{} + tl := newAlarmTickLoop(t, st, sink) + tl.rules = []loop.Rule{{Name: "mute", Severity: loop.Sev4}} // no StillTrue + + if _, err := st.RecordNudge(ctx, "mute", string(delivery.ChannelTelegram), "still bad", now); err != nil { + t.Fatalf("record nudge: %v", err) + } + + live := tl.stopFinishedAlarms(ctx, []string{"mute"}, loop.State{}, now.Add(time.Minute)) + if len(live) != 1 { + t.Fatalf("a nil StillTrue was read as resolved: live = %v", live) + } + + live = tl.stopFinishedAlarms(ctx, []string{"mute"}, loop.State{}, now.Add(maxAlarmAge+time.Minute)) + if len(live) != 0 { + t.Fatalf("the age cap did not stop a rule with no StillTrue: live = %v", live) + } +} diff --git a/cmd/mavend/tick.go b/cmd/mavend/tick.go index 3c7b0a0..2c3563f 100644 --- a/cmd/mavend/tick.go +++ b/cmd/mavend/tick.go @@ -10,6 +10,7 @@ package main import ( "context" + "errors" "fmt" "log" "os" @@ -249,6 +250,7 @@ func (t *tickLoop) tick(ctx context.Context, now time.Time) { return } keys = t.repeatableRules(keys) + keys = t.stopFinishedAlarms(ctx, keys, state, now) if len(keys) == 0 { return } @@ -260,6 +262,83 @@ func (t *tickLoop) tick(ctx context.Context, now time.Time) { } } +// maxAlarmAge — how long one un-acked telegram alarm may keep repeating. +// +// This is the floor brake and it applies to every rule, including one that +// says nothing about its own condition (Vikunja #535). Nothing in the tree can +// ack a telegram nudge: MarkAcked has no caller outside internal/store, and the +// only ack that exists is a voice "готово" on a box that runs no voice loop. So +// "repeat until acked" meant "repeat forever", and it did — every five minutes +// for over two hours. +// +// Two hours at the five-minute default is about 24 messages, which is already +// past the point of being read. An alarm nobody answered in two hours is not +// one more repeat away from being answered, and the right move is to stop +// talking, not to talk louder. +const maxAlarmAge = 2 * time.Hour + +// stopFinishedAlarms returns the keys that may still repeat, and closes the +// rest. +// +// Two ways an alarm ends without him. The condition cleared, which the rule +// answers through StillTrue — deliberately NOT Predicate, which is +// edge-triggered and reads false one tick after the alarm is raised, so using +// it would cancel every alarm immediately. Or the alarm simply got old, which +// is the bound that does not need the rule's cooperation. +// +// A rule with no StillTrue is not treated as resolved. Silence about the +// condition is not evidence the condition cleared, so those keys only ever stop +// on age. +func (t *tickLoop) stopFinishedAlarms(ctx context.Context, keys []string, state loop.State, now time.Time) []string { + if len(keys) == 0 { + return nil + } + byName := make(map[string]loop.Rule, len(t.rules)) + for _, r := range t.rules { + byName[r.Name] = r + } + live := keys[:0:0] + for _, key := range keys { + outcome := "" + switch r := byName[key]; { + case r.StillTrue != nil && !r.StillTrue(state): + outcome = store.NudgeResolved + case t.alarmIsOlderThan(ctx, key, maxAlarmAge, now): + // Not "resolved": nothing says the thing got better. This is her + // giving up on being answered, and /notifications should say so. + outcome = store.NudgeIgnored + } + if outcome == "" { + live = append(live, key) + continue + } + n, err := t.store.ResolvePendingTelegram(ctx, key, outcome, now) + if err != nil { + // Could not close it, so do not drop it either: repeating is the + // lesser fault against losing the alarm entirely. + log.Printf("tick: stop alarm %s: %v", key, err) + live = append(live, key) + continue + } + log.Printf("tick: alarm %s ended (%s), %d pending nudge(s) closed", key, outcome, n) + } + return live +} + +// alarmIsOlderThan reports whether the oldest un-acked send for this rule is +// past the cap. A read failure answers false: an alarm that repeats one more +// time is better than one silenced by a transient store error. +func (t *tickLoop) alarmIsOlderThan(ctx context.Context, rule string, age time.Duration, now time.Time) bool { + oldest, err := t.store.OldestPendingTelegram(ctx, rule) + if err != nil { + if !errors.Is(err, store.ErrNudgeNotFound) { + log.Printf("tick: oldest pending %s: %v", rule, err) + } + return false + } + return now.Sub(oldest) >= age +} + // repeatableRules drops keys whose rule is not wired any more. // // The repeat path reads the nudges table, not the rule set: any sev4 telegram diff --git a/internal/loop/rules.go b/internal/loop/rules.go index 1fc5ff6..e062df6 100644 --- a/internal/loop/rules.go +++ b/internal/loop/rules.go @@ -35,6 +35,22 @@ type Rule struct { // the prefix here instead. Prefixes never make a rule inert: an empty // family is the predicate's own "no data" case. WantPrefixes []string + + // StillTrue — is the CONDITION still true, ignoring whether it is worth + // saying again? Distinct from Predicate on purpose, and the distinction is + // the whole reason this field exists (Vikunja #535). + // + // Predicate answers "should this fire now", which folds in edge-triggering: + // ServiceDownRule ends in !s.NudgedSince(...), so it reads false the instant + // a nudge goes out even though the service is still down. A repeat loop that + // consulted Predicate would cancel every alarm one tick after raising it, + // which is exactly backwards. + // + // Only a rule whose alarm repeats needs this. nil means "I cannot tell you", + // and the caller must then fall back to a bound it can enforce without the + // rule's help. nil must never be read as "the condition cleared": a rule + // that says nothing about its condition is not a rule that resolved. + StillTrue func(State) bool } // Cooldown — tunable bounded by the envelope so a weird week (auto-tuned) can't @@ -158,6 +174,10 @@ func ServiceDownRule() Rule { } return !s.NudgedSince("service_down", newest) }, + // The condition without the edge trigger. DownServices is the same + // helper the predicate and the phraser read, so the repeat stops on + // exactly the monitors he was told about. + StillTrue: func(s State) bool { return len(DownServices(s)) > 0 }, } }