Files
felhom.eu/hub/internal/notify/backup_run_digest_test.go
T
admin f21e7caed1
gates / gates (push) Successful in 7s
hub v0.90.1 — the digest's per-app lines stop repeating the filesystem figures (R-182)
Found by reading the first REAL digest, not by design. Every app row ended with
the same usage clause the mail already prints once on its own Filesystem line.
On a two-app box that is untidy; down a list of a dozen it is the same forty
characters twelve times, pushing the part that DIFFERS off a phone screen at
07:00 — the only moment this mail has to work.

The reserve's refusal message is authored for a single-app alert where naming
the filesystem is right, so the message is unchanged; the digest trims the
duplicate when rendering. trimRepeatedUsage removes ONLY an exact
"— <target path>:" suffix, so an unrelated reason is untouched and a reason that
is nothing but the usage clause is left alone rather than emptied.

Also updates TestRecoveryUnitCaptureFailed_NeverReachesTheCustomer, which
required the OPERATOR to be emailed a per-app capture failure. That was correct
when the event was the only signal and is wrong now that it is the record and
the digest is the notification. Its customer-safety claim is unchanged and is
why the test still exists; the operator assertion is inverted with the reasoning
written in place, and R-158's guarantee is shown to have MOVED, not weakened.
2026-08-03 13:54:02 +02:00

302 lines
15 KiB
Go

