felhom-controller/controller/internal/backup/offbox_progress.go

package backup

import (
	"bufio"
	"context"
	"encoding/json"
	"io"
	"os"
	"os/exec"
	"sync"
	"time"
)

// Offsite backup progress (v0.147.0, feedback slice 4c).
//
// THE PROBLEM: „Távoli mentés most" started a background restic run and redirected with „A távoli
// mentés elindult". After that the page polled a status field whose only values were running / ok /
// error. For a first offsite push of tens of gigabytes over SFTP that is 20+ minutes of a spinner
// with no total, no percentage and no indication of WHICH app is being pushed — indistinguishable
// from a hang.
//
// restic already reports all of it: `backup --json` writes newline-delimited status objects to
// stdout. We only had to stop throwing them away — the existing runner seam uses CombinedOutput(),
// which buffers everything until exit.
//
// SCOPE: the MANUAL trigger only. The nightly scheduled run stays silent (nobody is watching a
// progress bar at 03:00, and a sink left installed would keep publishing stale percentages into a
// page that never asked). The sink is installed for the duration of a manual run and cleared after.

// OffboxProgress is a snapshot of an in-flight manual offsite backup.
type OffboxProgress struct {
	Active     bool    `json:"active"`
	CurrentApp string  `json:"current_app"`
	Percent    float64 `json:"percent"` // 0..100, restic's byte-based percent_done
	BytesDone  int64   `json:"bytes_done"`
	TotalBytes int64   `json:"total_bytes"`
	DoneHuman  string  `json:"done_human"`
	TotalHuman string  `json:"total_human"`
	// FilesDone/TotalFiles matter more than they look. On an INCREMENTAL run where nothing changed,
	// restic transfers no new bytes: bytes_done stays 0 (it is `omitempty`, so it is not even in the
	// JSON) and percent_done stays 0 for the whole run, while restic still walks every file. Measured
	// on the demo box: a 430MB immich push sat at 0% for 40+ seconds and then completed. A byte-only
	// bar is therefore indistinguishable from a hang precisely in the COMMON case. File counts move
	// in that case, so the page falls back to them.
	FilesDone  int64 `json:"files_done"`
	TotalFiles int64 `json:"total_files"`
	// CurrentFile/ElapsedSec are the last resort, and on real data the most important fields here.
	// restic 0.14 only counts a file into files_done/bytes_done when it COMPLETES, so a single
	// dominant file freezes both counters: measured on the demo box, immich sat at files_done 1 of 46
	// and bytes_done 0 for 42 seconds while restic worked on one ~430MB volume tar. No percentage can
	// move during that window. What CAN be shown truthfully is which file is being processed and how
	// long it has been going — "working on X, 42s" is a completely different message from "0%".
	CurrentFile string `json:"current_file"`
	ElapsedSec  int64  `json:"elapsed_sec"`
	// Phase names the part of the run in progress. A run is NOT just the per-app loop: after the last
	// app come the shares leg and `forget --prune`, which on the demo box took 40 of a 57-second run.
	// Without this the card froze on the last app's finished counters for that whole tail — the same
	// silence the slice exists to remove, just relocated. "" = per-app backup.
	Phase string `json:"phase"`
}

// resticStatusLine is the subset of restic's `--json` status object we consume. restic emits several
// message_types (status, summary, error, verbose_status); anything that is not "status" is ignored
// here rather than treated as garbage, because restic adds new types between versions and an unknown
// type must never break the run. Schema captured from
// restic 0.14.0 (the version in the controller image) via a live `backup --dry-run --json`:
//
//	{"message_type":"status","percent_done":0,"total_files":1,"total_bytes":112}
//	{"message_type":"status","percent_done":0.558,"total_files":173,"files_done":87,
//	 "total_bytes":166878,"bytes_done":93161,"current_files":[...]}
//
// Note every numeric field except percent_done is `omitempty` on restic's side: a zero simply is not
// in the JSON. That is why an incremental run reports no bytes_done at all rather than an explicit 0.
type resticStatusLine struct {
	MessageType    string   `json:"message_type"`
	PercentDone    float64  `json:"percent_done"` // 0..1
	TotalBytes     int64    `json:"total_bytes"`
	BytesDone      int64    `json:"bytes_done"`
	TotalFiles     int64    `json:"total_files"`
	FilesDone      int64    `json:"files_done"`
	CurrentFiles   []string `json:"current_files"`
	SecondsElapsed int64    `json:"seconds_elapsed"`
}

// resticProgress is one parsed status line.
type resticProgress struct {
	Percent     float64 // 0..100
	BytesDone   int64
	TotalBytes  int64
	FilesDone   int64
	TotalFiles  int64
	CurrentFile string
	ElapsedSec  int64
}

