fix(cloud-backups): stop paging on self-healing backup retries - #14
Conversation
The oci-artifacts-backup CronJob alerted on a customer prod instance on 2026-08-08. Investigation showed the backup never actually failed: attempt 1 died on a refused TCP dial to the ACR private endpoint during tag pagination, and attempt 2 completed the upload. The alert fired only because backup_attempt_failed was logged at ERROR, and the operator's rule pages on any level=ERROR. Only ERROR-level logs leave the pod, so the successful outcome was invisible and every blip read as an outage. Underneath, `oras backup` aborts a whole repo on one ECONNREFUSED: oras-go's retry predicate retries dial TIMEOUTS only, so a refused connection is never retried (reproduced against a fake ACR paginator; a reset, a 429 and a 500 injected at the same point all recover). The tool's own 3x retry already absorbs that, so the registry behaviour is left alone and the reporting is fixed instead. Alerting levels: - backup_attempt_failed drops to WARN while a retry remains. The single ERROR for a target that really failed is backup_exhausted, which now carries attempts_used and every attempt's cause -- it previously had no error field at all, so a genuine give-up alerted with a blank cause. - New WARN backup_recovered_after_retry, so a repeatedly flaky registry is still visible without paging. - pipeline_completed_with_failures and pipeline_failed_all_repos_missing gained a flat error field naming the targets; the failing paths were only inside a nested summary map, which alerting renders opaquely. - Both sites used "msg" as an attr key. slog's JSON handler already emits the event name as "msg", so the record carried a duplicate key and every JSON parser kept the last one -- the event name never survived parsing. Renamed to "detail". - Causes are truncated per attempt (MaxCauseLength) before being joined, bounding what was a ~24KB single field, and PreflightCheck's stderr now uses a tailBuffer like its Backup/Restore siblings instead of an unbounded builder. Behaviour: - PreflightCheck ran outside the retry loop, so the same transient failure landing on the probe aborted the entire job for every target with no retry at all. It now shares the backup retry/backoff via RunPreflightWithRetry, with the auth fast-fail preserved. - Under explicit registry paths, a skipped (absent) repository is now an ERROR. PrintSummary only escalates when EVERY target is missing, so 49 of 50 could vanish at INFO with exit 0. Rolling months stays exempt, since it deliberately fabricates a previous-month path that legitimately may not exist yet. Verified end to end against a local rig reproducing the exact production error (fake ACR Link-header pagination + oras 1.3.3 + minio): the Aug-8 scenario now emits zero ERROR lines, a preflight refusal survives, and a sustained refusal emits exactly two ERRORs that name the target and the causes. New tests pin the level of all five terminal outcomes and are mutation-checked -- reverting each guarantee fails its test. Co-Authored-By: Claude <noreply@anthropic.com> ReARM-Agent: 1420896f-adf5-4843-896f-d863cfcc6528 ReARM-Agentic-Session: 94afdb9d-05d3-44ad-abcd-92e753ddf2df
…review
Four independent review lenses were run against the previous commit, each
blind to the others. One REFUTED its central safety claim with a
reproducible counterexample, and the others found defects the first
commit introduced. All of the following are proven by execution, not
inspection.
The counterexample: a repository can be silently skipped, producing no
backup, no ERROR and exit 0. `repositoryAbsent` classified any log tail
containing bare "404" as "repository does not exist". Content digests are
hex and contain "404" in ~1.5% of cases, so a refused dial on a repo with
enough blobs in the 8KB tail was misread as an absence -- the same
ECONNREFUSED that started this investigation. The skip then set
jobHandled, bypassed the remaining retries, and under the shipped
appendRollingMonths=true default produced pipeline_completed_successfully.
- repositoryAbsent now vetoes the classification on any transport marker
(connection refused/reset, dial tcp, i/o timeout, no such host, TLS
handshake, unexpected EOF, deadline exceeded), matches
case-insensitively, and recognises the canonical distribution error
("name unknown"). The case-sensitivity gap was also making preflight
abort entire runs against distribution-compatible registries, verified
live -- the previous commit's preflight retry merely made that failure
60s slower.
- A skip that lands AFTER an attempt already failed for another reason is
now an ERROR carrying the earlier causes, since the absence is
unconfirmed.
- The rolling-months exemption for missing targets was too broad: it
exempted the whole run, but only the PREVIOUS-month target may
legitimately be absent. The current month is being actively written.
orchestrator.SkipIsExpected now decides this, sharing the date
arithmetic with resolveTargets rather than re-deriving it.
Regressions the previous commit introduced, now fixed:
- TruncateCause kept the HEAD of what is already a TAIL buffer. These
tools print their diagnostic last, so the surviving ERROR contained
upload progress noise and the line naming the fault was dropped -
exactly inverting the intent. It now keeps the tail.
- PreflightCheck was switched to a tailBuffer, but its output is what the
absence/auth predicates match on, so bounding it changed CLASSIFICATION,
not just message size. Reverted; the surfaced string is bounded at the
call site instead, where it is display-only.
- The missing-targets ERROR counted len(skipped), a slice capped at
MaxPathsTracked=100, so 150 skips of 200 reported "100 of 200".
- PrintSummary joined those same capped lists with no marker, and pg
audit-rotate records the database name once per archive, so the field
read "3 of 3 target(s) failed: rearm, rearm, rearm". formatPaths now
dedupes and discloses truncation.
- Abandoning mid-retry (context cancelled during backoff) returned
silently; the causes were WARN-only and therefore invisible. Now emits
backup_abandoned at ERROR.
- pipeline_failed_all_repos_missing and backup_targets_missing_from_registry
both fired for the all-skipped case. Deduplicated.
Everything added outside internal/pipeline previously had no tests, which
is why the cap bug got through. Added coverage for repositoryAbsent (both
directions), SkipIsExpected, PreviousMonthSuffix across a year boundary,
formatPaths, GetSkipped aliasing, and the three new ERROR paths.
Verified end to end on the rig: the Aug-8 transient refusal still emits
zero ERRORs; an absent CURRENT-month repo now emits one ERROR naming it;
an absent previous-month repo stays silent; a sustained refusal emits two
ERRORs carrying the causes. go test -race clean.
Reviewed but deliberately NOT fixed here, filed separately: encryption
silently disabled when the optional secret key is absent (writes a
plaintext backup, exit 0); no dead man's switch; a panic in the upload
goroutine escapes the recover(); ~36h worst-case time-to-first-ERROR.
Co-Authored-By: Claude <noreply@anthropic.com>
ReARM-Agent: 1420896f-adf5-4843-896f-d863cfcc6528
ReARM-Agentic-Session: 94afdb9d-05d3-44ad-abcd-92e753ddf2df
Adversarial validation: four independent lenses, one refutationRan four blind review lenses against 2714bb3 to check the central risk of this PR -- that demoting per-attempt failures to WARN hides real errors. One refuted the safety claim with a reproducible counterexample. 8c4f644 fixes everything found. The counterexample (now closed)A repository could be silently skipped: no backup, no ERROR, exit 0. Measured collision probability: 26% for a repo with ~130 blobs in the tail, 69% at 500. Fixed by vetoing the absence classification on any transport marker, matching case-insensitively, and recognising the canonical distribution error ( Regressions this PR had introduced
Blast radius: PG lane verified safe
Rig results after the fixes
Filed separately, NOT in this PR
|
Follow-up: yesterday's alert was a false positive from this branch, now fixed (ae37f86)The guard added here fired on prod for Why. Under rolling months the tool does no discovery -- it fabricates Fix. Alert per base path, not per target: did this base path produce any backup? One month absent is indistinguishable from a quiet month; a base path producing nothing is unambiguous and is what a renamed/deleted/mistyped path looks like. Explicit paths expand to one target each, so the strict behaviour there is preserved by construction rather than by a special case. On the existence check. Rejected as unreachable, not merely undesirable. Telling "never created" from "deleted" needs state the credentials don't contain: the registry can't enumerate repositories without catalogue scope, and the destination can't be read back under the write-only credential Worth recording for whoever revisits this: on Azure the write-only ideal in the Verified on the rig against the production shape (rebom both months, downloadable previous month only):
|
1 participant
What happened
The
oci-artifacts-backupCronJob alerted on a customer prod instance on 2026-08-08:No backup was lost. The alert carried
attempt = 1, and nobackup_exhaustedorpipeline_completed_with_failuresfollowed it. Attempt 2 completed the upload. The alert fired onlybecause
backup_attempt_failedwas logged at ERROR and the operator's rule pages on anylevel=ERROR. Since only ERROR-level logs leave the pod, the successful outcome was invisible andevery transient blip read as an outage. There was no fix on 2026-08-01 either: the only change was
an image roll whose cloud-backups delta is the audit-rotate refactor, so the repeat was expected.
Root cause underneath
oras backupaborts an entire repo on a single un-retriedECONNREFUSEDduring tag enumeration.oras-go's retry predicate (
registry/remote/retry/policy.go) retries dial timeouts only:ECONNREFUSEDhasTimeout() == false, so it gives up after one dial. Reproduced against a fakeACR paginator emitting the same
Link: rel="next"header, fault-injecting on page 2:The tool's own 3x retry already absorbs this, so this PR leaves the registry behaviour alone and
fixes the reporting instead.
Changes
Alerting levels
backup_attempt_faileddrops to WARN while a retry remains.backup_exhaustedbecomes the singleERROR for a target that really failed, and now carries
attempts_usedplus every attempt's cause(it previously had no
errorfield, so a genuine give-up alerted with a blank cause).backup_recovered_after_retry, so a repeatedly flaky registry stays visible without paging.pipeline_completed_with_failures/pipeline_failed_all_repos_missinggained a flaterrorfield naming the targets; the failing paths lived only inside a nested
summarymap."msg"as an attr key. slog's JSON handler already emits the event name asmsg, so the record carried a duplicate key and every JSON parser keeps the last one -- the eventname never survived parsing, which defeated the point of adding a flat field. Renamed to
detail.PreflightCheckstderr now uses atailBufferlike itsBackup/Restoresiblings rather than anunbounded builder.
Behaviour
PreflightCheckran outside the retry loop, so the same transient failure landing on the probeaborted the whole job for every target with zero retries. Now shares the backup retry/backoff via
RunPreflightWithRetry, auth fast-fail preserved.PrintSummaryonlyescalates when every target is missing, so 49 of 50 could vanish at INFO with exit 0. Rolling
months stays exempt: it deliberately fabricates a previous-month path that may legitimately not
exist yet, and alerting on that would recreate the noise this PR removes.
Verification
End-to-end against a local rig reproducing the exact production failure (fake ACR
Link-headerpagination + oras 1.3.3 +
registry:2+ minio, realcloud-backupbinary):New tests pin the level of all five terminal outcomes (table-driven) and guard against reintroducing
the duplicate-
msgkey. All are mutation-checked: reverting each guarantee fails its test.go build/go vet/go test ./...green,gofmtclean, added lines pure ASCII.Review
Two-layer self-review gate run before this PR. Layer 2 (conventions) found the duplicate-
msgbug,the duplicated auth predicate, and that truncation had been applied to the WARN path while the ERROR
path stayed raw -- all fixed here. Not run:
/security-review, since this touches no auth, secrets,input handling or crypto (the aggregated
errorfield carries the same tool output already loggedper attempt, so it is no new exposure).
Deliberately out of scope
cmd/pg_backup.go:113andcmd/pg_audit_rotate.go:137callPreflightCheckwith the identicalno-retry structure. Not touched here:
pg audit-rotateis the rotate-backup-drop path andwidening this PR into a destructive lane I have not validated is not worth it. Worth a follow-up.
oras's tag phase resumable or batched, which would make an ECONNREFUSED survivable withina single attempt rather than costing a full restart. That is a real redesign.
refused the redial. It is environmental and currently self-heals within ~20s.
🤖 Generated with Claude Code