v0.289.1: strip the provider rclone notice; an unreadable snapshot count is never a measured zero (found live on demo-felhom)

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

CHANGELOG.md

@@ -1,3 +1,17 @@
+## v0.289.1 — the provider's rclone notice no longer reads as "0 snapshots" (found live on demo-felhom) (2026-10-03)
+
+**MinAgent: 0.131.0** (unchanged). Needs hub v0.127.0 (unchanged).
+
+- **Found live in the first run through the pinned key:** the provider's rclone prints
+  `NOTICE: Config file … not found - using defaults` on every connection, restic forwards it into the combined output,
+  every `--json` parse failed, and the box recorded **0 snapshots as MEASURED** (`stats_known`) over a store holding 12 —
+  the shape the hub's R-431 detector reads as a mass deletion — and the clean-up step could not list snapshots.
+  `Manager.runner()` now strips exactly that notice line (`stripRcloneNotice`; an rclone ERROR line stays).
+- **An unreadable snapshot count is no longer a measured zero (R-331 class):** `offboxRecordStats` returns
+  `(count, ok)`; on a failed or unparseable listing the box keeps the last measured count and reports `stats_known=false`.
+- Tests: `TestStripRcloneNotice`, `TestRunOffbox_UnreadableCountIsNotZero` (red-proved). **Second release this session,
+  against the one-release rule, because v0.289.0 was live on a box and reporting a false zero.**
+
 ## v0.289.0 — the off-site key cannot delete: append-only transport, no password on the box, retention only inside a hub window (decisions 68–69, R-820, R-822) (2026-10-03)
 
 **MinAgent: 0.131.0** (unchanged). **Needs hub v0.127.0** (the key registrar and the window endpoints; an older hub

controller/internal/backup/offbox.go

@@ -1,6 +1,7 @@
 package backup
 
 import (
+	"bytes"
 	"context"
 	"crypto/rand"
 	"crypto/sha256"
@@ -425,10 +426,32 @@ func (m *Manager) offboxSize() func(string) int64 {
 }
 
 func (m *Manager) runner() offboxRunner {
+	r := defaultOffboxRunner
 	if m.offboxRunner != nil {
-		return m.offboxRunner
+		r = m.offboxRunner
 	}
-	return defaultOffboxRunner
+	return func(ctx context.Context, env []string, args ...string) ([]byte, error) {
+		out, err := r(ctx, env, args...)
+		return stripRcloneNotice(out), err
+	}
+}
+
+// rcloneNoticeRe is the ONE line the provider's rclone prints on every connection of the pinned
+// transport (v0.289.0) — restic forwards it with an "rclone: " prefix into the combined output:
+//
+//	rclone: 2026/10/03 15:05:42 NOTICE: Config file "/home/.config/rclone/rclone.conf" not found - using defaults
+//
+// MEASURED LIVE on demo-felhom 2026-10-03: left in, every `--json` parse failed ("invalid character
+// 'r'"), so the box recorded 0 snapshots AS MEASURED (StatsKnown) over a store holding 12 — the exact
+// shape R-431's detector reads as a mass deletion. Only this exact notice is removed; any other rclone
+// line (an error) stays in the output. Pinned by TestStripRcloneNotice.
+var rcloneNoticeRe = regexp.MustCompile(`(?m)^rclone: \d{4}/\d\d/\d\d \d\d:\d\d:\d\d NOTICE: Config file "[^"]*rclone\.conf" not found - using defaults\r?\n?`)
+
+func stripRcloneNotice(out []byte) []byte {
+	if len(out) == 0 || !bytes.Contains(out, []byte("rclone: ")) {
+		return out
+	}
+	return rcloneNoticeRe.ReplaceAll(out, nil)
 }
 
 func (m *Manager) offboxDir() string        { return filepath.Join(m.cfg.Paths.DataDir, "offbox") }
@@ -1034,9 +1057,9 @@ func (m *Manager) runOffboxBackup(ctx context.Context, withProgress bool) error
 	}
 
 	dur := time.Since(start)
-	snapshots := 0
+	snapshots, countKnown := 0, false
 	if runErr == nil {
-		snapshots = m.offboxRecordStats(ctx, base, env)
+		snapshots, countKnown = m.offboxRecordStats(ctx, base, env)
 	}
 	// THE LANGUAGE IS RESOLVED HERE, OUTSIDE THE CALLBACK, AND IT IS NOT A STYLE CHOICE.
 	//
@@ -1114,8 +1137,15 @@ func (m *Manager) runOffboxBackup(ctx context.Context, withProgress bool) error
 				o.LastStatus = "ok"
 			}
 			o.LastError = ""
