275 lines
13 KiB
Go
275 lines
13 KiB
Go
package backup
|
|
|
|
import (
|
|
"errors"
|
|
"fmt"
|
|
"os"
|
|
"path/filepath"
|
|
"time"
|
|
|
|
"gitea.dooplex.hu/admin/felhom-controller/internal/util"
|
|
)
|
|
|
|
// ── R-1270: the verdict follows the app (brief 2026-10-25, Part 3) ─────────────────────────────────────────────────
|
|
//
|
|
// MEASURED BEFORE (catalog sweep 2026-10-24; again on 9202 2026-10-25, `audits/restore-truth-2026-10-25/before/`): the
|
|
// controller logged „tandoor restored but health check failed: stack tandoor did not reach running state within 1m30s"
|
|
// at WARN, the restore function returned success, and the page the household reads said `ok: true` — „…visszaállítva —
|
|
// az alkalmazás újraindult." The app was `starting` and never came up. Every restore path had the same WARN-and-succeed
|
|
// shape: the unit restore, the off-site restore, the second drive's file restore and the no-unit fallback.
|
|
//
|
|
// THE RULE. A restore whose app does not reach running in time NEVER reports success. It returns ErrRestoreNotStarted
|
|
// and the household reads „Az adatokat visszatöltöttük, de az alkalmazás még nem indult el. Várj pár percet, majd nyisd
|
|
// meg újra. Ha így marad, szólj nekünk." The operator gets one alarm (backup_run_failures, leg `restore-not-started`).
|
|
//
|
|
// THE SAFEST READING (brief 2026-10-25 Part 3.2 — the operator may change it). A health timeout does NOT pour the old
|
|
// data back: a slow first start (a database migration) is common, and a put-back would throw away a correct restore.
|
|
// The data stays restored and the restore's undo copy is KEPT (the same „kept for support" state a failed put-back
|
|
// leaves, `07` §8 — no new retention rule). A watcher looks for the app for lateStartWatch more: when it runs, the
|
|
// record turns to success („…elindult") and the copy is released by the normal rule (removed, as after any successful
|
|
// restore). If it never runs, the copy stays for support, as a failed put-back's does.
|
|
|
|
// ErrRestoreNotStarted is the KIND of a restore whose data is back but whose app did not reach running in time.
|
|
var ErrRestoreNotStarted = errors.New("the data is restored but the app did not start in time")
|
|
|
|
// lateStartWatch / lateStartPoll bound the watcher after a not-started verdict (tests shorten them).
|
|
var (
|
|
lateStartWatch = 30 * time.Minute
|
|
lateStartPoll = 30 * time.Second
|
|
)
|
|
|
|
// SetRestoreNotStartedNotify wires the operator alarm for a restore whose app did not start (main.go).
|
|
func (m *Manager) SetRestoreNotStartedNotify(fn func(stack, kind string, cause error)) {
|
|
m.restoreNotStartedNotify = fn
|
|
}
|
|
|
|
// restoreNotStarted is the verdict of a restore whose health check failed: the undo copy is kept, the operator is told
|
|
// once, the watcher starts, and the household's sentence is returned as the error. kind names the path (log + alarm).
|
|
func (m *Manager) restoreNotStarted(stack, kind string, healthErr error, undo *liveVolumeCopy) error {
|
|
copyDir := ""
|
|
if undo != nil && undo.dir != "" {
|
|
undo.keep = true
|
|
copyDir = undo.dir
|
|
}
|
|
m.logger.Printf("[ERROR] [backup] %s: the %s put the data back, but the app did not start: %v — NOT reported as a success; the restore copy is kept (%s); watching %s for a late start (R-1270)",
|
|
stack, kind, healthErr, orNone(copyDir), lateStartWatch)
|
|
if m.restoreNotStartedNotify != nil {
|
|
m.restoreNotStartedNotify(stack, kind, healthErr)
|
|
}
|
|
go m.watchLateStart(stack, copyDir, time.Now(), lateStartWatch)
|
|
return util.MsgErrorf(ErrRestoreNotStarted, "err.backup.restore_not_started", stack)
|
|
}
|
|
|
|
func orNone(s string) string {
|
|
if s == "" {
|
|
return "no copy"
|
|
}
|
|
return s
|
|
}
|
|
|
|
// watchLateStart waits for the app after a not-started verdict. When it has run STABLY (stableStart): the record says
|
|
// so and the kept copy is removed (the normal rule after a successful restore). A new restore of the app ends the watch
|
|
// untouched.
|
|
func (m *Manager) watchLateStart(stack, copyDir string, since time.Time, watch time.Duration) {
|
|
switch m.waitStableStart(stack, since, since.Add(watch)) {
|
|
case stableAborted:
|
|
return // a new restore of this app owns it now
|
|
case stableNot:
|
|
m.logger.Printf("[WARN] [backup] %s: still not running stably %s after its restore — the restore copy stays for support (%s) (R-1270)", stack, lateStartWatch, orNone(copyDir))
|
|
return
|
|
}
|
|
removeCopyDir(m, stack, copyDir)
|
|
m.markLateStart(stack, m.note("note.restore.late_started", stack))
|
|
m.logger.Printf("[INFO] [backup] %s: the app started %s after its restore and ran stably for %s — the restore is a success now; the restore copy is released (R-1270)", stack, time.Since(since).Round(time.Second), stableStartWindow)
|
|
}
|
|
|
|
func removeCopyDir(m *Manager, stack, copyDir string) {
|
|
if copyDir == "" {
|
|
return
|
|
}
|
|
if err := os.RemoveAll(copyDir); err != nil {
|
|
m.logger.Printf("[WARN] [backup] %s: the restore copy %s could not be removed: %v", stack, copyDir, err)
|
|
return
|
|
}
|
|
_ = os.Remove(filepath.Dir(copyDir))
|
|
}
|
|
|
|
// ── R-1270 follow-up (brief 2026-10-26, fix A): the undo copy goes only after a STABLE start ─────────────────────────
|
|
//
|
|
// MEASURED (code at `e8d2151`): the watcher deleted the undo copy on the FIRST sample in which the stack read
|
|
// „running", and a restore whose health wait passed (one running sample, waitForHealthy) dropped it at once. An app
|
|
// that crashes and restarts reads „running" for a few seconds between crashes, so its way back could go while it was
|
|
// still broken.
|
|
//
|
|
// THE RULE (one helper for both places). „Started" means: for stableStartWindow, every sample (each stableStartPoll)
|
|
// has the stack running, every container with a healthcheck `healthy`, the same containers, and no container's
|
|
// RestartCount grown. The first verdict may still say success at once (the page; the 90 s health wait is unchanged) —
|
|
// the copy is RELEASED only after the window (releaseAfterStableStart). The verdict and the release are therefore two
|
|
// moments; `07` §6.3 says so. The window: 3 minutes — Docker's restart back-off grows to one minute, so a container
|
|
// that crashes after up to a minute of running restarts at least once inside it, and RestartCount catches every restart
|
|
// whatever its timing; it costs the household nothing (the app runs meanwhile), only the copy's disk for 3 minutes more.
|
|
|
|
var (
|
|
// verdictStableWindow is the first verdict's own stable window (after the 90 s health wait found the app running):
|
|
// 45 s — longer than the 20 s crash cycle of the measured case, so an app that runs, crashes and restarts is
|
|
// „not started yet" on the page too, and short enough that a good restore is reported within about two minutes.
|
|
verdictStableWindow = 45 * time.Second
|
|
stableStartWindow = 3 * time.Minute
|
|
stableStartPoll = 10 * time.Second
|
|
stableReleaseWatch = 30 * time.Minute
|
|
)
|
|
|
|
// ContainerSample is one container of a stack as a stable-start sample sees it.
|
|
type ContainerSample struct {
|
|
ID string
|
|
Running bool
|
|
RestartCount int
|
|
Health string // "" when the container has no healthcheck
|
|
}
|
|
|
|
// containerSampler is the optional provider half that reads the stack's containers (restart counts, health). A provider
|
|
// without it is judged on RefreshAndIsRunning alone.
|
|
type containerSampler interface {
|
|
ContainerSamples(name string) ([]ContainerSample, error)
|
|
}
|
|
|
|
type stableResult int
|
|
|
|
const (
|
|
stableYes stableResult = iota
|
|
stableNot
|
|
stableAborted
|
|
)
|
|
|
|
// stableSample is one look: ok, and the fingerprint (container id → restart count) a stable window must keep.
|
|
func (m *Manager) stableSample(stack string) (bool, map[string]int) {
|
|
if m.stackProvider == nil || !m.stackProvider.RefreshAndIsRunning(stack) {
|
|
m.debugStable(stack, "the stack does not read running")
|
|
return false, nil
|
|
}
|
|
cs, ok := m.stackProvider.(containerSampler)
|
|
if !ok {
|
|
return true, map[string]int{}
|
|
}
|
|
samples, err := cs.ContainerSamples(stack)
|
|
if err != nil || len(samples) == 0 {
|
|
m.debugStable(stack, fmt.Sprintf("no container sample (%d, err %v)", len(samples), err))
|
|
return false, nil
|
|
}
|
|
fp := make(map[string]int, len(samples))
|
|
for _, c := range samples {
|
|
if !c.Running || (c.Health != "" && c.Health != "healthy") {
|
|
m.debugStable(stack, fmt.Sprintf("container %.12s running=%v health=%q", c.ID, c.Running, c.Health))
|
|
return false, nil
|
|
}
|
|
fp[c.ID] = c.RestartCount
|
|
}
|
|
return true, fp
|
|
}
|
|
|
|
func (m *Manager) debugStable(stack, why string) {
|
|
if m.logger != nil && m.isDebug() {
|
|
m.logger.Printf("[DEBUG] [backup] stable-start sample %s: not ok — %s", stack, why)
|
|
}
|
|
}
|
|
|
|
func sameRestartFingerprint(a, b map[string]int) bool {
|
|
if len(a) != len(b) {
|
|
return false
|
|
}
|
|
for k, v := range a {
|
|
if bv, ok := b[k]; !ok || bv != v {
|
|
return false
|
|
}
|
|
}
|
|
return true
|
|
}
|
|
|
|
// waitStableStart waits until deadline for a stable window. stableAborted when a NEW restore of the app begins — one
|
|
// that began after this watch did. (The watch starts inside its own restore, before the handler ends that restore's
|
|
// record, so „a restore of the app is running" alone would end every watch at once.)
|
|
func (m *Manager) waitStableStart(stack string, watchFrom, deadline time.Time) stableResult {
|
|
return m.waitStableFor(stack, watchFrom, deadline, stableStartWindow)
|
|
}
|
|
|
|
// waitStableFor is waitStableStart with an explicit window (the first verdict's is shorter, verdictStableWindow).
|
|
func (m *Manager) waitStableFor(stack string, watchFrom, deadline time.Time, window time.Duration) stableResult {
|
|
var since time.Time
|
|
var fp0 map[string]int
|
|
poll := stableStartPoll // read once: the rule this watch began under
|
|
for time.Now().Before(deadline) {
|
|
if m.restoreBegunAfter(stack, watchFrom) {
|
|
return stableAborted
|
|
}
|
|
ok, fp := m.stableSample(stack)
|
|
switch {
|
|
case !ok:
|
|
since, fp0 = time.Time{}, nil
|
|
case since.IsZero() || !sameRestartFingerprint(fp0, fp):
|
|
since, fp0 = time.Now(), fp
|
|
case time.Since(since) >= window:
|
|
return stableYes
|
|
}
|
|
time.Sleep(poll)
|
|
}
|
|
return stableNot
|
|
}
|
|
|
|
// releaseAfterStableStart is the success path's release: the copy stays until the app ran stably for the window, then
|
|
// it is removed. If the app does not run stably within stableReleaseWatch, the copy stays for support and the operator
|
|
// is told once (the page already said the restore worked — the app's own status shows what it does now).
|
|
func (m *Manager) releaseAfterStableStart(stack, kind string, undo *liveVolumeCopy) {
|
|
if undo == nil || undo.dir == "" {
|
|
return
|
|
}
|
|
undo.deferred = true
|
|
dir := undo.dir
|
|
from := time.Now() // taken HERE, before the goroutine: a restore begun after this moment is a new one
|
|
until := from.Add(stableReleaseWatch)
|
|
go func() {
|
|
switch m.waitStableStart(stack, from, until) {
|
|
case stableYes:
|
|
removeCopyDir(m, stack, dir)
|
|
m.logger.Printf("[INFO] [backup] %s: ran stably for %s after its %s — the restore copy is released (R-1270)", stack, stableStartWindow, kind)
|
|
case stableAborted:
|
|
m.logger.Printf("[INFO] [backup] %s: a new restore began before the %s's start was stable — its restore copy stays for support (%s)", stack, kind, dir)
|
|
default:
|
|
m.logger.Printf("[ERROR] [backup] %s: did not run stably within %s after its %s — the restore copy stays for support (%s) (R-1270)", stack, stableReleaseWatch, kind, dir)
|
|
if m.restoreNotStartedNotify != nil {
|
|
m.restoreNotStartedNotify(stack, kind+" (not stable after its start)", fmt.Errorf("no stable %s within %s", stableStartWindow, stableReleaseWatch))
|
|
}
|
|
}
|
|
}()
|
|
}
|
|
|
|
// restoreBegunAfter reports whether a restore of stack is running that began after t.
|
|
func (m *Manager) restoreBegunAfter(stack string, t time.Time) bool {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
return m.restoreRunningForLocked(stack) && m.opStartedAt.After(t)
|
|
}
|
|
|
|
// restoredAppStarted is the restore's first verdict (every path): the 90 s health wait (one running sample, as before)
|
|
// AND then a stable verdictStableWindow within another health timeout — so an app that crashes and restarts is not
|
|
// reported as started. nil = started (the page says so; the copy is still released only after stableStartWindow).
|
|
func (m *Manager) restoredAppStarted(stack string) error {
|
|
if err := m.waitForHealthy(stack, healthTimeout); err != nil {
|
|
return err
|
|
}
|
|
from := time.Now()
|
|
switch m.waitStableFor(stack, from, from.Add(healthTimeout+verdictStableWindow), verdictStableWindow) {
|
|
case stableYes:
|
|
return nil
|
|
case stableAborted:
|
|
return fmt.Errorf("a new restore of %s began", stack)
|
|
}
|
|
return fmt.Errorf("stack %s did not run stably for %s (it restarted or turned unhealthy) after restore", stack, verdictStableWindow)
|
|
}
|
|
|
|
// ShortenRestoreTimingForTests (TESTS ONLY — other packages' TestMain) makes the stable-start rule take milliseconds,
|
|
// as this package's own TestMain does; a web or api test that runs a real restore then does not wait 45 s per call.
|
|
// Never called by production code (pinned by TestR488_HealthWaitDefaultsAreProduction reading the defaults).
|
|
func ShortenRestoreTimingForTests() {
|
|
verdictStableWindow, stableStartWindow, stableStartPoll = 10*time.Millisecond, 30*time.Millisecond, 2*time.Millisecond
|
|
}
|