diff --git a/CHANGELOG.md b/CHANGELOG.md index d1ae981..5e46154 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,24 @@ ## Changelog +### v0.147.2 — 4c follow-up 2: when NO counter can move, say what is being worked on (2026-07-19) + +The v0.147.1 file-count fallback fixed the incremental case but not the one the demo box actually +hits. Watching a second real run: **bookstack** reported clean byte progress (100%, 154.0 MB, 7/7 +files — the byte path works), while **immich** sat at `files_done 1 of 46`, `bytes_done 0`, for 42 +seconds. restic 0.14 only counts a file into `bytes_done`/`files_done` when it **completes**, so an +app dominated by a single large archive (immich's ~430MB volume tar) freezes *both* counters. No +percentage can move in that window. + +So stop trying to. restic keeps reporting `current_files` and `seconds_elapsed` throughout; the card +now shows the file being processed and the elapsed time — „Mentés: immich — 1 / 46 fájl (430.2 MB) · +feldolgozás alatt: immich_upload.tar · 42 mp". „Working on this file for 42 seconds" is a completely +different message from „0%", and it is the honest one. + +The last known `current_files` value persists across ticks that omit it (restic does not send it +every time, and blanking the label every other second is its own flicker), and switching app clears +it so one app's file is never shown against another. Both pinned by tests, along with the real +42-second status line shape. + ### 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 diff --git a/controller/internal/backup/offbox_progress.go b/controller/internal/backup/offbox_progress.go index 05433e2..3eec686 100644 --- a/controller/internal/backup/offbox_progress.go +++ b/controller/internal/backup/offbox_progress.go @@ -44,6 +44,14 @@ type OffboxProgress struct { // in that case, so the page falls back to them. FilesDone int64 `json:"files_done"` TotalFiles int64 `json:"total_files"` + // CurrentFile/ElapsedSec are the last resort, and on real data the most important fields here. + // restic 0.14 only counts a file into files_done/bytes_done when it COMPLETES, so a single + // dominant file freezes both counters: measured on the demo box, immich sat at files_done 1 of 46 + // and bytes_done 0 for 42 seconds while restic worked on one ~430MB volume tar. No percentage can + // move during that window. What CAN be shown truthfully is which file is being processed and how + // long it has been going — "working on X, 42s" is a completely different message from "0%". + CurrentFile string `json:"current_file"` + ElapsedSec int64 `json:"elapsed_sec"` } // resticStatusLine is the subset of restic's `--json` status object we consume. restic emits several @@ -59,21 +67,25 @@ type OffboxProgress struct { // 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"` + 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"` + CurrentFiles []string `json:"current_files"` + SecondsElapsed int64 `json:"seconds_elapsed"` } // resticProgress is one parsed status line. type resticProgress struct { - Percent float64 // 0..100 - BytesDone int64 - TotalBytes int64 - FilesDone int64 - TotalFiles int64 + Percent float64 // 0..100 + BytesDone int64 + TotalBytes int64 + FilesDone int64 + TotalFiles int64 + CurrentFile string + ElapsedSec int64 } // parseResticStatus parses ONE line of restic --json output. @@ -99,9 +111,14 @@ func parseResticStatus(line string) (resticProgress, bool) { if pct > 100 { pct = 100 } + cur := "" + if len(s.CurrentFiles) > 0 { + cur = s.CurrentFiles[0] + } return resticProgress{ Percent: pct, BytesDone: s.BytesDone, TotalBytes: s.TotalBytes, FilesDone: s.FilesDone, TotalFiles: s.TotalFiles, + CurrentFile: cur, ElapsedSec: s.SecondsElapsed, }, true } @@ -135,6 +152,7 @@ func (p *offboxProgressState) setApp(app string) { 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.CurrentFile, p.cur.ElapsedSec = "", 0 p.cur.DoneHuman, p.cur.TotalHuman = "", "" } p.mu.Unlock() @@ -145,6 +163,12 @@ func (p *offboxProgressState) update(r resticProgress) { if p.live { 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.ElapsedSec = r.ElapsedSec + // Keep the last KNOWN current file: restic omits current_files on some status ticks, and + // blanking the label every other second is its own kind of flicker. + if r.CurrentFile != "" { + p.cur.CurrentFile = r.CurrentFile + } p.cur.DoneHuman, p.cur.TotalHuman = humanizeBytes(r.BytesDone), humanizeBytes(r.TotalBytes) } p.mu.Unlock() diff --git a/controller/internal/backup/offbox_progress_test.go b/controller/internal/backup/offbox_progress_test.go index 0c80b3b..f8836b6 100644 --- a/controller/internal/backup/offbox_progress_test.go +++ b/controller/internal/backup/offbox_progress_test.go @@ -230,6 +230,50 @@ func TestParseResticStatusIncrementalRun(t *testing.T) { } } +// TestParseResticStatusKeepsCurrentFileAndElapsed — the case where NO counter can move: restic 0.14 +// only counts a file when it completes, so an app dominated by one big archive freezes bytes_done +// AND files_done. Measured on the demo box: immich at 1 of 46 files, 0 bytes, for 42 seconds while +// restic worked through a single ~430MB volume tar. current_files + seconds_elapsed are then the only +// honest signals of liveness left, so losing them in parsing would put the bar back to looking hung. +func TestParseResticStatusKeepsCurrentFileAndElapsed(t *testing.T) { + line := `{"message_type":"status","seconds_elapsed":42,"percent_done":0,"total_files":46,` + + `"files_done":1,"total_bytes":451130451,"current_files":["/mnt/hdd/felhom-data/backups/primary/immich/volumes/immich_upload.tar"]}` + r, ok := parseResticStatus(line) + if !ok { + t.Fatal("status line was not parsed") + } + if r.ElapsedSec != 42 { + t.Errorf("elapsed = %d, want 42", r.ElapsedSec) + } + if r.CurrentFile == "" { + t.Fatal("current_file lost — with no counter moving this is the only liveness signal left") + } + if want := "immich_upload.tar"; !strings.HasSuffix(r.CurrentFile, want) { + t.Errorf("current_file = %q, want it to end in %q", r.CurrentFile, want) + } +} + +// TestProgressKeepsLastKnownCurrentFile — restic omits current_files on some status ticks. Blanking +// the label every other second is its own kind of flicker, so the last known value must persist. +func TestProgressKeepsLastKnownCurrentFile(t *testing.T) { + var st offboxProgressState + st.begin() + st.setApp("immich") + st.update(resticProgress{CurrentFile: "/data/big.tar", ElapsedSec: 5, TotalFiles: 46, FilesDone: 1}) + st.update(resticProgress{CurrentFile: "", ElapsedSec: 7, TotalFiles: 46, FilesDone: 1}) // tick without current_files + if got := st.snapshot().CurrentFile; got != "/data/big.tar" { + t.Errorf("current_file = %q after a tick that omitted it, want the last known value", got) + } + if got := st.snapshot().ElapsedSec; got != 7 { + t.Errorf("elapsed = %d, want it to keep advancing (7)", got) + } + // A new app must clear it — otherwise the previous app's file is shown against the next one. + st.setApp("nextcloud") + if got := st.snapshot().CurrentFile; got != "" { + t.Errorf("current_file = %q after switching app, want cleared", got) + } +} + // 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) { diff --git a/controller/internal/web/templates/backups_remote.html b/controller/internal/web/templates/backups_remote.html index f4f303d..8aaec35 100644 --- a/controller/internal/web/templates/backups_remote.html +++ b/controller/internal/web/templates/backups_remote.html @@ -218,14 +218,20 @@ 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. */ + /* No bytes moving. restic 0.14 only counts a file into bytes_done/files_done when it + COMPLETES, so an app dominated by one big archive freezes both counters — measured + on the demo box: immich at 1 of 46 files, 0 bytes, for 42 seconds while restic + worked through a single ~430MB volume tar. A percentage cannot move in that window, + so do not pretend: name the file being processed and the elapsed time, which is + what actually tells the customer it is alive. */ var fpct = Math.round((p.files_done / p.total_files) * 100); - label += ' — ' + p.files_done + ' / ' + p.total_files + ' fájl ellenőrizve' + label += ' — ' + p.files_done + ' / ' + p.total_files + ' fájl' + (p.total_human ? ' (' + p.total_human + ')' : ''); + if(p.current_file){ + var base = p.current_file.split('/').pop(); + label += ' · feldolgozás alatt: ' + base; + } + if(p.elapsed_sec > 0){ label += ' · ' + p.elapsed_sec + ' mp'; } bar.style.width = Math.max(0, Math.min(100, fpct)) + '%'; } else { label += ' — a mentendő adatok felmérése…';