From 82ffa55a8fb53bd41f03788f928b60062e6adedb Mon Sep 17 00:00:00 2001 From: Lemon-miaow Date: Sun, 27 Sep 2026 08:40:32 +0800 Subject: [PATCH] =?UTF-8?q?fix(watchdog):=20=E5=A4=96=E9=83=A8=E5=BF=83?= =?UTF-8?q?=E8=B7=B3=E3=80=81=E5=B7=A1=E6=A3=80=E5=A4=B1=E8=B4=A5=E5=85=9C?= =?UTF-8?q?=E5=BA=95=E5=91=8A=E8=AD=A6=E3=80=81=E7=8A=B6=E6=80=81=E6=96=87?= =?UTF-8?q?=E4=BB=B6=E6=8D=9F=E5=9D=8F=E8=87=AA=E5=8A=A8=E7=A7=BB=E5=BC=80?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- cmd/felis/hostcreds_test.go | 2 +- cmd/felis/watchdog.go | 247 +++++++++-- cmd/felis/watchdog_heartbeat.go | 164 ++++++++ cmd/felis/watchdog_heartbeat_test.go | 589 +++++++++++++++++++++++++++ deploy/bootstrap.sh | 102 ++++- deploy/bootstrap_test.sh | 90 +++- deploy/uninstall.sh | 2 +- docs/troubleshooting.md | 74 +++- internal/watchdog/probes.go | 26 ++ internal/watchdog/watchdog.go | 45 +- internal/watchdog/watchdog_test.go | 63 +++ 11 files changed, 1360 insertions(+), 44 deletions(-) create mode 100644 cmd/felis/watchdog_heartbeat.go create mode 100644 cmd/felis/watchdog_heartbeat_test.go diff --git a/cmd/felis/hostcreds_test.go b/cmd/felis/hostcreds_test.go index 6bfe150..917761e 100644 --- a/cmd/felis/hostcreds_test.go +++ b/cmd/felis/hostcreds_test.go @@ -183,7 +183,7 @@ password_ref = "FELIS_TEST_UNSET_RELAY_PW" var stdout, stderr bytes.Buffer cmdWatchdog([]string{ "-config", cfgPath, "-state", statePath, "-quiet-file", filepath.Join(dir, "quiet"), - "-backup-dir", "", "-disk-paths", dir, "-smtp-password-file", pwPath, + "-backup-dir", "", "-disk-paths", dir, "-smtp-password-file", pwPath, "-heartbeat-file", filepath.Join(dir, "no-heartbeat"), }, &stdout, &stderr) if !strings.Contains(stdout.String(), "kube-api") { t.Fatalf("the run found the API server up; the test needs it down (stdout %s)", stdout.String()) diff --git a/cmd/felis/watchdog.go b/cmd/felis/watchdog.go index 909516d..27dd054 100644 --- a/cmd/felis/watchdog.go +++ b/cmd/felis/watchdog.go @@ -8,11 +8,13 @@ import ( "fmt" "io" "net" + "net/http" "os" "strings" "time" "felis.lolicon.best/internal/config" + "felis.lolicon.best/internal/mail" "felis.lolicon.best/internal/offsite" "felis.lolicon.best/internal/platform" "felis.lolicon.best/internal/store" @@ -46,25 +48,35 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { offsiteStatus := fs.String("offsite-status", offsite.DefaultStatusFile, "the record `felis offsite sync` leaves, checked when [offsite] is configured") toolsStatus := fs.String("build-tools-status", defaultBuildToolsStatus, "the record `felis mirror-build-tools` leaves, checked when builds scan against the registry's DB copy") dryRun := fs.Bool("dry-run", false, "print every finding and the mail that is due; send nothing and keep the state as it was") + heartbeatFile := fs.String("heartbeat-file", defaultHeartbeatFile, "file holding the heartbeat URL each run pings, a dead man's switch at a monitoring service that alerts when the pings stop (no file pings nothing)") + unitFailed := fs.Bool("unit-failed", false, "report a failed run of felis-watchdog.service instead of checking; felis-watchdog-failed.service runs this through OnFailure=") if err := fs.Parse(args); err != nil { if errors.Is(err, flag.ErrHelp) { return 0 } return 2 } + now := time.Now() + if *unitFailed { + return watchdogUnitFailed(unitFailedRun{ + cfgPath: *cfgPath, statePath: *statePath, 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, + }, stdout, stderr) + } cfg, err := config.Load(*cfgPath) if err != nil { fmt.Fprintf(stderr, "felis watchdog: %v\n", err) return 1 } - state, err := watchdog.LoadState(*statePath) + state, aside, err := watchdog.RecoverState(*statePath, now) if err != nil { fmt.Fprintf(stderr, "felis watchdog: %v\n", err) return 1 } ctx, cancel := context.WithTimeout(context.Background(), 90*time.Second) defer cancel() - now := time.Now() var report watchdog.Report add := func(f *watchdog.Finding) { @@ -72,6 +84,11 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { report.Findings = append(report.Findings, *f) } } + if aside != "" { + fmt.Fprintf(stderr, "felis watchdog: %s was unreadable; moved it to %s and started over\n", *statePath, aside) + f := watchdog.StateSetAside(aside) + add(&f) + } // The cluster: one unreachable API server stands in for every check behind it. minecraftNS := cfg.K8s.Namespace @@ -97,6 +114,7 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { } refreshSMTPPassword(ctx, *smtpPasswordFile, secrets, *controlNS, state, stderr) } + state.Relay = cachedRelay(cfg.SMTP) if recipients, err := ownerEmails(ctx, cfg.Database.URL); err != nil { f := watchdog.PostgresDown(err) @@ -136,45 +154,207 @@ func cmdWatchdog(args []string, stdout, stderr io.Writer) int { plan := state.Observe(report, now) host, _ := os.Hostname() subject, body := plan.Message(host, now) + beat := heartbeat{ + standby: standsBy(cfg.Offsite.Enabled(), *offsiteStatus), + quiet: now.Before(watchdog.QuietUntil(*quietPath)), + } + if beat.url, err = readHeartbeatURL(*heartbeatFile); err != nil { + fmt.Fprintf(stderr, "felis watchdog: %v; pinging no heartbeat\n", err) + } if *dryRun { if plan.Empty() { fmt.Fprintln(stdout, "felis watchdog: nothing is due to be mailed") } else { fmt.Fprintf(stdout, "felis watchdog: due to be mailed to %s:\nSubject: %s\n\n%s", strings.Join(state.Recipients, ", "), subject, strings.ReplaceAll(body, "\r\n", "\n")) } + if beat.url != "" { + fmt.Fprintf(stdout, "felis watchdog: a run pings the heartbeat at %s\n", redactURL(beat.url)) + } return 0 } - save := func() int { - if err := watchdog.SaveState(*statePath, state); err != nil { - fmt.Fprintf(stderr, "felis watchdog: save state: %v\n", err) - return 1 - } - return 0 + 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) + if saveErr != nil { + fmt.Fprintf(stderr, "felis watchdog: save state: %v\n", saveErr) } - if plan.Empty() { - return save() + beat.report = failureReport(unheard, mailFailed, saveErr, state.Open(), report) + beat.fail = beat.report != "" + beat.send(http.DefaultClient, stdout, stderr) + if mailFailed || saveErr != nil { + return 1 } - if hold := mailHold(*quietPath, cfg.Offsite.Enabled(), *offsiteStatus, now); hold != "" { - fmt.Fprintf(stdout, "felis watchdog: %s; holding this mail: %s\n", hold, subject) - return save() + return 0 +} + +// 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. +func failureReport(unheard string, mailFailed bool, saveErr error, open bool, r watchdog.Report) string { + var why []string + if unheard != "" && (mailFailed || open) { + why = append(why, "the alerts reach no one: "+unheard) + } + if saveErr != nil { + why = append(why, "the watchdog state did not save: "+saveErr.Error()) + } + if len(why) == 0 { + return "" + } + return strings.Join(why, "\n") + "\n\n" + findingLines(r) +} + +// findingLines is the report as the journal shows it. +func findingLines(r watchdog.Report) string { + var b strings.Builder + for _, f := range r.Findings { + fmt.Fprintf(&b, "[%s] %s: %s\n", f.Severity, f.Key, f.SummaryEN) + } + return b.String() +} + +// mailer is how a run reaches the owners. +type mailer struct { + relay *watchdog.Relay // nil: no [smtp] relay + password string + send func(*mail.SMTP) alertSender +} + +// deliver mails plan to the owners unless hold says why it waits, and commits +// it once it reached them, or once it is logged because nothing can reach them. +// unheard is why the owners hear nothing of this run's alerts, "" when they do; +// mailFailed is a mail that did not go out, left uncommitted so the same +// alerts come due again next run. +func (m mailer) deliver(ctx context.Context, state *watchdog.State, plan watchdog.Plan, subject, body, hold string, now time.Time, stdout, stderr io.Writer) (unheard string, mailFailed bool) { + switch { + case m.relay == nil: + unheard = "no [smtp] relay is configured" + case len(state.Recipients) == 0: + unheard = "no owner account has a verified email" } switch { - case cfg.SMTP.Host == "": - fmt.Fprintf(stdout, "felis watchdog: no [smtp] relay configured, so this is logged only: %s\n", subject) - case len(state.Recipients) == 0: - fmt.Fprintf(stdout, "felis watchdog: no owner account has a verified email, so this is logged only: %s\n", subject) + case plan.Empty(): + case hold != "": + fmt.Fprintf(stdout, "felis watchdog: %s; holding this mail: %s\n", hold, subject) + case unheard != "": + fmt.Fprintf(stdout, "felis watchdog: %s, so this is logged only: %s\n", unheard, subject) + state.Commit(plan, now) default: - if err := sendAlert(ctx, cfg, state, subject, body); err != nil { - // Not committed: the same alerts come due again next run. + relay := &mail.SMTP{Host: m.relay.Host, Port: m.relay.Port, From: m.relay.From, Username: m.relay.Username, Password: m.password, RequireTLS: m.relay.RequireTLS} + if err := sendAlert(ctx, m.send(relay), state.Recipients, subject, body); err != nil { fmt.Fprintf(stderr, "felis watchdog: mail %q: %v\n", subject, err) - save() - return 1 + return "the alert mail failed: " + err.Error(), true } fmt.Fprintf(stdout, "felis watchdog: mailed %s: %s\n", strings.Join(state.Recipients, ", "), subject) + state.Commit(plan, now) } - state.Commit(plan, now) - return save() + return unheard, false +} + +// configMailer reaches the owners through the relay felis.toml configures. +func configMailer(c config.SMTPConfig, cachedPassword string, send func(*mail.SMTP) alertSender) mailer { + return mailer{relay: cachedRelay(c), password: smtpPassword(c, cachedPassword), send: send} +} + +// cachedRelay is what State.Relay keeps of c, nil when no relay is configured. +func cachedRelay(c config.SMTPConfig) *watchdog.Relay { + if c.Host == "" { + return nil + } + return &watchdog.Relay{Host: c.Host, Port: c.Port, From: c.From, Username: c.Username, RequireTLS: c.TLSRequired()} +} + +// smtpPassword is the relay password a mail signs in with: the env var [smtp] +// password_ref names when it is set, else the one the state caches. +func smtpPassword(c config.SMTPConfig, cached string) string { + if ref := c.PasswordRef; ref != "" && os.Getenv(ref) != "" { + return os.Getenv(ref) + } + return cached +} + +// unitFailedRun is one run of felis-watchdog-failed.service. +type unitFailedRun struct { + cfgPath, statePath, 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 + send func(*mail.SMTP) alertSender + client *http.Client + now time.Time +} + +// watchdogUnitFailed is felis-watchdog-failed.service, which systemd starts +// through OnFailure= when a run of felis-watchdog.service fails: a crash, a +// felis.toml that no longer loads, a hang past the unit's timeout, a mail +// that did not go out. Such a run checks and mails nothing, so this records +// the failure as the alert watchdog/run, due after five failed runs in a row +// and cleared by the next run that succeeds; mails it through the relay the +// last good run cached when felis.toml does not load; and pings the +// heartbeat's failure endpoint. Every other alert keeps its state. +func watchdogUnitFailed(r unitFailedRun, stdout, stderr io.Writer) int { + detail := failureDetail(r.result, r.exitStatus) + cfg, cfgErr := config.Load(r.cfgPath) + if cfgErr != nil { + detail += "; " + cfgErr.Error() + } + fmt.Fprintf(stdout, "felis watchdog: felis-watchdog.service failed: %s\n", detail) + offsiteOn := cfgErr != nil || cfg.Offsite.Enabled() + beat := heartbeat{ + fail: true, + report: "felis-watchdog.service failed: " + detail, + standby: standsBy(offsiteOn, r.offsiteStatus), + quiet: r.now.Before(watchdog.QuietUntil(r.quietPath)), + } + var err error + 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) + if err != nil { + // The next run that gets that far moves a state that does not parse + // aside (watchdog.RecoverState). + fmt.Fprintf(stderr, "felis watchdog: %v; mailing nothing\n", err) + beat.report += "\nThe watchdog state does not load either, so nothing was mailed: " + err.Error() + beat.send(r.client, stdout, stderr) + return 1 + } + plan := state.Observe(watchdog.Report{Findings: []watchdog.Finding{watchdog.WatchdogFailed(detail)}, Unknown: []string{""}}, r.now) + host, _ := os.Hostname() + subject, body := plan.Message(host, r.now) + m := mailer{relay: state.Relay, password: state.SMTPPassword, send: r.send} + if cfgErr == nil { + m = configMailer(cfg.SMTP, state.SMTPPassword, r.send) + } + ctx, cancel := context.WithTimeout(context.Background(), time.Minute) + defer cancel() + unheard, mailFailed := m.deliver(ctx, state, plan, subject, body, mailHold(r.quietPath, offsiteOn, r.offsiteStatus, r.now), r.now, stdout, stderr) + code := 0 + if mailFailed { + code = 1 + } + if err := watchdog.SaveState(r.statePath, state); err != nil { + fmt.Fprintf(stderr, "felis watchdog: save state: %v\n", err) + code = 1 + } + if unheard != "" { + beat.report += "\nThe alerts reach no one: " + unheard + } + beat.send(r.client, stdout, stderr) + return code +} + +// failureDetail names how felis-watchdog.service failed. +func failureDetail(result, exitStatus string) string { + switch { + case result == "": + return "systemd named no cause (journalctl -u felis-watchdog -n 50)" + case exitStatus == "": + return "result " + result + } + return "result " + result + ", exit status " + exitStatus } // mailHold is why this run's mail waits, "" when it goes out: the installer's @@ -288,21 +468,24 @@ func proxyFinding(ctx context.Context, addr string) *watchdog.Finding { } } +// alertSender mails one alert; smtpSender is the real one. +type alertSender func(ctx context.Context, to, subject, body string) error + +func smtpSender(relay *mail.SMTP) alertSender { return relay.SendNotice } + +// watchdogSender is what a run mails through; tests stand a recorder in. +var watchdogSender = smtpSender + // sendAlert mails subject/body to every recipient; it fails only when no // recipient got it. -func sendAlert(ctx context.Context, cfg *config.Config, state *watchdog.State, subject, body string) error { - password := state.SMTPPassword - if ref := cfg.SMTP.PasswordRef; ref != "" && os.Getenv(ref) != "" { - password = os.Getenv(ref) - } - relay := smtpRelay(cfg.SMTP, password) +func sendAlert(ctx context.Context, send alertSender, recipients []string, subject, body string) error { var errs []error - for _, to := range state.Recipients { - if err := relay.SendNotice(ctx, to, subject, body); err != nil { + for _, to := range recipients { + if err := send(ctx, to, subject, body); err != nil { errs = append(errs, fmt.Errorf("%s: %w", to, err)) } } - if len(errs) == len(state.Recipients) { + if len(errs) == len(recipients) { return errors.Join(errs...) } return nil diff --git a/cmd/felis/watchdog_heartbeat.go b/cmd/felis/watchdog_heartbeat.go new file mode 100644 index 0000000..1dc52b3 --- /dev/null +++ b/cmd/felis/watchdog_heartbeat.go @@ -0,0 +1,164 @@ +package main + +import ( + "context" + "errors" + "fmt" + "io" + "net/http" + "net/url" + "os" + "strings" + "time" + + "felis.lolicon.best/internal/offsite" +) + +// defaultHeartbeatFile holds the heartbeat URL deploy/bootstrap.sh writes from +// FELIS_WATCHDOG_HEARTBEAT_URL. It lives in /etc/felis, so a host rebuilt from +// a bundle pings the same check once it takes the off-site bucket over. +const defaultHeartbeatFile = "/etc/felis/watchdog-heartbeat-url" + +const ( + // heartbeatTimeout bounds one ping; a monitoring service slower than that + // is as good as down for the run. + heartbeatTimeout = 10 * time.Second + // heartbeatReportMax caps the report a failure ping carries: monitoring + // services keep about the first 10 KB of a ping's body. + heartbeatReportMax = 10000 +) + +// heartbeat is the ping one run sends to a dead man's switch at a monitoring +// service (Healthchecks.io, and the services that copy its API), which alerts +// its own users when the pings stop: the host down, the timer gone, the +// watchdog failing before it can mail. No check on the host can report those. +// A run whose alerts reach the owners GETs url; one whose alerts reach no one +// POSTs report to url/fail, or withholds the ping when url has a query, where +// no /fail can be added and the missing ping trips the check instead. +type heartbeat struct { + url string // "" pings nothing + fail bool + report string + // standby is a host standing by for another host's off-site bucket: a + // rehearsal, or a rebuild not taken over. It pings nothing, or it would + // keep the check of the host that writes the bucket green after that host + // died. + standby bool + // quiet is the installer's quiet window, which restarts things on + // purpose: no failure is pinged. + quiet bool +} + +// send pings the heartbeat and logs the outcome. +func (b heartbeat) send(cl *http.Client, stdout, stderr io.Writer) { + switch { + case b.url == "": + return + case b.standby: + fmt.Fprintln(stdout, "felis watchdog: this host stands by for the off-site bucket; pinging no heartbeat (the host that writes the bucket pings it)") + return + case b.fail && b.quiet: + fmt.Fprintln(stdout, "felis watchdog: quiet while the installer runs; withholding the failure ping") + return + } + sent, err := b.ping(cl) + switch { + case err != nil: + fmt.Fprintf(stderr, "felis watchdog: heartbeat: %v\n", err) + case !sent: + fmt.Fprintf(stdout, "felis watchdog: withholding the heartbeat ping (the URL has a query, so it has no /fail endpoint)\n") + case b.fail: + fmt.Fprintf(stdout, "felis watchdog: pinged the heartbeat's failure endpoint at %s\n", redactURL(b.url)) + } +} + +// ping sends the request; sent is false when a failure withholds it. +func (b heartbeat) ping(cl *http.Client) (sent bool, err error) { + ctx, cancel := context.WithTimeout(context.Background(), heartbeatTimeout) + defer cancel() + method, target, body := http.MethodGet, b.url, io.Reader(nil) + if b.fail { + if strings.Contains(b.url, "?") { + return false, nil + } + method, target = http.MethodPost, strings.TrimSuffix(b.url, "/")+"/fail" + body = strings.NewReader(clipUTF8(b.report, heartbeatReportMax)) + } + req, err := http.NewRequestWithContext(ctx, method, target, body) + if err != nil { + return false, fmt.Errorf("%s %s: bad URL", method, redactURL(target)) + } + resp, err := cl.Do(req) + if err != nil { + // A url.Error quotes the whole URL, the check's key among it. + var ue *url.Error + if errors.As(err, &ue) { + err = ue.Err + } + return false, fmt.Errorf("%s %s: %w", method, redactURL(target), err) + } + io.Copy(io.Discard, io.LimitReader(resp.Body, 4096)) + resp.Body.Close() + if resp.StatusCode/100 != 2 { + return false, fmt.Errorf("%s %s: %s", method, redactURL(target), resp.Status) + } + return true, nil +} + +// clipUTF8 cuts s to at most n bytes without splitting a character. +func clipUTF8(s string, n int) string { + if len(s) <= n { + return s + } + return strings.ToValidUTF8(s[:n], "") +} + +// readHeartbeatURL reads the heartbeat URL from path; no file is no heartbeat. +func readHeartbeatURL(path string) (string, error) { + if path == "" { + return "", nil + } + raw, err := os.ReadFile(path) + if errors.Is(err, os.ErrNotExist) { + return "", nil + } + if err != nil { + return "", err + } + s := strings.TrimSpace(string(raw)) + if err := checkHeartbeatURL(s); err != nil { + return "", fmt.Errorf("%s: %w", path, err) + } + return s, nil +} + +// checkHeartbeatURL accepts an http(s) URL with a host. Its error leaves the +// URL out: the path is the check's key, which anyone who reads it can ping in +// the host's name. +func checkHeartbeatURL(s string) error { + u, err := url.Parse(s) + if err != nil || (u.Scheme != "http" && u.Scheme != "https") || u.Host == "" || strings.ContainsAny(s, " \t\r\n") { + return errors.New("the heartbeat URL is not an http:// or https:// URL") + } + return nil +} + +// redactURL is a heartbeat URL as logs show it: its scheme and host. +func redactURL(s string) string { + u, err := url.Parse(s) + if err != nil || u.Host == "" { + return "(the heartbeat URL)" + } + return u.Scheme + "://" + u.Host + "/..." +} + +// standsBy reports whether this host stands by for another host's off-site +// bucket (offsite.Status.Standby), however old that record is: the +// installer's take-over or the host's first write ends it. +func standsBy(offsiteOn bool, statusPath string) bool { + if !offsiteOn { + return false + } + st, err := offsite.ReadStatus(statusPath) + return err == nil && st != nil && st.Standby +} diff --git a/cmd/felis/watchdog_heartbeat_test.go b/cmd/felis/watchdog_heartbeat_test.go new file mode 100644 index 0000000..38757fa --- /dev/null +++ b/cmd/felis/watchdog_heartbeat_test.go @@ -0,0 +1,589 @@ +package main + +import ( + "bytes" + "context" + "errors" + "fmt" + "io" + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "strings" + "sync" + "testing" + "time" + "unicode/utf8" + + "felis.lolicon.best/internal/config" + "felis.lolicon.best/internal/mail" + "felis.lolicon.best/internal/offsite" + "felis.lolicon.best/internal/watchdog" +) + +// pingLog is a monitoring service that records every ping it gets. +type pingLog struct { + mu sync.Mutex + pings []string // "METHOD path?query" + bodies []string + status int +} + +func newPingServer(t *testing.T) (*pingLog, *httptest.Server) { + t.Helper() + l := &pingLog{status: http.StatusOK} + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + body, _ := io.ReadAll(r.Body) + l.mu.Lock() + defer l.mu.Unlock() + p := r.Method + " " + r.URL.Path + if r.URL.RawQuery != "" { + p += "?" + r.URL.RawQuery + } + l.pings = append(l.pings, p) + l.bodies = append(l.bodies, string(body)) + w.WriteHeader(l.status) + })) + t.Cleanup(srv.Close) + return l, srv +} + +func (l *pingLog) got() ([]string, []string) { + l.mu.Lock() + defer l.mu.Unlock() + return append([]string(nil), l.pings...), append([]string(nil), l.bodies...) +} + +// TestHeartbeatSend: a run whose alerts reach the owners GETs the URL, one +// whose alerts reach no one POSTs its report to /fail, and a standby host, a +// failure in the installer's quiet window and a query URL that has no /fail +// send nothing. +func TestHeartbeatSend(t *testing.T) { + const key = "/ping/5f1e0c2a-check-key" + for _, tc := range []struct { + what string + beat heartbeat + path string // appended to the server URL + want string // the ping, "" for none + wantBody string + wantOut string + }{ + {what: "success", beat: heartbeat{}, path: key, want: "GET " + key}, + {what: "failure", beat: heartbeat{fail: true, report: "the alerts reach no one: x"}, path: key, want: "POST " + key + "/fail", wantBody: "the alerts reach no one: x", wantOut: "pinged the heartbeat's failure endpoint"}, + {what: "failure, URL with a trailing slash", beat: heartbeat{fail: true, report: "r"}, path: key + "/", want: "POST " + key + "/fail", wantBody: "r"}, + {what: "success, URL with a query", beat: heartbeat{}, path: key + "?rid=7", want: "GET " + key + "?rid=7"}, + {what: "failure, URL with a query", beat: heartbeat{fail: true, report: "r"}, path: key + "?rid=7", wantOut: "withholding the heartbeat ping"}, + {what: "standby, success", beat: heartbeat{standby: true}, path: key, wantOut: "stands by for the off-site bucket"}, + {what: "standby, failure", beat: heartbeat{standby: true, fail: true}, path: key, wantOut: "stands by for the off-site bucket"}, + {what: "quiet, failure", beat: heartbeat{quiet: true, fail: true}, path: key, wantOut: "withholding the failure ping"}, + {what: "quiet, success", beat: heartbeat{quiet: true}, path: key, want: "GET " + key}, + } { + log, srv := newPingServer(t) + b := tc.beat + b.url = srv.URL + tc.path + var stdout, stderr bytes.Buffer + b.send(srv.Client(), &stdout, &stderr) + pings, bodies := log.got() + switch { + case tc.want == "" && len(pings) != 0: + t.Errorf("%s: pinged %v, want nothing", tc.what, pings) + case tc.want != "" && (len(pings) != 1 || pings[0] != tc.want): + t.Errorf("%s: pinged %v, want %q", tc.what, pings, tc.want) + case tc.want != "" && bodies[0] != tc.wantBody: + t.Errorf("%s: body %q, want %q", tc.what, bodies[0], tc.wantBody) + } + if !strings.Contains(stdout.String(), tc.wantOut) || stderr.Len() != 0 { + t.Errorf("%s: stdout %q (want %q), stderr %q", tc.what, stdout.String(), tc.wantOut, stderr.String()) + } + } +} + +// TestHeartbeatErrors: a ping the service refuses or that cannot connect is +// logged without the URL's path, the check's key. +func TestHeartbeatErrors(t *testing.T) { + const key = "5f1e0c2a-check-key" + log, srv := newPingServer(t) + log.status = http.StatusNotFound + var stdout, stderr bytes.Buffer + heartbeat{url: srv.URL + "/" + key}.send(srv.Client(), &stdout, &stderr) + if got := stderr.String(); !strings.Contains(got, "heartbeat: GET http://127.0.0.1") || !strings.Contains(got, "404") || strings.Contains(got, key) { + t.Errorf("refused ping: stderr %q; want the host and status, not the key", got) + } + + closed := httptest.NewServer(http.NotFoundHandler()) + dead := closed.URL + "/" + key + closed.Close() + stderr.Reset() + heartbeat{url: dead, fail: true, report: "r"}.send(http.DefaultClient, &stdout, &stderr) + if got := stderr.String(); !strings.Contains(got, "heartbeat: POST http://127.0.0.1") || strings.Contains(got, key) { + t.Errorf("unreachable service: stderr %q; want the host, not the key", got) + } +} + +// TestHeartbeatReportClipped: a long report is cut to what the service keeps, +// on a character boundary. +func TestHeartbeatReportClipped(t *testing.T) { + log, srv := newPingServer(t) + report := strings.Repeat("磁盘", heartbeatReportMax) + heartbeat{url: srv.URL + "/k", fail: true, report: report}.send(srv.Client(), io.Discard, io.Discard) + _, bodies := log.got() + if len(bodies) != 1 || len(bodies[0]) > heartbeatReportMax || len(bodies[0]) < heartbeatReportMax-3 || !utf8.ValidString(bodies[0]) { + t.Fatalf("clipped body: %d pings, %d bytes, valid UTF-8 %v", len(bodies), len(bodies[0]), utf8.ValidString(bodies[0])) + } + if got := clipUTF8("short", heartbeatReportMax); got != "short" { + t.Errorf("clipUTF8(short) = %q", got) + } +} + +func TestReadHeartbeatURL(t *testing.T) { + dir := t.TempDir() + path := filepath.Join(dir, "watchdog-heartbeat-url") + if u, err := readHeartbeatURL(path); u != "" || err != nil { + t.Fatalf("no file: %q, %v", u, err) + } + if u, err := readHeartbeatURL(""); u != "" || err != nil { + t.Fatalf("no path: %q, %v", u, err) + } + writeTestFile(t, path, "https://hc-ping.com/5f1e0c2a\n", 0o600) + if u, err := readHeartbeatURL(path); u != "https://hc-ping.com/5f1e0c2a" || err != nil { + t.Fatalf("good file: %q, %v", u, err) + } + for _, bad := range []string{"", "hc-ping.com/5f1e0c2a", "ftp://hc-ping.com/5f1e0c2a", "https:///5f1e0c2a", "https://hc-ping.com/5f1e 0c2a"} { + writeTestFile(t, path, bad, 0o600) + u, err := readHeartbeatURL(path) + if u != "" || err == nil || !strings.Contains(err.Error(), path) || (bad != "" && strings.Contains(err.Error(), "5f1e")) { + t.Errorf("%q: %q, %v; want an error naming the file and not the URL", bad, u, err) + } + } +} + +func TestRedactURL(t *testing.T) { + for in, want := range map[string]string{ + "https://hc-ping.com/5f1e0c2a": "https://hc-ping.com/...", + "http://user:pw@status.example:8080/k?x=1": "http://status.example:8080/...", + "not a url": "(the heartbeat URL)", + } { + if got := redactURL(in); got != want { + t.Errorf("redactURL(%q) = %q, want %q", in, got, want) + } + } +} + +// TestStandsBy: a standby record keeps the host from pinging however old it +// is; a displaced host, the writer, or a host without [offsite] pings. +func TestStandsBy(t *testing.T) { + status := filepath.Join(t.TempDir(), "status.json") + if standsBy(true, status) { + t.Fatal("no status file stands by") + } + old := &offsite.Writer{HostID: "bbbbbbbbbbbbbbbb", Host: "prod-1", At: time.Now().Add(-30 * 24 * time.Hour)} + for _, tc := range []struct { + what string + st offsite.Status + offsiteOn bool + want bool + }{ + {"standing by for a writer gone quiet a month ago", offsite.Status{Standby: true, Writer: old}, true, true}, + {"standing by, [offsite] since removed", offsite.Status{Standby: true, Writer: old}, false, false}, + {"displaced", offsite.Status{Displaced: true, Writer: old}, true, false}, + {"the writer itself", offsite.Status{LastSuccess: time.Now()}, true, false}, + } { + if err := offsite.WriteStatus(status, tc.st); err != nil { + t.Fatal(err) + } + if got := standsBy(tc.offsiteOn, status); got != tc.want { + t.Errorf("%s: standsBy = %v, want %v", tc.what, got, tc.want) + } + } +} + +func TestFailureReport(t *testing.T) { + r := watchdog.Report{Findings: []watchdog.Finding{{Key: "postgres", Severity: watchdog.Critical, SummaryEN: "PostgreSQL is down"}}} + for _, tc := range []struct { + what string + unheard string + mailFailed bool + saveErr error + open bool + want string // "" for a success ping + }{ + {what: "all good", open: true}, + {what: "no relay, nothing mailed yet", unheard: "no [smtp] relay is configured"}, + {what: "no relay, an alert open", unheard: "no [smtp] relay is configured", open: true, want: "the alerts reach no one: no [smtp] relay is configured"}, + {what: "the mail failed", unheard: "the alert mail failed: refused", mailFailed: true, want: "the alerts reach no one: the alert mail failed: refused"}, + {what: "the state did not save", saveErr: errors.New("disk full"), want: "the watchdog state did not save: disk full"}, + } { + got := failureReport(tc.unheard, tc.mailFailed, tc.saveErr, tc.open, r) + if (got == "") != (tc.want == "") || !strings.Contains(got, tc.want) || (got != "" && !strings.Contains(got, "[critical] postgres: PostgreSQL is down")) { + t.Errorf("%s: report %q, want %q and the findings", tc.what, got, tc.want) + } + } +} + +// alertRecorder records the mail a run hands the relay. +type alertRecorder struct { + relays []*mail.SMTP + sent []string // "to: subject" + fail map[string]bool +} + +func (f *alertRecorder) sender(relay *mail.SMTP) alertSender { + f.relays = append(f.relays, relay) + return func(_ context.Context, to, subject, _ string) error { + if f.fail[to] { + return errors.New("550 refused") + } + f.sent = append(f.sent, to+": "+subject) + return nil + } +} + +// TestMailerDeliver: a plan goes out and is committed; held, it waits +// uncommitted; with no relay or recipient it is logged and committed; a mail +// no recipient got is left uncommitted to come due again. +func TestMailerDeliver(t *testing.T) { + now := time.Now() + relay := &watchdog.Relay{Host: "smtp.example.com", Port: 587, From: "felis@example.com", Username: "felis"} + for _, tc := range []struct { + what string + relay *watchdog.Relay + recipients []string + hold string + fail map[string]bool + wantUnheard string + wantFailed bool + committed bool + sent int + }{ + {what: "mailed", relay: relay, recipients: []string{"a@example.com", "b@example.com"}, committed: true, sent: 2}, + {what: "one recipient refused", relay: relay, recipients: []string{"a@example.com", "b@example.com"}, fail: map[string]bool{"a@example.com": true}, committed: true, sent: 1}, + {what: "every recipient refused", relay: relay, recipients: []string{"a@example.com"}, fail: map[string]bool{"a@example.com": true}, wantUnheard: "the alert mail failed", wantFailed: true}, + {what: "held", relay: relay, recipients: []string{"a@example.com"}, hold: "quiet until later"}, + {what: "no relay", recipients: []string{"a@example.com"}, wantUnheard: "no [smtp] relay is configured", committed: true}, + {what: "no recipient", relay: relay, wantUnheard: "no owner account has a verified email", committed: true}, + } { + state := &watchdog.State{Recipients: tc.recipients} + plan := state.Observe(watchdog.Report{Findings: []watchdog.Finding{{Key: "postgres", Severity: watchdog.Critical, SummaryEN: "down"}}}, now) + f := &alertRecorder{fail: tc.fail} + m := mailer{relay: tc.relay, password: "relay-pw", send: f.sender} + var stdout, stderr bytes.Buffer + unheard, failed := m.deliver(context.Background(), state, plan, "subject", "body", tc.hold, now, &stdout, &stderr) + if !strings.HasPrefix(unheard, tc.wantUnheard) || (tc.wantUnheard == "") != (unheard == "") || failed != tc.wantFailed { + t.Errorf("%s: unheard %q, failed %v; want %q, %v", tc.what, unheard, failed, tc.wantUnheard, tc.wantFailed) + } + if got := !state.Alerts["postgres"].Notified.IsZero(); got != tc.committed { + t.Errorf("%s: committed %v, want %v", tc.what, got, tc.committed) + } + if len(f.sent) != tc.sent { + t.Errorf("%s: sent %v, want %d mails", tc.what, f.sent, tc.sent) + } + if len(f.relays) > 0 { + if got := *f.relays[0]; got != (mail.SMTP{Host: "smtp.example.com", Port: 587, From: "felis@example.com", Username: "felis", Password: "relay-pw"}) { + t.Errorf("%s: relay %+v", tc.what, got) + } + } + } +} + +// TestCachedRelay: the cache keeps the relay's coordinates and its TLS rule, +// and nothing when no relay is configured. +func TestCachedRelay(t *testing.T) { + if r := cachedRelay(testSMTPConfig("")); r != nil { + t.Fatalf("no relay cached %+v", r) + } + got := cachedRelay(testSMTPConfig("smtp.example.com")) + if got == nil || *got != (watchdog.Relay{Host: "smtp.example.com", Port: 2525, From: "felis@example.com", Username: "felis", RequireTLS: true}) { + t.Fatalf("cachedRelay = %+v", got) + } + if got := cachedRelay(testSMTPConfig("127.0.0.1")); got == nil || got.RequireTLS { + t.Fatalf("a relay on this host: %+v, want TLS not required", got) + } +} + +func testSMTPConfig(host string) config.SMTPConfig { + if host == "" { + return config.SMTPConfig{} + } + return config.SMTPConfig{Host: host, Port: 2525, From: "felis@example.com", Username: "felis"} +} + +// TestSMTPPassword: the env var password_ref names wins over the cache once +// it is set. +func TestSMTPPassword(t *testing.T) { + c := testSMTPConfig("smtp.example.com") + c.PasswordRef = "FELIS_TEST_WATCHDOG_RELAY_PW" + t.Setenv(c.PasswordRef, "") + if got := smtpPassword(c, "cached"); got != "cached" { + t.Errorf("env var unset: %q", got) + } + t.Setenv(c.PasswordRef, "from-env") + if got := smtpPassword(c, "cached"); got != "from-env" { + t.Errorf("env var set: %q", got) + } +} + +const testWatchdogConfig = `[database] +url = "postgres://felis:pw@127.0.0.1:1/felis?sslmode=disable&connect_timeout=2" +[server] +root_domain = "example.com" +[archive] +store = "tarLocal" +[k8s] +egress_mode = "nodeport" +` + +const testWatchdogSMTP = `[smtp] +host = "smtp.config.example" +port = 2525 +from = "felis@example.com" +username = "felis" +password_ref = "FELIS_TEST_WATCHDOG_RELAY_PW" +` + +// unitFailedFixture is a host whose watchdog last ran well: one alert open, +// one owner and the relay cached. +func unitFailedFixture(t *testing.T, cfg string) (unitFailedRun, *alertRecorder, *pingLog) { + t.Helper() + dir := t.TempDir() + log, srv := newPingServer(t) + beatFile := filepath.Join(dir, "watchdog-heartbeat-url") + writeTestFile(t, beatFile, srv.URL+"/check-key\n", 0o600) + cfgPath := filepath.Join(dir, "felis.toml") + writeTestFile(t, cfgPath, cfg, 0o600) + statePath := filepath.Join(dir, "state.json") + state := &watchdog.State{ + Recipients: []string{"owner@example.com"}, + SMTPPassword: "cached-pw", + Relay: &watchdog.Relay{Host: "smtp.cached.example", Port: 587, From: "felis@example.com", RequireTLS: true}, + } + mem := watchdog.Finding{Key: "memory", Severity: watchdog.Warning, SummaryEN: "memory low"} + state.Commit(state.Observe(watchdog.Report{Findings: []watchdog.Finding{mem}}, time.Now().Add(-time.Hour)), time.Now().Add(-time.Hour)) + if err := watchdog.SaveState(statePath, state); err != nil { + t.Fatal(err) + } + f := &alertRecorder{} + return unitFailedRun{ + cfgPath: cfgPath, statePath: statePath, 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 +} + +// TestWatchdogUnitFailedBrokenConfig: failed runs of a watchdog whose +// felis.toml no longer loads are mailed through the relay the last good run +// cached, after five in a row; every one pings /fail; the open alert keeps +// its state. +func TestWatchdogUnitFailedBrokenConfig(t *testing.T) { + r, f, log := unitFailedFixture(t, "[database\n") + start := r.now + for i := 0; i <= 5; i++ { + r.now = start.Add(time.Duration(i) * 2 * time.Minute) + var stdout, stderr bytes.Buffer + if code := watchdogUnitFailed(r, &stdout, &stderr); code != 0 { + t.Fatalf("run %d: exit %d (stdout %s, stderr %s)", i, code, stdout.String(), stderr.String()) + } + if i < 5 && len(f.sent) != 0 { + t.Fatalf("run %d, %v after the first failure: mailed %v, want nothing yet", i, r.now.Sub(start), f.sent) + } + } + if len(f.sent) != 1 || !strings.Contains(f.sent[0], "owner@example.com: ") { + t.Fatalf("mailed %v, want one alert to the cached owner", f.sent) + } + if got := *f.relays[0]; got.Host != "smtp.cached.example" || got.Password != "cached-pw" || !got.RequireTLS { + t.Fatalf("relay %+v, want the cached one", got) + } + pings, bodies := log.got() + if len(pings) != 6 || pings[0] != "POST /check-key/fail" || !strings.Contains(bodies[0], "felis-watchdog.service failed: result exit-code, exit status 1; ") { + t.Fatalf("pings %v, bodies %q", pings, bodies) + } + state, err := watchdog.LoadState(r.statePath) + if err != nil { + t.Fatal(err) + } + if a := state.Alerts["watchdog/run"]; a == nil || a.Notified.IsZero() || !strings.Contains(a.SummaryEN, "result exit-code, exit status 1") { + t.Fatalf("watchdog/run alert = %+v", a) + } + if a := state.Alerts["memory"]; a == nil || !a.ClearedAt.IsZero() || !a.Notified.Before(start) { + t.Fatalf("memory alert = %+v, want it untouched", a) + } +} + +// 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) { + r, f, _ := unitFailedFixture(t, testWatchdogConfig+testWatchdogSMTP) + t.Setenv("FELIS_TEST_WATCHDOG_RELAY_PW", "env-pw") + start := r.now + for _, at := range []time.Duration{0, 10 * time.Minute} { + r.now = start.Add(at) + var stdout, stderr bytes.Buffer + if code := watchdogUnitFailed(r, &stdout, &stderr); code != 0 { + t.Fatalf("exit %d (stdout %s, stderr %s)", code, stdout.String(), stderr.String()) + } + } + if len(f.relays) != 1 || f.relays[0].Host != "smtp.config.example" || f.relays[0].Port != 2525 || f.relays[0].Password != "env-pw" { + t.Fatalf("relays %+v, want the configured one with the env password", f.relays) + } +} + +// TestWatchdogUnitFailedHeld: in the installer's quiet window the alert waits +// and no failure is pinged; a host standing by for the off-site bucket pings +// nothing either. +func TestWatchdogUnitFailedHeld(t *testing.T) { + r, f, log := unitFailedFixture(t, "[database\n") + writeTestFile(t, r.quietPath, fmt.Sprintf("%d\n", r.now.Add(time.Hour).Unix()), 0o644) + start := r.now + for _, at := range []time.Duration{0, 10 * time.Minute} { + r.now = start.Add(at) + watchdogUnitFailed(r, io.Discard, io.Discard) + } + if pings, _ := log.got(); len(f.sent) != 0 || len(pings) != 0 { + t.Fatalf("quiet window: mailed %v, pinged %v", f.sent, pings) + } + + os.Remove(r.quietPath) + w := &offsite.Writer{HostID: "bbbbbbbbbbbbbbbb", Host: "prod-1", At: r.now.Add(-time.Hour)} + if err := offsite.WriteStatus(r.offsiteStatus, offsite.Status{Standby: true, Writer: w}); err != nil { + t.Fatal(err) + } + var stdout bytes.Buffer + watchdogUnitFailed(r, &stdout, io.Discard) + if pings, _ := log.got(); len(f.sent) != 0 || len(pings) != 0 || !strings.Contains(stdout.String(), "stands by for host prod-1") { + t.Fatalf("standby: mailed %v, pinged %v, stdout %s", f.sent, pings, stdout.String()) + } +} + +// TestWatchdogUnitFailedStateUnreadable: with no state to mail from, the +// failure still reaches the heartbeat. +func TestWatchdogUnitFailedStateUnreadable(t *testing.T) { + r, f, log := unitFailedFixture(t, "[database\n") + writeTestFile(t, r.statePath, "{", 0o600) + if code := watchdogUnitFailed(r, io.Discard, io.Discard); code != 1 { + t.Fatalf("exit %d, want 1", code) + } + pings, bodies := log.got() + if len(f.sent) != 0 || len(pings) != 1 || pings[0] != "POST /check-key/fail" || !strings.Contains(bodies[0], "state does not load") { + t.Fatalf("mailed %v, pinged %v %q", f.sent, pings, bodies) + } +} + +func TestFailureDetail(t *testing.T) { + for _, tc := range [][3]string{ + {"exit-code", "1", "result exit-code, exit status 1"}, + {"timeout", "", "result timeout"}, + {"", "", "systemd named no cause (journalctl -u felis-watchdog -n 50)"}, + } { + if got := failureDetail(tc[0], tc[1]); got != tc[2] { + t.Errorf("failureDetail(%q, %q) = %q, want %q", tc[0], tc[1], got, tc[2]) + } + } +} + +// TestWatchdogRunHeartbeat runs whole watchdog passes with the API server and +// PostgreSQL down and the relay a recorder: a pass whose alerts reach the +// owners pings success; one whose mail fails, or that has no relay while an +// alert is open, posts its report to /fail; a host standing by for the +// off-site bucket pings nothing; a state file that does not parse is moved +// aside and reported. +func TestWatchdogRunHeartbeat(t *testing.T) { + due := func(statePath string) { + // PostgreSQL has been down for an hour and nobody was told yet. + s := &watchdog.State{Recipients: []string{"owner@example.com"}, SMTPPassword: "cached-pw"} + s.Observe(watchdog.Report{Findings: []watchdog.Finding{watchdog.PostgresDown(errors.New("refused"))}}, time.Now().Add(-time.Hour)) + if err := watchdog.SaveState(statePath, s); err != nil { + t.Fatal(err) + } + } + open := func(statePath string) { + // The owners were told of PostgreSQL half an hour ago. + s := &watchdog.State{Recipients: []string{"owner@example.com"}} + at := time.Now().Add(-30 * time.Minute) + r := watchdog.Report{Findings: []watchdog.Finding{watchdog.PostgresDown(errors.New("refused"))}} + s.Observe(r, at.Add(-time.Hour)) + s.Commit(s.Observe(r, at), at) + if err := watchdog.SaveState(statePath, s); err != nil { + t.Fatal(err) + } + } + const offsiteTable = "[offsite]\nendpoint = \"https://s3.example.com\"\nbucket = \"felis\"\n" + t.Setenv("FELIS_TEST_WATCHDOG_RELAY_PW", "env-pw") + for _, tc := range []struct { + what string + cfg string + state func(path string) + standby bool + quiet bool + refused bool + wantCode int + want string // the ping, "" for none + wantBody string + wantOut string + wantSent int + }{ + {what: "nothing due", cfg: testWatchdogConfig + testWatchdogSMTP, want: "GET /check-key"}, + {what: "mailed", cfg: testWatchdogConfig + testWatchdogSMTP, state: due, want: "GET /check-key", wantSent: 1}, + {what: "the mail fails", cfg: testWatchdogConfig + testWatchdogSMTP, state: due, refused: true, wantCode: 1, want: "POST /check-key/fail", wantBody: "the alerts reach no one: the alert mail failed: owner@example.com: 550 refused"}, + {what: "no relay, an alert open", cfg: testWatchdogConfig, state: due, want: "POST /check-key/fail", wantBody: "the alerts reach no one: no [smtp] relay is configured"}, + {what: "no relay, an alert open, the installer running", cfg: testWatchdogConfig, state: open, quiet: true, wantOut: "withholding the failure ping"}, + {what: "standing by for the off-site bucket", cfg: testWatchdogConfig + testWatchdogSMTP + offsiteTable, state: due, standby: true, wantOut: "stands by for the off-site bucket"}, + {what: "a state that does not parse", cfg: testWatchdogConfig, state: func(p string) { writeTestFile(t, p, "{", 0o600) }, want: "GET /check-key", wantOut: "[warning] watchdog/state: the watchdog's state file was unreadable and was moved to "}, + } { + dir := t.TempDir() + t.Setenv("KUBECONFIG", filepath.Join(dir, "no-kubeconfig")) + log, srv := newPingServer(t) + beatFile := filepath.Join(dir, "watchdog-heartbeat-url") + writeTestFile(t, beatFile, srv.URL+"/check-key\n", 0o600) + cfgPath := filepath.Join(dir, "felis.toml") + writeTestFile(t, cfgPath, tc.cfg, 0o600) + statePath := filepath.Join(dir, "state.json") + if tc.state != nil { + tc.state(statePath) + } + statusPath := filepath.Join(dir, "offsite-status.json") + if tc.standby { + w := &offsite.Writer{HostID: "bbbbbbbbbbbbbbbb", Host: "prod-1", At: time.Now().Add(-time.Hour)} + if err := offsite.WriteStatus(statusPath, offsite.Status{Standby: true, Writer: w}); err != nil { + t.Fatal(err) + } + } + if tc.quiet { + writeTestFile(t, filepath.Join(dir, "quiet"), fmt.Sprintf("%d\n", time.Now().Add(time.Hour).Unix()), 0o644) + } + rec := &alertRecorder{} + if tc.refused { + rec.fail = map[string]bool{"owner@example.com": true} + } + watchdogSender = rec.sender + var stdout, stderr bytes.Buffer + code := cmdWatchdog([]string{ + "-config", cfgPath, "-state", statePath, "-quiet-file", filepath.Join(dir, "quiet"), + "-backup-dir", "", "-disk-paths", dir, "-smtp-password-file", filepath.Join(dir, "smtp-password"), + "-offsite-status", statusPath, "-heartbeat-file", beatFile, + }, &stdout, &stderr) + watchdogSender = smtpSender + pings, bodies := log.got() + fail := code != tc.wantCode || len(rec.sent) != tc.wantSent || !strings.Contains(stdout.String(), tc.wantOut) + if tc.want == "" { + fail = fail || len(pings) != 0 + } else { + fail = fail || len(pings) != 1 || pings[0] != tc.want || !strings.Contains(bodies[0], tc.wantBody) + } + if fail { + t.Errorf("%s: exit %d, mailed %v, pings %v %q; want exit %d, %d mails, %q with %q\nstdout %s\nstderr %s", tc.what, code, rec.sent, pings, bodies, tc.wantCode, tc.wantSent, tc.want, tc.wantBody, stdout.String(), stderr.String()) + } + if tc.wantSent > 0 { + if got := *rec.relays[0]; got.Host != "smtp.config.example" || got.Port != 2525 || got.Password != "env-pw" { + t.Errorf("%s: relay %+v, want the configured one with the env password", tc.what, got) + } + if s, err := watchdog.LoadState(statePath); err != nil || s.Relay == nil || s.Relay.Host != "smtp.config.example" { + t.Errorf("%s: the state caches relay %+v (%v), want the configured one", tc.what, s.Relay, err) + } + } + if strings.Contains(tc.wantOut, "watchdog/state") { + if aside, _ := filepath.Glob(statePath + ".unreadable-*"); len(aside) != 1 { + t.Errorf("%s: moved aside %v, want one file", tc.what, aside) + } + } + } +} diff --git a/deploy/bootstrap.sh b/deploy/bootstrap.sh index 4a26b7b..ae96901 100644 --- a/deploy/bootstrap.sh +++ b/deploy/bootstrap.sh @@ -266,6 +266,13 @@ FELIS_OFFSITE_BUCKET="${FELIS_OFFSITE_BUCKET:-}" FELIS_OFFSITE_REGION="${FELIS_OFFSITE_REGION:-}" FELIS_OFFSITE_PREFIX="${FELIS_OFFSITE_PREFIX:-}" FELIS_OFFSITE_DB_KEEP="${FELIS_OFFSITE_DB_KEEP:-}" +# The watchdog's heartbeat (troubleshooting §14): the ping URL of a check at a monitoring +# service such as Healthchecks.io, a dead man's switch. Every watchdog run pings it, and +# the service mails its own users when the pings stop or report failure: the host down, +# the watchdog broken, alerts that reach no one. Nothing on this host can report its own +# death. The URL is kept in /etc/felis/watchdog-heartbeat-url, mode 0600, as its path is +# the key that pings the check; off removes it, and a re-run without it keeps it. +FELIS_WATCHDOG_HEARTBEAT_URL="${FELIS_WATCHDOG_HEARTBEAT_URL:-}" INSTALL_MODE="${FELIS_INSTALL_MODE:-}" # strict stops the install on any preflight problem (preflight below); warn reports them # and goes on, for a host the checks misjudge. @@ -416,6 +423,8 @@ NANO_SERVICE="/etc/systemd/system/felis-nano.service" DB_BACKUP_SERVICE="/etc/systemd/system/felis-db-backup.service" DB_BACKUP_TIMER="/etc/systemd/system/felis-db-backup.timer" WATCHDOG_SERVICE="/etc/systemd/system/felis-watchdog.service" +# OnFailure= of felis-watchdog.service: reports a run that failed (felis watchdog -unit-failed). +WATCHDOG_FAILED_SERVICE="/etc/systemd/system/felis-watchdog-failed.service" WATCHDOG_TIMER="/etc/systemd/system/felis-watchdog.timer" UPDATE_CHECK_SERVICE="/etc/systemd/system/felis-update-check.service" UPDATE_CHECK_TIMER="/etc/systemd/system/felis-update-check.timer" @@ -436,6 +445,8 @@ BUILD_TOOLS_STATUS="/var/lib/felis/build-tools/status.json" # restarts the control plane and the system servers on purpose. cleanup removes it; the # time in it is the backstop for an installer killed before its EXIT trap runs. WATCHDOG_QUIET_FILE="/run/felis/watchdog-quiet-until" +# FELIS_WATCHDOG_HEARTBEAT_URL, where felis watchdog reads it by default. +WATCHDOG_HEARTBEAT_FILE="${STATE_DIR}/watchdog-heartbeat-url" VELOCITY_DIR="/opt/felis/velocity" VELOCITY_USER="felis-velocity" VELOCITY_SERVICE="/etc/systemd/system/felis-velocity.service" @@ -926,6 +937,7 @@ validate_settings() { validate_listen FELIS_NANO_LISTEN "$FELIS_NANO_LISTEN" validate_cidr FELIS_NANO_PROXY_CIDR "$FELIS_NANO_PROXY_CIDR" validate_offsite_settings + validate_heartbeat_url case "$FELIS_PREFLIGHT" in strict|warn) ;; *) die "FELIS_PREFLIGHT must be strict or warn (got '${FELIS_PREFLIGHT}')" ;; @@ -1028,6 +1040,18 @@ validate_offsite_settings() { fi } +# validate_heartbeat_url checks FELIS_WATCHDOG_HEARTBEAT_URL before anything is +# installed: a check's http(s) ping URL, or off. The messages leave the URL out: its path +# is the key that pings the check. +validate_heartbeat_url() { + case "$FELIS_WATCHDOG_HEARTBEAT_URL" in + "" | off) ;; + *[[:space:]]* | *\"* | *\'* | *\\*) die "FELIS_WATCHDOG_HEARTBEAT_URL must not contain spaces, quotes or backslashes" ;; + http://[!/]* | https://[!/]*) ;; + *) die "FELIS_WATCHDOG_HEARTBEAT_URL must be the http:// or https:// ping URL of a monitoring service's check, or off" ;; + esac +} + # --------------------------------------------------------------------------- # 0. Privilege & host facts # --------------------------------------------------------------------------- @@ -4685,11 +4709,6 @@ summary_offsite() { fi } -# The platform watchdog: every two minutes it checks the control plane, the login gate, -# the fleet, PostgreSQL, the game proxy, the database backups and the host's disks and -# memory, and mails the owners (their verified addresses, over the [smtp] relay) what -# has stayed wrong long enough to matter. It runs on the host so a k3s that is down is -# still reported. The first run happens now, so a broken unit shows up in this install. # The daily version check. Felis applies no update on its own; `felis update --record` # compares what this host runs with the newest upstream releases and stores the result, # which the panel's Updates page shows with the command that applies each update. It runs @@ -4730,16 +4749,29 @@ EOF ok "version check: daily; the panel's Updates page shows what has a newer release (journalctl -u felis-update-check)" } +# The platform watchdog: every two minutes it checks the control plane, the login gate, +# the fleet, PostgreSQL, the game proxy, the database backups and the host's disks and +# memory, and mails the owners (their verified addresses, over the [smtp] relay) what +# has stayed wrong long enough to matter. It runs on the host so a k3s that is down is +# still reported. The first run happens now, so a broken unit shows up in this install. +# A run that fails starts felis-watchdog-failed.service (OnFailure=), which mails the +# failure once five runs in a row failed, through the relay the last good run cached, and +# pings the heartbeat's failure endpoint. The heartbeat (FELIS_WATCHDOG_HEARTBEAT_URL) is +# what notices a host that is down or a watchdog that no longer runs at all. The units +# name no heartbeat flag: felis watchdog reads WATCHDOG_HEARTBEAT_FILE by default, so an +# older binary put back under these units still runs. install_watchdog_timer() { local disks="/,/var/lib/rancher/k3s,/var/lib/felis" path for path in "$FELIS_WORLDS_HOST_PATH" "$FELIS_ARCHIVE_LOCAL_PATH" "$FELIS_DB_BACKUP_DIR"; do if [ -n "$path" ]; then disks="${disks},${path}"; fi done + write_heartbeat_url install -d -m 0700 "$(dirname "$WATCHDOG_STATE")" cat > "$WATCHDOG_SERVICE" < "$WATCHDOG_FAILED_SERVICE" < "$WATCHDOG_TIMER" <&2 || true warn "the first watchdog run failed (log above); nothing will be mailed until it runs: sudo systemctl start felis-watchdog.service" fi } +# write_heartbeat_url keeps FELIS_WATCHDOG_HEARTBEAT_URL in WATCHDOG_HEARTBEAT_FILE, mode +# 0600 and replaced whole; off removes the file, and no value keeps it as it is. +write_heartbeat_url() { + local tmp + case "$FELIS_WATCHDOG_HEARTBEAT_URL" in + "") return 0 ;; + off) + rm -f -- "$WATCHDOG_HEARTBEAT_FILE" + return 0 + ;; + esac + # mktemp creates the file 0600, before the key is in it. + tmp="$(mktemp "${WATCHDOG_HEARTBEAT_FILE}.XXXXXX")" + printf '%s\n' "$FELIS_WATCHDOG_HEARTBEAT_URL" > "$tmp" + mv -f -- "$tmp" "$WATCHDOG_HEARTBEAT_FILE" +} + +# heartbeat_host is the heartbeat URL as the install shows it: its scheme and host. +heartbeat_host() { + local url rest host + url="$(head -n 1 "$WATCHDOG_HEARTBEAT_FILE")" + rest="${url#*://}" + host="${rest%%/*}" + host="${host%%\?*}" + host="${host##*@}" + printf '%s://%s/...' "${url%%://*}" "$host" +} + +# summary_heartbeat closes the install on the heartbeat: without one, nothing off this +# machine notices it going down. +summary_heartbeat() { + if [ -f "$WATCHDOG_HEARTBEAT_FILE" ]; then + log "Heartbeat: every watchdog run pings $(heartbeat_host); that service mails you when the pings stop." + return 0 + fi + warn "NO HEARTBEAT: nothing off this machine notices it going down or its watchdog stopping." + warn "Create a check at a monitoring service (Healthchecks.io or alike; period 2 min, grace 10 min)," + warn "then re-run with FELIS_WATCHDOG_HEARTBEAT_URL= (docs/troubleshooting.md §14)." +} + # The build lane's tools: kaniko and trivy (pinned by digest in internal/build/tools.go) # and Trivy's vulnerability and Java DBs, copied into the registry's mirror/ where build # Jobs pull them; the build namespace has no internet egress. The timer refreshes the DBs @@ -5374,6 +5463,7 @@ summary() { fi echo summary_offsite + summary_heartbeat echo } diff --git a/deploy/bootstrap_test.sh b/deploy/bootstrap_test.sh index 6de6360..c826906 100644 --- a/deploy/bootstrap_test.sh +++ b/deploy/bootstrap_test.sh @@ -1837,6 +1837,7 @@ run_timer() { # exit status of the first backup FELIS_DB_BACKUP_METRICS=/var/lib/node_exporter/textfile_collector/felis_db_backup.prom \ HOST_BIN=/usr/local/bin/felis STATE_DIR=/etc/felis bash -c ' ok() { printf "OK: %s\n" "$*"; }; warn() { printf "WARN: %s\n" "$*"; } + log() { printf "LOG: %s\n" "$*"; }; die() { printf "DIE: %s\n" "$*"; exit 1; } systemctl() { printf "SYSTEMCTL: %s\n" "$*"; [ "$1" != start ] || return "$FIRST"; } journalctl() { printf "JOURNAL: pg_dump: connection refused\n"; } '"$tblock"' @@ -1894,23 +1895,36 @@ esac wblock="$(awk '/^install_watchdog_timer\(\) \{/,/^}/' "$BS")" [ -n "$wblock" ] || { echo "FAIL: no install_watchdog_timer found in $BS"; exit 1; } -[ "$(printf '%s\n' "$wblock" | wc -l)" -lt 60 ] \ +[ "$(printf '%s\n' "$wblock" | wc -l)" -lt 90 ] \ || { echo "FAIL: the extracted block is not install_watchdog_timer -- did its closing brace move?"; exit 1; } qblock="$(awk '/^quiet_watchdog\(\) \{/,/^}/' "$BS")" [ -n "$qblock" ] || { echo "FAIL: no quiet_watchdog found in $BS"; exit 1; } +hbblock="" +for fn in write_heartbeat_url heartbeat_host summary_heartbeat validate_heartbeat_url; do + blk="$(awk "/^${fn}\\(\\) \\{/,/^}/" "$BS")" + [ -n "$blk" ] || { echo "FAIL: no ${fn} found in $BS"; exit 1; } + [ "$(printf '%s\n' "$blk" | wc -l)" -lt 30 ] \ + || { echo "FAIL: the extracted block is not ${fn} -- did its closing brace move?"; exit 1; } + hbblock="${hbblock}${blk} +" +done tdir="$(mktemp -d)" run_watchdog_timer() { # $1: exit status of the first run, $2: FELIS_WORLDS_HOST_PATH, $3: NODE_IP FIRST="$1" FELIS_WORLDS_HOST_PATH="$2" NODE_IP="${3:-}" WATCHDOG_SERVICE="$tdir/felis-watchdog.service" WATCHDOG_TIMER="$tdir/felis-watchdog.timer" \ + WATCHDOG_FAILED_SERVICE="$tdir/felis-watchdog-failed.service" WATCHDOG_HEARTBEAT_FILE="$tdir/watchdog-heartbeat-url" \ WATCHDOG_STATE="$tdir/watchdog/state.json" WATCHDOG_QUIET_FILE=/run/felis/watchdog-quiet-until \ FELIS_DB_BACKUP_DIR=/var/lib/felis/db-backups FELIS_ARCHIVE_LOCAL_PATH=/var/lib/felis/archives FELIS_GAME_PORT=25577 \ HOST_BIN=/usr/local/bin/felis STATE_DIR=/etc/felis bash -c ' set -Eeuo pipefail ok() { printf "OK: %s\n" "$*"; }; warn() { printf "WARN: %s\n" "$*"; } systemctl() { printf "SYSTEMCTL: %s\n" "$*"; [ "$1" != start ] || return "$FIRST"; } + log() { printf "LOG: %s\n" "$*"; }; die() { printf "DIE: %s\n" "$*"; exit 1; } journalctl() { printf "JOURNAL: parse /etc/felis/felis.host.toml\n"; } + FELIS_WATCHDOG_HEARTBEAT_URL="${FELIS_WATCHDOG_HEARTBEAT_URL:-}" + '"$hbblock"' '"$wblock"' - install_watchdog_timer' 2>&1 + eval "${SCRIPT:-install_watchdog_timer}"' 2>&1 } out="$(run_watchdog_timer 0 "")" @@ -1930,6 +1944,78 @@ else echo "FAIL the watchdog state directory must be 0700"; fails=$((fails + 1)) fi +# A run that fails is reported by felis-watchdog-failed.service, and the heartbeat URL is +# kept private and shown by its host only. The units name no heartbeat flag, so a binary +# from before it still runs under them. +failed_unit="$(cat "$tdir/felis-watchdog-failed.service")" +expect "a failed run starts the failure report" "OnFailure=felis-watchdog-failed.service" "$unit" +expect "the failure report runs the host binary against the watchdog's state" \ + "ExecStart=/usr/local/bin/felis watchdog -unit-failed -config /etc/felis/felis.host.toml -state $tdir/watchdog/state.json -quiet-file /run/felis/watchdog-quiet-until +" "$failed_unit" +expect "the failure report is a oneshot" "Type=oneshot" "$failed_unit" +expect "a wedged failure report is killed" "TimeoutStartSec=2min" "$failed_unit" +case "$unit$failed_unit" in + *-heartbeat*) echo "FAIL the watchdog units must name no heartbeat flag (an older binary refuses it)"; fails=$((fails + 1)) ;; + *) echo "PASS the watchdog units name no heartbeat flag" ;; +esac +case "$out" in + *"pings the heartbeat"*) echo "FAIL without a heartbeat URL the install must claim no heartbeat: $out"; fails=$((fails + 1)) ;; + *) echo "PASS without a heartbeat URL the install claims none" ;; +esac +[ ! -e "$tdir/watchdog-heartbeat-url" ] && echo "PASS no heartbeat URL writes no file" \ + || { echo "FAIL no heartbeat URL must write no file"; fails=$((fails + 1)); } + +out="$(FELIS_WATCHDOG_HEARTBEAT_URL=https://hc-ping.com/5f1e0c2a-key run_watchdog_timer 0 "")" +expect "the heartbeat URL is kept where felis watchdog reads it" "https://hc-ping.com/5f1e0c2a-key" "$(cat "$tdir/watchdog-heartbeat-url" 2>&1)" +if [ "$(stat -c %a "$tdir/watchdog-heartbeat-url" 2>/dev/null || stat -f %Lp "$tdir/watchdog-heartbeat-url")" = 600 ]; then + echo "PASS the heartbeat URL file is private (its path pings the check)" +else + echo "FAIL the heartbeat URL file must be 0600"; fails=$((fails + 1)) +fi +expect "the install says the watchdog pings the heartbeat" \ + "OK: watchdog: checks every 2 minutes and mails the owners' verified addresses and pings the heartbeat at https://hc-ping.com/... (journalctl -u felis-watchdog)" "$out" +case "$out" in + *5f1e0c2a*) echo "FAIL the install printed the heartbeat URL's key: $out"; fails=$((fails + 1)) ;; + *) echo "PASS the install shows the heartbeat by its host only" ;; +esac +out="$(run_watchdog_timer 0 "")" +expect "a re-run without the variable keeps the heartbeat" "https://hc-ping.com/5f1e0c2a-key" "$(cat "$tdir/watchdog-heartbeat-url" 2>&1)" +expect "a re-run without the variable still reports the heartbeat" "and pings the heartbeat at https://hc-ping.com/..." "$out" +out="$(SCRIPT=summary_heartbeat run_watchdog_timer 0 "")" +expect "the summary names the heartbeat by its host" "LOG: Heartbeat: every watchdog run pings https://hc-ping.com/...;" "$out" +out="$(FELIS_WATCHDOG_HEARTBEAT_URL=off run_watchdog_timer 0 "")" +[ ! -e "$tdir/watchdog-heartbeat-url" ] && echo "PASS off removes the heartbeat" \ + || { echo "FAIL FELIS_WATCHDOG_HEARTBEAT_URL=off must remove the file"; fails=$((fails + 1)); } +leftover="$(find "$tdir" -maxdepth 1 -name 'watchdog-heartbeat-url.*')" +[ -z "$leftover" ] && echo "PASS writing the heartbeat URL leaves no temporary file" \ + || { echo "FAIL temporary files left: $leftover"; fails=$((fails + 1)); } +out="$(SCRIPT=summary_heartbeat run_watchdog_timer 0 "")" +expect "without a heartbeat the summary says so loudly" "WARN: NO HEARTBEAT: nothing off this machine notices it going down or its watchdog stopping." "$out" +expect "and says how to add one" "then re-run with FELIS_WATCHDOG_HEARTBEAT_URL= (docs/troubleshooting.md §14)." "$out" +out="$(FELIS_WATCHDOG_HEARTBEAT_URL='https://user:pw@status.example:8443?rid=5f1e0c2a' SCRIPT='write_heartbeat_url; heartbeat_host' run_watchdog_timer 0 "")" +expect "the host shown drops the sign-in and the query" "https://status.example:8443/..." "$out" +rm -f "$tdir/watchdog-heartbeat-url" +for good in "" off https://hc-ping.com/5f1e0c2a http://10.0.0.5:8000/ping/5f1e0c2a; do + out="$(FELIS_WATCHDOG_HEARTBEAT_URL="$good" SCRIPT='validate_heartbeat_url; echo fine' run_watchdog_timer 0 "")" + expect "the heartbeat URL <$good> is accepted" "fine" "$out" +done +for bad in hc-ping.com/5f1e0c2a ftp://hc-ping.com/5f1e0c2a https:///5f1e0c2a 'https://hc-ping.com/5f1e 0c2a' 'https://hc-ping.com/5f1e"0c2a' "$(printf 'https://hc-ping.com/5f1e\n0c2a')"; do + out="$(FELIS_WATCHDOG_HEARTBEAT_URL="$bad" SCRIPT='validate_heartbeat_url; echo fine' run_watchdog_timer 0 "")" + case "$out" in + *"DIE: FELIS_WATCHDOG_HEARTBEAT_URL must"*fine*|*5f1e*) echo "FAIL the heartbeat URL <$bad>: $out"; fails=$((fails + 1)) ;; + *"DIE: FELIS_WATCHDOG_HEARTBEAT_URL must"*) echo "PASS the heartbeat URL <$bad> is refused without being echoed" ;; + *) echo "FAIL the heartbeat URL <$bad> was accepted: $out"; fails=$((fails + 1)) ;; + esac +done +case "$(awk '/^validate_settings\(\) \{/,/^}/' "$BS")" in + *validate_heartbeat_url*) echo "PASS the heartbeat URL is checked before anything is installed" ;; + *) echo "FAIL validate_settings must call validate_heartbeat_url"; fails=$((fails + 1)) ;; +esac +case "$(awk '/^summary\(\) \{/,/^}/' "$BS")" in + *summary_offsite*summary_heartbeat*) echo "PASS the install's summary ends on the heartbeat" ;; + *) echo "FAIL summary must call summary_heartbeat"; fails=$((fails + 1)) ;; +esac + out="$(run_watchdog_timer 0 /srv/worlds)" expect "a custom worlds root is watched for free space" "-disk-paths /,/var/lib/rancher/k3s,/var/lib/felis,/srv/worlds," "$(cat "$tdir/felis-watchdog.service")" case "$unit" in diff --git a/deploy/uninstall.sh b/deploy/uninstall.sh index 810147a..450a2e3 100644 --- a/deploy/uninstall.sh +++ b/deploy/uninstall.sh @@ -60,7 +60,7 @@ FELIS_CRD="minecraftservers.felis.lolicon.best" # service that is already gone. FELIS_UNITS=( felis-db-backup.timer felis-watchdog.timer felis-offsite.timer felis-build-tools.timer felis-update-check.timer - felis-db-backup.service felis-watchdog.service felis-offsite.service felis-build-tools.service felis-update-check.service + felis-db-backup.service felis-watchdog.service felis-watchdog-failed.service felis-offsite.service felis-build-tools.service felis-update-check.service felis-velocity.service felis-nano.service cloudflared-felis.service felis-postgres-firewall.service ) diff --git a/docs/troubleshooting.md b/docs/troubleshooting.md index 66c6690..8e8b864 100644 --- a/docs/troubleshooting.md +++ b/docs/troubleshooting.md @@ -1537,6 +1537,8 @@ Every two minutes the host checks: | Host memory available below 10% | 15 min | warning | | The host no longer holds the address the install was made on (§13c) | 5 min | critical | | The system clock is not synchronized by NTP (§13c) | 30 min | warning | +| The watchdog's own runs keep failing (`watchdog/run`, below) | 10 min | critical | +| The watchdog's state file did not parse and was moved aside (`watchdog/state`, below) | at once, once | warning | How it mails: @@ -1562,7 +1564,8 @@ How it mails: PostgreSQL or of the API server can therefore still be mailed. [GO-TESTED: a run with the API server and PostgreSQL both down caches the host copy.] - **No relay or no verified owner address:** each alert is written to the - journal only. + journal only, and a run with a heartbeat pings its failure endpoint while an + alert is open (below). Commands: @@ -1580,6 +1583,74 @@ the game-proxy or the address check. The unit carries `-proxy-addr 127.0.0.1:`, `-node-ip ` and the disk list the install chose. `systemctl cat felis-watchdog` shows them. +### The heartbeat: what notices the host itself going down + +A host that is off, a timer that stopped, a watchdog that fails before it can +mail: the host reports none of these about itself. A heartbeat covers them. +Every run pings a check at an outside monitoring service (Healthchecks.io, or +one that copies its API), and that service mails you when the pings stop. + +1. Create a check there with a period of 2 minutes and a grace of 10 minutes. +2. Re-run the installer with `FELIS_WATCHDOG_HEARTBEAT_URL=`. It writes the URL to `/etc/felis/watchdog-heartbeat-url` (root-only, + 0600). The URL's path is the check's key, so the install and the journal + show only its scheme and host. + +A later install without the variable keeps the file, and +`FELIS_WATCHDOG_HEARTBEAT_URL=off` removes it. An install with no heartbeat +ends with a `NO HEARTBEAT` warning. [SH-TESTED: `deploy/bootstrap_test.sh`] + +What a run pings: + +| The run | Ping | +|---|---| +| Its alerts reach the owners (mailed, or nothing due) | `GET ` | +| An alert is open and reaches no one (no relay, no verified owner address), the mail fails, or the state does not save | `POST /fail`, with the reason and the findings in the body | +| One of those failures while the installer runs | nothing | +| A host standing by for another host's off-site bucket (§16) | nothing: the host that writes the bucket pings the check | + +A URL with a query (`?`) has no `/fail` endpoint, so a failing run sends no +ping and the check trips once its grace runs out. A ping that times out (10 s) +or gets a non-2xx answer logs `felis watchdog: heartbeat: ...`; the run's exit +status stays that of its checks and its mail. [GO-TESTED: +`TestHeartbeatSend`, `TestWatchdogRunHeartbeat`] + +A bundle (§16) carries `/etc/felis` and the heartbeat file with it. A host +rebuilt from one stands by and pings nothing until `felis offsite take-over`; +from then on it pings the same check. + +### When the watchdog itself fails + +`felis-watchdog.service` carries `OnFailure=felis-watchdog-failed.service`. A +failed run (a crash, the 3 min time limit, a `felis.toml` that no longer loads) +starts `felis watchdog -unit-failed`, which: + +- pings the heartbeat's `/fail` at once with systemd's result, e.g. + `felis-watchdog.service failed: result exit-code, exit status 3`, except + while the installer runs or the host stands by; +- records `watchdog/run` and mails it once runs have kept failing for 10 + minutes. The relay and recipients come from `felis.toml` when it loads and + from the watchdog's cache when it does not. The first passing run resolves + it like any other finding. + +[VM-TESTED: on systemd 252, a failing unit with this `OnFailure=` passed +`result exit-code, exit status 3` to the fallback, which posted it to a local +`/fail` endpoint; with the installer's quiet file present it withheld the +ping. GO-TESTED: `TestWatchdogUnitFailedBrokenConfig`, six failures two +minutes apart mail once, at 10 minutes, through the cached relay.] + +A state file (`/var/lib/felis/watchdog/state.json`) that does not parse is +renamed to `state.json.unreadable-`. The run starts from a fresh +state and mails `watchdog/state` once. The fresh state has lost the open +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`] + +```bash +journalctl -u felis-watchdog-failed -n 20 # what the fallback reported and pinged +systemctl status felis-watchdog # the failed run's result +``` + ### Metrics All four mandated metrics have real producers; scrape them when triaging: @@ -2631,6 +2702,7 @@ for 10 seconds (the Free plan's limits). | Node out of disk; pods evicted / ImagePullBackOff | §13b | | Which metric to scrape | §14 | | An alert mail from the watchdog; nothing is mailed when something breaks | §14 | +| The host went down and nothing noticed; `NO HEARTBEAT` at install; `felis-watchdog-failed` in the journal; `state.json.unreadable-*` | §14 | | `FelisOperatorDown` / `FelisAPIDown` / `FelisLoginGateDown` / `FelisReconcileStuck` | §14, §1, §2 | | Upgrade / roll back a bad control-plane image | §15 | | `image_change_unconfirmed` / `image_not_in_registry` / `registry_unavailable`; move a world to a newer Minecraft | §15b | diff --git a/internal/watchdog/probes.go b/internal/watchdog/probes.go index 919057d..d5f5412 100644 --- a/internal/watchdog/probes.go +++ b/internal/watchdog/probes.go @@ -38,6 +38,8 @@ const ( diskLowFor = 15 * time.Minute diskCriticalFor = 5 * time.Minute memoryLowFor = 15 * time.Minute + // watchdogFailedFor is five failed runs in a row. + watchdogFailedFor = 10 * time.Minute // jobFailureWindow is how far back a failed Job is still news. jobFailureWindow = 24 * time.Hour @@ -292,6 +294,30 @@ func nodeFindings(n *corev1.Node) []Finding { return out } +// WatchdogFailed is the watchdog's own run failing (felis-watchdog-failed.service, +// through OnFailure=): while it fails no other check runs and nothing else is +// mailed. detail is how the run ended. It waits watchdogFailedFor, so one run cut +// short by a slow host mails nobody. +func WatchdogFailed(detail string) Finding { + return Finding{ + Key: "watchdog/run", Severity: Critical, For: watchdogFailedFor, + Summary: "平台巡检本身运行失败，其他检查都没有执行，出了别的问题也不会有告警：" + detail, + SummaryEN: "the platform watchdog itself fails, so no other check runs and nothing else is mailed: " + detail, + Hint: "journalctl -u felis-watchdog -n 50; sudo felis watchdog -dry-run (docs/troubleshooting.md §14)", + } +} + +// StateSetAside is a state file RecoverState moved aside: the alerts it held +// start over, so a condition still firing is mailed again as new. +func StateSetAside(aside string) Finding { + return Finding{ + Key: "watchdog/state", Severity: Warning, Event: true, + Summary: fmt.Sprintf("平台巡检的状态文件无法读取，已移到 %s 并重新开始：仍未恢复的告警会当作新告警再发一次", aside), + SummaryEN: fmt.Sprintf("the watchdog's state file was unreadable and was moved to %s; its alerts start over, so one still firing is mailed again as new", aside), + Hint: "df -h /var/lib/felis (a full disk cuts writes short)", + } +} + // KubeAPIDown is the finding for an API server that did not answer. func KubeAPIDown(err error) Finding { return Finding{ diff --git a/internal/watchdog/watchdog.go b/internal/watchdog/watchdog.go index e65654d..dd9a8a1 100644 --- a/internal/watchdog/watchdog.go +++ b/internal/watchdog/watchdog.go @@ -83,6 +83,30 @@ type State struct { // still be mailed. Recipients []string `json:"recipients,omitempty"` SMTPPassword string `json:"smtp_password,omitempty"` + // Relay is the [smtp] relay of the last run that could read felis.toml, + // so a run of the watchdog that failed can still be mailed after the + // config stopped loading; nil when there is none. + Relay *Relay `json:"relay,omitempty"` +} + +// Relay is the part of [smtp] a mail needs, besides the password. +type Relay struct { + Host string `json:"host"` + Port int `json:"port"` + From string `json:"from"` + Username string `json:"username,omitempty"` + RequireTLS bool `json:"require_tls"` +} + +// Open reports whether the owners were told of a condition that still holds: +// an alert mailed (or logged) and not seen gone since, one-off events aside. +func (s *State) Open() bool { + for _, a := range s.Alerts { + if !a.Notified.IsZero() && a.ClearedAt.IsZero() && !a.Event { + return true + } + } + return false } const ( @@ -276,6 +300,9 @@ func without(all []Alert, skip ...[]Alert) []Alert { return out } +// ErrBadState is a state file that is not the JSON the watchdog writes. +var ErrBadState = errors.New("watchdog: the state file is not one the watchdog wrote") + // LoadState reads the state file; a missing file is a fresh state. func LoadState(path string) (*State, error) { raw, err := os.ReadFile(path) @@ -287,7 +314,7 @@ func LoadState(path string) (*State, error) { } var s State if err := json.Unmarshal(raw, &s); err != nil { - return nil, fmt.Errorf("parse %s: %w", path, err) + return nil, fmt.Errorf("%w: %s: %v", ErrBadState, path, err) } if s.Alerts == nil { s.Alerts = map[string]*Alert{} @@ -295,6 +322,22 @@ func LoadState(path string) (*State, error) { return &s, nil } +// RecoverState is LoadState for a run that must go on: a state file that does +// not parse (a disk that filled mid-write, a hand edit) is renamed aside and +// the run starts from a fresh state, rather than every later run failing on +// it and mailing nothing. aside is where it went, "" when nothing was moved. +func RecoverState(path string, now time.Time) (s *State, aside string, err error) { + s, err = LoadState(path) + if !errors.Is(err, ErrBadState) { + return s, "", err + } + aside = fmt.Sprintf("%s.unreadable-%d", path, now.Unix()) + if rerr := os.Rename(path, aside); rerr != nil { + return nil, "", fmt.Errorf("%w (and could not move it aside: %v)", err, rerr) + } + return &State{Alerts: map[string]*Alert{}}, aside, nil +} + // SaveState writes s atomically, readable by root only: it caches the relay // password. func SaveState(path string, s *State) error { diff --git a/internal/watchdog/watchdog_test.go b/internal/watchdog/watchdog_test.go index 2914c29..45ecac8 100644 --- a/internal/watchdog/watchdog_test.go +++ b/internal/watchdog/watchdog_test.go @@ -1,6 +1,7 @@ package watchdog import ( + "fmt" "os" "path/filepath" "strings" @@ -205,3 +206,65 @@ func TestQuietUntil(t *testing.T) { t.Errorf("QuietUntil = %v", got) } } + +// TestRecoverState: a state file that does not parse is moved aside, whole, +// and the run starts over; a good or missing one is loaded as LoadState does. +func TestRecoverState(t *testing.T) { + dir := t.TempDir() + path := filepath.Join(dir, "state.json") + if err := os.WriteFile(path, []byte(`{"alerts": {"memo`), 0o600); err != nil { + t.Fatal(err) + } + s, aside, err := RecoverState(path, t0) + if err != nil || s == nil || s.Alerts == nil || len(s.Alerts) != 0 { + t.Fatalf("RecoverState(bad) = %+v, %q, %v; want a fresh state", s, aside, err) + } + if want := path + ".unreadable-" + fmt.Sprint(t0.Unix()); aside != want { + t.Fatalf("aside = %q, want %q", aside, want) + } + if raw, err := os.ReadFile(aside); err != nil || string(raw) != `{"alerts": {"memo` { + t.Fatalf("the moved file = %q, %v; want the bad state kept as it was", raw, err) + } + if _, err := os.Stat(path); !os.IsNotExist(err) { + t.Fatalf("the bad state is still at %s (%v)", path, err) + } + + good := &State{Recipients: []string{"owner@example.com"}} + run(good, Report{Findings: []Finding{finding("memory", Warning, 0)}}, t0) + if err := SaveState(path, good); err != nil { + t.Fatal(err) + } + s, aside, err = RecoverState(path, t0) + if err != nil || aside != "" || s.Alerts["memory"] == nil || len(s.Recipients) != 1 { + t.Fatalf("RecoverState(good) = %+v, %q, %v", s, aside, err) + } + s, aside, err = RecoverState(filepath.Join(dir, "missing.json"), t0) + if err != nil || aside != "" || s.Alerts == nil { + t.Fatalf("RecoverState(missing) = %+v, %q, %v", s, aside, err) + } +} + +// TestStateOpen: open is a condition the owners were told of that still holds. +func TestStateOpen(t *testing.T) { + s := &State{} + f := finding("memory", Warning, time.Hour) + run(s, Report{Findings: []Finding{f}}, t0) + if s.Open() { + t.Fatal("a pending alert, never mailed, counts as open") + } + run(s, Report{Findings: []Finding{f}}, t0.Add(time.Hour)) + if !s.Open() { + t.Fatal("a mailed alert still firing is not open") + } + run(s, Report{}, t0.Add(time.Hour+time.Minute)) + if s.Open() { + t.Fatal("an alert seen gone counts as open") + } + ev := finding("watchdog/state", Warning, 0) + ev.Event = true + e := &State{} + run(e, Report{Findings: []Finding{ev}}, t0) + if e.Open() { + t.Fatal("a one-off event counts as open") + } +}