package stacks import ( "context" "errors" "fmt" "path/filepath" "sort" "strings" "sync" "time" "gitea.dooplex.hu/admin/felhom-controller/internal/backupwindow" ) // ── The automatic update leg (`09` §3 decisions 11, 12, 14, 15, 20; §6.4 part 7; controller v0.271.0) ── // // WHAT IT IS. One more leg of the nightly chain: after the off-site copy, before the full-system backup. // It presses the SAME public guarded Update a person presses (StartGuardedUpdate) — no second update // path — one app at a time, ONE tested step per app per night, and never: // - an app whose installed version has no ladder entry (older than the ladder, or no test record); // - a step whose verdict is not `proven`, or that carries the `needs_person` mark; // - a `files_may_change` step unless a fresh WHOLE copy of the app exists on the box (decision 25/26); // - the step that was undone or held last time, while the catalog's ladder is unchanged (R-680); // - a held app, an app that is current, ahead, or unorderable. // It starts no step at or after W+5h (decision 20); a step already running finishes. // // WHERE IT IS CALLED FROM. The `offbox-backup` scheduler job, after the off-site copy, on EVERY path — // configured, not configured, failed, skipped, panicked (cmd/controller chainUpdateLeg, pinned by // TestChainUpdateLeg_*). The full-system backup's gate asks UpdateLegState and waits while the leg runs, // until W+5h (quiesce.Options.UpdateLegFn). // // WHAT THE HOUSEHOLD HEARS. Nothing new: an undone or held step already sends app_update_undone / // app_update_held from the update itself. A successful automatic step sends NO mail; the app page shows // one line from app.yaml's last_auto_update. The operator gets one summary line per night in the log and // in the hub report (LastUpdateLegSummary). // Leg skip reasons — stable keys for the log, the summary and tests. const ( LegSkipHeld = "held" LegSkipUnpinned = "unpinned" LegSkipUnknownOrder = "order_unknown" LegSkipAhead = "ahead" LegSkipNoTestRecord = "no_test_record" LegSkipOlderThanLadder = "older_than_ladder" LegSkipNotProven = "not_proven" LegSkipNeedsPerson = "needs_person" LegSkipFilesNoCopy = "files_may_change_no_whole_copy" LegSkipFailedBefore = "failed_before" LegSkipWindowEnd = "window_end" LegSkipSwitchedOff = "switched_off" LegSkipCancelled = "cancelled" legCurrent = "current" // not a skip: nothing to do LegOutcomeDone = "done" LegOutcomeUndone = "undone" LegOutcomeHeld = "held" LegOutcomeFailed = "failed" LegOutcomeSkipped = "skipped" ) // legTransient are the refusals a later press may not meet (R-609's split): retried ONCE later in the leg. var legTransient = map[string]bool{"busy": true, "updating": true, "deploying": true, "migrating": true, "self_updating": true} // UpdateLegOptions wires the leg (main.go). INIT-ONLY via SetUpdateLeg. type UpdateLegOptions struct { // Enabled is the per-box switch `app_update.unattended` (decision 12, default ON). Read at the start // and before every press, so switching it off stops the leg before its next step. Enabled func() bool // WindowStart is the effective backup window start W "HH:MM" — the leg starts no step at or after W+5h. WindowStart func() string // FreshWholeCopy answers decision 13's `files_may_change` mark: is there a fresh copy on this box that // brings the app back WHOLE (decision 25/26's truth table)? nil = no → such a step is always skipped. FreshWholeCopy func(ctx context.Context, name string) (bool, string) // Location is the wall clock W is read in (Europe/Budapest); nil = time.Local. Location *time.Location // Poll is how often the leg looks whether its step has ended (default 5 s). Poll time.Duration // RetryWait is how long the leg waits before its one retry of transient refusals (default 2 min). RetryWait time.Duration // Now is the clock (tests); nil = time.Now. Now func() time.Time } // LegStep is one app's line in the night's summary. type LegStep struct { App string `json:"app"` Outcome string `json:"outcome"` // done | undone | held | failed | skipped Reason string `json:"reason,omitempty"` From map[string]string `json:"from,omitempty"` To map[string]string `json:"to,omitempty"` Seconds float64 `json:"seconds,omitempty"` } // UpdateLegSummary is one night's leg — the operator's summary line and the hub report's `update_leg`. type UpdateLegSummary struct { Trigger string `json:"trigger"` StartedAt time.Time `json:"started_at"` EndedAt time.Time `json:"ended_at"` Deadline time.Time `json:"deadline"` Enabled bool `json:"enabled"` Done int `json:"done"` Undone int `json:"undone"` Held int `json:"held"` Failed int `json:"failed"` Skipped int `json:"skipped"` // Stopped says why the leg ended early: window_end | switched_off | cancelled | "" (it ran through). Stopped string `json:"stopped,omitempty"` Steps []LegStep `json:"steps"` } // Line is the one operator-English summary line. func (s *UpdateLegSummary) Line() string { var skips []string for _, st := range s.Steps { if st.Outcome == LegOutcomeSkipped { skips = append(skips, st.App+"="+st.Reason) } } stop := "" if s.Stopped != "" { stop = " stopped=" + s.Stopped } return fmt.Sprintf("update leg (%s): done=%d undone=%d held=%d failed=%d skipped=%d%s in %s [skipped: %s]", s.Trigger, s.Done, s.Undone, s.Held, s.Failed, s.Skipped, stop, s.EndedAt.Sub(s.StartedAt).Round(time.Second), strings.Join(skips, ", ")) } func (s *UpdateLegSummary) add(st LegStep) { s.Steps = append(s.Steps, st) switch st.Outcome { case LegOutcomeDone: s.Done++ case LegOutcomeUndone: s.Undone++ case LegOutcomeHeld: s.Held++ case LegOutcomeFailed: s.Failed++ default: s.Skipped++ } } type updateLegState struct { run sync.Mutex // single-flight: one leg at a time mu sync.Mutex // guards the fields below opts *UpdateLegOptions active bool stepRunning bool last *UpdateLegSummary } // SetUpdateLeg wires the leg. INIT-ONLY (main.go). Without it RunUpdateLeg does nothing and says so. func (m *Manager) SetUpdateLeg(o UpdateLegOptions) { if o.Poll <= 0 { o.Poll = 5 * time.Second } if o.RetryWait <= 0 { o.RetryWait = 2 * time.Minute } if o.Location == nil { o.Location = time.Local } if o.Now == nil { o.Now = time.Now } m.leg.mu.Lock() m.leg.opts = &o m.leg.mu.Unlock() } // UpdateLegState is what the full-system backup's gate asks (decision 20): is the leg running, and is one // of its steps in flight right now. func (m *Manager) UpdateLegState() (active, stepRunning bool) { m.leg.mu.Lock() defer m.leg.mu.Unlock() return m.leg.active, m.leg.stepRunning } // LastUpdateLegSummary is the last leg's summary, or nil when none ran since the controller started. func (m *Manager) LastUpdateLegSummary() *UpdateLegSummary { m.leg.mu.Lock() defer m.leg.mu.Unlock() if m.leg.last == nil { return nil } c := *m.leg.last c.Steps = append([]LegStep{}, m.leg.last.Steps...) // R-687: `[]`, never `null`, in the hub report return &c } func (m *Manager) setLegFlags(active, step bool) { m.leg.mu.Lock() m.leg.active, m.leg.stepRunning = active, step m.leg.mu.Unlock() } // LegDeadline is the instant the leg starts no more steps: W+5h of the night that contains `now` (the // most recent W at or before now). An unparseable W falls back to the default window. func LegDeadline(now time.Time, window string, loc *time.Location) time.Time { if loc == nil { loc = time.Local } startMin, err := backupwindow.ParseHHMM(window) if err != nil { startMin, _ = backupwindow.ParseHHMM(backupwindow.DefaultWindow) } n := now.In(loc) w := time.Date(n.Year(), n.Month(), n.Day(), startMin/60, startMin%60, 0, 0, loc) if w.After(n) { w = w.AddDate(0, 0, -1) } return w.Add(time.Duration(backupwindow.UpdateLegStopOffsetMin) * time.Minute) } // RunUpdateLeg runs one night's leg and returns its summary (nil when another leg is running or the leg // is not wired). trigger names the caller for the log ("after-offsite"). func (m *Manager) RunUpdateLeg(ctx context.Context, trigger string) *UpdateLegSummary { if !m.leg.run.TryLock() { m.logger.Printf("[WARN] [update-leg] a leg is already running — this call (%s) does nothing", trigger) return nil } defer m.leg.run.Unlock() m.leg.mu.Lock() o := m.leg.opts m.leg.mu.Unlock() if o == nil { m.logger.Printf("[WARN] [update-leg] not wired (SetUpdateLeg) — no automatic app updates") return nil } sum := &UpdateLegSummary{Trigger: trigger, StartedAt: o.Now(), Steps: []LegStep{}} finish := func() *UpdateLegSummary { sum.EndedAt = o.Now() m.logger.Printf("[INFO] [update-leg] %s", sum.Line()) m.leg.mu.Lock() m.leg.last = sum m.leg.mu.Unlock() return sum } sum.Enabled = o.Enabled == nil || o.Enabled() if !sum.Enabled { sum.Stopped = LegSkipSwitchedOff m.logger.Printf("[INFO] [update-leg] automatic app updates are switched OFF on this box (app_update.unattended=false) — no app is pressed tonight") return finish() } window := "" if o.WindowStart != nil { window = o.WindowStart() } sum.Deadline = LegDeadline(sum.StartedAt, window, o.Location) m.setLegFlags(true, false) defer m.setLegFlags(false, false) m.logger.Printf("[INFO] [update-leg] started (%s): window %s, no step starts at or after %s", trigger, window, sum.Deadline.In(o.Location).Format("15:04")) // The freshest view of the catalog and the pins — a sync may have landed since the last scan. if err := m.ScanStacks(); err != nil { m.logger.Printf("[WARN] [update-leg] rescan before the leg failed: %v — using the last scan", err) } var names []string for _, st := range m.GetStacks() { if st.Deployed && !st.Protected && !m.cfg.IsProtectedStack(st.Name) { names = append(names, st.Name) } } sort.Strings(names) var retry []string for pass := 0; pass < 2 && sum.Stopped == ""; pass++ { list := names if pass == 1 { list, retry = retry, nil if len(list) == 0 { break } m.logger.Printf("[INFO] [update-leg] %d app(s) were refused for a passing reason — one retry in %s: %v", len(list), o.RetryWait, list) select { case <-ctx.Done(): case <-time.After(o.RetryWait): } } for i, name := range list { if stop := m.legStop(ctx, o, sum); stop != "" { sum.Stopped = stop for _, rest := range list[i:] { sum.add(LegStep{App: rest, Outcome: LegOutcomeSkipped, Reason: stop}) } if pass == 0 { for _, rest := range retry { sum.add(LegStep{App: rest, Outcome: LegOutcomeSkipped, Reason: stop}) } } break } entry, reason := m.legCandidate(ctx, name, o) if reason == legCurrent { continue } if reason != "" { m.logger.Printf("[INFO] [update-leg] %s: skipped — %s", name, reason) sum.add(LegStep{App: name, Outcome: LegOutcomeSkipped, Reason: reason}) continue } t0 := o.Now() if err := m.StartGuardedUpdate(name); err != nil { why := "refused" var ref *UpdateRefusal if errors.As(err, &ref) { why = ref.Reason } if legTransient[why] && pass == 0 { m.logger.Printf("[INFO] [update-leg] %s: refused (%s) — a passing reason, retried once later tonight", name, why) retry = append(retry, name) continue } m.logger.Printf("[INFO] [update-leg] %s: skipped — the update refused (%s)", name, why) sum.add(LegStep{App: name, Outcome: LegOutcomeSkipped, Reason: "refused:" + why}) continue } m.logger.Printf("[INFO] [update-leg] %s: step pressed %s → %s", name, summarisePin(entry.From), summarisePin(entry.To)) m.setLegFlags(true, true) outcome := m.legWait(ctx, o, name) m.setLegFlags(true, false) step := LegStep{App: name, Outcome: outcome, From: entry.From, To: entry.To, Seconds: o.Now().Sub(t0).Round(100 * time.Millisecond).Seconds()} sum.add(step) m.recordAutoUpdate(name, &AutoUpdateRecord{At: t0.UTC().Format(time.RFC3339), Outcome: outcome, From: entry.From, To: entry.To}) m.logger.Printf("[INFO] [update-leg] %s: step ended %s after %.1f s", name, outcome, step.Seconds) } } return finish() } // legStop is the leg's own stop check before every press: cancelled, switched off, or W+5h reached. func (m *Manager) legStop(ctx context.Context, o *UpdateLegOptions, sum *UpdateLegSummary) string { switch { case ctx.Err() != nil: m.logger.Printf("[WARN] [update-leg] cancelled (the controller is stopping) — the remaining apps wait for the next night") return LegSkipCancelled case o.Enabled != nil && !o.Enabled(): m.logger.Printf("[INFO] [update-leg] the switch was turned OFF during the leg — no further step tonight") return LegSkipSwitchedOff case !o.Now().Before(sum.Deadline): m.logger.Printf("[INFO] [update-leg] W+5h reached (%s) — no new step starts; the full-system backup keeps its hour, the rest waits for the next night", sum.Deadline.In(o.Location).Format("15:04")) return LegSkipWindowEnd } return "" } // legWait waits until the pressed step has ended and returns its outcome. A cancelled context stops the // WAIT only — the update job itself runs on, and its journal finishes it after a restart. func (m *Manager) legWait(ctx context.Context, o *UpdateLegOptions, name string) string { for m.IsUpdating(name) { select { case <-ctx.Done(): return LegOutcomeFailed case <-time.After(o.Poll): } } st, ok := m.GetStack(name) if !ok { return LegOutcomeFailed } switch { case st.UpdatePhase == UpdatePhaseDone: return LegOutcomeDone case st.UpdatePhase == UpdatePhaseUndone: return LegOutcomeUndone case st.updateHeld || st.UpdateErrorKey == UpdateErrorKeyHeld || st.HoldReason != "": return LegOutcomeHeld } return LegOutcomeFailed } // legCandidate decides whether the leg may press this app tonight, and which step it would take. It // returns ("", entry) to press, legCurrent when there is nothing to do, or a skip reason. func (m *Manager) legCandidate(ctx context.Context, name string, o *UpdateLegOptions) (LadderEntry, string) { st, ok := m.GetStack(name) if !ok || !st.Deployed { return LadderEntry{}, legCurrent } if st.HoldReason != "" || st.updateHeld { return LadderEntry{}, LegSkipHeld } if g := m.guards(); g != nil { if held, _ := g.HoldFor(name); held { return LadderEntry{}, LegSkipHeld } } switch CatalogOrder(*st) { case UpdateOrderCurrent: return LadderEntry{}, legCurrent case UpdateOrderAhead: return LadderEntry{}, LegSkipAhead case UpdateOrderBehind: default: return LadderEntry{}, LegSkipUnknownOrder } if st.AppConfig == nil || len(st.AppConfig.PinnedImages) == 0 { return LadderEntry{}, LegSkipUnpinned } pinned := st.AppConfig.PinnedImages tplDir := filepath.Dir(m.CatalogTemplatePath(name, "docker-compose.yml")) ladder, err := LoadLadder(filepath.Join(tplDir, ".felhom.yml")) if err != nil || len(ladder) == 0 { return LadderEntry{}, LegSkipNoTestRecord } idx := -1 for i := len(ladder) - 1; i >= 0; i-- { // the SAME choice nextLadderStep makes if sameRefs(ladder[i].From, pinned) { idx = i break } } if idx < 0 { if sameRefs(ladder[len(ladder)-1].To, pinned) { return LadderEntry{}, LegSkipNoTestRecord // at the head, behind only by something no step records } m.logger.Printf("[INFO] [update-leg] %s: the installed version %s matches no update_ladder entry — an app older than the ladder is never pressed by the leg (a person can)", name, summarisePin(pinned)) return LadderEntry{}, LegSkipOlderThanLadder } e := ladder[idx] if e.Verdict != "proven" { return e, LegSkipNotProven } if e.Marks.NeedsPerson != nil && strings.TrimSpace(*e.Marks.NeedsPerson) != "" { return e, LegSkipNeedsPerson } if fs := st.AppConfig.FailedStep; fs != nil && sameRefs(fs.To, e.To) && fs.Ladder == LadderPrint(ladder) { return e, LegSkipFailedBefore } if e.Marks.FilesMayChange { whole, why := false, "no whole-copy check wired" if o.FreshWholeCopy != nil { whole, why = o.FreshWholeCopy(ctx, name) } if !whole { m.logger.Printf("[INFO] [update-leg] %s: the step may change the app's files and no fresh whole copy exists (%s)", name, why) return e, LegSkipFilesNoCopy } // R-687: the TAKEN case names the copy that allowed it, as the skip names why not. m.logger.Printf("[INFO] [update-leg] %s: the step may change the app's files — taken, a fresh whole copy exists: %s", name, why) } return e, "" } // ── The records the leg and the update write into app.yaml ───────────────────────────────────────── // FailedStep is R-680's record: the step whose update was undone or held. type FailedStep struct { To map[string]string `yaml:"to" json:"to"` Ladder string `yaml:"ladder" json:"ladder"` // LadderPrint of the ladder it failed on At string `yaml:"at" json:"at"` Outcome string `yaml:"outcome" json:"outcome"` // undone | held } // AutoUpdateRecord is the leg's last step on an app — the page's line. type AutoUpdateRecord struct { At string `yaml:"at" json:"at"` Outcome string `yaml:"outcome" json:"outcome"` From map[string]string `yaml:"from,omitempty" json:"from,omitempty"` To map[string]string `yaml:"to,omitempty" json:"to,omitempty"` } // mutateAppConfig loads app.yaml, applies fn (false = nothing to write), saves it and mirrors the // in-memory copy. A failed write is logged and never fails the caller — these are records. func (m *Manager) mutateAppConfig(name, dir, what string, fn func(cfg *AppConfig) bool) { cfg := LoadAppConfig(dir) if cfg == nil || !fn(cfg) { return } meta := LoadMetadata(dir) if err := SaveAppConfig(dir, cfg, m.encKey, SensitiveEnvVars(&meta)); err != nil { m.logger.Printf("[ERROR] [stacks] %s: recording %s failed: %v", name, what, err) return } m.mu.Lock() if st, ok := m.stacks[name]; ok && st.AppConfig != nil { fn(st.AppConfig) } m.mu.Unlock() } // recordFailedStep writes R-680's record for the step `to` (undone or held), tied to the ladder the // catalog carries now. func (m *Manager) recordFailedStep(name, dir string, to map[string]string, outcome string) { if len(to) == 0 { return } ladder, _ := LoadLadder(m.CatalogTemplatePath(name, ".felhom.yml")) rec := &FailedStep{To: to, Ladder: LadderPrint(ladder), At: m.now().UTC().Format(time.RFC3339), Outcome: outcome} m.mutateAppConfig(name, dir, "failed_update_step", func(cfg *AppConfig) bool { cfg.FailedStep = rec; return true }) m.logger.Printf("[INFO] [stacks] update %s: step %s recorded as %s — the automatic leg will not press it again until the catalog's ladder changes (ladder %s)", name, summarisePin(to), outcome, rec.Ladder) } // clearFailedStep drops R-680's record after a successful update. func (m *Manager) clearFailedStep(name, dir string) { m.mutateAppConfig(name, dir, "failed_update_step", func(cfg *AppConfig) bool { if cfg.FailedStep == nil { return false } cfg.FailedStep = nil return true }) } func (m *Manager) recordAutoUpdate(name string, rec *AutoUpdateRecord) { st, ok := m.GetStack(name) if !ok { return } m.mutateAppConfig(name, filepath.Dir(st.ComposePath), "last_auto_update", func(cfg *AppConfig) bool { cfg.LastAutoUpdate = rec; return true }) }