diff --git a/modules/restic/README.md b/modules/restic/README.md index 1ec851b8..c415262e 100644 --- a/modules/restic/README.md +++ b/modules/restic/README.md @@ -18,6 +18,12 @@ Against mistakes, not disasters: nothing leaves the machine. kept for good. That is a choice: deleting a module's last restore point is a person's act, and until then it costs only space. +**A repository another restic holds** (a listing of the restore points, say, while a delivery plan backs up +the machine's modules before their moves) is waited for: the thinning asks restic to retry the lock for up to +ten minutes (`--retry-lock`, novox/hq issue 620), and fails only after that. A failed thinning keeps every +restore point, and the module's health stays unhealthy until a thinning succeeds: the next night's, or one +after `node-backup.now`. + `node-backup.backed-up` lists each module's restore points taken by hand under `handTaken`: when each was taken, the time it is kept at least until, whether it still waits for a later good night, and a sentence saying so. diff --git a/modules/restic/cmd/restic-backups/backups.go b/modules/restic/cmd/restic-backups/backups.go index 4485b9d5..876c73ac 100644 --- a/modules/restic/cmd/restic-backups/backups.go +++ b/modules/restic/cmd/restic-backups/backups.go @@ -406,6 +406,15 @@ func (b *Backups) backUp(ctx context.Context, only string, hand bool) (map[strin return outcome, nil } +// thinningWaitsForALock is how long the thinning waits for a repository another restic holds, with restic's own +// --retry-lock, before it fails as it did before (novox/hq issue 620). The night's lock keeps out this module's own +// backups and restores, not a restic outside it: a listing of the restore points, asked while a delivery plan backs +// up a machine's data modules before their moves (ADR 0233), held the lock 246 ms before a thinning asked for it. +// Ten minutes outlasts such a plan's backups of every data module on a machine (a whole night of fifteen modules +// took under five minutes) and stays well within the half hour after which restic takes a lock as stale; a lock +// held longer than this is not a passing collision, and is said the same night. +const thinningWaitsForALock = 10 * time.Minute + // thin forgets the restore points taken by hand that are past their days and have a later night of their // module, by id, then thins the rest by the counts, keeping every one still tagged as taken by hand (novox/hq // issue 453). It answers the short ids it let go — on an error of the counts' thinning too, for those are gone. A list that does not read thins nothing: a restore point @@ -420,14 +429,14 @@ func (b *Backups) thin(ctx context.Context, keep Retention) ([]string, error) { ids, letGo = append(ids, s.ID), append(letGo, s.ShortID) } if len(ids) > 0 { - if _, err := b.restic(ctx, append([]string{"forget"}, ids...)...); err != nil { + if _, err := b.restic(ctx, append([]string{"forget", "--retry-lock", thinningWaitsForALock.String()}, ids...)...); err != nil { return nil, err } b.Say("let go the restore points taken by hand past %d days with a later night: %s", keep.Hand, strings.Join(letGo, ", ")) } _, err = b.restic(ctx, "forget", "--prune", "--group-by", "host,tags", "--keep-daily", fmt.Sprint(keep.Daily), "--keep-weekly", fmt.Sprint(keep.Weekly), "--keep-monthly", fmt.Sprint(keep.Monthly), - "--keep-tag", HandTag) + "--keep-tag", HandTag, "--retry-lock", thinningWaitsForALock.String()) return letGo, err } diff --git a/modules/restic/cmd/restic-backups/backups_test.go b/modules/restic/cmd/restic-backups/backups_test.go index 24930540..3a545185 100644 --- a/modules/restic/cmd/restic-backups/backups_test.go +++ b/modules/restic/cmd/restic-backups/backups_test.go @@ -108,7 +108,7 @@ func TestANightDumpsBeforeEachSnapshotAndOneFailingModuleFailsOnlyItself(t *test "sh -c fail-it", "restic backup --json --tag module=mail /", "restic snapshots --json", - "restic forget --prune --group-by host,tags --keep-daily 14 --keep-weekly 8 --keep-monthly 6 --keep-tag hand", + "restic forget --prune --group-by host,tags --keep-daily 14 --keep-weekly 8 --keep-monthly 6 --keep-tag hand --retry-lock 10m0s", } if !reflect.DeepEqual(calls, want) { t.Errorf("ran\n%s\nwant\n%s", strings.Join(calls, "\n"), strings.Join(want, "\n")) diff --git a/modules/restic/cmd/restic-backups/hand_test.go b/modules/restic/cmd/restic-backups/hand_test.go index 22af7160..afd4637b 100644 --- a/modules/restic/cmd/restic-backups/hand_test.go +++ b/modules/restic/cmd/restic-backups/hand_test.go @@ -74,7 +74,7 @@ func TestAHandTakenBackupIsTaggedAndTheThinningKeepsThatTag(t *testing.T) { if got := h.with("restic backup"); len(got) != 2 || got[1] != "restic backup --json --tag module=pg /" { t.Errorf("the night backed up with %q, want it tagged with its module alone", got) } - want := "restic forget --prune --group-by host,tags --keep-daily 14 --keep-weekly 8 --keep-monthly 6 --keep-tag hand" + want := "restic forget --prune --group-by host,tags --keep-daily 14 --keep-weekly 8 --keep-monthly 6 --keep-tag hand --retry-lock 10m0s" for _, f := range h.with("restic forget") { if f != want { t.Errorf("thinned with %q, want %q", f, want) @@ -134,7 +134,7 @@ func TestTheThinningForgetsAnExpiredHandTakenRestorePointByItsId(t *testing.T) { _, err := b.BackUp(context.Background(), "") must(t, err) forgets := h.with("restic forget") - if len(forgets) != 2 || forgets[0] != "restic forget aaaaaaaa11" || !strings.HasPrefix(forgets[1], "restic forget --prune") { + if len(forgets) != 2 || forgets[0] != "restic forget --retry-lock 10m0s aaaaaaaa11" || !strings.HasPrefix(forgets[1], "restic forget --prune") { t.Fatalf("thinned with %q, want the expired one forgotten by id, then the rotation", forgets) } th := b.LastRun().Thinned diff --git a/modules/restic/cmd/restic-backups/lock_test.go b/modules/restic/cmd/restic-backups/lock_test.go new file mode 100644 index 00000000..c474f30c --- /dev/null +++ b/modules/restic/cmd/restic-backups/lock_test.go @@ -0,0 +1,100 @@ +package main + +// The thinning waits for a repository another restic holds (novox/hq issue 620): met three times, each when a +// restic process outside the night's lock — a listing of the restore points while a delivery plan backs up a +// machine's data modules before their moves (ADR 0233) — held the repository's lock a few hundred milliseconds +// before the thinning asked for it, and the thinning failed at once. + +import ( + "context" + "errors" + "slices" + "strings" + "testing" + "time" +) + +// lockedRestic is a fake restic whose repository another process holds for heldFor, as restic answers it: a +// forget without --retry-lock fails at once; one with it waits up to its bound, and succeeds when the lock is +// let go within it, else fails with restic's words. waited is how long the forgets it was asked waited. +type lockedRestic struct { + handRestic + heldFor time.Duration + waited []time.Duration +} + +const lockSaid = "unable to create lock in backend: repository is already locked by PID 4242 on the-machine by root " + + "(UID 0, GID 0) / lock was created at 2026-10-22 18:14:22 (246 ms ago)" + +func (l *lockedRestic) run(ctx context.Context, name string, args ...string) (string, error) { + if name != "restic" || args[5] != "forget" { + return l.handRestic.run(ctx, name, args...) + } + l.calls = append(l.calls, "restic "+strings.Join(args[5:], " ")) + bound := time.Duration(0) + if i := slices.Index(args, "--retry-lock"); i >= 0 && i+1 < len(args) { + d, err := time.ParseDuration(args[i+1]) + if err != nil { + return "", errors.New("invalid argument for --retry-lock: " + args[i+1]) + } + bound = d + } + if l.heldFor > bound { + l.waited = append(l.waited, bound) + return "", errors.New(lockSaid) + } + l.waited = append(l.waited, l.heldFor) + l.heldFor = 0 + return "", nil +} + +func TestTheThinningWaitsForALockHeldBriefly(t *testing.T) { + for _, held := range []time.Duration{3 * time.Second, 5 * time.Minute} { + l := &lockedRestic{heldFor: held} + b := &Backups{Where: placed(t, "# pg\npath /\n"), Run: l.run, Now: time.Now, Say: quiet} + _, err := b.BackUp(context.Background(), "") + must(t, err) + if th := b.LastRun().Thinned; th == nil || !th.OK { + t.Errorf("held for %s: recorded %+v, want the thinning to wait for the lock and succeed", held, th) + } + if why := b.Health(context.Background()).Why; strings.Contains(why, "Thinning the restore points failed") { + t.Errorf("held for %s: the health says %q", held, why) + } + } +} + +func TestTheThinningStillFailsOnALockHeldPastItsBound(t *testing.T) { + l := &lockedRestic{heldFor: thinningWaitsForALock + time.Minute} + b := &Backups{Where: placed(t, "# pg\npath /\n"), Run: l.run, Now: time.Now, Say: quiet} + _, err := b.BackUp(context.Background(), "") + must(t, err) + th := b.LastRun().Thinned + if th == nil || th.OK || !strings.Contains(th.Error, "already locked") { + t.Fatalf("recorded %+v, want the thinning failed on the lock", th) + } + if !slices.Equal(l.waited, []time.Duration{thinningWaitsForALock}) { + t.Errorf("waited %v, want once, for %s", l.waited, thinningWaitsForALock) + } + why := b.Health(context.Background()).Why + for _, want := range []string{"Thinning the restore points failed at", "already locked", "Nothing was forgotten", + "node-backup.now on this machine thins again"} { + if !strings.Contains(why, want) { + t.Errorf("the health says %q, want %q in it", why, want) + } + } +} + +// A restore point taken by hand that is let go by its id waits for the lock as well: it is the thinning too. +func TestTheThinningForgetsByIdWaitingForTheLock(t *testing.T) { + now := time.Date(2026, 10, 20, 3, 0, 0, 0, time.UTC) + l := &lockedRestic{heldFor: 3 * time.Second, handRestic: handRestic{made: "bbbbbbbb11", snaps: []Snapshot{ + {ID: "aaaaaaaa11", ShortID: "aaaaaaaa", Time: now.AddDate(0, 0, -9), Tags: []string{"module=pg", HandTag}}, + {ID: "bbbbbbbb11", ShortID: "bbbbbbbb", Time: now, Tags: []string{"module=pg"}}, + }}} + b := &Backups{Where: placed(t, "# pg\npath /\n"), Run: l.run, Now: func() time.Time { return now }, Say: quiet} + _, err := b.BackUp(context.Background(), "") + must(t, err) + if th := b.LastRun().Thinned; th == nil || !th.OK || !slices.Equal(th.LetGo, []string{"aaaaaaaa"}) { + t.Errorf("recorded %+v, want aaaaaaaa let go after waiting for the lock", th) + } +} diff --git a/modules/restic/cmd/restic-backups/retention_test.go b/modules/restic/cmd/restic-backups/retention_test.go index 2e0ce490..58a7ced4 100644 --- a/modules/restic/cmd/restic-backups/retention_test.go +++ b/modules/restic/cmd/restic-backups/retention_test.go @@ -51,7 +51,7 @@ func thinning(t *testing.T, retention *string) (string, []string) { func TestANightThinsByTheRetentionTheMeshWrote(t *testing.T) { conf := "# Written by the mesh.\ndaily=7\nweekly=4\nmonthly=24\nhand=10\n" got, _ := thinning(t, &conf) - if want := "restic forget --prune --group-by host,tags --keep-daily 7 --keep-weekly 4 --keep-monthly 24 --keep-tag hand"; got != want { + if want := "restic forget --prune --group-by host,tags --keep-daily 7 --keep-weekly 4 --keep-monthly 24 --keep-tag hand --retry-lock 10m0s"; got != want { t.Errorf("ran %q, want %q", got, want) } }