mesh/check failed: unit: modules/gitea.test: [gitea] where the poll of merges last looked from could not be read, so none is kept — no runtime | 3cce1…
mesh/merge-gate head 3cce15fa811e merged into trunk 835bf22b7d40 — pass: builds restic → ace, g14, novox, shanks; no bus step; every machine composes with …
mesh/repo-check head 3cce15fa811e merged into trunk 835bf22b7d40 — pass: its merge-check.sh passed, each part in its toolchain: merge-check.sh (go), merge-…
mesh/delivery delivered
A restic outside the night's lock, such as a listing while a delivery plan backs up data modules before their moves, held the lock 246 ms before the thinning asked for it, and the thinning failed at once, raising an urgent condition for a timing collision. restic's --retry-lock now waits up to ten minutes on both of the thinning's forgets; past that it fails with restic's words as before.
101 lines
4.2 KiB
Go
101 lines
4.2 KiB
Go
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)
|
|
}
|
|
}
|