// parseResticStatus parses ONE line of restic --json output.
//
// Kept as a pure function precisely so it can be tested without restic, a network, or a repo — the
// parser is the part that silently rots when restic changes its output, and a progress bar that
// quietly stops moving is worse than no progress bar at all.
func parseResticStatus(line string) (resticProgress, bool) {
	var s resticStatusLine
	if err := json.Unmarshal([]byte(line), &s); err != nil {
		return resticProgress{}, false
	}
	if s.MessageType != "status" {
		return resticProgress{}, false
	}
	pct := s.PercentDone * 100
	// restic revises its total as the scan proceeds, so percent_done legitimately moves backwards
	// mid-run and has been seen slightly above 1 near completion. Clamp — a bar wider than its track
	// is a visible bug.
	if pct < 0 {
		pct = 0
	}
	if pct > 100 {
		pct = 100
	}
	cur := ""
	if len(s.CurrentFiles) > 0 {
		cur = s.CurrentFiles[0]
	}
	return resticProgress{
		Percent: pct, BytesDone: s.BytesDone, TotalBytes: s.TotalBytes,
		FilesDone: s.FilesDone, TotalFiles: s.TotalFiles,
		CurrentFile: cur, ElapsedSec: s.SecondsElapsed,
	}, true
}

// offboxProgressState is the published snapshot, guarded independently of the Manager mutex so a
// poll never blocks behind the running backup.
type offboxProgressState struct {
	mu   sync.Mutex
	cur  OffboxProgress
	live bool
}

func (p *offboxProgressState) begin() {
	p.mu.Lock()
	p.cur = OffboxProgress{Active: true}
	p.live = true
	p.mu.Unlock()
}

func (p *offboxProgressState) end() {
	p.mu.Lock()
	p.cur = OffboxProgress{}
	p.live = false
	p.mu.Unlock()
}

func (p *offboxProgressState) setApp(app string) {
	p.mu.Lock()
	if p.live {
		// A new app resets the byte counters: restic's percentages are per-invocation, and carrying
		// the previous app's 100% into the next app's start would show a bar that jumps backwards.
		p.cur.CurrentApp = app
		p.cur.Phase = ""
		p.cur.Percent, p.cur.BytesDone, p.cur.TotalBytes = 0, 0, 0
		p.cur.FilesDone, p.cur.TotalFiles = 0, 0
		p.cur.CurrentFile, p.cur.ElapsedSec = "", 0
		p.cur.DoneHuman, p.cur.TotalHuman = "", ""
	}
	p.mu.Unlock()
}

// setPhase marks a non-per-app stage of the run and clears the app-scoped counters, so the card
// stops showing the last app's finished numbers against work that is no longer about that app.
func (p *offboxProgressState) setPhase(phase string) {
	p.mu.Lock()
	if p.live {
		p.cur.Phase = phase
		p.cur.CurrentApp = ""
		p.cur.Percent, p.cur.BytesDone, p.cur.TotalBytes = 0, 0, 0
		p.cur.FilesDone, p.cur.TotalFiles = 0, 0
		p.cur.CurrentFile, p.cur.ElapsedSec = "", 0
		p.cur.DoneHuman, p.cur.TotalHuman = "", ""
	}
	p.mu.Unlock()
}

// OffboxPhaseDump is the PRE-app-loop stage (R-44, v0.148.0); OffboxPhaseShares /
// OffboxPhaseRetention are the post-app-loop stages.
const (
	OffboxPhaseDump      = "dump"
	OffboxPhaseShares    = "shares"
	OffboxPhaseRetention = "retention"
)

func (p *offboxProgressState) update(r resticProgress) {
	p.mu.Lock()
	if p.live {
		p.cur.Percent, p.cur.BytesDone, p.cur.TotalBytes = r.Percent, r.BytesDone, r.TotalBytes
		p.cur.FilesDone, p.cur.TotalFiles = r.FilesDone, r.TotalFiles
		p.cur.ElapsedSec = r.ElapsedSec
		// Keep the last KNOWN current file: restic omits current_files on some status ticks, and
		// blanking the label every other second is its own kind of flicker.
		if r.CurrentFile != "" {
			p.cur.CurrentFile = r.CurrentFile
		}
		p.cur.DoneHuman, p.cur.TotalHuman = humanizeBytes(r.BytesDone), humanizeBytes(r.TotalBytes)
	}
	p.mu.Unlock()
}

func (p *offboxProgressState) snapshot() OffboxProgress {
	p.mu.Lock()
	defer p.mu.Unlock()
	return p.cur
}

// OffboxProgressSnapshot is the poll surface for the „Távoli mentés" page.
func (m *Manager) OffboxProgressSnapshot() OffboxProgress { return m.offboxProgress.snapshot() }

// offboxStreamRunner is the streaming restic-exec seam: like offboxRunner, but calls onLine for each
// stdout line AS IT ARRIVES instead of only returning the buffered output at exit. Tests inject a
// fake that emits canned `--json` status lines, so the whole progress path is exercised without
// restic, a network or a repo.
type offboxStreamRunner func(ctx context.Context, env []string, onLine func(string), args ...string) ([]byte, error)

