From 77e8d5590b718f1d7814525fbec31c8a331d54f1 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Sun, 19 Jul 2026 09:44:21 +0200 Subject: [PATCH] =?UTF-8?q?v0.147.1=20=E2=80=94=204c=20follow-up:=20the=20?= =?UTF-8?q?bar=20must=20move=20on=20an=20INCREMENTAL=20run?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Found by watching the v0.147.0 card during a real manual run on the demo box, which is the only way this was going to surface: a 430MB immich push reported 0% for 40+ seconds and then completed. The parser was not broken. restic was genuinely reporting no transferred bytes — on an incremental run where nothing changed, bytes_done is omitempty on restic's side so it is not even in the JSON, and percent_done stays 0 for the whole run. Confirmed against the real schema by capturing backup --dry-run --json from restic 0.14.0 in the controller image rather than guessing; those captured lines are now quoted verbatim in the type's doc comment. Why it mattered: a byte-only bar is indistinguishable from a hang in the COMMON case, which is precisely the silence 4c set out to remove. Shipping it would have traded "no feedback" for "feedback that says 0% and looks stuck". files_done/total_files are now parsed and published alongside the bytes; the card prefers bytes when bytes move, otherwise drives the bar from files and says "N / M fájl ellenőrizve". parseResticStatus returns a struct instead of four positional values, and a new test pins the real incremental line shape (bytes absent, files climbing) so a refactor cannot quietly restore the stuck bar. Co-Authored-By: Claude Opus 4.8 (1M context) Claude-Session: https://claude.ai/code/session_01Nn3VgQk9iwEGgyx6QJ2NvE --- CHANGELOG.md | 26 ++++++++ controller/internal/backup/offbox_progress.go | 61 +++++++++++++++---- .../internal/backup/offbox_progress_test.go | 56 ++++++++++++++--- .../web/templates/backups_remote.html | 13 +++- 4 files changed, 132 insertions(+), 24 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4f710d1..d1ae981 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,31 @@ ## Changelog +### v0.147.1 — 4c follow-up: the progress bar must move on an INCREMENTAL run (2026-07-19) + +Found by watching the v0.147.0 card during a real manual run on the demo box, which is the only way +this was ever going to surface. + +**The observation.** A 430MB immich push reported `0%` for 40+ seconds and then completed. The +parser was not broken — restic was genuinely reporting no transferred bytes. On an incremental run +where nothing changed, restic transfers nothing: `bytes_done` is `omitempty` on restic's side, so it +is not even present in the JSON, and `percent_done` stays 0 for the whole run. Confirmed against the +real schema by capturing `backup --dry-run --json` output from restic 0.14.0 in the controller image +(the version comment in `offbox_progress.go` now quotes those captured lines verbatim). + +**Why it mattered.** A byte-only progress bar is indistinguishable from a hang in the COMMON case — +the incremental run — which is precisely the silence 4c set out to remove. Shipping it would have +replaced "no feedback" with "feedback that says 0% and looks stuck". + +- `files_done` / `total_files` are now parsed and published alongside the byte counters. They move on + an incremental run even when bytes do not. +- The card prefers bytes when bytes are moving; otherwise it drives the bar from files and says + „N / M fájl ellenőrizve"; only before restic knows a total does it say „a mentendő adatok + felmérése…". +- `parseResticStatus` now returns a struct rather than four positional values, and a new test pins + the real incremental-run line shape (bytes absent, files climbing) so a future refactor cannot + quietly drop the file counters and restore the stuck bar. + + ### v0.147.0 — feedback slice 1: pressing a button says something (2026-07-19) Green: `go build ./... && go vet ./... && go test ./...` all pass (23 packages); diff --git a/controller/internal/backup/offbox_progress.go b/controller/internal/backup/offbox_progress.go index 983d3c1..05433e2 100644 --- a/controller/internal/backup/offbox_progress.go +++ b/controller/internal/backup/offbox_progress.go @@ -31,45 +31,78 @@ import ( type OffboxProgress struct { Active bool `json:"active"` CurrentApp string `json:"current_app"` - Percent float64 `json:"percent"` // 0..100 + 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"` } // 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. +// 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"` } -// parseResticStatus parses ONE line of restic --json output into a progress delta. +// resticProgress is one parsed status line. +type resticProgress struct { + Percent float64 // 0..100 + BytesDone int64 + TotalBytes int64 + FilesDone int64 + TotalFiles 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) (pct float64, done, total int64, ok bool) { +func parseResticStatus(line string) (resticProgress, bool) { var s resticStatusLine if err := json.Unmarshal([]byte(line), &s); err != nil { - return 0, 0, 0, false + return resticProgress{}, false } if s.MessageType != "status" { - return 0, 0, 0, false + return resticProgress{}, false } - pct = s.PercentDone * 100 + 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 } - return pct, s.BytesDone, s.TotalBytes, true + return resticProgress{ + Percent: pct, BytesDone: s.BytesDone, TotalBytes: s.TotalBytes, + FilesDone: s.FilesDone, TotalFiles: s.TotalFiles, + }, true } // offboxProgressState is the published snapshot, guarded independently of the Manager mutex so a @@ -101,16 +134,18 @@ func (p *offboxProgressState) setApp(app string) { // the previous app's 100% into the next app's start would show a bar that jumps backwards. p.cur.CurrentApp = app p.cur.Percent, p.cur.BytesDone, p.cur.TotalBytes = 0, 0, 0 + p.cur.FilesDone, p.cur.TotalFiles = 0, 0 p.cur.DoneHuman, p.cur.TotalHuman = "", "" } p.mu.Unlock() } -func (p *offboxProgressState) update(pct float64, done, total int64) { +func (p *offboxProgressState) update(r resticProgress) { p.mu.Lock() if p.live { - p.cur.Percent, p.cur.BytesDone, p.cur.TotalBytes = pct, done, total - p.cur.DoneHuman, p.cur.TotalHuman = humanizeBytes(done), humanizeBytes(total) + 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.DoneHuman, p.cur.TotalHuman = humanizeBytes(r.BytesDone), humanizeBytes(r.TotalBytes) } p.mu.Unlock() } @@ -233,8 +268,8 @@ func (m *Manager) resticBackupStep(ctx context.Context, env, base []string, labe // 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 pct, done, total, ok := parseResticStatus(line); ok { - m.offboxProgress.update(pct, done, total) + if r, ok := parseResticStatus(line); ok { + m.offboxProgress.update(r) } }, full...) if err == nil || !offboxLockRe.Match(out) { diff --git a/controller/internal/backup/offbox_progress_test.go b/controller/internal/backup/offbox_progress_test.go index a9d0528..0c80b3b 100644 --- a/controller/internal/backup/offbox_progress_test.go +++ b/controller/internal/backup/offbox_progress_test.go @@ -181,29 +181,65 @@ func TestParseResticStatusIgnoresNonStatus(t *testing.T) { ``, `{}`, } { - if _, _, _, ok := parseResticStatus(line); ok { + if _, ok := parseResticStatus(line); ok { t.Errorf("parsed a non-status line as progress: %q", line) } } - pct, done, total, ok := parseResticStatus(jsonStatus(0.42, 4200, 10000)) + r, ok := parseResticStatus(jsonStatus(0.42, 4200, 10000)) if !ok { t.Fatal("a real status line was not parsed") } - if pct != 42 || done != 4200 || total != 10000 { - t.Errorf("got %v %d %d, want 42 4200 10000", pct, done, total) + if r.Percent != 42 || r.BytesDone != 4200 || r.TotalBytes != 10000 { + t.Errorf("got %v %d %d, want 42 4200 10000", r.Percent, r.BytesDone, r.TotalBytes) + } +} + +// TestParseResticStatusIncrementalRun is the case that MATTERS and the one a synthetic test suite +// would never think to write. It is a real status line shape from restic 0.14 on the demo box: +// an incremental push where nothing changed transfers no new bytes, so restic omits bytes_done +// entirely (`omitempty`) and percent_done stays 0 — while files_done climbs steadily. +// +// Measured live: a 430MB immich push reported 0% for 40+ seconds and then completed. A byte-only +// progress bar is therefore indistinguishable from a hang in the COMMON case, which is the exact +// failure 4c exists to remove. The file counters must survive parsing so the page can fall back to +// them. +func TestParseResticStatusIncrementalRun(t *testing.T) { + // bytes_done and files_done absent — restic's scan-start state. + r, ok := parseResticStatus(`{"message_type":"status","percent_done":0,"total_files":1,"total_bytes":112}`) + if !ok { + t.Fatal("scan-start status line was not parsed") + } + if r.BytesDone != 0 || r.TotalBytes != 112 || r.TotalFiles != 1 { + t.Errorf("scan-start: got %+v", r) + } + + // The incremental steady state: no bytes moving, files moving. + r, ok = parseResticStatus(`{"message_type":"status","percent_done":0,"total_files":8123,"files_done":4110,"total_bytes":451130451}`) + if !ok { + t.Fatal("incremental status line was not parsed") + } + if r.BytesDone != 0 { + t.Errorf("bytes_done = %d, want 0 (absent in the JSON)", r.BytesDone) + } + if r.FilesDone != 4110 || r.TotalFiles != 8123 { + t.Errorf("file counters lost: got %d/%d, want 4110/8123 — the page has nothing left to move", + r.FilesDone, r.TotalFiles) + } + if r.TotalBytes != 451130451 { + t.Errorf("total_bytes = %d, want 451130451", r.TotalBytes) } } // TestParseResticStatusClampsPercent — restic has been seen to report percent_done slightly above 1 // near completion. A bar wider than its track is a visible bug. func TestParseResticStatusClampsPercent(t *testing.T) { - pct, _, _, ok := parseResticStatus(`{"message_type":"status","percent_done":1.04}`) - if !ok || pct != 100 { - t.Errorf("percent = %v (ok=%v), want clamped to 100", pct, ok) + r, ok := parseResticStatus(`{"message_type":"status","percent_done":1.04}`) + if !ok || r.Percent != 100 { + t.Errorf("percent = %v (ok=%v), want clamped to 100", r.Percent, ok) } - pct, _, _, ok = parseResticStatus(`{"message_type":"status","percent_done":-0.2}`) - if !ok || pct != 0 { - t.Errorf("percent = %v (ok=%v), want clamped to 0", pct, ok) + r, ok = parseResticStatus(`{"message_type":"status","percent_done":-0.2}`) + if !ok || r.Percent != 0 { + t.Errorf("percent = %v (ok=%v), want clamped to 0", r.Percent, ok) } } diff --git a/controller/internal/web/templates/backups_remote.html b/controller/internal/web/templates/backups_remote.html index c8d342c..f4f303d 100644 --- a/controller/internal/web/templates/backups_remote.html +++ b/controller/internal/web/templates/backups_remote.html @@ -213,9 +213,20 @@ /* Only claim a percentage once restic has told us a total — before the scan finishes, percent is 0 of 0, and a bar pinned at 0% reads as "stuck" rather than "measuring". */ var label = p.current_app ? ('Mentés: ' + p.current_app) : 'Mentés folyamatban'; - if(p.total_bytes > 0){ + if(p.bytes_done > 0){ + /* Bytes are genuinely moving — the informative case. */ label += ' — ' + Math.round(p.percent) + '% (' + p.done_human + ' / ' + p.total_human + ')'; bar.style.width = Math.max(0, Math.min(100, p.percent)) + '%'; + } else if(p.total_files > 0){ + /* An INCREMENTAL run where nothing changed transfers no new bytes: restic reports + bytes_done 0 and percent 0 for the WHOLE run while still walking every file + (measured on the demo box: 430MB immich, 0% for 40+ seconds, then done). Driving the + bar off bytes here would be indistinguishable from a hang, so fall back to files — + which do move — and say what is actually happening. */ + var fpct = Math.round((p.files_done / p.total_files) * 100); + label += ' — ' + p.files_done + ' / ' + p.total_files + ' fájl ellenőrizve' + + (p.total_human ? ' (' + p.total_human + ')' : ''); + bar.style.width = Math.max(0, Math.min(100, fpct)) + '%'; } else { label += ' — a mentendő adatok felmérése…'; bar.style.width = '0%';