felhom-controller/controller/internal/stacks/unattended.go

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"
	// LegSkipStoppedByHousehold (R-721, v0.283.0): the household stopped the app; an update would start it.
	LegSkipStoppedByHousehold = "stopped_by_household"
	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 {
	return m.runUpdateLeg(ctx, trigger, false)
}

// RunUpdateLegNow is the leg for a MANUAL run of the night's chain (R-705, the debug action): the same
// leg, but its step deadline is its start + the leg's normal length (backupwindow.UpdateLegLengthMin),
// not W+5h of the last window — which, by day, has passed and would make the leg start nothing.
func (m *Manager) RunUpdateLegNow(ctx context.Context, trigger string) *UpdateLegSummary {
	return m.runUpdateLeg(ctx, trigger, true)
}

func (m *Manager) runUpdateLeg(ctx context.Context, trigger string, manual bool) *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)
	if manual {
		sum.Deadline = sum.StartedAt.Add(time.Duration(backupwindow.UpdateLegLengthMin) * time.Minute)
	}
	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 DesiredStateOf(*st) == DesiredStateStopped {
		return LadderEntry{}, LegSkipStoppedByHousehold
	}
	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 })
}