After a power cut: remove the dead half-written backup (R-1006); a backup task from before the boot is not in flight (R-1008)

2026-10-14 11:29:41 +02:00
parent e7d4ecd607
commit a2f3aeeeff
18 changed files with 1129 additions and 40 deletions
@@ -0,0 +1,208 @@
+// Package vzpartial removes a dead, half-written vzdump backup of a guest from a local dir storage (R-1006).
+//
+// A power cut during the night's whole-guest backup leaves `vzdump-lxc-<vmid>-<date>.tar.dat` and its `.tmp/` directory
+// on the target (demo-hp 2026-10-14: 12.2 GB on the host root). Nothing removes them: Proxmox does not list them as
+// backups, every later backup is skipped „not enough space", and a host root that fills up breaks LVM's own metadata
+// writes (audits/power-cut-fixes-2026-10-14 C4). This package finds such a leftover and asks the root helper
+// /usr/local/sbin/felhom-vzdump-partial-clean to remove it; the helper re-checks every rule as root.
+//
+// Rules here (the helper repeats them, and adds the open-file check the agent cannot do):
+//   - only a `dir` storage; only names of the exact vzdump pattern for that vmid (NamePattern) — never a finished
+//     archive, a log, another guest;
+//   - only when no vzdump for that vmid is in flight (the R-1008 answer: a task from before the boot is not in flight);
+//   - only when dead: last modified before this boot, or untouched for QuietFor.
+//
+// Any doubt leaves the entry and logs why. Pinned by vzpartial_test.go.
+package vzpartial
+
+import (
+	"context"
+	"fmt"
+	"log/slog"
+	"os"
+	"path/filepath"
+	"regexp"
+	"strconv"
+	"strings"
+	"time"
+
+	"gitea.dooplex.hu/admin/felhom-agent/internal/proxmox"
+)
+
+// Helper is the root helper's installed path (configs/felhom-vzdump-partial-clean, delivered by the config bundle).
+const Helper = "/usr/local/sbin/felhom-vzdump-partial-clean"
+
+// QuietFor is how long an entry written in THIS boot must be untouched before it counts as dead (the helper's QUIET_S).
+const QuietFor = 120 * time.Second
+
+// NamePattern matches the half-written entries of one guest: the archive being written (.tar.dat / .vma.dat) and the
+// temporary directory (.tmp). The timestamp is vzdump's own (host local time).
+func NamePattern(vmid int) *regexp.Regexp {
+	return regexp.MustCompile(`^vzdump-(lxc|qemu)-` + strconv.Itoa(vmid) +
+		`-[0-9]{4}_[0-9]{2}_[0-9]{2}-[0-9]{2}_[0-9]{2}_[0-9]{2}\.(tar\.dat|vma\.dat|tmp)$`)
+}
+
+// Entry is one leftover found in the dump directory.
+type Entry struct {
+	Name    string
+	Dir     bool
+	ModTime time.Time
+	Size    int64
+}
+
+// Candidates lists the entries of dumpDir that match vmid's half-written pattern. A missing directory is no error.
+func Candidates(dumpDir string, vmid int) ([]Entry, error) {
+	ents, err := os.ReadDir(dumpDir)
+	if err != nil {
+		if os.IsNotExist(err) {
+			return nil, nil
+		}
+		return nil, err
+	}
+	re := NamePattern(vmid)
+	var out []Entry
+	for _, e := range ents {
+		if !re.MatchString(e.Name()) || e.Type()&os.ModeSymlink != 0 {
+			continue
+		}
+		info, err := e.Info()
+		if err != nil {
+			continue
+		}
+		if strings.HasSuffix(e.Name(), ".tmp") != info.IsDir() {
+			continue // a .tmp that is not a directory, or an archive name that is one: not vzdump's
+		}
+		mt := info.ModTime()
+		if info.IsDir() {
+			mt = newestUnder(filepath.Join(dumpDir, e.Name()), mt)
+		}
+		out = append(out, Entry{Name: e.Name(), Dir: info.IsDir(), ModTime: mt, Size: info.Size()})
+	}
+	return out, nil
+}
+
+func newestUnder(dir string, mt time.Time) time.Time {
+	_ = filepath.WalkDir(dir, func(_ string, d os.DirEntry, err error) error {
+		if err != nil {
+			return nil
+		}
+		if i, e := d.Info(); e == nil && i.ModTime().After(mt) {
+			mt = i.ModTime()
+		}
+		return nil
+	})
+	return mt
+}
+
+// Dead decides whether an entry is dead: written before this boot, or untouched for QuietFor. bootOK=false (the boot
+// time could not be read) leaves only the quiet rule.
+func Dead(e Entry, boot time.Time, bootOK bool, now time.Time) (bool, string) {
+	if bootOK && e.ModTime.Before(boot) {
+		return true, "written before this boot"
+	}
+	if age := now.Sub(e.ModTime); age >= QuietFor {
+		return true, "untouched for " + age.Round(time.Second).String()
+	}
+	return false, "modified " + now.Sub(e.ModTime).Round(time.Second).String() + " ago — may still be written"
+}
+
+// StorageAPI is the one Proxmox read the cleaner needs (the storage's type and path).
+type StorageAPI interface {
+	ListStorage(ctx context.Context) ([]proxmox.Storage, error)
+}
+
+// Cleaner removes dead leftovers. All fields but Logger and Now are required; a nil Cleaner is a no-op.
+type Cleaner struct {
+	API      StorageAPI
+	Runner   proxmox.Runner // the fenced sudo runner
+	InFlight func(ctx context.Context, vmid int) (bool, error)
+	Boot     func() (int64, bool)
+	Logger   *slog.Logger
+	Now      func() time.Time
+	// dumpDir maps a storage path to its dump directory (tests); nil = <path>/dump.
+	dumpDir func(path string) string
+}
+
+// Result is one removal or one entry left in place.
+type Result struct {
+	Entry   Entry
+	Removed bool
+	Why     string
+}
+
+// Clean removes the dead leftovers of vmid on storage. It never returns an error for „nothing to do"; every entry it
+// finds is logged with what was done and why.
+func (c *Cleaner) Clean(ctx context.Context, storage string, vmid int) []Result {
+	if c == nil || c.API == nil || c.Runner == nil || c.InFlight == nil || c.Boot == nil {
+		return nil
+	}
+	log := c.Logger
+	if log == nil {
+		log = slog.Default()
+	}
+	now := time.Now
+	if c.Now != nil {
+		now = c.Now
+	}
+	stores, err := c.API.ListStorage(ctx)
+	if err != nil {
+		log.Warn("vzdump-partial: storage list unreadable — not looking for leftovers", "storage", storage, "err", err)
+		return nil
+	}
+	var st *proxmox.Storage
+	for i := range stores {
+		if stores[i].Storage == storage {
+			st = &stores[i]
+			break
+		}
+	}
+	if st == nil || st.Type != "dir" || st.Path == "" {
+		return nil // PBS, LVM, NFS …: vzdump does not leave a .tar.dat there that this agent may remove
+	}
+	dump := filepath.Join(st.Path, "dump")
+	if c.dumpDir != nil {
+		dump = c.dumpDir(st.Path)
+	}
+	ents, err := Candidates(dump, vmid)
+	if err != nil {
+		log.Warn("vzdump-partial: dump directory unreadable", "dir", dump, "err", err)
+		return nil
+	}
+	if len(ents) == 0 {
+		return nil
+	}
+	var out []Result
+	inFlight, err := c.InFlight(ctx, vmid)
+	if err != nil || inFlight {
+		why := "a backup of this guest is in flight"
+		if err != nil {
+			why = "cannot tell whether a backup is in flight: " + err.Error()
+		}
+		for _, e := range ents {
+			log.Info("vzdump-partial: leaving a half-written backup", "storage", storage, "vmid", vmid, "name", e.Name, "why", why)
+			out = append(out, Result{Entry: e, Why: why})
+		}
+		return out
+	}
+	b, bootOK := c.Boot()
+	boot := time.Unix(b, 0)
+	for _, e := range ents {
+		dead, why := Dead(e, boot, bootOK, now())
+		if !dead {
+			log.Info("vzdump-partial: leaving a half-written backup", "storage", storage, "vmid", vmid, "name", e.Name, "why", why)
+			out = append(out, Result{Entry: e, Why: why})
+			continue
+		}
+		stdout, stderr, err := c.Runner.Run(ctx, Helper, storage, strconv.Itoa(vmid), e.Name)
+		if err != nil {
+			why = fmt.Sprintf("the root helper refused: %s", strings.TrimSpace(string(stderr)))
+			log.Warn("vzdump-partial: leaving a half-written backup", "storage", storage, "vmid", vmid, "name", e.Name, "why", why, "err", err)
+			out = append(out, Result{Entry: e, Why: why})
+			continue
+		}
+		log.Warn("vzdump-partial: removed a dead half-written backup", "storage", storage, "vmid", vmid, "name", e.Name,
+			"bytes", e.Size, "why", why, "helper", strings.TrimSpace(string(stdout)))
+		out = append(out, Result{Entry: e, Removed: true, Why: why})
+	}
+	return out
+}
@@ -0,0 +1,206 @@
+package vzpartial
+
+import (
+	"context"
+	"errors"
+	"io"
+	"os"
+	"os/exec"
+	"path/filepath"
+	"runtime"
+	"testing"
+	"time"
+
+	"gitea.dooplex.hu/admin/felhom-agent/internal/proxmox"
+)
+
+const vmid = 9201
+const name = "vzdump-lxc-9201-2026_10_14-10_42_25"
+
+var boot = time.Unix(1791967481, 0)
+
+type fakeAPI struct{ stores []proxmox.Storage }
+
+func (f fakeAPI) ListStorage(context.Context) ([]proxmox.Storage, error) { return f.stores, nil }
+
+type fakeRunner struct {
+	calls [][]string
+	err   error
+}
+
+func (r *fakeRunner) Run(_ context.Context, n string, a ...string) ([]byte, []byte, error) {
+	r.calls = append(r.calls, append([]string{n}, a...))
+	if r.err != nil {
+		return nil, []byte("REFUSED: in use"), r.err
+	}
+	return []byte("removed"), nil, nil
+}
+func (r *fakeRunner) RunStdin(ctx context.Context, _ io.Reader, n string, a ...string) ([]byte, []byte, error) {
+	return r.Run(ctx, n, a...)
+}
+
+type rig struct {
+	dump   string
+	runner *fakeRunner
+	c      *Cleaner
+}
+
+func newRig(t *testing.T, storeType string, inFlight bool, inErr error) *rig {
+	t.Helper()
+	root := t.TempDir()
+	dump := filepath.Join(root, "dump")
+	if err := os.MkdirAll(dump, 0o755); err != nil {
+		t.Fatal(err)
+	}
+	r := &rig{dump: dump, runner: &fakeRunner{}}
+	r.c = &Cleaner{
+		API:      fakeAPI{stores: []proxmox.Storage{{Storage: "local", Type: storeType, Path: root}}},
+		Runner:   r.runner,
+		InFlight: func(context.Context, int) (bool, error) { return inFlight, inErr },
+		Boot:     func() (int64, bool) { return boot.Unix(), true },
+		Now:      func() time.Time { return boot.Add(5 * time.Minute) },
+	}
+	return r
+}
+
+func (r *rig) put(t *testing.T, n string, dir bool, mt time.Time) {
+	t.Helper()
+	p := filepath.Join(r.dump, n)
+	if dir {
+		if err := os.MkdirAll(filepath.Join(p, "etc"), 0o755); err != nil {
+			t.Fatal(err)
+		}
+		_ = os.Chtimes(filepath.Join(p, "etc"), mt, mt)
+	} else if err := os.WriteFile(p, []byte("x"), 0o644); err != nil {
+		t.Fatal(err)
+	}
+	_ = os.Chtimes(p, mt, mt)
+}
+
+func (r *rig) asked() []string {
+	var out []string
+	for _, c := range r.runner.calls {
+		if len(c) == 4 && c[0] == Helper && c[1] == "local" && c[2] == "9201" {
+			out = append(out, c[3])
+		}
+	}
+	return out
+}
+
+// RED-PROOF: remove the `bootOK && e.ModTime.Before(boot)` rule in Dead → a pre-boot entry modified 1 min before the
+// boot is still „untouched for 6m" — so the test uses a 1-min-old-at-boot entry AND a Now 30 s after the boot.
+func TestClean_RemovesDeadPartialAndTmp(t *testing.T) {
+	r := newRig(t, "dir", false, nil)
+	r.c.Now = func() time.Time { return boot.Add(30 * time.Second) }
+	r.put(t, name+".tar.dat", false, boot.Add(-time.Minute))
+	r.put(t, name+".tmp", true, boot.Add(-time.Minute))
+	res := r.c.Clean(context.Background(), "local", vmid)
+	if got := r.asked(); len(got) != 2 {
+		t.Fatalf("both dead entries must go to the helper, got %v", got)
+	}
+	for _, x := range res {
+		if !x.Removed || x.Why != "written before this boot" {
+			t.Fatalf("%+v", x)
+		}
+	}
+}
+
+func TestClean_RemovesQuietPartialOfThisBoot(t *testing.T) {
+	r := newRig(t, "dir", false, nil)
+	r.put(t, name+".tar.dat", false, boot.Add(time.Minute)) // 4 min before Now
+	r.c.Clean(context.Background(), "local", vmid)
+	if len(r.asked()) != 1 {
+		t.Fatal("a partial untouched for QuietFor must be removed")
+	}
+}
+
+// Each keep has its positive control (the dead pre-boot partial in the same rig IS asked for).
+func TestClean_Keeps(t *testing.T) {
+	cases := map[string]func(t *testing.T) (*rig, string){
+		// RED-PROOF: drop the InFlight check in Clean → the in-flight partial is asked for → fails.
+		"in flight": func(t *testing.T) (*rig, string) { return newRig(t, "dir", true, nil), name + ".tar.dat" },
+		"in-flight unknown": func(t *testing.T) (*rig, string) {
+			return newRig(t, "dir", false, errors.New("api down")), name + ".tar.dat"
+		},
+		// RED-PROOF: drop the `st.Type != "dir"` test → an lvmthin target is cleaned → fails.
+		"not a dir storage": func(t *testing.T) (*rig, string) { return newRig(t, "lvmthin", false, nil), name + ".tar.dat" },
+	}
+	for what, mk := range cases {
+		r, n := mk(t)
+		r.put(t, n, false, boot.Add(-time.Hour))
+		r.c.Clean(context.Background(), "local", vmid)
+		if len(r.asked()) != 0 {
+			t.Fatalf("%s: must keep, helper asked for %v", what, r.asked())
+		}
+		ctl := newRig(t, "dir", false, nil)
+		ctl.put(t, n, false, boot.Add(-time.Hour))
+		ctl.c.Clean(context.Background(), "local", vmid)
+		if len(ctl.asked()) != 1 {
+			t.Fatalf("%s: positive control not removed", what)
+		}
+	}
+}
+
+// RED-PROOF: weaken NamePattern to `vzdump-.*` → the finished archive / log / other guest's partial are asked for.
+func TestClean_OnlyThisGuestsHalfWrittenNames(t *testing.T) {
+	r := newRig(t, "dir", false, nil)
+	old := boot.Add(-time.Hour)
+	for _, n := range []string{name + ".tar.zst", name + ".log", name + ".tar.zst.notes", "vzdump-lxc-9202-2026_10_14-10_42_25.tar.dat",
+		"vzdump-lxc-92011-2026_10_14-10_42_25.tar.dat", name + ".tar.dat.bak", name + ".tar.da", "x" + name + ".tar.dat"} {
+		r.put(t, n, false, old)
+	}
+	r.put(t, name+".tar.dat", false, old) // the positive control in the same directory
+	r.c.Clean(context.Background(), "local", vmid)
+	if got := r.asked(); len(got) != 1 || got[0] != name+".tar.dat" {
+		t.Fatalf("only %s.tar.dat may be asked for, got %v", name, got)
+	}
+}
+
+func TestClean_KeepsRecentAndWrongKindAndSymlink(t *testing.T) {
+	r := newRig(t, "dir", false, nil)
+	r.put(t, name+".tar.dat", false, boot.Add(4*time.Minute))                            // 1 min before Now: may still be written
+	r.put(t, "vzdump-lxc-9201-2026_10_14-11_00_00.tmp", false, boot.Add(-time.Hour))     // a FILE named .tmp
+	r.put(t, "vzdump-lxc-9201-2026_10_14-13_00_00.tar.dat", false, boot.Add(-time.Hour)) // positive control
+	r.c.Clean(context.Background(), "local", vmid)
+	if got := r.asked(); len(got) != 1 || got[0] != "vzdump-lxc-9201-2026_10_14-13_00_00.tar.dat" {
+		t.Fatalf("only the positive control may be asked for, got %v", got)
+	}
+}
+
+// RED-PROOF: drop the ModeSymlink skip in Candidates → the symlink (quiet: Now is an hour ahead) is asked for → fails.
+func TestClean_KeepsSymlink(t *testing.T) {
+	r := newRig(t, "dir", false, nil)
+	r.c.Now = func() time.Time { return time.Now().Add(time.Hour) }
+	target := filepath.Join(r.dump, "elsewhere")
+	_ = os.WriteFile(target, []byte("x"), 0o644)
+	_ = os.Symlink(target, filepath.Join(r.dump, "vzdump-lxc-9201-2026_10_14-12_00_00.tar.dat"))
+	r.put(t, "vzdump-lxc-9201-2026_10_14-13_00_00.tar.dat", false, boot.Add(-time.Hour)) // positive control
+	r.c.Clean(context.Background(), "local", vmid)
+	if got := r.asked(); len(got) != 1 || got[0] != "vzdump-lxc-9201-2026_10_14-13_00_00.tar.dat" {
+		t.Fatalf("only the positive control may be asked for, got %v", got)
+	}
+}
+
+func TestClean_HelperRefusalIsNotARemoval(t *testing.T) {
+	r := newRig(t, "dir", false, nil)
+	r.runner.err = errors.New("exit status 1")
+	r.put(t, name+".tar.dat", false, boot.Add(-time.Hour))
+	res := r.c.Clean(context.Background(), "local", vmid)
+	if len(res) != 1 || res[0].Removed {
+		t.Fatalf("a refused helper call must not count as removed: %+v", res)
+	}
+}
+
+// The root helper's own tests (configs/test_felhom_vzdump_partial_clean.py) run with the Go suite.
+func TestRootHelperPythonSuite(t *testing.T) {
+	py, err := exec.LookPath("python3")
+	if err != nil {
+		t.Skip("python3 not found")
+	}
+	_, file, _, _ := runtime.Caller(0)
+	script := filepath.Join(filepath.Dir(file), "..", "..", "configs", "test_felhom_vzdump_partial_clean.py")
+	out, err := exec.Command(py, script).CombinedOutput()
+	if err != nil {
+		t.Fatalf("helper suite failed: %v\n%s", err, out)
+	}
+}