// SetOffboxStreamRunner installs the streaming seam (nil → the real streaming exec).
func (m *Manager) SetOffboxStreamRunner(r offboxStreamRunner) { m.offboxStreamRunner = r }

func (m *Manager) streamRunner() offboxStreamRunner {
	if m.offboxStreamRunner != nil {
		return m.offboxStreamRunner
	}
	return defaultOffboxStreamRunner
}

// defaultOffboxStreamRunner runs restic with stdout scanned line-by-line. stderr is captured whole
// (restic's --json progress goes to stdout; errors go to stderr) and appended to the returned output
// so callers keep the same error-diagnosis material CombinedOutput gave them.
func defaultOffboxStreamRunner(ctx context.Context, env []string, onLine func(string), args ...string) ([]byte, error) {
	cmd := exec.CommandContext(ctx, "restic", args...)
	cmd.Env = append(os.Environ(), env...)

	stdout, err := cmd.StdoutPipe()
	if err != nil {
		return nil, err
	}
	var stderr syncBuf
	cmd.Stderr = &stderr

	if err := cmd.Start(); err != nil {
		return nil, err
	}

	var tail lineTail
	scanner := bufio.NewScanner(stdout)
	// restic status lines are small, but a --json summary listing many paths can exceed the 64KB
	// default; a scanner that dies mid-run would silently freeze the progress bar.
	scanner.Buffer(make([]byte, 0, 64*1024), 4*1024*1024)
	for scanner.Scan() {
		line := scanner.Text()
		tail.add(line)
		if onLine != nil {
			onLine(line)
		}
	}
	_, _ = io.Copy(io.Discard, stdout)

	werr := cmd.Wait()
	// Keep only the tail of stdout: the full --json stream of a large backup is megabytes of status
	// spam, and every caller uses this output for error diagnosis (and lock-pattern matching) only.
	out := append(tail.bytes(), stderr.bytes()...)
	return out, werr
}

// lineTail keeps the last N lines seen, so error diagnosis has context without buffering the whole
// --json stream.
type lineTail struct {
	lines []string
}

func (t *lineTail) add(s string) {
	const keep = 40
	t.lines = append(t.lines, s)
	if len(t.lines) > keep {
		t.lines = t.lines[len(t.lines)-keep:]
	}
}

func (t *lineTail) bytes() []byte {
	var b []byte
	for _, l := range t.lines {
		b = append(b, l...)
		b = append(b, '\n')
	}
	return b
}

type syncBuf struct {
	mu sync.Mutex
	b  []byte
}

func (s *syncBuf) Write(p []byte) (int, error) {
	s.mu.Lock()
	s.b = append(s.b, p...)
	s.mu.Unlock()
	return len(p), nil
}

func (s *syncBuf) bytes() []byte {
	s.mu.Lock()
	defer s.mu.Unlock()
	return append([]byte{}, s.b...)
}

// resticBackupStep is resticStep's streaming twin, used ONLY by the app-backup leg when a manual run
// has a progress sink installed. It keeps resticStep's crash-lock self-heal semantics by delegating
// the retry path to resticStep (a retry after an unlock is rare and does not need progress).
func (m *Manager) resticBackupStep(ctx context.Context, env, base []string, label, app string, args ...string) ([]byte, error) {
	if !m.offboxProgress.snapshot().Active {
		return m.resticStep(ctx, env, base, label, args...) // nightly / no watcher: unchanged path
	}
	m.offboxProgress.setApp(app)
	full := append(append([]string{}, base...), args...)
	// --json turns on the machine-readable progress stream. It is added ONLY here, so the nightly
	// run's output format (and everything that greps it) is untouched.
	full = append(full, "--json")
	out, err := m.streamRunner()(ctx, env, func(line string) {
		if r, ok := parseResticStatus(line); ok {
			m.offboxProgress.update(r)
		}
	}, full...)
	if err == nil || !offboxLockRe.Match(out) {
		return out, err
	}
	// Lock collision: fall back to the non-streaming step, which owns the unlock --remove-all
	// self-heal. Progress stalls for that one retry; correctness beats a moving bar.
	m.logger.Printf("[WARN] [offbox] %s hit a lock during a manual run — retrying via the self-healing step", label)
	return m.resticStep(ctx, env, base, label, args...)
}

// beginManualProgress installs the progress sink for a manual run and returns the cleanup func.
func (m *Manager) beginManualProgress() func() {
	m.offboxProgress.begin()
	started := time.Now()
	return func() {
		m.logger.Printf("[INFO] [offbox] manual run progress reporting ended after %s", time.Since(started).Round(time.Second))
		m.offboxProgress.end()
	}
}