Files
felhom-controller/controller/internal/backup/offbox_integrity.go
T
admin 45770f2282
gates / gates (push) Successful in 11s
v0.227.1: the damage classifier matched restic's ordinary progress output
A patch and not a rebuilt 0.227.0: that tag was already running on demo-hp, and
re-pushing changed bytes under a live tag is the :latest hazard with extra steps.

looksLikeRepositoryDamage matched bare "pack ", "tree ", "snapshot ", "blob ". A
HEALTHY restic check prints "check all packs" and "check snapshots, trees and
blobs" -- so any check that failed for a NON-damage reason, a connection dropped
mid-run for instance, would have been classified as a corrupted repository and
told the customer their backups may be damaged. That is the false alarm that
teaches an operator to ignore the true one.

Caught by the NEGATIVE control, built from the real bytes of a real passing
check on demo-hp. The spec made the negative control mandatory and this is what
it was for: a control that has only ever seen the failing case proves nothing.

Signatures are now phrases from restic's own error wording.

Also in this commit: CONTEXT.md records the three rulings (take the flag and
skip, due-ness not a weekday, publish on OffboxReportStatus not the R-331 dead
fields) plus the measurement a future session would otherwise assume wrongly --
THE STRUCTURE CHECK DOES NOT CATCH SILENT CORRUPTION. README documents the job,
the route and the config, and corrects a line that listed four debug backup
routes when only two exist. REUSE gains three rows, including one that records
R-398 was my own mistake so nobody re-files it.
2026-08-30 21:22:23 +02:00

271 lines
13 KiB
Go