+			if countKnown {
 				o.SnapshotCount = snapshots
 				o.StatsKnown = true // R-225: measured, even if the answer is zero
+			} else {
+				// v0.289.0: the listing FAILED — that is not a measurement of zero (R-331). Keep the
+				// last measured count and say it is not known now; a reported 0 here reads as a mass
+				// deletion to the hub (R-431). Pinned by TestRunOffbox_UnreadableCountIsNotZero.
+				o.StatsKnown = false
+			}
 			o.EnlargedBlocked = blockedNames // replace each run (sorted); empty slice clears it
 			var warns []string
 			warnKind := ""
@@ -1832,18 +1862,20 @@ func (m *Manager) offboxPruneOnly(ctx context.Context, base, env []string) {
 }
 
 // offboxRecordStats reads the snapshot count (best-effort) for the UI; also fills repo size when stats works.
-func (m *Manager) offboxRecordStats(ctx context.Context, base, env []string) int {
+func (m *Manager) offboxRecordStats(ctx context.Context, base, env []string) (int, bool) {
 	sctx, cancel := context.WithTimeout(ctx, offboxProbeTimeout)
 	defer cancel()
 	out, err := m.runner()(sctx, env, append(append([]string{}, base...), "snapshots", "--json")...)
 	if err != nil {
-		return 0
+		m.logger.Printf("[WARN] [offbox] snapshot count unreadable (kept the last measured value): %v", err)
+		return 0, false
 	}
 	var snaps []struct {
 		ID string `json:"id"`
 	}
-	if json.Unmarshal(out, &snaps) != nil {
-		return 0
+	if jerr := json.Unmarshal(out, &snaps); jerr != nil {
+		m.logger.Printf("[WARN] [offbox] snapshot count unparseable (kept the last measured value): %v", jerr)
+		return 0, false
 	}
 	// Repo size (best-effort, RAW-DATA mode). SP-1: `--mode raw-data` reports the actual
 	// deduplicated+compressed repo bytes (what the Storage Box really fills), not the modeless
@@ -1863,7 +1895,7 @@ func (m *Manager) offboxRecordStats(ctx context.Context, base, env []string) int
 			})
 		}
 	}
-	return len(snaps)
+	return len(snaps), true
 }
 
 // RestoreOffbox restores an app's latest off-box snapshot to destDir (a scratch/verify location — it does

controller/internal/backup/offbox_3a_test.go

@@ -367,7 +367,7 @@ func TestOffbox3a_StatsRawDataMode(t *testing.T) {
 		return nil, nil
 	})
 	base, env := m.offboxBaseArgs(sett.GetOffboxTarget())
-	m.offboxRecordStats(context.Background(), base, env)
+	_, _ = m.offboxRecordStats(context.Background(), base, env)
 	if !contains(statsArgs, "--mode") || valAfter(statsArgs, "--mode") != "raw-data" {
 		t.Fatalf("stats must run in raw-data mode, got %v", statsArgs)
 	}

controller/internal/backup/offbox_window_test.go

@@ -235,3 +235,34 @@ func TestAbandon_PinnedDefersToOperator(t *testing.T) {
 		t.Fatal("second sweep deleted")
 	}
 }
+
+// The provider's rclone notice must not reach a JSON parser — measured live on demo-felhom (v0.289.0).
+func TestStripRcloneNotice(t *testing.T) {
+	in := "rclone: 2026/10/03 15:05:42 NOTICE: Config file \"/home/.config/rclone/rclone.conf\" not found - using defaults\n[{\"id\":\"s1\"}]\n"
+	if got := string(stripRcloneNotice([]byte(in))); got != "[{\"id\":\"s1\"}]\n" {
+		t.Fatalf("got %q", got)
+	}
+	keep := "rclone: 2026/10/03 15:05:42 ERROR : something real\n"
+	if got := string(stripRcloneNotice([]byte(keep))); got != keep {
+		t.Fatalf("an rclone ERROR line was stripped: %q", got)
+	}
+}
+
+// THE CONSEQUENCE (R-331/R-431): a run whose snapshot listing cannot be read must NOT record 0 as a
+// measurement. Before the fix the box reported 0 snapshots with stats_known over a store holding 12.
+func TestRunOffbox_UnreadableCountIsNotZero(t *testing.T) {
+	m, sett := newOffboxManager(t)
+	sett.UpdateOffboxStatus(func(o *settings.OffboxTarget) { o.SnapshotCount, o.StatsKnown = 11, true })
+	m.SetOffboxRunner(func(ctx context.Context, env []string, args ...string) ([]byte, error) {
+		if contains(args, "snapshots") {
+			return []byte("rclone: 2026/10/03 15:05:42 ERROR : boom\nnot json"), nil
+		}
+		rr := &recordingOffboxRunner{}
+		return rr.run(ctx, env, args...)
+	})
+	_ = m.RunOffboxBackup(context.Background())
+	got := sett.GetOffboxTarget()
+	if got.StatsKnown && got.SnapshotCount == 0 {
+		t.Fatalf("an unreadable count was recorded as a measured zero: %+v", got.SnapshotCount)
+	}
+}