Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
38 changes: 35 additions & 3 deletions cloud-backups/cmd/oci_backup.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import (
"log/slog"
"os"
"os/signal"
"strings"
"syscall"
"time"

Expand All @@ -15,6 +16,7 @@ import (
"github.com/relizaio/cloud-backup/internal/config"
"github.com/relizaio/cloud-backup/internal/oras"
"github.com/relizaio/cloud-backup/internal/orchestrator"
"github.com/relizaio/cloud-backup/internal/pipeline"
"github.com/relizaio/cloud-backup/internal/registry"
"github.com/relizaio/cloud-backup/internal/stats"
"github.com/relizaio/cloud-backup/internal/storage"
Expand Down Expand Up @@ -87,7 +89,7 @@ func runBackup() error {
slog.Error("registry_login_failed", "error", err.Error())
return err
}
defer authCtx.Cleanup() // guaranteed to run no os.Exit below this point
defer authCtx.Cleanup() // guaranteed to run - no os.Exit below this point

regClient := registry.New(cfg.RegistryHost, authCtx.ConfigDir, cfg.PlainHTTP)

Expand All @@ -101,8 +103,8 @@ func runBackup() error {
basePaths := cfg.CleanBasePaths()
if len(basePaths) > 0 {
slog.Info("running_preflight_auth_check", "target", basePaths[0])
if err := regClient.PreflightCheck(ctx, basePaths[0]); err != nil {
slog.Error("preflight_check_failed", "error", err.Error())
if err := pipeline.RunPreflightWithRetry(ctx, regClient, basePaths[0]); err != nil {
slog.Error("preflight_check_failed", "target", basePaths[0], "error", pipeline.TruncateCause(err.Error()))
return err
}
slog.Info("preflight_check_passed")
Expand All @@ -127,12 +129,42 @@ func runBackup() error {

// 6. Report result
stats.PrintSummary("backup_pipeline_completed", tracker, cfg.StorageType, time.Since(pipelineStart))

// PrintSummary only escalates when EVERY target is missing, so a partial skip
// otherwise stays at INFO and the run still exits 0 -- 49 of 50 repos could
// vanish silently. A skipped target produced no backup, so it is only
// tolerable when the absence is expected: under rolling months the
// PREVIOUS-month path may legitimately not exist. The CURRENT month is being
// actively written, and under explicit paths every target was named by an
// operator, so those absences are real gaps and must be visible.
// PrintSummary already covers the all-skipped case at ERROR; do not double-report.
if !allTargetsSkipped(tracker) {
var unexpected []string
for _, s := range tracker.GetSkipped() {
if !orchestrator.SkipIsExpected(s, cfg.AppendRollingMonths, time.Now().UTC()) {
unexpected = append(unexpected, s)
}
}
if len(unexpected) > 0 {
slog.Error("backup_targets_missing_from_registry",
"detail", "a skipped target produced no backup; absence is only expected for the previous-month rolling target",
"error", fmt.Sprintf("%d of %d target(s) produced no backup because the repository was reported absent: %s",
len(unexpected), tracker.GetTotal(), strings.Join(unexpected, ", ")))
}
}

if tracker.GetFailedCount() > 0 || (tracker.GetTotal() > 0 && tracker.GetTotal() == tracker.GetSkippedCount()) {
return fmt.Errorf("backup pipeline completed with failures")
}
return nil
}

// allTargetsSkipped mirrors the condition PrintSummary uses to raise
// pipeline_failed_all_repos_missing, so the two do not both alert on it.
func allTargetsSkipped(t *stats.Tracker) bool {
return t.GetTotal() > 0 && t.GetSkippedCount() == t.GetTotal()
}

func init() {
ociCmd.AddCommand(backupCmd)
backupCmd.Flags().StringSlice("registry-base-paths", []string{}, "Comma-separated list of target repositories (ENV: REGISTRY_BASE_PATHS)")
Expand Down
22 changes: 20 additions & 2 deletions cloud-backups/internal/orchestrator/backup.go
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ type BackupManager struct {
EncPassword string // used only to build the modifier chain
DumpPrefix string
Timeout time.Duration
DeterministicName bool // when true, use last path segment as filename (no timestamp/random) overwrites on re-run
DeterministicName bool // when true, use last path segment as filename (no timestamp/random) - overwrites on re-run
}

// RunBackups resolves the final target list and fans out concurrent backup workers.
Expand Down Expand Up @@ -96,7 +96,7 @@ func (m *BackupManager) resolveTargets(basePaths []string, rollingMonths bool) [
slog.Info("rolling_months_strategy_enabled", "base_paths", basePaths)
now := time.Now().UTC()
currentMonth := now.Format("2006-01")
previousMonth := now.AddDate(0, 0, -now.Day()).Format("2006-01")
previousMonth := PreviousMonthSuffix(now)

var targets []string
for _, p := range basePaths {
Expand All @@ -105,3 +105,21 @@ func (m *BackupManager) resolveTargets(basePaths []string, rollingMonths bool) [
}
return targets
}

// PreviousMonthSuffix is the YYYY-MM appended to build the previous-month
// target. Exported because that target is the ONLY one under rolling months
// whose absence is legitimate (it may predate the deployment, or the month may
// have had no artifacts); callers deciding whether a skip is expected need to
// identify it, and must not re-derive the date arithmetic independently.
func PreviousMonthSuffix(now time.Time) string {
return now.AddDate(0, 0, -now.Day()).Format("2006-01")
}

// SkipIsExpected reports whether a skipped (absent) target is a legitimate
// absence rather than a missing backup. Under explicit paths every target was
// named by an operator, so no absence is expected. Under rolling months only
// the previous-month target may legitimately not exist -- the CURRENT month is
// the one being actively written, and its absence means a real gap.
func SkipIsExpected(target string, rollingMonths bool, now time.Time) bool {
return rollingMonths && strings.HasSuffix(target, "-"+PreviousMonthSuffix(now))
}
55 changes: 53 additions & 2 deletions cloud-backups/internal/orchestrator/backup_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -72,7 +72,7 @@ func TestPGSuffixContract(t *testing.T) {
t.Errorf("OCI suffix must not contain .dump: %q", ociSuffix)
}

// PG suffix is .dump (or .dump.age) no gzip layer at all.
// PG suffix is .dump (or .dump.age) - no gzip layer at all.
pgSuffixPlain := ".dump"
pgSuffixEnc := ".dump.age"
for _, s := range []string{pgSuffixPlain, pgSuffixEnc} {
Expand Down Expand Up @@ -137,7 +137,7 @@ func TestResolveTargets_RollingProducesCurrentAndPreviousMonth(t *testing.T) {
t.Fatalf("got %d paths, want 2", len(got))
}
// Both should be distinct (different months, unless we're on the 1st of the month
// and it wraps but even then the function produces two entries)
// and it wraps - but even then the function produces two entries)
if got[0] == got[1] {
// This can happen on the 1st of the month when prev == current month boundary edge case
// Just verify both are present and have month suffix
Expand Down Expand Up @@ -236,3 +236,54 @@ func TestRunBackups_ContextCancelled(t *testing.T) {
total := tracker.GetTotal()
_ = total
}

// Under rolling months only the PREVIOUS-month target may legitimately be
// absent. The current month is being actively written, so treating its absence
// as expected would let a deleted or renamed repo pass as a healthy run -- the
// exact silent-gap this predicate exists to close.
func TestSkipIsExpected(t *testing.T) {
now := time.Date(2026, 8, 14, 3, 35, 0, 0, time.UTC)

tests := []struct {
name string
target string
rollingMonths bool
want bool
}{
{"previous month under rolling months", "rearm-artifacts/rebom-artifacts-2026-07", true, true},
{"current month under rolling months", "rearm-artifacts/rebom-artifacts-2026-08", true, false},
{"unrelated month under rolling months", "rearm-artifacts/rebom-artifacts-2026-05", true, false},
{"previous month under explicit paths", "rearm-artifacts/rebom-artifacts-2026-07", false, false},
{"explicit path", "rearm-artifacts/rebom-artifacts", false, false},
}

for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
if got := SkipIsExpected(tc.target, tc.rollingMonths, now); got != tc.want {
t.Errorf("SkipIsExpected(%q, %v): got %v want %v", tc.target, tc.rollingMonths, got, tc.want)
}
})
}
}

// The suffix must match what resolveTargets actually builds, or the predicate
// would exempt nothing and re-open the noise it is meant to avoid. January is
// the case naive month arithmetic gets wrong.
func TestPreviousMonthSuffix_CrossesYearBoundary(t *testing.T) {
if got := PreviousMonthSuffix(time.Date(2026, 1, 5, 0, 0, 0, 0, time.UTC)); got != "2025-12" {
t.Errorf("January must roll back to the previous December, got %q", got)
}

m := &BackupManager{}
now := time.Date(2026, 1, 5, 0, 0, 0, 0, time.UTC)
targets := m.resolveTargets([]string{"repo"}, true)
// resolveTargets uses time.Now(); assert the shape it produces agrees with
// the helper for the same instant rather than pinning a wall-clock date.
if len(targets) != 2 {
t.Fatalf("expected current+previous targets, got %v", targets)
}
if !strings.HasSuffix(targets[1], "-"+PreviousMonthSuffix(time.Now().UTC())) {
t.Errorf("second target %q must carry the previous-month suffix used by SkipIsExpected", targets[1])
}
_ = now
}
147 changes: 133 additions & 14 deletions cloud-backups/internal/pipeline/stream.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,10 @@ import (
const (
MaxBackupAttempts = 3
DefaultTimeout = 2 * time.Hour
// MaxCauseLength bounds a single attempt's cause inside an aggregated log
// field, so an alert payload stays ingestible. Generous enough to keep the
// failing URL and the tool's error line, which is what identifies the fault.
MaxCauseLength = 2000
)

var (
Expand All @@ -41,50 +45,165 @@ func RunWithRetry(ctx context.Context, src datasource.Source, storeProvider stor
}
}()

var attemptErrs []string

for attempt := 1; attempt <= MaxBackupAttempts; attempt++ {
if ctx.Err() != nil {
return
}
slog.Info("backup_started", "target", target, "attempt", attempt)
bytesUploaded, err := executeStream(ctx, src, storeProvider, target, backupName, nameSuffix, writerModifiers, timeout, deterministicName, totalHint)
if err == nil {
// A target that needed a retry recovered on its own, so it is not
// operator-actionable and must not alert. It is still worth a line,
// because a repeatedly flaky registry shows up here first.
if len(attemptErrs) > 0 {
slog.Warn("backup_recovered_after_retry", "target", target, "attempts_used", attempt,
"earlier_failures", strings.Join(attemptErrs, " | "))
}
slog.Info("backup_successful", "target", target, "duration", time.Since(startTimer).Round(time.Second).String(), "size_human", stats.FormatBytes(bytesUploaded))
jobHandled = true
tracker.RecordSuccess()
tracker.AddBytes(bytesUploaded)
return
}
// FAST-FAIL ON UNAUTHORIZED
if strings.Contains(err.Error(), "unauthorized") || strings.Contains(err.Error(), "authentication required") {
slog.Error("fatal_authentication_error", "target", target, "msg", "Credentials rejected. Halting retries.")
if isAuthRejection(err) {
// "detail", not "msg": slog's JSON handler already emits the event
// name as "msg", and a second "msg" attr is written verbatim, so
// every JSON parser in the alerting path keeps the LAST one and the
// event name never survives parsing.
slog.Error("fatal_authentication_error", "target", target, "detail", "Credentials rejected. Halting retries.",
"error", TruncateCause(err.Error()))
jobHandled = true
tracker.RecordFailure(target)
return // Exit immediately, do not wait for backoff
}

if strings.Contains(err.Error(), "repository name not known to registry") {
// An absent repository is a legitimate skip, but only if it is the
// FIRST thing we saw. Reaching here after an attempt already failed
// for another reason means the classification is suspect (it is a
// substring match on a log tail), and swallowing it would retire the
// target with no ERROR at all. Surface those earlier causes.
if len(attemptErrs) > 0 {
slog.Error("repository_not_found_after_failed_attempts", "target", target,
"detail", "classified as absent only after earlier attempts failed; treat the absence as unconfirmed",
"error", strings.Join(attemptErrs, " | "))
}
slog.Warn("repository_not_found_skipping", "target", target)
jobHandled = true
tracker.RecordSkipped(target)
return
}

slog.Error("backup_attempt_failed", "target", target, "attempt", attempt, "error", err.Error())
// WARN, not ERROR: this attempt may still be retried, and operator
// alerting fires on ERROR. A transient registry blip that the next
// attempt recovers from is not an incident, and paging on it trains
// operators to ignore the channel. The single ERROR for a target that
// really did fail is backup_exhausted below.
attemptErrs = append(attemptErrs, fmt.Sprintf("attempt %d: %s", attempt, TruncateCause(err.Error())))
slog.Warn("backup_attempt_failed", "target", target, "attempt", attempt, "error", err.Error())
if attempt < MaxBackupAttempts {
backoff := RetryBackoffBase * time.Duration(1<<uint(attempt))
if backoff > MaxBackoffDuration {
backoff = MaxBackoffDuration
}
timer := time.NewTimer(backoff)
select {
case <-ctx.Done():
timer.Stop()
if !waitBackoff(ctx, attempt) {
// Abandoned mid-retry. PrintSummary will report the target as
// failed, but only the causes we collected explain WHY, and they
// are otherwise WARN-only -- invisible where alerting is
// ERROR-only. Emit them before giving up.
slog.Error("backup_abandoned", "target", target, "attempts_used", len(attemptErrs),
"detail", "run cancelled before the retries were exhausted",
"error", strings.Join(attemptErrs, " | "))
return
case <-timer.C:
}
}
}
slog.Error("backup_exhausted", "target", target)
// Carry every attempt's cause, because this is the only ERROR the operator
// sees for a failed target and an empty one is unactionable.
slog.Error("backup_exhausted", "target", target, "attempts_used", len(attemptErrs),
"error", strings.Join(attemptErrs, " | "))
}

// isAuthRejection reports whether the registry refused the credentials, in which
// case retrying cannot help. Matching on error text is this module's established
// idiom (see internal/registry/oras.go); the point of the helper is that the
// backup and preflight drivers share ONE definition of the predicate.
func isAuthRejection(err error) bool {
if err == nil {
return false
}
msg := err.Error()
return strings.Contains(msg, "unauthorized") || strings.Contains(msg, "authentication required")
}

// TruncateCause bounds one attempt's cause before it goes into an aggregated
// log field. A cause carries the tail of the backup tool's own output (an 8KB
// tailBuffer), and backup_exhausted joins one per attempt -- unbounded, that is
// a single ~24KB field, which alerting backends truncate at an arbitrary point
// or reject outright.
//
// Keep the TAIL, not the head. The upstream buffer is already a tail buffer
// precisely because these tools print their diagnostic last, after progress
// chatter: `oras` ends with "Error: failed to ...". Head-truncating a tail
// buffer throws away the only line that names the fault and keeps the progress
// noise, so the surviving ERROR says nothing.
func TruncateCause(cause string) string {
if len(cause) <= MaxCauseLength {
return cause
}
// ToValidUTF8 because the cut can land mid-rune, and an invalid byte becomes
// U+FFFD once the record is JSON-encoded -- corruption that reads like a bug
// in the failure itself.
tail := strings.ToValidUTF8(cause[len(cause)-MaxCauseLength:], "")
return fmt.Sprintf("(truncated, %d bytes total, showing last %d) ...", len(cause), MaxCauseLength) + tail
}

// waitBackoff sleeps the exponential backoff for the just-failed attempt.
// It reports false when ctx was cancelled while waiting, meaning the caller
// should give up rather than start another attempt.
func waitBackoff(ctx context.Context, attempt int) bool {
backoff := RetryBackoffBase * time.Duration(1<<uint(attempt))
if backoff > MaxBackoffDuration {
backoff = MaxBackoffDuration
}
timer := time.NewTimer(backoff)
defer timer.Stop()
select {
case <-ctx.Done():
return false
case <-timer.C:
return true
}
}

// RunPreflightWithRetry probes the source with the same bounded retry/backoff a
// backup attempt gets. Preflight gates the WHOLE run, so without this a single
// transient network failure on one probe aborts every target with no retry at
// all -- a strictly worse outcome than the per-target failure it exists to
// prevent. Credential rejections still fail fast, since retrying cannot help.
func RunPreflightWithRetry(ctx context.Context, src datasource.Source, target string) error {
var lastErr error
for attempt := 1; attempt <= MaxBackupAttempts; attempt++ {
if ctx.Err() != nil {
return ctx.Err()
}
lastErr = src.PreflightCheck(ctx, target)
if lastErr == nil {
return nil
}
if isAuthRejection(lastErr) {
return lastErr
}
// Raw, not truncated: this is WARN and stays in the pod log, where the
// full detail is worth having. Truncation belongs on the ERROR that
// leaves the pod and lands in an alert payload.
slog.Warn("preflight_attempt_failed", "target", target, "attempt", attempt, "error", lastErr.Error())
if attempt < MaxBackupAttempts {
if !waitBackoff(ctx, attempt) {
return lastErr
}
}
}
return lastErr
}

func executeStream(parentCtx context.Context, src datasource.Source, storeProvider storage.Provider, target, backupName, nameSuffix string, writerModifiers []WriterModifier, timeout time.Duration, deterministicName bool, totalHint int64) (int64, error) {
Expand Down Expand Up @@ -179,7 +298,7 @@ func RunRestore(ctx context.Context, src datasource.Source, storeProvider storag
pipeR, pipeW := io.Pipe()
errChan := make(chan error, 1)

// 2. Goroutine: download apply reader modifiers write to pipeW
// 2. Goroutine: download -> apply reader modifiers -> write to pipeW
go func() {
var gErr error
defer func() {
Expand Down
Loading
Loading