Skip to content

Commit bd943db

Browse files
authored
fix(backup): retry the scheduled base backup before failing the night (#218)
A base backup streams gigabytes through many multipart uploads, and wal-g aborts the whole push on the first part the destination refuses. Its S3 client (aws-sdk-go v1 in wal-g 3.0.8) retries only what the SDK classes as transient — 5xx, 429, throttling codes, connection resets — so a bare HTTP 400 from an S3-compatible destination fails the push outright. On a production host using Hetzner Object Storage, three of six nightly pushes were lost that way, each to a single part, while the same configuration succeeded on the other nights and on demand. The unit had one ExecStart and nothing to try again with. The backup unit now runs a host-side script, installed beside the verify script, that attempts the push up to three times, a minute and then five minutes apart, and exits with the last attempt's status. The loop lives in POSIX sh rather than in Restart= because systemd re-runs every ExecStart on a restart — retention included — and its start rate limiter bounds restarts by time rather than count, so a push slower than the limiter's window would retry forever. Retention stays a separate ExecStart, so it never runs after a push that failed every attempt. The flock still wraps the whole script, so an interactive `ob backup` waits rather than interleaving. Claude-Session: https://claude.ai/code/session_01VubhEStkwQngp9TwWiH9T7
1 parent c9f622a commit bd943db

4 files changed

Lines changed: 249 additions & 5 deletions

File tree

‎internal/app/names.go‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -553,3 +553,11 @@ func (n Names) BackupRunLock(service string) string {
553553
func (n Names) BackupVerifyScript(service string) string {
554554
return path.Join(n.AppDir(), "backup", "verify-"+service+".sh")
555555
}
556+
557+
// BackupPushScript is the host-side base backup the scheduled backup unit
558+
// runs. It lives beside the verify script for the same reason: it drives
559+
// docker from the host, and it is where the unit's retry loop is written down
560+
// rather than in a unit file that cannot bound one.
561+
func (n Names) BackupPushScript(service string) string {
562+
return path.Join(n.AppDir(), "backup", "backup-"+service+".sh")
563+
}

‎internal/engine/backup_schedule.go‎

Lines changed: 77 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -19,9 +19,10 @@ import (
1919
// Two timers per protected service, taken straight from the policy rather than
2020
// invented:
2121
//
22-
// - the backup schedule takes a base backup and then applies retention, in
23-
// that order, so the repository is never briefly below the number of
24-
// generations the policy promises;
22+
// - the backup schedule takes a base backup — retrying it a bounded number
23+
// of times, because one refused upload part aborts the whole push — and
24+
// then applies retention, in that order, so the repository is never
25+
// briefly below the number of generations the policy promises;
2526
// - the drill schedule verifies the archived WAL forms an unbroken
2627
// chain, which is the check a green backup does not imply.
2728
//
@@ -100,8 +101,11 @@ func (e *Engine) SyncBackupSchedules(ctx context.Context) error {
100101
commands []string
101102
}{
102103
{"backup", projection.Policy.Schedule, []string{
103-
walgExec(container, "backup-push", app.PgDataPath),
104-
// Retention after the new generation exists, never before.
104+
"/bin/sh " + n.BackupPushScript(service),
105+
// Retention after the new generation exists, never before. A
106+
// separate ExecStart, so a push that fails every attempt
107+
// stops the unit here and never expires a generation to make
108+
// room for one that does not exist.
105109
prune,
106110
}},
107111
{"verify", projection.Policy.Drill.Schedule, []string{
@@ -140,11 +144,19 @@ func (e *Engine) SyncBackupSchedules(ctx context.Context) error {
140144
// straight through would be marked successful by systemd over a repository
141145
// with holes in it, for as long as nobody looked. The interactive command
142146
// judges the same report in Go; this is the unattended half of it.
147+
//
148+
// The backup unit runs a script for a different reason: a single
149+
// ExecStart has no way to try again, and a base backup is the one
150+
// scheduled job where giving up on the first fault loses a whole night.
143151
for _, service := range backedUpServiceNames(e.Spec) {
144152
if err := e.writeServiceFile(ctx, n.BackupVerifyScript(service),
145153
[]byte(backupVerifyScript(n.ServiceContainer(service)))); err != nil {
146154
return fmt.Errorf("cannot install the archive verification for %s: %w", service, err)
147155
}
156+
if err := e.writeServiceFile(ctx, n.BackupPushScript(service),
157+
[]byte(backupPushScript(n.ServiceContainer(service)))); err != nil {
158+
return fmt.Errorf("cannot install the scheduled base backup for %s: %w", service, err)
159+
}
148160
}
149161

150162
wantedNames := map[string]bool{}
@@ -223,6 +235,66 @@ func backupVerifyScript(container string) string {
223235
}, "\n")
224236
}
225237

238+
// backupPushRetryWaits is the pause, in seconds, before each further attempt
239+
// at the scheduled base backup; its length is the number of retries.
240+
//
241+
// A base backup streams gigabytes through many multipart uploads, and the
242+
// whole push aborts on the first part the destination refuses — wal-g treats
243+
// a lost part as fatal, and its S3 client only retries the errors the SDK
244+
// classes as transient, which a bare HTTP 400 from an edge proxy is not. Seen
245+
// on a production host against an S3-compatible destination: three of six
246+
// nights lost to one part, with the same configuration succeeding on the
247+
// others. Two more attempts, a minute and then five apart, cover a fault
248+
// that lasts seconds without hiding one that lasts the night.
249+
var backupPushRetryWaits = []int{60, 300}
250+
251+
// backupPushScript is the scheduled base backup.
252+
//
253+
// It is a script rather than a unit directive because systemd's Restart=
254+
// re-runs every ExecStart, so a retry of the push would also re-run the
255+
// retention that follows it, and the start rate limiter bounds restarts by
256+
// time, not count — a push slower than the limiter's window retries forever.
257+
// A loop in POSIX sh is bounded by construction and exits with the last
258+
// attempt's status, so the unit still fails, visibly, when every attempt
259+
// does. It runs under the unit's flock for its whole span, retries included,
260+
// so an interactive `ob backup` keeps waiting rather than interleaving.
261+
func backupPushScript(container string) string {
262+
return backupPushScriptWith(walgExec(container, "backup-push", app.PgDataPath), backupPushRetryWaits)
263+
}
264+
265+
func backupPushScriptWith(command string, waits []int) string {
266+
attempts := len(waits) + 1
267+
schedule := make([]string, 0, len(waits))
268+
for _, wait := range waits {
269+
schedule = append(schedule, fmt.Sprint(wait))
270+
}
271+
// Bounded by the attempt count, not by running out of waits: one wait per
272+
// retry is what makes `$1` defined every time the loop reaches `shift`.
273+
return strings.Join([]string{
274+
"#!/bin/sh",
275+
"# Written by Onebox. Edits are overwritten on the next apply.",
276+
"set -u",
277+
fmt.Sprintf("attempts=%d", attempts),
278+
"attempt=0",
279+
"set -- " + strings.Join(schedule, " "),
280+
"while :; do",
281+
" attempt=$((attempt + 1))",
282+
" " + command,
283+
" status=$?",
284+
` [ "$status" -eq 0 ] && exit 0`,
285+
` if [ "$attempt" -ge "$attempts" ]; then`,
286+
` echo "onebox: base backup failed on attempt $attempt of $attempts (exit $status); giving up" >&2`,
287+
` exit "$status"`,
288+
" fi",
289+
` wait=$1`,
290+
" shift",
291+
` echo "onebox: base backup attempt $attempt of $attempts failed (exit $status); retrying in ${wait}s" >&2`,
292+
` sleep "$wait"`,
293+
"done",
294+
"",
295+
}, "\n")
296+
}
297+
226298
func walgExec(container string, args ...string) string {
227299
parts := []string{"/usr/bin/docker", "exec", "-u", "postgres", container, app.WalgBinary}
228300
return strings.Join(append(parts, args...), " ")

‎internal/engine/schedule_test.go‎

Lines changed: 156 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import (
55
"context"
66
"encoding/json"
77
"errors"
8+
"fmt"
89
"os"
910
"os/exec"
1011
"path/filepath"
@@ -965,6 +966,161 @@ func TestBackupServiceUnitRecordsEnvironmentOwnership(t *testing.T) {
965966
}
966967
}
967968

969+
// The scheduled base backup has to survive one refused upload part.
970+
//
971+
// wal-g aborts the whole push when the destination refuses a single multipart
972+
// part, and its S3 client does not retry a bare HTTP 400, so a unit with one
973+
// ExecStart lost three nights in six on a production host while the same
974+
// configuration succeeded on the others. The loop is bounded, and when every
975+
// attempt fails the unit still fails with the last attempt's status — a retry
976+
// that hid that would be a backup that had silently stopped.
977+
func TestTheScheduledBaseBackupRetriesBeforeFailingTheUnit(t *testing.T) {
978+
if runtime.GOOS == "windows" {
979+
t.Skip("the scheduled backup is a POSIX shell script")
980+
}
981+
dir := t.TempDir()
982+
counter := filepath.Join(dir, "attempts")
983+
for _, tc := range []struct {
984+
name string
985+
succeedFrom int // the attempt that succeeds; 0 means none does
986+
wantExit int
987+
wantRuns int
988+
wantStderr []string
989+
}{
990+
{"first attempt succeeds", 1, 0, 1, nil},
991+
{"second attempt succeeds", 2, 0, 2, []string{"attempt 1 of 3 failed (exit 7); retrying in 0s"}},
992+
{"every attempt fails", 0, 7, 3, []string{
993+
"attempt 1 of 3 failed (exit 7); retrying in 0s",
994+
"attempt 2 of 3 failed (exit 7); retrying in 0s",
995+
"failed on attempt 3 of 3 (exit 7); giving up",
996+
}},
997+
} {
998+
t.Run(tc.name, func(t *testing.T) {
999+
if err := os.WriteFile(counter, nil, 0o600); err != nil {
1000+
t.Fatal(err)
1001+
}
1002+
// The stand-in for `docker exec ... backup-push`: a program of its
1003+
// own, as the real one is. Each run appends a line, and it succeeds
1004+
// once the line count reaches the attempt meant to succeed.
1005+
push := filepath.Join(dir, "push.sh")
1006+
if err := os.WriteFile(push, []byte(fmt.Sprintf(
1007+
"echo run >> %s\n[ %d -gt 0 ] && [ \"$(wc -l < %s | tr -d ' ')\" -ge %d ] || exit 7\n",
1008+
counter, tc.succeedFrom, counter, tc.succeedFrom)), 0o600); err != nil {
1009+
t.Fatal(err)
1010+
}
1011+
script := filepath.Join(dir, "backup.sh")
1012+
if err := os.WriteFile(script, []byte(backupPushScriptWith("sh "+push, []int{0, 0})), 0o600); err != nil {
1013+
t.Fatal(err)
1014+
}
1015+
var stderr bytes.Buffer
1016+
cmd := exec.CommandContext(context.Background(), "sh", script)
1017+
cmd.Stderr = &stderr
1018+
err := cmd.Run()
1019+
exit := 0
1020+
var exitErr *exec.ExitError
1021+
if errors.As(err, &exitErr) {
1022+
exit = exitErr.ExitCode()
1023+
} else if err != nil {
1024+
t.Fatal(err)
1025+
}
1026+
if exit != tc.wantExit {
1027+
t.Errorf("exit %d, want %d:\n%s", exit, tc.wantExit, stderr.String())
1028+
}
1029+
runs, err := os.ReadFile(counter)
1030+
if err != nil {
1031+
t.Fatal(err)
1032+
}
1033+
if got := strings.Count(string(runs), "run\n"); got != tc.wantRuns {
1034+
t.Errorf("the push ran %d times, want %d:\n%s", got, tc.wantRuns, stderr.String())
1035+
}
1036+
for _, want := range tc.wantStderr {
1037+
if !strings.Contains(stderr.String(), want) {
1038+
t.Errorf("stderr does not say %q:\n%s", want, stderr.String())
1039+
}
1040+
}
1041+
})
1042+
}
1043+
1044+
// The installed script: the real push, the real waits, and shell that does
1045+
// not bail out of the loop at the first failed attempt.
1046+
script := backupPushScript("shop-database-1")
1047+
for _, want := range []string{
1048+
"/usr/bin/docker exec -u postgres shop-database-1 " + app.WalgBinary + " backup-push " + app.PgDataPath,
1049+
"attempts=3",
1050+
"set -- 60 300",
1051+
`exit "$status"`,
1052+
} {
1053+
if !strings.Contains(script, want) {
1054+
t.Errorf("the scheduled base backup does not contain %q:\n%s", want, script)
1055+
}
1056+
}
1057+
if strings.Contains(script, "set -e") {
1058+
t.Errorf("set -e exits at the first failed attempt before the loop can retry:\n%s", script)
1059+
}
1060+
check := exec.CommandContext(context.Background(), "sh", "-n")
1061+
check.Stdin = strings.NewReader(script)
1062+
if output, err := check.CombinedOutput(); err != nil {
1063+
t.Fatalf("the scheduled base backup is not valid POSIX shell: %v: %s\n%s", err, output, script)
1064+
}
1065+
}
1066+
1067+
// The unit retries the push and only the push.
1068+
//
1069+
// Retention stays a separate ExecStart on purpose: systemd stops a oneshot at
1070+
// the first ExecStart that fails, so a push that failed every attempt never
1071+
// reaches `delete retain`. A retry wired into the unit with Restart= would
1072+
// instead re-run every ExecStart, retention included, on each attempt.
1073+
func TestTheScheduledBackupUnitRetriesThePushAndNotTheRetention(t *testing.T) {
1074+
f := &transport.Fake{Dynamic: func(cmd string) (transport.Result, bool) {
1075+
if strings.HasSuffix(cmd, "echo ok") {
1076+
return transport.Result{Stdout: "ok\n"}, true
1077+
}
1078+
return transport.Result{}, false
1079+
}}
1080+
resolved := protectedPostgresResolved(t, "7513211627332151223")
1081+
e := New(resolved, nil, f, Options{Out: &bytes.Buffer{}, Sleep: noSleep, Environment: "production"})
1082+
if err := e.SyncBackupSchedules(context.Background()); err != nil {
1083+
t.Fatal(err)
1084+
}
1085+
n := resolved.Spec.NamesFor("production")
1086+
var unit, script string
1087+
for _, body := range f.Inputs {
1088+
switch {
1089+
case strings.Contains(body, "Description=Onebox backup backup for postgres"):
1090+
unit = body
1091+
case strings.HasPrefix(body, "#!/bin/sh") && strings.Contains(body, "backup-push"):
1092+
script = body
1093+
}
1094+
}
1095+
if unit == "" {
1096+
t.Fatalf("no backup unit was written:\n%s", strings.Join(f.Commands, "\n"))
1097+
}
1098+
if script == "" || !strings.Contains(strings.Join(f.Commands, "\n"), n.BackupPushScript("postgres")) {
1099+
t.Fatalf("the retrying base backup was not installed at %s:\n%s", n.BackupPushScript("postgres"), strings.Join(f.Commands, "\n"))
1100+
}
1101+
lock := n.BackupRunLock("postgres")
1102+
push := "ExecStart=/usr/bin/flock -w 3600 " + lock + " /bin/sh " + n.BackupPushScript("postgres")
1103+
prune := "ExecStart=/usr/bin/flock -w 3600 " + lock + " /usr/bin/docker exec -u postgres " +
1104+
n.ServiceContainer("postgres") + " " + app.WalgBinary + " delete retain FULL"
1105+
for _, want := range []string{push, prune} {
1106+
if !strings.Contains(unit, want) {
1107+
t.Errorf("the backup unit does not contain %q:\n%s", want, unit)
1108+
}
1109+
}
1110+
if strings.Index(unit, push) > strings.Index(unit, prune) {
1111+
t.Errorf("retention runs before the push:\n%s", unit)
1112+
}
1113+
if strings.Contains(unit, "backup-push") {
1114+
t.Errorf("the unit runs the push outside the retrying script:\n%s", unit)
1115+
}
1116+
if strings.Contains(unit, "Restart=") {
1117+
t.Errorf("a systemd restart would re-run retention with every attempt:\n%s", unit)
1118+
}
1119+
if !strings.Contains(script, "/usr/bin/docker exec -u postgres "+n.ServiceContainer("postgres")+" "+app.WalgBinary+" backup-push "+app.PgDataPath) {
1120+
t.Errorf("the installed script does not push this service's cluster:\n%s", script)
1121+
}
1122+
}
1123+
9681124
func TestScheduledJobRunnersRecordRunStateForTheNotifier(t *testing.T) {
9691125
names := app.Names{App: "sample", BasePath: "/var/lib/onebox"}
9701126
for _, tc := range []struct {

‎site/src/content/docs/guides/back-up-a-database.mdx‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,14 @@ be telling you the database is protected at the moment it is not.
6767
The restart is a real restart. Enabling is a maintenance action, not a
6868
configuration change.
6969

70+
The scheduled base backup does not give up on its first fault. A push streams
71+
gigabytes through many multipart uploads and aborts on the first part the
72+
destination refuses, so the unit tries up to three times, a minute and then
73+
five minutes apart, under the same lock an interactive `ob backup` waits on.
74+
Retention runs only after a push that succeeded. A night on which every attempt
75+
fails is still a failed unit: `systemctl status onebox-backup-database-backup`
76+
says so, and the journal has each attempt's reason.
77+
7078
## The credential file
7179

7280
The encrypted file your target names needs three entries — the two you named,

0 commit comments

Comments
 (0)