package backup
import (
"context"
"fmt"
"regexp"
"strings"
"time"
"gitea.dooplex.hu/admin/felhom-controller/internal/settings"
)
// ── R-359 — nothing ever checked that the off-site copies are still readable ─────────────────────
//
// The whole-guest tier has verify jobs. The tier holding the customer's documents and photos had
// none: the complete set of restic verbs this controller used was
// `restore, snapshots, backup, unlock, stats, init, forget, prune, cat, config` — no `check`.
// We would have found out at restore time, with a customer waiting.
//
// On 2026-08-21 one packet in a set-aside store was deliberately damaged and plain `restic check`
// caught it at once. That is an empirical result, not an assumption — it is why this row exists.
//
// ── THE HAZARD THAT SHAPES THIS WHOLE FILE ──────────────────────────────────────────────────────
//
// `resticStep` self-heals a crash lock: when a command fails with "repository is already locked" it
// runs **`unlock --remove-all`** and retries once. Its own doc comment records why that is safe —
// *"the in-process single-flight mutex (held by every caller of this method) proves no sibling
// operation is live"*. Every off-site operation takes `acquireRunning` for exactly that reason.
//
// **An integrity check that did not take the flag would break that invariant.** It could meet the
// lock of a `forget --prune` running from this same box, remove it, and retry over the top of a live
// prune. So this check TAKES THE FLAG, and **skips rather than waits** when it cannot get it: waiting
// would pin a nightly backup behind a check, and a skipped check simply runs tomorrow. That is the
// single most important property in this file, and `TestR359_SkipsWhenRunningFlagHeld` asserts it as
// a NON-EFFECT — restic was never invoked, and `unlock` never appeared in any argument list.
// integrityCheckTimeout bounds one check so a hung repository cannot pin the single-writer flag.
//
// CHOSEN, not inherited: a structure check on a store this size is minutes (measured at ~4 s against
// demo-hp's 134 MB store, and it scales with the index rather than the data). 30 minutes is far above
// any plausible structure check and far below "forever", so the failure mode of a wedged SFTP mount is
// a released flag and a retry tomorrow, never a box whose backups stop because a check never returned.
//
// It is deliberately NOT sized for a `--read-data-subset` run, which downloads pack data and can take
// hours. That option ships OFF (R-399); whoever turns it on must revisit this number, and this comment
// is the note that says so.
const integrityCheckTimeout = 30 * time.Minute
// defaultIntegrityMaxAgeDays is the max age of a SUCCESSFUL check before one is due again.
const defaultIntegrityMaxAgeDays = 7
// readDataSubsetRe accepts the forms restic documents for --read-data-subset: "n/m", a percentage
// like "5%", or a size like "50M". Anything else is refused at read time rather than passed through —
// a typo must not fail the whole check, which is what handing restic an unparsed value would do.
var readDataSubsetRe = regexp.MustCompile(`^([0-9]+/[0-9]+|[0-9]+(\.[0-9]+)?%|[0-9]+[KMGT]?)$`)
// IntegrityResult is what one off-site integrity check did, so every surface — the log, the event, the
// report and the debug endpoint — states the same facts from one place.
//
// Skipped is a first-class outcome, not an error. A check that yielded to a running backup did the
// right thing, and reporting it as a failure would alarm on correct behaviour.
//
// Unreachable is separated from a failed check for the reason §8 of the task records and R-185
// established for a tier the box cannot read: **"I could not look" and "I looked and it is broken" are
// different facts** and must not produce the same alarm. R-339 already alarms on reachability; a
// second alarm for the same fact is noise, and worse, it would train the operator to discount the one
// alarm that means the customer's backups are damaged.
type IntegrityResult struct {
RanAt time.Time
Duration time.Duration
ReadDataSubset string // "" = structure only
OK bool
Skipped bool
SkipReason string
Unreachable bool
// Output is truncated restic output for the LOG. It never reaches a customer message — R-379 is
// the reason: 615 bytes of raw database text reached a customer once.
Output string
}
// integrityReadDataSubset resolves the configured subset spec, refusing anything malformed.
//
// Fail-safe direction: an unrecognised value becomes "" (structure check only) with a WARN, never a
// passthrough. Handing restic `--read-data-subset=banana` fails the entire check, which would turn a
// typo in a config file into a store that silently stops being verified.
func (m *Manager) integrityReadDataSubset() string {
spec := strings.TrimSpace(m.cfg.Monitoring.Integrity.ReadDataSubset)
if spec == "" {
return ""
}
if !readDataSubsetRe.MatchString(spec) {
m.logger.Printf("[WARN] [offbox] integrity: read_data_subset %q is not a form restic accepts (n/m, N%%, or a size like 50M) — running the STRUCTURE check only", spec)
return ""
}
return spec
}
// integrityMaxAge returns the configured max age of a successful check, defaulting to 7 days.
func (m *Manager) integrityMaxAge() time.Duration {
d := m.cfg.Monitoring.Integrity.MaxAgeDays
if d <= 0 {
d = defaultIntegrityMaxAgeDays
}
return time.Duration(d) * 24 * time.Hour
}
// IntegrityDue reports whether a check is due, and the age of the last successful one.
//
// DUE-NESS, NOT A WEEKDAY. A job that fires only on Sundays is a job that silently skips a week every
// time the box is off on a Sunday — which is R-341's exact failure, a dated check quietly missed and
// never caught up. Asking "is the last one older than the max age?" catches up on the next day the box
// is running, whatever day that is.
//
// A repository that has never been checked is DUE. That is the fail-safe direction: an unchecked store
// must not read as a fresh one.
func (m *Manager) IntegrityDue(now time.Time) (due bool, last time.Time) {
t := m.settings.GetOffboxTarget()
if t == nil || strings.TrimSpace(t.LastIntegrityCheck) == "" {
return true, time.Time{}
}
parsed, err := time.Parse(time.RFC3339, t.LastIntegrityCheck)
if err != nil {
m.logger.Printf("[WARN] [offbox] integrity: last-check stamp %q does not parse (%v) — treating the store as never checked", t.LastIntegrityCheck, err)
return true, time.Time{}
}
return now.Sub(parsed) >= m.integrityMaxAge(), parsed
}
// recordIntegrityOutcome persists the verdict and advances due-ness.
//
// Called ONLY when a check actually reached a verdict — pass or fail. A FAILING store advances
// due-ness deliberately: re-checking a broken repository every night is load with no new information,
// the hourly operator cooldown already governs the mail, and the failure is already recorded where a
// surface can read it. A skip or an unreachable repository does NOT reach here, so tomorrow tries
// again.
// RecordIntegrityOutcome is the exported entry point; the caller in main.go owns the decision of WHEN
// a verdict counts, because only it knows whether the run was forced or scheduled.
func (m *Manager) RecordIntegrityOutcome(at time.Time, ok bool) { m.recordIntegrityOutcome(at, ok) }
func (m *Manager) recordIntegrityOutcome(at time.Time, ok bool) {
if err := m.settings.UpdateOffboxStatus(func(o *settings.OffboxTarget) {
o.LastIntegrityCheck = at.UTC().Format(time.RFC3339)
o.LastIntegrityOK = ok
}); err != nil {
m.logger.Printf("[ERROR] [offbox] integrity: could not persist the check outcome: %v — the check RAN and its verdict was ok=%v, but due-ness did not advance, so it will run again tomorrow", err, ok)
}
}
// CheckOffboxIntegrity runs one off-site integrity check. It NEVER writes to the repository: `check`
// is a read verb, and nothing here prunes, forgets, unlocks or backs up.
//
// Due-ness is NOT consulted here — the caller decides. The scheduled job asks IntegrityDue first; the
// operator's debug button deliberately does not, because "run it now" is the whole point of a button.
// Every other guard applies to both, including the single-writer flag.
func (m *Manager) CheckOffboxIntegrity(ctx context.Context) IntegrityResult {
res := IntegrityResult{RanAt: time.Now()}
if !m.OffboxConfigured() {
// A box with no off-site tier has nothing to check. Silent, and not an alarm.
res.Skipped, res.SkipReason = true, "no off-site target configured"
return res
}
// THE HAZARD GATE. See the file header. Skip, never wait: waiting would pin the nightly backup
// behind this check, and a skipped check costs nothing because tomorrow's run tries again.
if err := m.acquireRunning(); err != nil {
res.Skipped, res.SkipReason = true, "a backup or restore is already running"
m.logger.Printf("[INFO] [offbox] integrity: skipped — %s; due-ness is NOT advanced, so this retries on the next run", res.SkipReason)
return res
}
defer m.releaseRunning()
t := m.settings.GetOffboxTarget()
base, env := m.offboxBaseArgs(t)
// Does the repository answer at all? A failure here is UNREACHABLE, not damage — the distinction
// the whole result type exists for.
if err := m.ensureOffboxRepo(ctx, base, env); err != nil {
res.Unreachable = true
res.Output = truncate([]byte(err.Error()))
m.logger.Printf("[WARN] [offbox] integrity: the repository could not be reached, so NOTHING was checked (this is not an integrity failure — R-339 owns reachability): %v", err)
return res
}
args := []string{"check"}
if subset := m.integrityReadDataSubset(); subset != "" {
res.ReadDataSubset = subset
args = append(args, "--read-data-subset="+subset)
}
cctx, cancel := context.WithTimeout(ctx, integrityCheckTimeout)
defer cancel()
start := time.Now()
out, err := m.resticStep(cctx, env, base, "integrity-check", args...)
res.Duration = time.Since(start)
res.Output = truncate(out)
if err == nil {
res.OK = true
m.logger.Printf("[INFO] [offbox] integrity: check PASSED in %s (%s)", res.Duration.Round(time.Second), integrityDepthLabel(res.ReadDataSubset))
return res
}
// A timeout is NOT damage. The check did not finish, so it saw nothing, so it may not claim the
// store is broken — and it must not advance due-ness either.
if cctx.Err() != nil {
res.Unreachable = true
m.logger.Printf("[WARN] [offbox] integrity: the check did not finish within %s, so nothing was concluded about the store (NOT reported as damage): %v", integrityCheckTimeout, err)
return res
}
// Connect / credential / lock failures are the repository being unavailable, not unreadable.
// classifyResticProbe already names those causes; reusing it avoids a second classifier that could
// disagree with the first.
if cls := classifyResticProbe(out, err); cls == "other" || cls == "orphaned" || cls == "norepo" {
if !looksLikeRepositoryDamage(out) {
res.Unreachable = true
m.logger.Printf("[WARN] [offbox] integrity: the check could not run to a verdict (%s) — NOT reported as damage: %v: %s", cls, err, res.Output)
return res
}
}
m.logger.Printf("[ERROR] [offbox] integrity: check FAILED after %s — restic reported: %s", res.Duration.Round(time.Second), res.Output)
return res
}
// looksLikeRepositoryDamage reports whether restic's output describes a store that is READABLE and
// WRONG, as opposed to one that could not be opened.
//
// The strings are restic's own, from the 2026-08-21 damaged-pack drill and restic's check source. The
// direction is deliberate: an output this does not recognise is treated as "could not look", because
// telling a customer their backups are damaged is the more expensive mistake of the two, and R-339
// already alarms when the store cannot be reached.
func looksLikeRepositoryDamage(out []byte) bool {
s := strings.ToLower(string(out))
// THE SIGNATURES ARE PHRASES, NOT WORDS, AND THE REASON IS A BUG THIS FILE ALREADY HAD.
//
// The first draft matched bare `"pack "`, `"tree "`, `"snapshot "` and `"blob "`. Those appear in
// restic's ORDINARY PROGRESS OUTPUT — a healthy run prints `check all packs` and
// `check snapshots, trees and blobs` — so a check that failed for a NON-damage reason (a dropped
// connection mid-run, say) would have been classified as a corrupted store and alarmed the customer
// that their backups were damaged. Caught by the negative control in
// TestR359_HealthyRealOutputIsNotDamage, using the real bytes of a real passing check.
//
// Every phrase below is restic's own error wording, taken from the 2026-08-30 damaged-pack run on
// demo-hp or from restic's check source — never paraphrased.
for _, sig := range []string{
"does not match", // "Pack ID does not match, want <id>, got <id>" — the measured one
"not found in index", // a blob or pack the index promises and the store lacks
"blob not found", //
"size mismatch", //
"ciphertext verification failed",
"integrity error",
"repository contains errors", // restic's own summary verdict
"failed to load index", //
} {
if strings.Contains(s, sig) {
return true
}
}
return false
}
// integrityDepthLabel names how deep the check went, for a log line.
func integrityDepthLabel(subset string) string {
if subset == "" {
return "structure and index only — no pack data was downloaded"
}
return fmt.Sprintf("structure, index, and %s of the pack data re-read", subset)
}