77e8d5590b
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) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Nn3VgQk9iwEGgyx6QJ2NvE
265 lines
9.5 KiB
Go
265 lines
9.5 KiB
Go
package backup
|
|
|
|
import (
|
|
"context"
|
|
"strings"
|
|
"testing"
|
|
)
|
|
|
|
// v0.147.0 slice 4c — live progress for a MANUAL offsite run.
|
|
//
|
|
// These tests exercise the WHOLE path a real run takes: a fake restic emits canned `--json` status
|
|
// lines through the streaming seam, and the assertion is on what the poll surface
|
|
// (OffboxProgressSnapshot) reports — not on the parser in isolation. A parser that works but is
|
|
// never wired to the snapshot would leave the customer looking at the same silent spinner, which is
|
|
// the bug being fixed.
|
|
//
|
|
// RED-PROOF (run manually, both confirmed to fail):
|
|
// 1. break the parser — flip `s.MessageType != "status"` to `== "status"` in parseResticStatus:
|
|
// TestManualRunReportsParsedProgress fails ("percent = 0, want 42").
|
|
// 2. drop the wiring — make resticBackupStep always delegate to resticStep:
|
|
// the same test fails (no --json, no stream, no snapshot).
|
|
|
|
// jsonStatus is one restic --json status line.
|
|
func jsonStatus(pct float64, done, total int64) string {
|
|
return `{"message_type":"status","percent_done":` + ftoa(pct) + `,"total_bytes":` + itoa(total) + `,"bytes_done":` + itoa(done) + `}`
|
|
}
|
|
|
|
func ftoa(f float64) string {
|
|
// small helper — avoids strconv import noise in the canned lines
|
|
switch f {
|
|
case 0:
|
|
return "0"
|
|
case 0.42:
|
|
return "0.42"
|
|
case 1:
|
|
return "1"
|
|
}
|
|
return "0.5"
|
|
}
|
|
|
|
func itoa(i int64) string {
|
|
if i == 0 {
|
|
return "0"
|
|
}
|
|
var b []byte
|
|
neg := i < 0
|
|
if neg {
|
|
i = -i
|
|
}
|
|
for i > 0 {
|
|
b = append([]byte{byte('0' + i%10)}, b...)
|
|
i /= 10
|
|
}
|
|
if neg {
|
|
return "-" + string(b)
|
|
}
|
|
return string(b)
|
|
}
|
|
|
|
// TestManualRunReportsParsedProgress is the headline: a manual run driven by a fake restic that emits
|
|
// --json status lines must make OffboxProgressSnapshot report the parsed percentage, byte counts and
|
|
// the app currently being pushed.
|
|
func TestManualRunReportsParsedProgress(t *testing.T) {
|
|
e := newSharesOffboxEnv(t, "immich")
|
|
if err := e.sett.SetSMBEnabled(false); err != nil { // keep this test to the app leg only
|
|
t.Fatal(err)
|
|
}
|
|
|
|
var seen []OffboxProgress
|
|
var sawJSONFlag bool
|
|
e.m.SetOffboxStreamRunner(func(ctx context.Context, env []string, onLine func(string), args ...string) ([]byte, error) {
|
|
for _, a := range args {
|
|
if a == "--json" {
|
|
sawJSONFlag = true
|
|
}
|
|
}
|
|
// Emit a scan phase (total not yet known), then real progress, sampling the published
|
|
// snapshot after each line exactly as the polling page would.
|
|
onLine(jsonStatus(0, 0, 0))
|
|
seen = append(seen, e.m.OffboxProgressSnapshot())
|
|
onLine(`{"message_type":"verbose_status","action":"unchanged"}`) // must be ignored, not fatal
|
|
onLine(jsonStatus(0.42, 4200, 10000))
|
|
seen = append(seen, e.m.OffboxProgressSnapshot())
|
|
return []byte(`{"message_type":"summary","snapshot_id":"abc"}`), nil
|
|
})
|
|
// The non-streaming seam still serves every other restic call (cat config, forget, snapshots…).
|
|
e.m.SetOffboxRunner(func(ctx context.Context, env []string, args ...string) ([]byte, error) {
|
|
if contains(args, "snapshots") {
|
|
return []byte(`[]`), nil
|
|
}
|
|
return []byte(""), nil
|
|
})
|
|
|
|
if err := e.m.RunOffboxBackupWithProgress(context.Background()); err != nil {
|
|
t.Fatalf("manual run: %v", err)
|
|
}
|
|
|
|
if !sawJSONFlag {
|
|
t.Fatal("the manual backup leg did not pass --json to restic — nothing could ever be parsed")
|
|
}
|
|
if len(seen) != 2 {
|
|
t.Fatalf("expected 2 sampled snapshots, got %d", len(seen))
|
|
}
|
|
|
|
// While restic is still scanning, total is unknown: report 0 rather than inventing a percentage.
|
|
if seen[0].TotalBytes != 0 || seen[0].Percent != 0 {
|
|
t.Errorf("scan phase: got %+v, want zeroed counters", seen[0])
|
|
}
|
|
if seen[0].CurrentApp != "immich" {
|
|
t.Errorf("scan phase: current_app = %q, want %q", seen[0].CurrentApp, "immich")
|
|
}
|
|
|
|
got := seen[1]
|
|
if got.Percent != 42 {
|
|
t.Errorf("percent = %v, want 42", got.Percent)
|
|
}
|
|
if got.BytesDone != 4200 || got.TotalBytes != 10000 {
|
|
t.Errorf("bytes = %d/%d, want 4200/10000", got.BytesDone, got.TotalBytes)
|
|
}
|
|
if got.CurrentApp != "immich" {
|
|
t.Errorf("current_app = %q, want %q", got.CurrentApp, "immich")
|
|
}
|
|
if got.TotalHuman == "" || got.DoneHuman == "" {
|
|
t.Errorf("humanized byte strings not populated: %+v", got)
|
|
}
|
|
if !got.Active {
|
|
t.Error("progress reported inactive during a manual run")
|
|
}
|
|
|
|
// After the run the sink must be torn down, or the page would keep rendering a stale bar.
|
|
if after := e.m.OffboxProgressSnapshot(); after.Active || after.Percent != 0 {
|
|
t.Errorf("progress still published after the run: %+v", after)
|
|
}
|
|
}
|
|
|
|
// TestNightlyRunStaysSilent pins the scope decision: the scheduled run must neither install the sink
|
|
// nor pass --json, so its output format (and everything that greps it) is untouched.
|
|
func TestNightlyRunStaysSilent(t *testing.T) {
|
|
e := newSharesOffboxEnv(t, "immich")
|
|
if err := e.sett.SetSMBEnabled(false); err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
e.m.SetOffboxStreamRunner(func(ctx context.Context, env []string, onLine func(string), args ...string) ([]byte, error) {
|
|
t.Fatal("the nightly run used the streaming runner — progress must be manual-only")
|
|
return nil, nil
|
|
})
|
|
var backupArgs []string
|
|
e.m.SetOffboxRunner(func(ctx context.Context, env []string, args ...string) ([]byte, error) {
|
|
if contains(args, "backup") {
|
|
backupArgs = append([]string{}, args...)
|
|
}
|
|
if contains(args, "snapshots") {
|
|
return []byte(`[]`), nil
|
|
}
|
|
return []byte(""), nil
|
|
})
|
|
|
|
if err := e.m.RunOffboxBackup(context.Background()); err != nil {
|
|
t.Fatalf("nightly run: %v", err)
|
|
}
|
|
if backupArgs == nil {
|
|
t.Fatal("no backup call was made")
|
|
}
|
|
if contains(backupArgs, "--json") {
|
|
t.Errorf("the nightly run passed --json: %v", backupArgs)
|
|
}
|
|
if p := e.m.OffboxProgressSnapshot(); p.Active {
|
|
t.Errorf("the nightly run published progress: %+v", p)
|
|
}
|
|
}
|
|
|
|
// TestParseResticStatusIgnoresNonStatus covers the lines restic actually interleaves with status
|
|
// output. An unknown message_type must be ignored, never mistaken for progress — restic adds new
|
|
// types between versions.
|
|
func TestParseResticStatusIgnoresNonStatus(t *testing.T) {
|
|
for _, line := range []string{
|
|
`{"message_type":"summary","total_bytes_processed":123}`,
|
|
`{"message_type":"verbose_status","action":"new"}`,
|
|
`{"message_type":"error","error":{"message":"boom"}}`,
|
|
`not json at all`,
|
|
``,
|
|
`{}`,
|
|
} {
|
|
if _, ok := parseResticStatus(line); ok {
|
|
t.Errorf("parsed a non-status line as progress: %q", line)
|
|
}
|
|
}
|
|
r, ok := parseResticStatus(jsonStatus(0.42, 4200, 10000))
|
|
if !ok {
|
|
t.Fatal("a real status line was not parsed")
|
|
}
|
|
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) {
|
|
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)
|
|
}
|
|
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)
|
|
}
|
|
}
|
|
|
|
// TestLineTailKeepsOnlyTheTail — the --json stream of a large backup is megabytes of status spam, and
|
|
// every caller uses this output for error diagnosis and lock-pattern matching. Buffering all of it
|
|
// would be a memory leak proportional to backup size.
|
|
func TestLineTailKeepsOnlyTheTail(t *testing.T) {
|
|
var tl lineTail
|
|
for i := 0; i < 500; i++ {
|
|
tl.add("line-" + itoa(int64(i)))
|
|
}
|
|
out := string(tl.bytes())
|
|
if strings.Contains(out, "line-0\n") {
|
|
t.Error("the oldest line survived — the tail is unbounded")
|
|
}
|
|
if !strings.Contains(out, "line-499") {
|
|
t.Error("the newest line was dropped")
|
|
}
|
|
if n := strings.Count(out, "\n"); n > 64 {
|
|
t.Errorf("tail kept %d lines, want a small bounded number", n)
|
|
}
|
|
}
|