0d52a42c17
gates / gates (push) Successful in 12s
Nothing ever verified 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 contained no `check`. We would have found out at restore time, with a customer waiting. On 2026-08-21 a deliberately damaged pack was caught at once by plain `restic check`; we had never run it. R-397: NotifyIntegrityOK/NotifyIntegrityFailed existed with no caller, the hub allowlists both event types and carries the Hungarian text for both, the settings checkbox exists, and the debug button posts to /api/debug/backup/ integrity. Everything was built except the part that runs. SIXTH instance of that shape in this project. THE HAZARD SHAPES THE WHOLE DESIGN. resticStep self-heals a crash lock by running `unlock --remove-all` and retrying, and its own comment records why that is safe: every caller holds the in-process single-flight mutex, so any lock it meets is stale. A check that did not take that flag could meet a LIVE prune's lock from this same box, remove it, and retry over the top of it. So the check TAKES THE FLAG and SKIPS rather than waits -- waiting would pin the nightly backup behind it, and a skip costs nothing because due-ness makes tomorrow try again. TestR359_SkipsWhenRunningFlagHeld asserts the NON-EFFECTS: restic never invoked, `unlock` never in any argv. Its red-proof prints the real thing -- restic running `check` while the flag was held. DUE-NESS, NOT A WEEKDAY. Daily job, weekly behaviour: "is the last successful check older than 7 days?" not "is it Sunday?". R-341 is exactly the other shape, a dated check quietly missed and never caught up. No Weekly primitive added. THREE OUTCOMES, NOT TWO. Skipped, Unreachable and failed are different facts. "I could not look" is not "I looked and it is broken" -- R-339 already owns reachability, and a second alarm for the same fact trains the operator to discount the one alarm that means the backups are damaged. A timeout is unreachable, never damage. A failure advances due-ness (a broken store must not be re-checked nightly); a skip and an unreachable store do not. Success is severity `info`, which severityNotifies DROPS -- it mails NOBODY, by design. A weekly success e-mail is how people stop reading their alerts. The customer gets a SENTENCE; restic's words go to the log, truncated (R-379: 615 bytes of raw database text reached a customer once). read-data-subset ships OFF and a malformed value is refused at read time rather than handed to restic, where one typo would fail the whole check. Published on OffboxReportStatus, NOT on report.BackupReport's IntegrityOK -- those were retired by R-331 YESTERDAY and TestBackupReport_DeadFieldsStayZero still passes unmodified. Also: the monitoring page stopped promising a Sunday job that never existed, and the debug button got its dispatch case. PART 0 WAS NOT BUILT, AND R-398 WAS MY OWN MISTAKE. The seam it asked for already exists: offboxRunner/SetOffboxRunner/m.runner() has been injectable since the off-site tier shipped, and other tests drive restic-backed paths through it. A resticStepFn seam would have been WORSE here -- it would replace the `unlock --remove-all` escalation and hide it from the assertions that must see it. R-358's AST ordering test is converted to a real execution test instead, which immediately surfaced something the AST walk could not: unlockStale legitimately runs before the restore. Four red-proofs, each printing the pre-fix behaviour. Green gate: 28 packages, rc 0. All 12 controller gates OK.
260 lines
13 KiB
Go
260 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))
|
|
for _, sig := range []string{
|
|
"pack ", // "pack 1234abcd: not found in index" / "... size mismatch"
|
|
"load index", // a broken index
|
|
"blob ", // "blob not found"
|
|
"tree ", // "tree 1234: file ... blob not found"
|
|
"snapshot ", // "error for snapshot ...: ..."
|
|
"ciphertext verification failed",
|
|
"integrity error",
|
|
"repository contains errors",
|
|
} {
|
|
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)
|
|
}
|