diff --git a/cmd/felis/watchdog.go b/cmd/felis/watchdog.go index 8c44687..7971505 100644 --- a/cmd/felis/watchdog.go +++ b/cmd/felis/watchdog.go @@ -37,6 +37,7 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { fs.SetOutput(stderr) cfgPath := fs.String("config", "/etc/felis/felis.toml", "path to felis.toml (the host copy, which reaches PostgreSQL on 127.0.0.1)") statePath := fs.String("state", "/var/lib/felis/watchdog/state.json", "state kept between runs (root only: it caches the relay password)") + fallbackState := fs.String("fallback-state", watchdog.FallbackStatePath, "where a run keeps its state while -state cannot be written, so what it mailed is not mailed again (tmpfs: until the host restarts; \"\" keeps none)") smtpPasswordFile := fs.String("smtp-password-file", hostSMTPPasswordPath, "the relay password `felis setup` keeps on the host; the felis-smtp Secret stands in while it is missing") quietPath := fs.String("quiet-file", "/run/felis/watchdog-quiet-until", "Unix time before which nothing is mailed; the installer writes it while it restarts things on purpose") backupDir := fs.String("backup-dir", "/var/lib/felis/db-backups", `control-plane database backups to check for freshness ("" skips the check)`) @@ -59,7 +60,7 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { now := time.Now() if *unitFailed { return watchdogUnitFailed(unitFailedRun{ - cfgPath: *cfgPath, statePath: *statePath, quietPath: *quietPath, + cfgPath: *cfgPath, statePath: *statePath, fallbackPath: *fallbackState, quietPath: *quietPath, offsiteStatus: *offsiteStatus, heartbeatFile: *heartbeatFile, result: os.Getenv("MONITOR_SERVICE_RESULT"), exitStatus: os.Getenv("MONITOR_EXIT_STATUS"), send: watchdogSender, client: http.DefaultClient, now: now, @@ -70,7 +71,8 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { fmt.Fprintf(stderr, "felis watchdog: %v\n", err) return 1 } - state, aside, err := watchdog.RecoverState(*statePath, now) + loadPath := watchdog.NewestState(*statePath, *fallbackState) + state, aside, err := watchdog.RecoverState(loadPath, now) if err != nil { fmt.Fprintf(stderr, "felis watchdog: %v\n", err) return 1 @@ -85,7 +87,7 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { } } if aside != "" { - fmt.Fprintf(stderr, "felis watchdog: %s was unreadable; moved it to %s and started over\n", *statePath, aside) + fmt.Fprintf(stderr, "felis watchdog: %s was unreadable; moved it to %s and started over\n", loadPath, aside) f := watchdog.StateSetAside(aside) add(&f) } @@ -176,7 +178,7 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { m := configMailer(cfg.SMTP, state.SMTPPassword, watchdogSender) unheard, mailFailed := m.deliver(ctx, state, plan, subject, body, mailHold(*quietPath, cfg.Offsite.Enabled(), *offsiteStatus, now), now, stdout, stderr) - saveErr := watchdog.SaveState(*statePath, state) + saveErr := watchdog.SaveStateOr(*statePath, *fallbackState, state) if saveErr != nil { fmt.Fprintf(stderr, "felis watchdog: save state: %v\n", saveErr) } @@ -192,7 +194,9 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { // failureReport is what the heartbeat's failure ping carries, "" when the run // pings success: the alerts this run knows of reach no one (a mail that // failed, or no relay or recipient while something is open), or the state did -// not save and the next run mails the same alerts again. +// not save to its file: kept on tmpfs it holds until the host restarts, which +// forgets what was mailed, and with nowhere to keep it the next run mails the +// same alerts again. func failureReport(unheard string, mailFailed bool, saveErr error, open bool, r watchdog.Report) string { var why []string if unheard != "" && (mailFailed || open) { @@ -278,7 +282,7 @@ func smtpPassword(c config.SMTPConfig, cached string) string { // unitFailedRun is one run of felis-watchdog-failed.service. type unitFailedRun struct { - cfgPath, statePath, quietPath, offsiteStatus, heartbeatFile string + cfgPath, statePath, fallbackPath, quietPath, offsiteStatus, heartbeatFile string // result and exitStatus are what systemd hands an OnFailure= unit // (MONITOR_SERVICE_RESULT, MONITOR_EXIT_STATUS; systemd 251 and later). result, exitStatus string @@ -313,7 +317,7 @@ func watchdogUnitFailed(r unitFailedRun, stdout, stderr io.Writer) int { if beat.url, err = readHeartbeatURL(r.heartbeatFile); err != nil { fmt.Fprintf(stderr, "felis watchdog: %v; pinging no heartbeat\n", err) } - state, err := watchdog.LoadState(r.statePath) + state, err := watchdog.LoadState(watchdog.NewestState(r.statePath, r.fallbackPath)) if err != nil { // The next run that gets that far moves a state that does not parse // aside (watchdog.RecoverState). @@ -336,7 +340,7 @@ func watchdogUnitFailed(r unitFailedRun, stdout, stderr io.Writer) int { if mailFailed { code = 1 } - if err := watchdog.SaveState(r.statePath, state); err != nil { + if err := watchdog.SaveStateOr(r.statePath, r.fallbackPath, state); err != nil { fmt.Fprintf(stderr, "felis watchdog: save state: %v\n", err) code = 1 } diff --git a/cmd/felis/watchdog_heartbeat_test.go b/cmd/felis/watchdog_heartbeat_test.go index 38757fa..5b059b0 100644 --- a/cmd/felis/watchdog_heartbeat_test.go +++ b/cmd/felis/watchdog_heartbeat_test.go @@ -364,7 +364,7 @@ func unitFailedFixture(t *testing.T, cfg string) (unitFailedRun, *alertRecorder, } f := &alertRecorder{} return unitFailedRun{ - cfgPath: cfgPath, statePath: statePath, quietPath: filepath.Join(dir, "quiet"), + cfgPath: cfgPath, statePath: statePath, fallbackPath: filepath.Join(t.TempDir(), "watchdog-state.json"), quietPath: filepath.Join(dir, "quiet"), offsiteStatus: filepath.Join(dir, "offsite-status.json"), heartbeatFile: beatFile, result: "exit-code", exitStatus: "1", send: f.sender, client: srv.Client(), now: time.Now(), }, f, log @@ -409,6 +409,32 @@ func TestWatchdogUnitFailedBrokenConfig(t *testing.T) { } } +// TestWatchdogUnitFailedStateThatDoesNotSave: with the state file read-only, +// each report keeps the state in the fallback and the next one reads it, so +// the failure is mailed once, after five in a row, and never again. +func TestWatchdogUnitFailedStateThatDoesNotSave(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("root writes into a read-only directory") + } + r, f, _ := unitFailedFixture(t, "[database\n") + dir := filepath.Dir(r.statePath) + if err := os.Chmod(dir, 0o500); err != nil { + t.Fatal(err) + } + t.Cleanup(func() { os.Chmod(dir, 0o700) }) + start := r.now + for i := 0; i <= 8; i++ { + r.now = start.Add(time.Duration(i) * 2 * time.Minute) + var stdout, stderr bytes.Buffer + if code := watchdogUnitFailed(r, &stdout, &stderr); code != 1 || !strings.Contains(stderr.String(), "; kept in "+r.fallbackPath) { + t.Fatalf("run %d: exit %d, stderr %s; want exit 1 and the state kept in the fallback", i, code, stderr.String()) + } + if want := min(max(i-4, 0), 1); len(f.sent) != want { + t.Fatalf("run %d, %v after the first failure: mailed %d, want %d", i, r.now.Sub(start), len(f.sent), want) + } + } +} + // TestWatchdogUnitFailedConfigRelay: with felis.toml loading, the relay is // the configured one and signs in with the env var password_ref names. func TestWatchdogUnitFailedConfigRelay(t *testing.T) { diff --git a/cmd/felis/watchdog_test.go b/cmd/felis/watchdog_test.go index cd1f538..52cfe5d 100644 --- a/cmd/felis/watchdog_test.go +++ b/cmd/felis/watchdog_test.go @@ -99,10 +99,12 @@ func TestMailHold(t *testing.T) { // the heartbeat URL points at a ping log. type watchdogHost struct { dir, statePath string - args []string - rec *alertRecorder - pings *pingLog - url string + // fallbackPath stands in for /run/felis, in a directory of its own. + fallbackPath string + args []string + rec *alertRecorder + pings *pingLog + url string } func newWatchdogHost(t *testing.T, cfg string, state *watchdog.State) *watchdogHost { @@ -110,7 +112,8 @@ func newWatchdogHost(t *testing.T, cfg string, state *watchdog.State) *watchdogH dir := t.TempDir() t.Setenv("KUBECONFIG", filepath.Join(dir, "no-kubeconfig")) pings, srv := newPingServer(t) - h := &watchdogHost{dir: dir, statePath: filepath.Join(dir, "state.json"), rec: &alertRecorder{}, pings: pings, url: srv.URL} + h := &watchdogHost{dir: dir, statePath: filepath.Join(dir, "state.json"), fallbackPath: filepath.Join(t.TempDir(), "watchdog-state.json"), + rec: &alertRecorder{}, pings: pings, url: srv.URL} writeTestFile(t, filepath.Join(dir, "felis.toml"), cfg, 0o600) writeTestFile(t, filepath.Join(dir, "watchdog-heartbeat-url"), srv.URL+"/check-key\n", 0o600) if state != nil { @@ -119,7 +122,7 @@ func newWatchdogHost(t *testing.T, cfg string, state *watchdog.State) *watchdogH } } h.args = []string{ - "-config", filepath.Join(dir, "felis.toml"), "-state", h.statePath, "-quiet-file", filepath.Join(dir, "quiet"), + "-config", filepath.Join(dir, "felis.toml"), "-state", h.statePath, "-fallback-state", h.fallbackPath, "-quiet-file", filepath.Join(dir, "quiet"), "-backup-dir", "", "-disk-paths", dir, "-k3s-cert-dirs", "", "-smtp-password-file", filepath.Join(dir, "smtp-password"), "-offsite-status", filepath.Join(dir, "offsite-status.json"), "-build-tools-status", filepath.Join(dir, "build-tools.json"), "-heartbeat-file", filepath.Join(dir, "watchdog-heartbeat-url"), @@ -292,8 +295,9 @@ func TestWatchdogRunChecksWhatIsConfigured(t *testing.T) { } // TestWatchdogRunStateThatDoesNotSave: a pass whose state does not save mails -// as usual, exits 1 and posts the failure to the heartbeat, since the next run -// mails the same alerts again. +// as usual, keeps its state in the fallback, exits 1 and posts the failure to +// the heartbeat. The next pass reads the fallback and mails nothing again; the +// first one whose state saves drops the fallback. func TestWatchdogRunStateThatDoesNotSave(t *testing.T) { if os.Geteuid() == 0 { t.Skip("root writes into a read-only directory") @@ -304,10 +308,24 @@ func TestWatchdogRunStateThatDoesNotSave(t *testing.T) { t.Fatal(err) } t.Cleanup(func() { os.Chmod(h.dir, 0o700) }) + kept := "; kept in " + h.fallbackPath + " until the host restarts" + for i := range 2 { + code, stdout, stderr := h.run() + pings, bodies := h.pings.got() + if code != 1 || len(h.rec.sent) != 1 || !strings.Contains(stderr, "felis watchdog: save state: ") || !strings.Contains(stderr, kept) || + len(pings) != i+1 || pings[i] != "POST /check-key/fail" || !strings.HasPrefix(bodies[i], "the watchdog state did not save: ") { + t.Fatalf("pass %d: exit %d, mailed %v, pings %v %q; want exit 1, one mail in all and the save failure posted to /fail\nstdout %s\nstderr %s", i, code, h.rec.sent, pings, bodies, stdout, stderr) + } + } + + if err := os.Chmod(h.dir, 0o700); err != nil { + t.Fatal(err) + } code, stdout, stderr := h.run() - pings, bodies := h.pings.got() - if code != 1 || len(h.rec.sent) != 1 || !strings.Contains(stderr, "felis watchdog: save state: ") || - len(pings) != 1 || pings[0] != "POST /check-key/fail" || !strings.HasPrefix(bodies[0], "the watchdog state did not save: ") { - t.Errorf("exit %d, mailed %v, pings %v %q; want exit 1, one mail and the save failure posted to /fail\nstdout %s\nstderr %s", code, h.rec.sent, pings, bodies, stdout, stderr) + if _, err := os.Stat(h.fallbackPath); code != 0 || len(h.rec.sent) != 1 || !errors.Is(err, fs.ErrNotExist) { + t.Fatalf("once the state saves: exit %d, mailed %v, fallback %v; want exit 0, no new mail, the fallback gone\nstdout %s\nstderr %s", code, h.rec.sent, err, stdout, stderr) + } + if s, err := watchdog.LoadState(h.statePath); err != nil || s.Alerts["postgres"] == nil || s.Alerts["postgres"].Notified.IsZero() { + t.Fatalf("saved state = %+v, %v; want the mailed PostgreSQL alert", s, err) } } diff --git a/docs/troubleshooting.md b/docs/troubleshooting.md index 04daa86..c6a3d9e 100644 --- a/docs/troubleshooting.md +++ b/docs/troubleshooting.md @@ -1787,6 +1787,17 @@ alerts' history, so each problem still present is mailed again as new. A power loss right after a save or a hand edit usually causes this; check `df -h /var/lib/felis`, then delete the set-aside copy. [GO-TESTED: `TestRecoverState`] +A state file that cannot be written (a full or read-only `/var/lib/felis`) +leaves the run's state in `/run/felis/watchdog-state.json` (tmpfs, root-only). +The next run reads whichever of the two was written last, so an alert that was +mailed is not mailed again every two minutes. Each such run logs `save state: +...; kept in /run/felis/watchdog-state.json until the host restarts`, exits 1 +and pings the heartbeat's `/fail`; after five in a row `watchdog/run` is mailed +once. The first run whose state file saves again deletes the tmpfs copy. A +restart before that forgets what was mailed, so the open problems are mailed +again as new. [GO-TESTED: `TestSaveStateOr`, `TestWatchdogRunStateThatDoesNotSave`, +`TestWatchdogUnitFailedStateThatDoesNotSave`] + ```bash journalctl -u felis-watchdog-failed -n 20 # what the fallback reported and pinged systemctl status felis-watchdog # the failed run's result diff --git a/internal/watchdog/watchdog.go b/internal/watchdog/watchdog.go index dd9a8a1..cee47d2 100644 --- a/internal/watchdog/watchdog.go +++ b/internal/watchdog/watchdog.go @@ -367,6 +367,45 @@ func SaveState(path string, s *State) error { return os.Rename(tmp.Name(), path) } +// FallbackStatePath is where a run keeps its state when the state file cannot be +// written (a full or read-only /var/lib): tmpfs, which lasts until the host +// restarts, next to the installer's quiet marker. +const FallbackStatePath = "/run/felis/watchdog-state.json" + +// NewestState is the state file a run reads: fallback when a run wrote it after +// path (its save to path failed, SaveStateOr), else path. +func NewestState(path, fallback string) string { + fb, err := os.Stat(fallback) // "" is no fallback: it does not stat + if err != nil { + return path + } + if st, err := os.Stat(path); err == nil && !fb.ModTime().After(st.ModTime()) { + return path + } + return fallback +} + +// SaveStateOr saves s to path and drops fallback. When path cannot be written it +// saves s to fallback instead, so the next run still knows what this one mailed +// and does not mail it again every two minutes. The error is path's either way, +// saying where the state went. +func SaveStateOr(path, fallback string, s *State) error { + err := SaveState(path, s) + if err == nil { + if fallback != "" { + os.Remove(fallback) + } + return nil + } + if fallback == "" { + return err + } + if ferr := SaveState(fallback, s); ferr != nil { + return fmt.Errorf("%w; nor in %s: %v", err, fallback, ferr) + } + return fmt.Errorf("%w; kept in %s until the host restarts", err, fallback) +} + // QuietUntil reads the maintenance marker the installer writes while it // restarts things on purpose: a Unix timestamp, before which nothing is mailed. // A missing or unreadable marker means no quiet period. diff --git a/internal/watchdog/watchdog_test.go b/internal/watchdog/watchdog_test.go index 45ecac8..de04f76 100644 --- a/internal/watchdog/watchdog_test.go +++ b/internal/watchdog/watchdog_test.go @@ -244,6 +244,91 @@ func TestRecoverState(t *testing.T) { } } +// TestSaveStateOr: a state file that cannot be written leaves the state in the +// fallback, which the next run reads; once the file takes it again the fallback +// goes, and a fallback older than the file is never read. +func TestSaveStateOr(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("root writes into a read-only directory") + } + dir := t.TempDir() + path := filepath.Join(dir, "state.json") + fbDir := filepath.Join(t.TempDir(), "run") + fallback := filepath.Join(fbDir, "watchdog-state.json") + before := &State{Recipients: []string{"owner@example.com"}} + if err := SaveState(path, before); err != nil { + t.Fatal(err) + } + if got := NewestState(path, fallback); got != path { + t.Fatalf("no fallback yet: NewestState = %q, want the file", got) + } + + mailed := &State{Recipients: []string{"owner@example.com"}} + run(mailed, Report{Findings: []Finding{finding("memory", Warning, 0)}}, t0) + if err := os.Chmod(dir, 0o500); err != nil { + t.Fatal(err) + } + t.Cleanup(func() { os.Chmod(dir, 0o700) }) + err := SaveStateOr(path, fallback, mailed) + if err == nil || !strings.HasSuffix(err.Error(), "; kept in "+fallback+" until the host restarts") { + t.Fatalf("SaveStateOr on a read-only directory = %v, want the error saying where the state went", err) + } + if got := NewestState(path, fallback); got != fallback { + t.Fatalf("after a failed save: NewestState = %q, want the fallback", got) + } + s, err := LoadState(fallback) + if err != nil || s.Alerts["memory"] == nil || !s.Alerts["memory"].Notified.Equal(t0) { + t.Fatalf("fallback = %+v, %v; want the alert mailed at t0", s, err) + } + + if err := os.Chmod(dir, 0o700); err != nil { + t.Fatal(err) + } + if err := SaveStateOr(path, fallback, s); err != nil { + t.Fatalf("SaveStateOr once the file is writable: %v", err) + } + if _, err := os.Stat(fallback); !os.IsNotExist(err) { + t.Fatalf("the fallback outlived a good save (%v)", err) + } + if got := NewestState(path, fallback); got != path { + t.Fatalf("after a good save: NewestState = %q, want the file", got) + } + + // A fallback older than the file (one whose removal failed) stays unread. + if err := SaveState(fallback, before); err != nil { + t.Fatal(err) + } + past := time.Now().Add(-time.Hour) + if err := os.Chtimes(fallback, past, past); err != nil { + t.Fatal(err) + } + if got := NewestState(path, fallback); got != path { + t.Fatalf("stale fallback: NewestState = %q, want the file", got) + } + + // No fallback: the error is the file's alone, and nothing else is read. + if err := os.Chmod(dir, 0o500); err != nil { + t.Fatal(err) + } + err = SaveStateOr(path, "", mailed) + if err == nil || strings.Contains(err.Error(), "; ") || NewestState(path, "") != path { + t.Fatalf("SaveStateOr with no fallback = %v, NewestState = %q", err, NewestState(path, "")) + } + + // With nowhere to keep it, the error says that too. + if err := os.Chmod(dir, 0o500); err != nil { + t.Fatal(err) + } + if err := os.Chmod(fbDir, 0o500); err != nil { + t.Fatal(err) + } + t.Cleanup(func() { os.Chmod(fbDir, 0o700) }) + err = SaveStateOr(path, fallback, mailed) + if err == nil || !strings.Contains(err.Error(), "; nor in "+fallback+": ") { + t.Fatalf("SaveStateOr with both read-only = %v", err) + } +} + // TestStateOpen: open is a condition the owners were told of that still holds. func TestStateOpen(t *testing.T) { s := &State{}