v0.145.0 code: the OS wrapper repairs dpkg's update journal by itself after a power cut (R-876); restore-test first check 30 min after start (R-874); neutral "sent late" text (R-875)

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0159rPz1ZhFKsS53msqPYxtS

internal/backup/r874_first_eval_test.go

@@ -0,0 +1,63 @@
+package backup
+
+import (
+	"context"
+	"fmt"
+	"sync/atomic"
+	"testing"
+	"time"
+
+	"gitea.dooplex.hu/admin/felhom-agent/internal/reconcile"
+)
+
+// R-874 (v0.145.0). THE MEASURED SHAPE (Part F spike, Tester 2): power-on sessions of ~1.5 h and ~5 min against a
+// 6 h evaluation ticker that restarts at every start — no restore-test ever evaluated. Now the first evaluation runs
+// FirstEval after start.
+// COMPANION RED-PROOF: drop the first-evaluation timer in Run (back to the bare ticker) → "no evaluation within".
+func TestR874_FirstEvaluationAfterStart(t *testing.T) {
+	var picks int32
+	s := NewScheduler(SchedulerOptions{
+		Runner: &fakeRTRunner{res: reconcile.RestoreTestResult{Pass: true, Verified: "boot+running"}},
+		Pick: func(context.Context) (string, error) {
+			atomic.AddInt32(&picks, 1)
+			return fmt.Sprintf("local:backup/vzdump-lxc-9201-%d.tar.zst", atomic.LoadInt32(&picks)), nil
+		},
+		Store: NewStore(), Spec: (&specSpy{}).build,
+		Cadence: 6 * time.Hour, FirstEval: 30 * time.Millisecond, Logger: quiet(),
+	})
+	ctx, cancel := context.WithCancel(context.Background())
+	done := make(chan struct{})
+	go func() { _ = s.Run(ctx); close(done) }()
+	deadline := time.Now().Add(3 * time.Second)
+	for atomic.LoadInt32(&picks) == 0 && time.Now().Before(deadline) {
+		time.Sleep(10 * time.Millisecond)
+	}
+	cancel()
+	<-done
+	if atomic.LoadInt32(&picks) == 0 {
+		t.Fatal("no evaluation within 3 s of start (FirstEval 30 ms) — a box with short sessions never gets a restore-test")
+	}
+}
+
+// The earned restraint stays: an agent that restarts before FirstEval never evaluates (a crash loop does not
+// hammer a failing tier).
+func TestR874_CrashLoopNeverEvaluates(t *testing.T) {
+	var picks int32
+	for i := 0; i < 5; i++ { // five quick "restarts"
+		s := NewScheduler(SchedulerOptions{
+			Runner: &fakeRTRunner{res: reconcile.RestoreTestResult{Pass: true}},
+			Pick:   func(context.Context) (string, error) { atomic.AddInt32(&picks, 1); return "x", nil },
+			Store:  NewStore(), Spec: (&specSpy{}).build,
+			Cadence: 6 * time.Hour, FirstEval: 200 * time.Millisecond, Logger: quiet(),
+		})
+		ctx, cancel := context.WithTimeout(context.Background(), 20*time.Millisecond)
+		_ = s.Run(ctx)
+		cancel()
+	}
+	if n := atomic.LoadInt32(&picks); n != 0 {
+		t.Fatalf("a restart before FirstEval evaluated %d time(s)", n)
+	}
+	if DefaultFirstEval != 30*time.Minute {
+		t.Fatalf("DefaultFirstEval = %s, the documented 30 min", DefaultFirstEval)
+	}
+}

internal/backup/schedule.go

@@ -60,12 +60,21 @@ type Scheduler struct {
 
 	// R-85 tier rotation. All optional: without them the scheduler behaves exactly as before
 	// (single tier via `pick`), which keeps every existing caller and test working untouched.
-	tiers    []string          // configured tier target ids, primary first
-	tierPick TierPicker        // newest archive on a named tier
-	rtState  *RestoreTestState // persisted last-successful-per-tier (drives oldest-first)
-	inFlight *InFlight         // shared with the backup path — Scenario F
+	tiers     []string          // configured tier target ids, primary first
+	tierPick  TierPicker        // newest archive on a named tier
+	rtState   *RestoreTestState // persisted last-successful-per-tier (drives oldest-first)
+	inFlight  *InFlight         // shared with the backup path — Scenario F
+	firstEval time.Duration     // R-874: the first evaluation after start
 }
 
