From 570410cd1af3959a5611fe40d5cc7561b87c7857 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Wed, 10 Jun 2026 14:54:18 +0200 Subject: [PATCH] slice 8B.2 (agent): emit snapshotted phase at storage-snapshot moment (v0.13.0) BackupRunner.BackupWithSnapshotHook tails the task log for the 'create storage snapshot' marker (snapshot mode only) and fires onSnapshot once; localapi flips /backup/status to 'snapshotted' before 'done' so the controller resumes early. Phase 0 validated on PVE 9.2.2: marker confirmed, downtime ~24s->~1s (934MB). Co-Authored-By: Claude Opus 4.8 --- CHANGELOG.md | 24 +++++++++ cmd/felhom-agent/main.go | 2 +- configs/build-golden.sh | 4 ++ internal/backup/backup_test.go | 6 ++- internal/backup/runner.go | 66 +++++++++++++++++++++-- internal/backup/runner_snapshot_test.go | 72 +++++++++++++++++++++++++ internal/localapi/server.go | 34 +++++++++--- internal/localapi/server_test.go | 58 ++++++++++++++++++-- 8 files changed, 248 insertions(+), 18 deletions(-) create mode 100644 internal/backup/runner_snapshot_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index efbcb10..b094021 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,30 @@ All notable changes to **felhom-agent** are recorded here. Update on every code change that gets pushed. +## v0.13.0 — slice 8B.2: quiesce downtime optimization (`snapshotted` phase) (2026-06-10) + +The agent half of slice 8B.2. In snapshot mode, vzdump only needs the app-stopped state captured at +the **storage-snapshot moment**; after that it reads from the snapshot and the app can resume. The +agent now emits a **`snapshotted`** phase on `GET /backup/status` when the snapshot is taken, so the +controller (v0.38.0) resumes its app early — app downtime drops from *whole-backup* to +*until-snapshot* with no loss of app-consistency. Validated Phase-0 first on PVE 9.2.2: the marker is +`INFO: create storage snapshot 'vzdump'`; downtime ~24s→~1s for a 934 MB guest. + +### Added / changed (`internal/backup` + `internal/localapi`) +- **`BackupRunner.BackupWithSnapshotHook(ctx, vmid, onSnapshot)`** — while the vzdump runs, a watcher + tails the task log (`TaskLogTail`) for the **`create storage snapshot`** marker and fires + `onSnapshot` **once**. The marker only appears in snapshot mode (stop/downgraded takes no storage + snapshot), and the watcher also bails on `backup mode: stop` — so it never fires in stop mode. + (`Backup` keeps its signature for the scheduler/selftest; both share one body.) +- **`/backup/status` phase `snapshotted`** (between `running` and `done`): `handleBackup` passes the + hook → `markSnapshotted` flips the running job to `snapshotted`. `done`/`failed` semantics unchanged. + +### Tests +- localapi: snapshot mode → phase reaches `snapshotted` before `done` (gated fake holds the backup + open); stop mode → `snapshotted` **never** emitted (stays running → done). runner: the watcher + fires `onSnapshot` on the marker; in stop-mode log it never fires. `snapshotWatchInterval` is a + package var so tests run fast. + ## v0.12.0 — slice 8C Phase A: disk endpoints + data-bearing classifier gate + mkfs executor (2026-06-10) The agent half of slice 8C, Phase A (additive). Adds the host disk-management endpoints the diff --git a/cmd/felhom-agent/main.go b/cmd/felhom-agent/main.go index e3661ef..9a60369 100644 --- a/cmd/felhom-agent/main.go +++ b/cmd/felhom-agent/main.go @@ -40,7 +40,7 @@ import ( // version is the agent version. Overridable at build time with // -ldflags "-X main.version="; defaults to the in-repo CHANGELOG version. -var version = "0.12.0" +var version = "0.13.0" func main() { var ( diff --git a/configs/build-golden.sh b/configs/build-golden.sh index be85bad..d9e4a49 100644 --- a/configs/build-golden.sh +++ b/configs/build-golden.sh @@ -87,6 +87,10 @@ IMAGE=$(cat /etc/felhom-controller-image 2>/dev/null || true) [ -n "$IMAGE" ] || { echo "[ctrl-bootstrap] FATAL: /etc/felhom-controller-image missing"; exit 1; } echo "[ctrl-bootstrap] deploying $IMAGE from $CFG" docker rm -f felhom-controller >/dev/null 2>&1 || true +# slice 8C: the controller is DE-PRIVILEGED — disk execution (scan/format/mount/migrate) is the +# host agent's job now, so this run grants NO disk privileges: no --privileged, no /dev, no +# /etc/fstab, no rshared /mnt. Only the bootstrap config (ro), the data volume, and the docker +# socket (app/stack management). The controller reaches the agent's local API for disk management. docker run -d --name felhom-controller --restart unless-stopped \ -e FELHOM_BOOTSTRAP_PATH=/etc/felhom-bootstrap/bootstrap.json \ -v /etc/felhom-bootstrap:/etc/felhom-bootstrap:ro \ diff --git a/internal/backup/backup_test.go b/internal/backup/backup_test.go index dc81100..9924e50 100644 --- a/internal/backup/backup_test.go +++ b/internal/backup/backup_test.go @@ -25,7 +25,8 @@ type fakeBackupAPI struct { content []proxmox.StorageContent contentErr error vzdumps []proxmox.VzdumpOptions - logLines []string // returned by TaskLogTail (e.g. "INFO: backup mode: stop") + logLines []string // returned by TaskLogTail (e.g. "INFO: backup mode: stop") + waitGate chan struct{} // if non-nil, WaitTask blocks until closed (8B.2 watcher timing) } func (f *fakeBackupAPI) Vzdump(_ context.Context, o proxmox.VzdumpOptions) (string, error) { @@ -33,6 +34,9 @@ func (f *fakeBackupAPI) Vzdump(_ context.Context, o proxmox.VzdumpOptions) (stri return f.vzdumpUPID, f.vzdumpErr } func (f *fakeBackupAPI) WaitTask(_ context.Context, _ string, _ proxmox.WaitOptions) (proxmox.TaskStatus, error) { + if f.waitGate != nil { + <-f.waitGate + } return proxmox.TaskStatus{Status: "stopped", ExitStatus: "OK"}, f.waitErr } func (f *fakeBackupAPI) GuestConfig(_ context.Context, _ int) (proxmox.GuestConfig, error) { diff --git a/internal/backup/runner.go b/internal/backup/runner.go index b4dfe55..0c64a4f 100644 --- a/internal/backup/runner.go +++ b/internal/backup/runner.go @@ -48,10 +48,33 @@ func NewBackupRunner(api BackupAPI, target string, mode proxmox.BackupMode, note return &BackupRunner{api: api, target: target, mode: mode, notes: notes, logger: logger, now: func() time.Time { return time.Now().UTC() }} } -// Backup runs one vzdump of vmid to the local target and returns the report record. A -// failure is returned BOTH as an error and as a Backup{Success:false,...} so the caller can -// record the failed attempt. +// snapshotMarker is the vzdump task-log line that signals the storage snapshot has been created +// and the backup is now reading from it — the point after which resuming the guest's app cannot +// affect the backup (slice 8B.2; validated on PVE 9.2.2: `INFO: create storage snapshot 'vzdump'`). +// It only appears in snapshot mode (stop mode takes no storage snapshot), so its presence ⟹ +// snapshot mode — the basis for the controller's early resume. +const snapshotMarker = "create storage snapshot" + +// snapshotWatchInterval is how often watchForSnapshot polls the task log. A package var so tests +// can shrink it (production: poll once a second — the marker appears in the first ~1s, §0). +var snapshotWatchInterval = time.Second + +// Backup runs one vzdump of vmid to the local target and returns the report record. func (r *BackupRunner) Backup(ctx context.Context, vmid int) (hub.Backup, error) { + return r.backup(ctx, vmid, nil) +} + +// BackupWithSnapshotHook is Backup plus an onSnapshot callback invoked ONCE, mid-backup, when the +// storage snapshot has been taken (snapshot mode only) — the 8B.2 early-resume signal. In +// stop/downgraded mode the marker never appears, so onSnapshot is never called (the caller then +// resumes at completion). onSnapshot must be cheap + non-blocking (it runs on a watcher goroutine). +func (r *BackupRunner) BackupWithSnapshotHook(ctx context.Context, vmid int, onSnapshot func()) (hub.Backup, error) { + return r.backup(ctx, vmid, onSnapshot) +} + +// backup is the shared body. A failure is returned BOTH as an error and as a +// Backup{Success:false,...} so the caller can record the failed attempt. +func (r *BackupRunner) backup(ctx context.Context, vmid int, onSnapshot func()) (hub.Backup, error) { start := r.now() rec := hub.Backup{ TargetID: r.target, @@ -83,6 +106,13 @@ func (r *BackupRunner) Backup(ctx context.Context, vmid int) (hub.Backup, error) return rec, fmt.Errorf("backup: vzdump vmid %d: %w", vmid, err) } if upid != "" { + // 8B.2: while the backup runs, watch the task log for the storage-snapshot marker and + // fire onSnapshot once (snapshot mode only) so the controller can resume its app early. + if onSnapshot != nil { + watchCtx, stopWatch := context.WithCancel(ctx) + defer stopWatch() + go r.watchForSnapshot(watchCtx, upid, onSnapshot) + } if _, err := r.api.WaitTask(ctx, upid, proxmox.WaitOptions{Timeout: 30 * time.Minute}); err != nil { rec.Error = err.Error() rec.DurationSeconds = time.Since(start).Seconds() @@ -113,6 +143,36 @@ func (r *BackupRunner) Backup(ctx context.Context, vmid int) (hub.Backup, error) return rec, nil } +// watchForSnapshot polls the running backup's task log until it sees the storage-snapshot marker +// (→ onSnapshot once) or the requested mode is reported as `stop` (→ downgraded; the marker will +// never come, so stop watching) or ctx is cancelled (backup finished). Best-effort: a log-read +// error is retried on the next tick; onSnapshot fires at most once. +func (r *BackupRunner) watchForSnapshot(ctx context.Context, upid string, onSnapshot func()) { + ticker := time.NewTicker(snapshotWatchInterval) + defer ticker.Stop() + for { + select { + case <-ctx.Done(): + return + case <-ticker.C: + lines, err := r.api.TaskLogTail(ctx, upid, 200) + if err != nil { + continue + } + // A stop-mode (or downgraded) backup never creates a storage snapshot → never resume early. + if m := parseBackupMode(lines); m != "" && m != string(proxmox.ModeSnapshot) { + return + } + for _, ln := range lines { + if strings.Contains(ln, snapshotMarker) { + onSnapshot() + return + } + } + } + } +} + // PickRestoreCandidate returns the newest backup archive on the target (any guest), or "" // when there is none — the restore-test then no-ops cleanly. func (r *BackupRunner) PickRestoreCandidate(ctx context.Context) (string, error) { diff --git a/internal/backup/runner_snapshot_test.go b/internal/backup/runner_snapshot_test.go new file mode 100644 index 0000000..fd15bd3 --- /dev/null +++ b/internal/backup/runner_snapshot_test.go @@ -0,0 +1,72 @@ +package backup + +import ( + "context" + "sync/atomic" + "testing" + "time" + + "gitea.dooplex.hu/admin/felhom-agent/internal/proxmox" +) + +// 8B.2: in snapshot mode, the runner fires onSnapshot when the storage-snapshot marker appears in +// the task log — mid-backup, before completion. +func TestBackupWithSnapshotHook_FiresOnMarker(t *testing.T) { + old := snapshotWatchInterval + snapshotWatchInterval = 2 * time.Millisecond + defer func() { snapshotWatchInterval = old }() + + api := &fakeBackupAPI{ + vzdumpUPID: "UPID:backup", + waitGate: make(chan struct{}), // hold the backup open so the watcher gets to poll + logLines: []string{"INFO: backup mode: snapshot", "INFO: create storage snapshot 'vzdump'"}, + content: []proxmox.StorageContent{{VolID: "local:backup/vzdump-lxc-9001-x", Content: "backup", VMID: 9001, Size: 100, CTime: 1}}, + } + r := NewBackupRunner(api, "local", "", "", quiet()) + + var fired int32 + done := make(chan struct{}) + go func() { + _, _ = r.BackupWithSnapshotHook(context.Background(), 9001, func() { atomic.StoreInt32(&fired, 1) }) + close(done) + }() + + // the watcher should fire onSnapshot well before we release the backup + deadline := time.Now().Add(time.Second) + for time.Now().Before(deadline) && atomic.LoadInt32(&fired) == 0 { + time.Sleep(2 * time.Millisecond) + } + if atomic.LoadInt32(&fired) != 1 { + t.Fatal("onSnapshot did not fire on the storage-snapshot marker") + } + close(api.waitGate) // let the backup complete + <-done +} + +// Stop/downgraded mode → no storage-snapshot marker → onSnapshot never fires (the 8B.2 fallback). +func TestBackupWithSnapshotHook_StopMode_NeverFires(t *testing.T) { + old := snapshotWatchInterval + snapshotWatchInterval = 2 * time.Millisecond + defer func() { snapshotWatchInterval = old }() + + api := &fakeBackupAPI{ + vzdumpUPID: "UPID:backup", + waitGate: make(chan struct{}), + logLines: []string{"INFO: backup mode: stop"}, // downgraded; no snapshot marker + content: []proxmox.StorageContent{{VolID: "local:backup/vzdump-lxc-9001-x", Content: "backup", VMID: 9001, Size: 100, CTime: 1}}, + } + r := NewBackupRunner(api, "local", "", "", quiet()) + + var fired int32 + done := make(chan struct{}) + go func() { + _, _ = r.BackupWithSnapshotHook(context.Background(), 9001, func() { atomic.StoreInt32(&fired, 1) }) + close(done) + }() + time.Sleep(40 * time.Millisecond) // the watcher polls several times + sees stop mode → returns + if atomic.LoadInt32(&fired) != 0 { + t.Fatal("onSnapshot fired in stop mode (must not)") + } + close(api.waitGate) + <-done +} diff --git a/internal/localapi/server.go b/internal/localapi/server.go index 6d1ca20..02742cf 100644 --- a/internal/localapi/server.go +++ b/internal/localapi/server.go @@ -28,10 +28,12 @@ type GuestAPI interface { WaitTask(ctx context.Context, upid string, opts proxmox.WaitOptions) (proxmox.TaskStatus, error) } -// BackupService enqueues a (crash-consistent) vzdump/PBS backup of a guest. Satisfied by -// *backup.BackupRunner. The app-consistent quiesce path is 8B. +// BackupService enqueues a vzdump/PBS backup of a guest. Satisfied by *backup.BackupRunner. +// BackupWithSnapshotHook (8B.2) invokes onSnapshot once mid-backup when the storage snapshot is +// taken (snapshot mode only) so the controller can resume its app early; in stop mode it is never +// called. type BackupService interface { - Backup(ctx context.Context, vmid int) (hub.Backup, error) + BackupWithSnapshotHook(ctx context.Context, vmid int, onSnapshot func()) (hub.Backup, error) } // BackupStore records + reads the latest backup/restore-test state. Satisfied by *backup.Store. @@ -80,10 +82,11 @@ const defaultBackupCadence = 24 * time.Hour // Backup phase vocabulary reported by GET /backup/status (slice 8B). The 8B.2 fast-follow adds a // `snapshotted` phase (vzdump --mode snapshot) so the controller can unquiesce at snapshot-taken. const ( - PhaseIdle = "idle" - PhaseRunning = "running" - PhaseDone = "done" - PhaseFailed = "failed" + PhaseIdle = "idle" + PhaseRunning = "running" + PhaseSnapshotted = "snapshotted" // 8B.2: storage snapshot taken — app may resume; backup continues + PhaseDone = "done" + PhaseFailed = "failed" ) // backupJob is the in-flight/last backup job for one guest (drives /backup/status phases). @@ -413,7 +416,9 @@ func (s *Server) handleBackup(w http.ResponseWriter, r *http.Request, vmid int) go func() { bctx, cancel := context.WithTimeout(base, 2*time.Hour) defer cancel() - b, err := s.backups.Backup(bctx, vmid) + // 8B.2: flip the job to `snapshotted` when the storage snapshot is taken, so the + // controller resumes its app early (snapshot mode only; in stop mode this never fires). + b, err := s.backups.BackupWithSnapshotHook(bctx, vmid, func() { s.markSnapshotted(vmid, jobID) }) if err != nil { b.VMID = vmid b.Success = false @@ -430,6 +435,19 @@ func (s *Server) handleBackup(w http.ResponseWriter, r *http.Request, vmid int) writeStatus(w, http.StatusAccepted, true, BackupResponse{VMID: vmid, JobID: jobID, Phase: PhaseRunning}, "") } +// markSnapshotted flips the guest's running job to the `snapshotted` phase (8B.2) — only if it is +// still the current job and still running (don't regress done/failed, and don't touch a newer job). +func (s *Server) markSnapshotted(vmid int, jobID string) { + s.jobsMu.Lock() + defer s.jobsMu.Unlock() + cur := s.jobs[vmid] + if cur == nil || cur.JobID != jobID || cur.Phase != PhaseRunning { + return + } + cur.Phase = PhaseSnapshotted + s.logger.Info("local-api: backup reached snapshotted (app may resume)", "vmid", vmid, "job", jobID) +} + // finishJob transitions the guest's job to done/failed (only if it is still the current job — a // later job started after a single-flight gap must not be overwritten by an older one's result). func (s *Server) finishJob(vmid int, jobID string, b hub.Backup) { diff --git a/internal/localapi/server_test.go b/internal/localapi/server_test.go index eaaef54..be2fa65 100644 --- a/internal/localapi/server_test.go +++ b/internal/localapi/server_test.go @@ -64,18 +64,23 @@ func (f *fakeGuests) WaitTask(_ context.Context, _ string, _ proxmox.WaitOptions } type fakeBackups struct { - mu sync.Mutex - vmids []int - gate chan struct{} // if non-nil, Backup blocks until it is closed (observe the running phase) - failErr string // if set, Backup returns this error (drives the failed phase) + mu sync.Mutex + vmids []int + gate chan struct{} // if non-nil, the backup blocks until it is closed (observe phases) + failErr string // if set, the backup returns this error (drives the failed phase) + fireSnapshot bool // if true, invoke onSnapshot (simulates snapshot-mode detection, 8B.2) } -func (f *fakeBackups) Backup(_ context.Context, vmid int) (hub.Backup, error) { +func (f *fakeBackups) BackupWithSnapshotHook(_ context.Context, vmid int, onSnapshot func()) (hub.Backup, error) { f.mu.Lock() f.vmids = append(f.vmids, vmid) gate := f.gate failErr := f.failErr + fire := f.fireSnapshot f.mu.Unlock() + if fire && onSnapshot != nil { + onSnapshot() // snapshot taken (mid-backup) → phase snapshotted + } if gate != nil { <-gate } @@ -446,6 +451,49 @@ func statusPhase(t *testing.T, h http.Handler) string { return resp.Data.Phase } +func waitPhase(t *testing.T, h http.Handler, want string) { + t.Helper() + deadline := time.Now().Add(time.Second) + for time.Now().Before(deadline) { + if statusPhase(t, h) == want { + return + } + time.Sleep(5 * time.Millisecond) + } + t.Fatalf("phase never reached %q (last=%q)", want, statusPhase(t, h)) +} + +// 8B.2: snapshot mode → the job flips to `snapshotted` mid-backup (before done), so the controller +// can resume its app early. The gated fake holds the backup open after firing onSnapshot. +func TestBackupStatus_Snapshotted_8B2(t *testing.T) { + b := &fakeBackups{gate: make(chan struct{}), fireSnapshot: true} + srv := newTestServerS(t, &fakeGuests{}, b, &fakeStore{}, nil) + h := srv.Handler() + + if do(t, h, "POST", "/backup", "A", "").Code != http.StatusAccepted { + t.Fatal("POST /backup not accepted") + } + waitPhase(t, h, PhaseSnapshotted) // onSnapshot fired → snapshotted, while the backup is still open + close(b.gate) // let the backup complete + waitPhase(t, h, PhaseDone) // and it still proceeds to done +} + +// 8B.2 fallback: stop/downgraded mode → onSnapshot never fires → phase never becomes `snapshotted` +// (the controller then resumes at done, exactly 8B). +func TestBackup_StopMode_NeverSnapshotted_8B2(t *testing.T) { + b := &fakeBackups{gate: make(chan struct{}), fireSnapshot: false} + srv := newTestServerS(t, &fakeGuests{}, b, &fakeStore{}, nil) + h := srv.Handler() + + do(t, h, "POST", "/backup", "A", "") + time.Sleep(40 * time.Millisecond) // give the goroutine time; it must NOT snapshot + if ph := statusPhase(t, h); ph != PhaseRunning { + t.Fatalf("stop mode: phase %q, want running (snapshotted must not be emitted)", ph) + } + close(b.gate) + waitPhase(t, h, PhaseDone) +} + func TestBackupStatus_FiltersToThisGuest(t *testing.T) { st := &fakeStore{backups: []hub.Backup{ {VMID: 9300, Success: true, StartedAt: "2026-06-10T10:00:00Z", Archive: "other"},