package notify
import (
"io"
"log"
"strings"
"testing"
)
// R-182 — one e-mail per backup run, and nothing dropped without a trace.
//
// MEASURED, NOT SUPPOSED. On 2026-08-03 nine `recovery_unit_capture_failed` events reached the hub
// and TWO operator e-mails went out. The operator cooldown key is
// `customerID + ":" + eventType + cooldownTierSuffix(details)`, that event carries `app` but no
// `tier`, so the key held no app identifier: the first refused app took the hour's slot and every
// other app's failure was discarded — **before `LogNotification`**, so it left no row on any channel
// and could not be found afterwards.
//
// The operator ruled against the obvious fix (putting `app` in the key), because on a full disk that
// is one e-mail per app. These pin the shape that replaced it.
// ── Scenario D — a suppressed operator event leaves a trace ───────────────────────────────────────
// The bare `return` at the cooldown is the whole reason this defect took a day to get the right way
// round: there was nothing to read. A drop must be as visible in the record as a send.
//
// DELIBERATELY EXERCISED ON A DIFFERENT EVENT TYPE than the one that exposed the defect.
// `recovery_unit_capture_failed` is now record-only and never reaches the cooldown at all, so using
// it here would prove nothing. `whole_guest_backup_failed` is an ordinary operator event, and using
// it pins §2.1's actual claim: the suppression row applies to EVERY operator event, not only the one
// that happened to be measured.
func TestSuppressedOperatorEvent_LeavesARow(t *testing.T) {
st := newDispStore(t)
d := NewDispatcher(st, "test-key", "from@felhom.eu", "op@felhom.eu", true, log.New(io.Discard, "", 0))
sent := captureSeam(d)
// Two events of the SAME type with no discriminator — the second must be suppressed.
d.ProcessEvent("c1", "whole_guest_backup_failed", "error", "opengist failed", `{"app":"opengist"}`, "controller")
d.ProcessEvent("c1", "whole_guest_backup_failed", "error", "privatebin failed", `{"app":"privatebin"}`, "controller")
if got := len(mailsFor(*sent, "op@felhom.eu")); got != 1 {
t.Fatalf("operator mails = %d, want 1 — the premise of this test is that the second IS suppressed", got)
}
rows, err := st.GetRecentNotifications("c1", 50)
if err != nil {
t.Fatal(err)
}
var sentRows, suppressed []store2Row
for _, r := range rows {
if r.Channel != "operator" || r.EventType != "whole_guest_backup_failed" {
continue
}
switch r.Status {
case "sent":
sentRows = append(sentRows, store2Row{r.Status, r.Message, r.ErrorMessage})
case "suppressed":
suppressed = append(suppressed, store2Row{r.Status, r.Message, r.ErrorMessage})
}
}
if len(sentRows) != 1 {
t.Fatalf("want 1 'sent' operator row, got %d", len(sentRows))
}
if len(suppressed) != 1 {
t.Fatalf("want 1 'suppressed' operator row, got %d — a cooldown drop that writes NOTHING is "+
"indistinguishable from an event that never happened, which is exactly how seven "+
"failures went missing on 2026-08-03", len(suppressed))
}
// The row must name the app that was dropped, or it records that something was suppressed
// without recording WHAT — half a fix.
if !strings.Contains(suppressed[0].message, "privatebin") {
t.Fatalf("the suppressed row does not name the dropped event: %q", suppressed[0].message)
}
// And it must carry the key, so the reason it collided is readable without reading code.
if !strings.Contains(suppressed[0].errMsg, "key=") {
t.Fatalf("the suppressed row does not carry the cooldown key: %q", suppressed[0].errMsg)
}
}
type store2Row struct{ status, message, errMsg string }
// ── Scenario E — two runs in a day each report ───────────────────────────────────────────────────
// The operator ruled explicitly on this: someone pressing the backup button is actively trying to
// get a backup, and finding out tomorrow would be worse than an extra mail in a rare case.
func TestTwoRunsInAnHour_BothReport(t *testing.T) {
st := newDispStore(t)
d := NewDispatcher(st, "test-key", "from@felhom.eu", "op@felhom.eu", true, log.New(io.Discard, "", 0))
sent := captureSeam(d)
nightly := `{"run_id":"run-a","run_kind":"nightly","failed":2,"attempted":5,"apps":[{"app":"opengist","leg":"volume dump","reason":"reserve"},{"app":"privatebin","leg":"volume dump","reason":"reserve"}]}`
manual := `{"run_id":"run-b","run_kind":"manual","failed":2,"attempted":5,"apps":[{"app":"opengist","leg":"volume dump","reason":"reserve"},{"app":"privatebin","leg":"volume dump","reason":"reserve"}]}`
d.ProcessEvent("c1", "backup_run_failures", "error", "2 of 5 apps failed", nightly, "controller")
d.ProcessEvent("c1", "backup_run_failures", "error", "2 of 5 apps failed", manual, "controller")
if got := len(mailsFor(*sent, "op@felhom.eu")); got != 2 {
t.Fatalf("operator mails = %d, want 2 — the 1-hour cooldown swallowed the manual run's "+
"digest, which is the fix reappearing one level up: press the button, the run fails, "+
"and you are told nothing because the machine already wrote this hour", got)
}
}
// The run discriminator must be NARROW, exactly like its `tier` sibling — empty unless the producer
// opts in — or every existing event type's cooldown silently stops collapsing anything.
func TestCooldownRunSuffix_EmptyForEverythingElse(t *testing.T) {
cases := []struct{ name, details string }{
{"no details", ""},
{"details without run_id", `{"app":"opengist","error":"boom"}`},
{"empty run_id value", `{"run_id":""}`},
{"malformed json", `{{{nope`},
{"run_id mentioned in a STRING, not as a key", `{"error":"the run_id: abc failed"}`},
{"null details", `null`},
}
for _, c := range cases {
if got := cooldownRunSuffix(c.details); got != "" {
t.Errorf("%s: suffix must be EMPTY so every other type's cooldown is unchanged, got %q", c.name, got)
}
}
if got := cooldownRunSuffix(`{"run_id":"run-a"}`); got != ":run-a" {
t.Fatalf("suffix should be the run id, got %q", got)
}
// The two suffixes must not interfere: a tier event still keys on its tier and nothing else.
if got := cooldownTierSuffix(`{"tier":"felhom-pbs"}`) + cooldownRunSuffix(`{"tier":"felhom-pbs"}`); got != ":felhom-pbs" {
t.Fatalf("a tier-only event's key changed to %q — R-97a's behaviour must be byte-identical", got)
}
}
// ── Scenario G — the customer never receives the digest ──────────────────────────────────────────
// v0.78.0 asserted in a COMMENT that a type with no `customerMessages` entry structurally cannot
// reach a customer. It can: FormatCustomerEmail falls back to the raw English message and the only
// customer gate is configuration. So this is demonstrated, not argued.
func TestDigest_IsOperatorOnly_EvenWithAWideEnabledList(t *testing.T) {
st := newDispStore(t)
// A customer who has enabled EVERYTHING, including this type by name.
if err := st.SaveNotificationPrefs("c1", "cust@example.com",
[]string{"backup_run_failures", "node_down", "disk_warning"}, 6); err != nil {
t.Fatal(err)
}
d := NewDispatcher(st, "test-key", "from@felhom.eu", "op@felhom.eu", true, log.New(io.Discard, "", 0))
sent := captureSeam(d)
details := `{"run_id":"run-a","run_kind":"nightly","failed":1,"attempted":3,"apps":[{"app":"opengist","leg":"volume dump","reason":"reserve"}]}`
d.ProcessEvent("c1", "backup_run_failures", "error", "1 of 3 apps failed", details, "controller")
if got := mailsFor(*sent, "cust@example.com"); len(got) != 0 {
t.Fatalf("the CUSTOMER received an operator digest (%d mails) — a list of which apps' "+
"backups failed is not something they can act on, and the raw body is English", len(got))
}
if got := len(mailsFor(*sent, "op@felhom.eu")); got != 1 {
t.Fatalf("operator mails = %d, want 1", got)
}
if !operatorOnlyEvents["backup_run_failures"] {
t.Fatal("backup_run_failures is not in operatorOnlyEvents — allowlisting alone does NOT " +
"keep it from a customer; that assumption shipped once and was wrong (v0.78.0)")
}
}
// ── Part 3 — the e-mail a person actually reads ──────────────────────────────────────────────────
func TestDigestEmail_ListsAppsLegsAndReasons(t *testing.T) {
details := `{"run_id":"run-a","run_kind":"nightly","failed":3,"attempted":40,` +
`"target_path":"/mnt/sys_drive","used_gb":64.3,"avail_gb":0.9,"total_gb":68.7,` +
`"used_percent":94,"space_known":true,"apps":[` +
`{"app":"opengist","leg":"volume dump","reason":"refused: below the reserve (headroom)"},` +
`{"app":"privatebin","leg":"volume dump","reason":"refused: below the reserve (headroom)"},` +
`{"app":"immich","leg":"database dump","reason":"pg_dump: connection refused"}]}`
subject, body := FormatOperatorEmail("demo-hp", "backup_run_failures", "error",
"3 of 40 apps failed to back up", details)
// The subject must carry the counts: the operator's first decision is made from it alone.
for _, want := range []string{"demo-hp", "3 of 40", "nightly"} {
if !strings.Contains(subject, want) {
t.Errorf("subject %q missing %q", subject, want)
}
}
// Every app, its leg and its reason.
for _, want := range []string{
"opengist", "privatebin", "immich",
"volume dump", "database dump",
"below the reserve", "pg_dump: connection refused",
} {
if !strings.Contains(body, want) {
t.Errorf("body missing %q:\n%s", want, body)
}
}
// The counts and the free space, so "one broken app" and "a full disk" read differently.
if !strings.Contains(body, "3 of 40") {
t.Errorf("body does not carry the failed-of-attempted count:\n%s", body)
}
if !strings.Contains(body, "0.9 GB free") {
t.Errorf("body does not carry the free space:\n%s", body)
}
// It must NOT be a JSON blob.
if strings.Contains(body, `"apps":[`) {
t.Errorf("the digest rendered as raw JSON — unreadable on a phone at 07:00:\n%s", body)
}
}
// An absent space reading must render as unavailable, never as zeros: "0 GB free" and "we could not
// look" are opposite diagnoses, and the operator acts differently on each.
func TestDigestEmail_UnknownSpaceIsNotZero(t *testing.T) {
details := `{"run_id":"r","run_kind":"nightly","failed":1,"attempted":2,"target_path":"/mnt/x",` +
`"space_known":false,"apps":[{"app":"a","leg":"capture","reason":"boom"}]}`
_, body := FormatOperatorEmail("demo-hp", "backup_run_failures", "error", "1 of 2 failed", details)
if strings.Contains(body, "0.0 GB free") {
t.Fatalf("an unreadable filesystem rendered as zeros:\n%s", body)
}
if !strings.Contains(body, "unavailable") {
t.Fatalf("an unreadable filesystem must say so:\n%s", body)
}
}
// A payload that cannot be parsed must still produce a mail — degraded, never swallowed.
func TestDigestEmail_UnparseableDetailsStillMails(t *testing.T) {
_, body := FormatOperatorEmail("demo-hp", "backup_run_failures", "error", "something failed", `{{{`)
if body == "" || !strings.Contains(body, "something failed") {
t.Fatalf("an unparseable digest lost the mail entirely:\n%s", body)
}
}
// ── Scenario C — every failure is RECORDED, e-mailed or not ──────────────────────────────────────
// The per-app event is the record; the digest is the notification. The record must not inherit the
// notification's conditions — no cooldown, no preferences, no dependence on a mail going out.
func TestPerAppFailure_IsRecordedButNotMailed(t *testing.T) {
st := newDispStore(t)
d := NewDispatcher(st, "test-key", "from@felhom.eu", "op@felhom.eu", true, log.New(io.Discard, "", 0))
sent := captureSeam(d)
apps := []string{"opengist", "privatebin", "immich", "homebox", "nextcloud"}
for _, a := range apps {
d.ProcessEvent("c1", "recovery_unit_capture_failed", "error",
"Recovery unit capture FAILED for \""+a+"\"", `{"app":"`+a+`"}`, "controller")
}
// NOT mailed — the digest is the notification.
if got := len(*sent); got != 0 {
t.Fatalf("%d mail(s) sent for per-app failures — they are the RECORD; one mail per app on a "+
"full disk is the volume problem wearing the correctness problem's clothes, which is "+
"exactly what the operator ruled against", got)
}
// But ALL FIVE recorded — this is the assertion yesterday's defect would have failed: nine
// arrived, two were mailed, seven left no row anywhere.
rows, err := st.GetRecentNotifications("c1", 50)
if err != nil {
t.Fatal(err)
}
seen := map[string]bool{}
for _, r := range rows {
if r.EventType == "recovery_unit_capture_failed" && r.Status == "recorded" {
for _, a := range apps {
if strings.Contains(r.Message, a) {
seen[a] = true
}
}
}
}
if len(seen) != len(apps) {
t.Fatalf("only %d of %d per-app failures were recorded (%v) — a failure that produced no row "+
"anywhere is the measured defect of 2026-08-03", len(seen), len(apps), seen)
}
}
// The per-app reason must not repeat the filesystem figures the digest already prints once. Reviewed
// as copy against the first real digest, not designed in the abstract.
func TestDigestEmail_ReasonDoesNotRepeatTheUsageLine(t *testing.T) {
reason := "refused: below the reserve (reserve: 97% used or 1.0 GiB free) — /mnt/sys_drive: 65.0/68.7 GB used (95%), 0.2 GB free"
details := `{"run_id":"r","run_kind":"nightly","failed":1,"attempted":2,"target_path":"/mnt/sys_drive",` +
`"used_gb":65,"avail_gb":0.2,"total_gb":68.7,"used_percent":95,"space_known":true,` +
`"apps":[{"app":"opengist","leg":"whole app","reason":"` + reason + `"}]}`
_, body := FormatOperatorEmail("demo-hp", "backup_run_failures", "error", "1 of 2 failed", details)
// The figures appear ONCE, on the Filesystem line — not again on every app row.
if strings.Count(body, "65.0/68.7 GB used") != 1 {
t.Fatalf("the usage clause appears %d times; it must appear once, on its own line — repeated "+
"down a list of a dozen apps it pushes the part that DIFFERS off a phone screen:\n%s",
strings.Count(body, "65.0/68.7 GB used"), body)
}
// But the reason itself survives — trimming must not eat the diagnosis.
if !strings.Contains(body, "below the reserve") {
t.Fatalf("the reason was trimmed away entirely:\n%s", body)
}
}
// A reason naming a DIFFERENT path, or none, must be left completely alone.
func TestTrimRepeatedUsage_LeavesUnrelatedReasonsAlone(t *testing.T) {
for _, c := range []struct{ reason, target string }{
{"pg_dump: connection refused", "/mnt/sys_drive"},
{"tar failed — /mnt/other: 1/2 GB used (50%), 1 GB free", "/mnt/sys_drive"},
{"boom", ""},
{"", "/mnt/sys_drive"},
} {
if got := trimRepeatedUsage(c.reason, c.target); got != c.reason {
t.Errorf("reason %q (target %q) was altered to %q", c.reason, c.target, got)
}
}
}