+// DefaultFirstEval (R-874): the first due-ness evaluation runs 30 minutes after the agent starts, then every
+// cadence. MEASURED need (2026-10-05 Part F spike): a box whose power-on sessions are all shorter than the 6 h
+// interval (Tester 2: ~1.5 h and ~5 min) NEVER evaluated, because the ticker restarts at each start. 30 minutes
+// keeps the earned restraint below — a crash-looping agent restarts far more often than that and still never
+// evaluates — while a box that stays on for half an hour gets its due test. Pinned by
+// TestR874_FirstEvaluationAfterStart and TestR874_CrashLoopNeverEvaluates.
+const DefaultFirstEval = 30 * time.Minute
+
 // SchedulerOptions configures a Scheduler.
 type SchedulerOptions struct {
 	Runner RestoreTestRunner
@@ -81,6 +90,8 @@ type SchedulerOptions struct {
 	// 0 → no settle requirement (any archive is a candidate).
 	Settle time.Duration
 	Logger *slog.Logger
+	// FirstEval (R-874, v0.145.0) is when the FIRST evaluation runs after start; 0 → DefaultFirstEval.
+	FirstEval time.Duration
 
 	// R-85 (all optional — omit for the pre-R-85 single-tier behaviour):
 	// Tiers are the configured tier target ids (primary first); TierPick resolves an archive on a
@@ -110,6 +121,12 @@ func NewScheduler(opts SchedulerOptions) *Scheduler {
 		tierPick: opts.TierPick,
 		rtState:  opts.State,
 		inFlight: opts.InFlight,
+		firstEval: func() time.Duration {
+			if opts.FirstEval > 0 {
+				return opts.FirstEval
+			}
+			return DefaultFirstEval
+		}(),
 	}
 }
 
@@ -120,8 +137,9 @@ func NewScheduler(opts SchedulerOptions) *Scheduler {
 // trigger any more: its phase is the process's uptime, and agent deploys reset it, which is exactly
 // the defect R-86 removes. What decides that a test happens is `EvaluateDue`.
 //
-// It still does NOT evaluate immediately on start — the first evaluation is one interval in. That
-// is an EARNED restraint, kept deliberately: a restore is heavy, agent restarts are routine, and a
+// It still does NOT evaluate immediately on start. v0.145.0 (R-874): the first evaluation is
+// firstEval (30 min) in, then every interval — it was one full interval in, which a box with short
+// power-on sessions never reached. The restraint itself is EARNED and kept: a restore is heavy, agent restarts are routine, and a
 // crash-loop that evaluated at start would hammer a permanently-failing tier as fast as it could
 // restart. Due-ness does not expire while we wait, so the only cost is up to one interval of
 // latency on a tier that just became due. On-demand runs use `--selftest=restore-test`.
@@ -135,6 +153,16 @@ func (s *Scheduler) Run(ctx context.Context) error {
 	}
 	s.logger.Info("backup: restore-test scheduler starting (per-archive due-check)",
 		"eval_interval", s.cadence, "settle", s.settle)
+	first := time.NewTimer(s.firstEval)
+	defer first.Stop()
+	select {
+	case <-ctx.Done():
+		s.logger.Info("backup: restore-test scheduler shutting down", "reason", ctx.Err())
+		return nil
+	case <-first.C:
+		s.logger.Info("backup: restore-test first evaluation after start (R-874)", "after", s.firstEval)
+		s.tick(ctx)
+	}
 	t := time.NewTicker(s.cadence)
 	defer t.Stop()
 	for {

internal/osupdate/unsent.go

@@ -101,7 +101,7 @@ func (l *Leg) sendUnsentLocked(ctx context.Context) int {
 		}
 		rep := l.reportFromKept(ctx, wr, f)
 		lg := l.log().With("run", rep.RunID, "layer", rep.Layer, "vmid", rep.VMID, "ring", rep.Ring, "trigger", rep.Trigger)
-		lg.Info("osupdate: sending a report the agent never sent (the agent stopped mid-pass, R-868)", "path", f)
+		lg.Info("osupdate: sending a kept report late (the agent was stopped mid-pass or the hub was away, R-868)", "path", f)
 		before := rep.unsent
 		_ = l.finish(ctx, lg, rep)
 		if _, err := os.Stat(before); os.IsNotExist(err) {
@@ -130,7 +130,7 @@ func (l *Leg) reportFromKept(ctx context.Context, wr WrapperReport, path string)
 	}
 	rep := Report{RunID: runID, Layer: wr.Layer, Trigger: trigger, Mode: wr.Mode, Ring: ring, ReleaseID: wr.ReleaseID,
 		VMID: wr.VMID, unsent: path}
-	prefix := "sent after the agent stopped mid-pass (R-868)"
+	prefix := "sent late — kept on the box until the hub could take it (R-868, R-875)"
 	switch {
 	case wr.refused():
 		rep.Outcome, rep.Refused, rep.HealthReason = "refused", wr.Refused, prefix

internal/osupdate/unsent_test.go

@@ -6,6 +6,7 @@ import (
 	"errors"
 	"os"
 	"path/filepath"
+	"strings"
 	"testing"
 	"time"
 
@@ -38,6 +39,10 @@ func TestR868_KilledPassIsReportedAtStart(t *testing.T) {
 	if r.Outcome != "applied" || !r.Healthy || r.Trigger != "debug" || r.RunID != kept.RunID || r.Ring != 0 || len(r.Upgraded) != 2 || r.VMID != 9201 {
 		t.Fatalf("report = %+v", r)
 	}
+	// R-875 (v0.145.0): neutral — the copy cannot tell a killed agent from an absent hub.
+	if !strings.HasPrefix(r.HealthReason, "sent late") || strings.Contains(r.HealthReason, "stopped mid-pass") {
+		t.Fatalf("health_reason = %q, want the neutral \"sent late …\"", r.HealthReason)
+	}
 	for _, p := range []string{rp, pp} {
 		if _, err := os.Stat(p); !os.IsNotExist(err) {
 			t.Fatalf("%s still on disk after the hub got it", filepath.Base(p))