From 6a1e2d0d0695fba379fc7b8fa2e0515feb2e4395 Mon Sep 17 00:00:00 2001 From: Andrey Kolkov Date: Tue, 21 Jul 2026 10:13:03 +0400 Subject: [PATCH 1/3] feat(backups): support PostgreSQL point-in-time recovery (PITR) Makes RestoreJob.spec.options.recoveryTime a genuinely supported, tested capability for the new backups.cozystack.io API (issue #2774). The recoveryTime -> CNPG bootstrap.recovery.recoveryTarget.targetTime plumbing already existed on the barman-cloud-plugin branch; this adds the reliability and verification layer the issue asked for: - Fail-fast for an unreachable target: when a RestoreJob has recoveryTime set and the recovery Cluster is not healthy, the driver reads the CNPG full-recovery pod logs and, once several distinct attempts have exited with PostgreSQL's "recovery ended before configured recovery target was reached" FATAL, fails the RestoreJob with conditions RecoveryConverged=False / Ready=False (reason RecoveryTargetUnreachable) instead of hanging to the restore deadline. Health is checked first, so a converged recovery always wins; counting distinct FATAL-ing attempts (not pod failures) tolerates a transient archive-lag miss on a near-now target and ignores transient recovery-pod crashes. Adds the pods/log RBAC grant the log read requires. - e2e (examples/backups/postgres/run-all.sh, wired into the Chainsaw postgres-2-backup-roundtrip suite): step 45 writes a before marker, captures the server timestamp, writes an after marker, restores to that timestamp and asserts the before row survived and the after row did not; step 46 submits a recoveryTime an hour ahead and asserts it fails fast with reason RecoveryTargetUnreachable. - Working, uncommented example (45-restorejob-pitr.yaml) and a docs section (docs/operations/backup-classes.md) covering the recoverable window, how to discover the earliest/latest restorable time from the backup catalog, the archive-lag tolerance, and idempotency under GitOps. Refs #2774 Co-Authored-By: Claude Opus 4.8 (1M context) Signed-off-by: Andrey Kolkov --- docs/operations/backup-classes.md | 57 ++++ examples/backups/postgres/00-helpers.sh | 6 + .../postgres/35-restorejob-in-place.yaml | 7 +- .../backups/postgres/45-restorejob-pitr.yaml | 34 ++ examples/backups/postgres/README.md | 3 +- examples/backups/postgres/cleanup.sh | 8 +- examples/backups/postgres/run-all.sh | 138 +++++++- hack/e2e-chainsaw/postgres/chainsaw-test.yaml | 36 +- .../cnpgstrategy_controller.go | 239 ++++++++++++- .../cnpgstrategy_controller_test.go | 320 ++++++++++++++++++ .../backupcontroller/restorejob_controller.go | 28 +- .../templates/rbac.yaml | 8 + 12 files changed, 860 insertions(+), 24 deletions(-) create mode 100644 examples/backups/postgres/45-restorejob-pitr.yaml diff --git a/docs/operations/backup-classes.md b/docs/operations/backup-classes.md index 322386db4..05642add1 100644 --- a/docs/operations/backup-classes.md +++ b/docs/operations/backup-classes.md @@ -199,3 +199,60 @@ spec: kind: Postgres name: orders-db ``` + +## Point-in-time recovery (PostgreSQL) + +A `RestoreJob` restores a `Postgres` application from a `Backup`. Omit `spec.options.recoveryTime` to recover to the latest point in the WAL archive; set it (RFC3339) to recover the database to an exact instant — a point-in-time recovery (PITR). Under the hood the CNPG barman-cloud plugin restores the newest base backup taken at/before that instant and replays archived WAL up to it, so the restored cluster reflects the database exactly as of `recoveryTime`; later writes are absent. + +```yaml +apiVersion: backups.cozystack.io/v1alpha1 +kind: RestoreJob +metadata: + name: orders-db-pitr + namespace: tenant-acme +spec: + backupRef: + name: orders-db-adhoc # a completed Backup of the source + targetApplicationRef: # omit for a destructive in-place restore + apiGroup: apps.cozystack.io + kind: Postgres + name: orders-db-copy # a pre-deployed, empty Postgres app + options: + recoveryTime: "2026-07-21T09:30:00Z" +``` + +A full, scripted example (write a marker, capture the timestamp, restore to it, assert what survived) is in [`examples/backups/postgres/`](../../examples/backups/postgres/) — `45-restorejob-pitr.yaml`, driven by `run-all.sh`. + +### The recoverable window + +`recoveryTime` must fall inside the window the archive can reconstruct: + +- **Earliest** — the completion of the oldest base backup still in the archive. You cannot recover to an instant before the first base backup: WAL replay always starts from a base backup, and retention (`barmanObjectStore.retentionPolicy`) eventually trims the oldest ones together with the WAL that predates them. +- **Latest** — the timestamp of the most recent WAL segment shipped to object storage. While the source runs with `backup.enabled: true` it archives continuously, so the latest restorable time trails "now" only by the archive lag (seconds for a healthy cluster). Once the source is deleted, the latest restorable time is frozen at whatever WAL made it to S3 before it went away. + +A `recoveryTime` **past the latest archived WAL cannot converge**: PostgreSQL replays every available WAL, never reaches the target, exits with `FATAL: recovery ended before configured recovery target was reached`, and CNPG re-creates the recovery instance in a loop. Such a wedged restore is failed by the restore deadline (`spec.options.restoreTimeoutSeconds`, default 30m) — and the driver reads the recovery pod's log at that point, so instead of a generic timeout the RestoreJob ends `status.phase: Failed` with conditions `RecoveryConverged=False` and `Ready=False`, both reason `RecoveryTargetUnreachable`, and a message naming the target. The driver deliberately does **not** fail earlier off that FATAL: a *reachable* near-now target hits the identical FATAL transiently — often repeatedly, on a slow archiver — before it converges, so an earlier trip would reject a recoverable restore. To reject an unreachable target quickly, set a short `restoreTimeoutSeconds`; otherwise widen the window (take a fresh backup, or restore closer to now) or pick a time inside it. + +Restoring to a **very recent** instant is safe as long as WAL archiving is current: the segment covering the target may not be in object storage yet and the same FATAL fires transiently, but because the driver only fails at the deadline (not on that FATAL), the recovery has the whole window to catch up — the next attempt promotes once the WAL ships and the cluster goes healthy, which completes the restore. Only a target that never becomes reachable within the deadline is failed. If archiving is badly behind (a stalled `archive_command`, an overloaded cluster) a near-now target can exceed even the default 30m window; restore to a point you can confirm is archived (e.g. at/before the most recent completed backup, per the discovery query below). + +A `recoveryTime` **before the earliest base backup** fails differently: PostgreSQL cannot begin replay before the base backup it restored, so recovery never reaches a consistent state and never emits the "recovery ended before …" FATAL the driver classifies on. That case also surfaces at the deadline, but with the generic reason `RestoreFailed` rather than `RecoveryTargetUnreachable`. Choosing a `recoveryTime` at/after the oldest base backup's completion (below) avoids it. + +### Discovering the earliest / latest restorable time + +CNPG's `Cluster.status.firstRecoverabilityPoint` exists in the status schema but is unreliable under the barman-cloud plugin — it was observed empty on every plugin-backed cluster on the dev7 test cluster (CNPG 1.28.1) — so read the window from the backup catalog instead. Each completed base backup records its WAL range and timestamps on the underlying `cnpg.io/Backup`: + +```bash +# Completed base backups, oldest first: STOP is the earliest instant that +# backup alone can restore to; the oldest STOP is the window's lower bound. +kubectl -n get backups.postgresql.cnpg.io \ + --sort-by=.status.stoppedAt \ + -o custom-columns=NAME:.metadata.name,PHASE:.status.phase,START:.status.startedAt,STOP:.status.stoppedAt,BEGINWAL:.status.beginWal,ENDWAL:.status.endWal + +# The cozystack Backup points at its underlying cnpg.io/Backup and S3 prefix. +kubectl -n get backup.backups.cozystack.io -o jsonpath='{.spec.driverMetadata}' +``` + +The upper bound — the latest archived WAL — is whatever the source has shipped so far; with archiving healthy, any time up to a few seconds ago is safe. To confirm the archive is current, check that the source cluster's WAL is flowing to S3 (the `barman-cloud` sidecar logs an upload per segment) before restoring to a near-now target. + +### Idempotency under GitOps + +An in-progress restore is safe to reconcile. The driver purges the target `Cluster` + PVCs exactly once per RestoreJob (guarded by the `TargetPurged` condition and a freshly-recovered check), suspends the target's HelmRelease across the purge so Flux cannot race the bootstrap swap, and resumes it once the recovery cluster is rendered. A Flux reconcile (or a controller restart) mid-restore therefore re-attaches to the recovering cluster rather than deleting it and starting over. diff --git a/examples/backups/postgres/00-helpers.sh b/examples/backups/postgres/00-helpers.sh index dad22bebc..ce33f6e44 100755 --- a/examples/backups/postgres/00-helpers.sh +++ b/examples/backups/postgres/00-helpers.sh @@ -24,7 +24,13 @@ export PG_TARGET_CLUSTER="postgres-${PG_TARGET_NAME}" export STRATEGY_NAME="${STRATEGY_NAME:-cnpg-strategy-default}" export BACKUPCLASS_NAME="${BACKUPCLASS_NAME:-postgres-cnpg}" export BACKUPJOB_NAME="${BACKUPJOB_NAME:-pg-src-adhoc}" +# A second ad-hoc BackupJob taken after the PITR marker writes; its completion +# is the deterministic "WAL past the recovery target is archived" gate for the +# point-in-time restore (see run-all.sh step 45). +export BACKUPJOB_POSTMARKER_NAME="${BACKUPJOB_POSTMARKER_NAME:-pg-src-postmarker}" export RESTOREJOB_TOCOPY_NAME="${RESTOREJOB_TOCOPY_NAME:-pg-src-to-pg-target}" +export RESTOREJOB_PITR_NAME="${RESTOREJOB_PITR_NAME:-pg-src-to-pg-target-pitr}" +export RESTOREJOB_UNREACHABLE_NAME="${RESTOREJOB_UNREACHABLE_NAME:-pg-src-to-pg-target-unreachable}" export PLAN_NAME="${PLAN_NAME:-pg-src-daily}" # App user password baked into 05-postgres-src.yaml (REPLACE_WITH_PASSWORD). export PG_PASSWORD="${PG_PASSWORD:-Xai7Wepo0aeThie8}" diff --git a/examples/backups/postgres/35-restorejob-in-place.yaml b/examples/backups/postgres/35-restorejob-in-place.yaml index 2c04abc5a..16d7253e7 100644 --- a/examples/backups/postgres/35-restorejob-in-place.yaml +++ b/examples/backups/postgres/35-restorejob-in-place.yaml @@ -2,7 +2,12 @@ # back into pg-src. WARNING: deletes the live cnpg.io Cluster and its PVCs # before re-bootstrapping from S3 - any data not yet streamed to WAL is lost. # -# Optional: spec.options.recoveryTime (RFC3339) for point-in-time recovery. +# Optional: spec.options.recoveryTime (RFC3339) turns this into a point-in-time +# recovery, same as the to-copy variant in 45-restorejob-pitr.yaml (which the +# e2e drives with a real, in-window timestamp). Uncomment and set a timestamp +# inside your recoverable window - see 45-restorejob-pitr.yaml and +# docs/operations/backup-classes.md ("Point-in-time recovery") for how to find +# the earliest/latest restorable time. --- apiVersion: backups.cozystack.io/v1alpha1 kind: RestoreJob diff --git a/examples/backups/postgres/45-restorejob-pitr.yaml b/examples/backups/postgres/45-restorejob-pitr.yaml new file mode 100644 index 000000000..7c9434f0c --- /dev/null +++ b/examples/backups/postgres/45-restorejob-pitr.yaml @@ -0,0 +1,34 @@ +# Point-in-time recovery (PITR) to a copy. +# +# Restores the source's Barman archive into pg-target as of a specific instant +# via spec.options.recoveryTime (RFC3339). The chart maps it onto CNPG's +# bootstrap.recovery.recoveryTarget.targetTime: PostgreSQL restores the newest +# base backup taken at/before that instant and replays archived WAL up to it, +# so the copy reflects the database exactly as of recoveryTime - later writes +# are absent. +# +# recoveryTime MUST fall inside the recoverable window: at/after the base +# backup's completion and at/before the latest WAL shipped to object storage. +# A target past the latest archived WAL cannot converge - the RestoreJob fails +# with condition Ready=False/RecoveryTargetUnreachable instead of hanging. See +# docs/operations/backup-classes.md ("Point-in-time recovery") for how to +# discover the earliest/latest restorable time. +# +# run-all.sh substitutes REPLACE_WITH_RECOVERY_TIME with a timestamp it captures +# between two marker writes, then asserts the pre-marker row is present and the +# post-marker row is absent. Editing by hand, replace it with an RFC3339 +# timestamp inside your window, e.g. "2026-05-01T12:00:00Z". +--- +apiVersion: backups.cozystack.io/v1alpha1 +kind: RestoreJob +metadata: + name: pg-src-to-pg-target-pitr +spec: + backupRef: + name: pg-src-adhoc + targetApplicationRef: + apiGroup: apps.cozystack.io + kind: Postgres + name: pg-target + options: + recoveryTime: "REPLACE_WITH_RECOVERY_TIME" diff --git a/examples/backups/postgres/README.md b/examples/backups/postgres/README.md index c7b759110..008c3e42f 100644 --- a/examples/backups/postgres/README.md +++ b/examples/backups/postgres/README.md @@ -14,6 +14,7 @@ The numbered manifests are the documented flow; a human can read and apply them - `25-backupjob-adhoc.yaml` — an ad-hoc `BackupJob`. - `30-postgres-target.yaml` + `40-restorejob-to-copy.yaml` — restore into a fresh copy, leaving the source running. - `35-restorejob-in-place.yaml` — the destructive in-place restore variant. +- `45-restorejob-pitr.yaml` — point-in-time recovery: restore into the copy as of a specific `spec.options.recoveryTime` (RFC3339). ## Placeholders and derived Secrets @@ -30,7 +31,7 @@ NAMESPACE=tenant-root examples/backups/postgres/run-all.sh NAMESPACE=tenant-root examples/backups/postgres/cleanup.sh ``` -`run-all.sh` writes a sentinel row into the source, waits for the `BackupJob` to reach `Succeeded`, restores to a copy, and asserts the sentinel round-tripped through S3 into the restored copy. Set `SKIP_RESTORE=1` to stop after a successful backup. +`run-all.sh` writes a sentinel row into the source, waits for the `BackupJob` to reach `Succeeded`, restores to a copy, and asserts the sentinel round-tripped through S3 into the restored copy. It then runs a **point-in-time recovery**: it writes a `before` marker, captures the server timestamp, writes an `after` marker, and restores the copy to that timestamp (`45-restorejob-pitr.yaml`), asserting the `before` row survived and the `after` row did not. Finally it submits a RestoreJob with a `recoveryTime` an hour in the future and asserts it **fails fast** with `status.phase: Failed` and reason `RecoveryTargetUnreachable` (rather than hanging to the restore deadline). Set `SKIP_RESTORE=1` to stop after a successful backup, or `SKIP_PITR=1` to stop after the latest-point restore. ## Automated e2e diff --git a/examples/backups/postgres/cleanup.sh b/examples/backups/postgres/cleanup.sh index 7046163da..e87487539 100755 --- a/examples/backups/postgres/cleanup.sh +++ b/examples/backups/postgres/cleanup.sh @@ -20,12 +20,14 @@ for app in "$PG_SRC_NAME" "$PG_TARGET_NAME"; do fi done -log_substep "Deleting RestoreJob..." -kubectl -n "$NAMESPACE" delete restorejob.backups.cozystack.io "$RESTOREJOB_TOCOPY_NAME" --ignore-not-found +log_substep "Deleting RestoreJobs..." +kubectl -n "$NAMESPACE" delete restorejob.backups.cozystack.io \ + "$RESTOREJOB_TOCOPY_NAME" "$RESTOREJOB_PITR_NAME" "$RESTOREJOB_UNREACHABLE_NAME" --ignore-not-found log_substep "Deleting Plan + BackupJob + derived Backup artefacts..." kubectl -n "$NAMESPACE" delete plan.backups.cozystack.io "$PLAN_NAME" --ignore-not-found -kubectl -n "$NAMESPACE" delete backupjob.backups.cozystack.io "$BACKUPJOB_NAME" --ignore-not-found +kubectl -n "$NAMESPACE" delete backupjob.backups.cozystack.io \ + "$BACKUPJOB_NAME" "$BACKUPJOB_POSTMARKER_NAME" --ignore-not-found # Only the Backups of THIS demo's apps — never `--all`: on a shared cluster the # namespace can hold Backup artefacts of other applications and flows. for b in $(kubectl -n "$NAMESPACE" get backups.backups.cozystack.io \ diff --git a/examples/backups/postgres/run-all.sh b/examples/backups/postgres/run-all.sh index 1b031fb81..71d22b547 100755 --- a/examples/backups/postgres/run-all.sh +++ b/examples/backups/postgres/run-all.sh @@ -19,13 +19,20 @@ set -euo pipefail SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" source "$SCRIPT_DIR/00-helpers.sh" +# Recovery target for the PITR phase; captured between two marker writes far +# below. Defaulted here so subst() can reference it under `set -u` before the +# PITR phase sets it (the placeholder only appears in 45-restorejob-pitr.yaml). +RECOVERY_TIME="${RECOVERY_TIME:-}" + # Substitute the manifest placeholders. $BUCKET / $S3_HOST are resolved from the -# Bucket below; $PG_PASSWORD is the app user's password. +# Bucket below; $PG_PASSWORD is the app user's password; $RECOVERY_TIME is the +# PITR target (empty for every manifest except 45-restorejob-pitr.yaml). subst() { sed \ -e "s|REPLACE_WITH_COSI_BUCKET_NAME|${BUCKET}|g" \ -e "s|REPLACE_WITH_S3_ENDPOINT|${S3_HOST}|g" \ -e "s|REPLACE_WITH_PASSWORD|${PG_PASSWORD}|g" \ + -e "s|REPLACE_WITH_RECOVERY_TIME|${RECOVERY_TIME}|g" \ "$SCRIPT_DIR/$1" } @@ -172,3 +179,132 @@ if [[ "$GOT" != "$SENTINEL_TOKEN" ]]; then exit 1 fi log_success "Round-trip verified: '${PG_TARGET_NAME}' restored sentinel '${GOT}' from S3." + +if [[ "${SKIP_PITR:-0}" == "1" ]]; then + log_warning "SKIP_PITR=1: stopping after the latest-point restore." + exit 0 +fi + +print_header "Step 45: point-in-time recovery (restore as of a timestamp between two writes)" +# The base backup (pg-src-adhoc) predates the two markers below; pg-src has +# archived WAL continuously since install, so a PITR to a time BETWEEN the +# markers must replay the 'before' write and stop short of the 'after' write. +log_substep "Writing the 'before' marker into the source..." +psql_exec "$PG_SRC_CLUSTER" demo " + CREATE TABLE IF NOT EXISTS pitr_marker (id int PRIMARY KEY, label text); + INSERT INTO pitr_marker (id, label) VALUES (1, 'before') + ON CONFLICT (id) DO UPDATE SET label = EXCLUDED.label;" + +# Capture the recovery target from the SERVER clock, right after 'before' +# committed. WAL record timestamps (which recovery_target_time compares +# against) come from the server, so the client clock must not be trusted. +# Sub-second (.US) precision is REQUIRED: whole-second to_char floors, and the +# 'before' write and this capture can land in the same wall-clock second, so a +# truncated target would sort *before* the 'before' commit and drop it. +RECOVERY_TIME=$(psql_exec "$PG_SRC_CLUSTER" demo \ + "SELECT replace(to_char(now() AT TIME ZONE 'UTC', 'YYYY-MM-DD HH24:MI:SS.US'), ' ', 'T') || 'Z';" \ + | tr -d '[:space:]') +[[ -n "$RECOVERY_TIME" ]] || { log_error "failed to capture recovery target time"; exit 1; } +log_success "Recovery target: ${RECOVERY_TIME}" + +# Open a clear gap so the 'after' commit timestamp is strictly past the target, +# then close the WAL segment holding both markers. +sleep 5 +log_substep "Writing the 'after' marker (must NOT survive the PITR)..." +psql_exec "$PG_SRC_CLUSTER" demo " + INSERT INTO pitr_marker (id, label) VALUES (2, 'after') + ON CONFLICT (id) DO UPDATE SET label = EXCLUDED.label; + CHECKPOINT; + SELECT pg_switch_wal();" + +# Gate the restore on the WAL covering the target actually being in object +# storage, deterministically. A fixed sleep races the barman-cloud archiver +# (a slow CI cluster was seen to lag minutes, which then tripped the restore's +# unreachable-target fail-fast on a target that WAS recoverable). A completed +# CNPG BackupJob guarantees WAL up to its stop point - past 'after', hence past +# the target - is archived (the same invariant the restore driver's WAL-archive +# gate keys off), and WAL is archived in order, so the whole chain up to the +# target is present. The point-in-time restore below still recovers from the +# ORIGINAL base backup (pg-src-adhoc); this one only advances the archive. +print_header "Step 45: complete a post-marker backup so the target's WAL is archived" +kubectl -n "$NAMESPACE" apply -f - < RestoreJob Failed with reason RecoveryTargetUnreachable." diff --git a/hack/e2e-chainsaw/postgres/chainsaw-test.yaml b/hack/e2e-chainsaw/postgres/chainsaw-test.yaml index 1b8c60020..c92a46d0b 100644 --- a/hack/e2e-chainsaw/postgres/chainsaw-test.yaml +++ b/hack/e2e-chainsaw/postgres/chainsaw-test.yaml @@ -127,14 +127,18 @@ spec: # The Postgres CR itself was applied by chainsaw and is deleted (and waited # on) automatically during cleanup — no explicit teardown step needed. --- -# Full barman-cloud backup -> to-copy RestoreJob round-trip, driving the -# validated example scripts (examples/backups/postgres) as the harness so the -# test and the documented flow can never drift. run-all.sh runs Bucket -> -# source Postgres + sentinel row -> CNPG strategy + BackupClass -> ad-hoc -# BackupJob (waits Succeeded) -> empty target Postgres + to-copy RestoreJob -# (waits Succeeded) and asserts the sentinel round-tripped through S3 into the -# restored copy — the in-cluster witness that a barman-cloud plugin backup is -# both taken and restorable end to end. +# Full barman-cloud backup -> restore round-trips, driving the validated +# example scripts (examples/backups/postgres) as the harness so the test and +# the documented flow can never drift. run-all.sh runs Bucket -> source +# Postgres + sentinel row -> CNPG strategy + BackupClass -> ad-hoc BackupJob +# (waits Succeeded) -> empty target Postgres + to-copy RestoreJob (waits +# Succeeded, asserts the sentinel round-tripped through S3) -> a point-in-time +# restore between two marker writes (step 45, asserts the pre-marker survived +# and the post-marker did not) -> a negative unreachable-target restore +# (step 46, asserts it fails fast with reason RecoveryTargetUnreachable rather +# than hanging to the deadline). The in-cluster witness that a barman-cloud +# plugin backup is taken, restorable, point-in-time-recoverable, and that a +# bad target is rejected quickly. # # Runs in tenant-root, not the default tenant-test: the S3 client here is the # barman-cloud sidecar INSIDE the Postgres Pod, and the e2e tenant is created @@ -181,13 +185,19 @@ spec: steps: - name: run try: - # The 25m budget is the whole documented flow: bucket provisioning, a + # The 40m budget is the whole documented flow: bucket provisioning, a # 2-replica source Postgres, the plugin base backup to S3, an empty target - # app, and the purge + re-bootstrap restore (convention 6: justified - # in-line). run-all.sh fails fast on terminal BackupJob/RestoreJob phases - # and stalled HelmReleases rather than polling out the budget. + # app, and THREE sequential purge + re-bootstrap restores against it - the + # latest-point to-copy restore, the point-in-time restore (step 45), and + # the negative unreachable-target restore (step 46, which sets a short + # restoreTimeoutSeconds and must fail at that deadline with reason + # RecoveryTargetUnreachable) (convention 6: justified in-line). The old 25m + # budget predated the PITR phases; three restores plus the negative phase + # need the larger window. run-all.sh fails fast on terminal + # BackupJob/RestoreJob phases and stalled HelmReleases rather than polling + # out the budget. - script: - timeout: 25m + timeout: 40m content: | set -eu cd ../../.. diff --git a/internal/backupcontroller/cnpgstrategy_controller.go b/internal/backupcontroller/cnpgstrategy_controller.go index f2ee5f5c4..c39573809 100644 --- a/internal/backupcontroller/cnpgstrategy_controller.go +++ b/internal/backupcontroller/cnpgstrategy_controller.go @@ -5,6 +5,9 @@ import ( "context" "encoding/json" "fmt" + "io" + "sort" + "strings" "time" corev1 "k8s.io/api/core/v1" @@ -75,6 +78,15 @@ const ( // with "WAL not found" and the source data is gone with the PVC. restoreCondWALArchiveReady = "WALArchiveReady" + // Condition Type recorded on a RestoreJob when the chart-rendered + // recovery Cluster keeps failing to converge - i.e. its bootstrap- + // recovery pods exit non-zero and CNPG recreates them in a loop. Set to + // False with reason RecoveryTargetUnreachable when a recoveryTime is in + // play (the usual cause: a point-in-time target past the latest archived + // WAL) or RecoveryFailed otherwise. Lets a tenant see *why* the restore + // is failing before the full restore deadline elapses. + restoreCondRecoveryConverged = "RecoveryConverged" + // Default deadline on the time a RestoreJob can spend waiting for the // target Cluster to reach a healthy state. Tenants override this via // RestoreJob.spec.options.restoreTimeoutSeconds when the source DB is @@ -97,6 +109,39 @@ const ( // a problem that won't self-resolve. cnpgWALArchiveDeadline = 3 * time.Minute + // Both constants below couple to CNPG/PostgreSQL internals. Verified + // against CNPG 1.28.1 + barman-cloud plugin (postgresql:18.1) on the dev7 + // test cluster. The negative e2e in examples/backups/postgres/run-all.sh + // (step 46: a recoveryTime past the archive must fail with reason + // RecoveryTargetUnreachable) is what catches a drift in either string on + // a future CNPG/PostgreSQL bump - if it regresses, this fail-fast silently + // degrades back to hanging until the restore deadline. + + // Container name of a CNPG bootstrap-recovery pod (--full-recovery). + // The driver reads this container's log to classify a stuck recovery. + cnpgRecoveryContainerName = "full-recovery" + + // cnpgRecoveryTargetUnreachableLog is the PostgreSQL FATAL a recovery + // instance logs when it replays every available WAL without reaching the + // configured recovery target and then gives up - the definitive signal + // that a point-in-time recoveryTime is past the latest archived WAL. + // Matching this exact string (rather than counting failed pods) is what + // keeps the fail-fast from misfiring on transient recovery-pod crashes + // (node blips, brief API-server unreachability) that CNPG recovers from: + // those never emit this message, and the recovery goes on to converge. + cnpgRecoveryTargetUnreachableLog = "recovery ended before configured recovery target was reached" + + // Number of tail lines of the recovery container log the driver scans for + // the unreachable-target signature. The message is emitted once near the + // end of the replay, so a small tail is enough and keeps the read cheap. + cnpgRecoveryLogTailLines = 200 + + // Max bootstrap-recovery pods whose log the driver reads when classifying a + // deadline-expired restore. Bounds the log reads even if many failed + // attempts have piled up; the newest few are enough since every attempt + // against an unreachable target reproduces the same FATAL. + cnpgRecoveryMaxInspectPods = 5 + // Cap on the wall-clock time a BackupJob can spend observing a // cnpg.io/Backup stuck in phase=failed before the driver gives up and // marks the BackupJob Failed. CNPG can transition out of "failed" on @@ -865,28 +910,87 @@ func (r *RestoreJobReconciler) reconcileCNPGRestore(ctx context.Context, restore return ctrl.Result{RequeueAfter: cnpgPollInterval}, nil } + // The restore deadline is the sole authority for "this restore is stuck". + // A recovery that CAN converge does so well within the deadline and reaches + // the healthy check below; only a genuinely wedged restore (most often a + // recoveryTime past the latest archived WAL) burns the whole window. We do + // NOT try to fail earlier off the recovery pod's FATAL: a valid near-now + // target hits the same "recovery ended before ... target ... reached" FATAL + // transiently - and repeatedly, for many attempts, on a slow archiver - + // before it converges, so any earlier trip wrongly rejects a recoverable + // restore (observed twice in CI). Instead we use that FATAL only to explain + // the failure precisely once the deadline has already elapsed. Tenants who + // want a fast rejection set a short spec.options.restoreTimeoutSeconds. deadline := options.effectiveRestoreDeadline() if restoreJob.Status.StartedAt != nil && time.Since(restoreJob.Status.StartedAt.Time) > deadline { - return r.markRestoreJobFailed(ctx, restoreJob, fmt.Sprintf( + classificationForbidden := false + if options.RecoveryTime != "" { + unreachable, pod, forbidden, uerr := r.recoveryTargetUnreachable(ctx, target.Namespace, clusterName) + if uerr != nil { + return ctrl.Result{}, uerr + } + classificationForbidden = forbidden + if unreachable { + msg := fmt.Sprintf( + "point-in-time recovery target %s is past the latest WAL archived to object storage: over the %s restore window recovery kept replaying all available WAL without reaching it and PostgreSQL gave up (%q; most recent recovery pod: %s). "+ + "Pick a recoveryTime inside the recoverable window - see the PITR docs on discovering the earliest/latest restorable time.", + options.RecoveryTime, deadline, cnpgRecoveryTargetUnreachableLog, pod) + apimeta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ + Type: restoreCondRecoveryConverged, + Status: metav1.ConditionFalse, + Reason: "RecoveryTargetUnreachable", + Message: msg, + }) + return r.markRestoreJobFailedReason(ctx, restoreJob, "RecoveryTargetUnreachable", msg) + } + } + msg := fmt.Sprintf( "RestoreJob exceeded %s deadline before target Cluster reached a healthy state (override via spec.options.restoreTimeoutSeconds)", - deadline)) + deadline) + if options.RecoveryTime != "" { + msg += fmt.Sprintf("; spec.options.recoveryTime %s may be past the recoverable window, or the source may be large enough to need a longer restoreTimeoutSeconds", options.RecoveryTime) + } + if classificationForbidden { + // The RecoveryTargetUnreachable classification needs to read the + // recovery pod's log; the controller was denied that (missing + // pods/log RBAC grant), so it could not tell an unreachable target + // apart from a slow one. Make the misconfiguration visible rather + // than hiding it behind a bare generic timeout. + msg += ". NOTE: could not read recovery pod logs to classify this failure - the controller's pods/log RBAC grant appears to be missing, so a RecoveryTargetUnreachable diagnosis was unavailable" + r.Recorder.Eventf(restoreJob, corev1.EventTypeWarning, "RecoveryClassificationForbidden", + "cannot read recovery pod logs (pods/log RBAC grant missing); unable to diagnose whether recoveryTime %s is past the recoverable window", options.RecoveryTime) + } + return r.markRestoreJobFailed(ctx, restoreJob, msg) } if !hasRecovery { return ctrl.Result{RequeueAfter: cnpgPollInterval}, nil } + // Recovery converged wins: mark success as soon as the Cluster is healthy, + // regardless of how many bootstrap-recovery pods crashed and were retried + // on the way (a slow archiver makes several transient failures normal). healthy, err := r.cnpgClusterHealthy(ctx, target.Namespace, clusterName) if err != nil { return ctrl.Result{}, err } if !healthy { + // Still recovering. Keep waiting; the deadline above is the backstop. return ctrl.Result{RequeueAfter: cnpgPollInterval}, nil } now := metav1.Now() restoreJob.Status.CompletedAt = &now restoreJob.Status.Phase = backupsv1alpha1.RestoreJobPhaseSucceeded + // Set RecoveryConverged=True for symmetry with the False the unreachable- + // target path records, so .status.conditions tells the whole story rather + // than only ever showing the condition on failure. + apimeta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ + Type: restoreCondRecoveryConverged, + Status: metav1.ConditionTrue, + Reason: "RecoveryConverged", + Message: fmt.Sprintf("target cnpg.io Cluster %s/%s reached a healthy state", target.Namespace, clusterName), + }) apimeta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ Type: "Ready", Status: metav1.ConditionTrue, @@ -1255,6 +1359,137 @@ func (r *RestoreJobReconciler) cnpgClusterHealthy(ctx context.Context, namespace return cluster.Status.Phase == cnpgClusterHealthyPhase, nil } +// logIndicatesRecoveryTargetUnreachable reports whether a recovery container +// log contains the PostgreSQL FATAL that a recovery instance emits when it +// exhausts the WAL archive before reaching the configured recovery target. +// Pure string match so it is unit-testable without a live cluster. +func logIndicatesRecoveryTargetUnreachable(recoveryLog string) bool { + return strings.Contains(recoveryLog, cnpgRecoveryTargetUnreachableLog) +} + +// recoveryUnreachableFromLogs reports whether any recovery-pod log carries the +// unreachable-target FATAL. It is consulted only once the restore deadline has +// elapsed (see reconcileCNPGRestore), so a single match is enough: recovery has +// already had the whole window to converge, and this only classifies *why* it +// did not. Pure so the decision is unit-testable without a live cluster. +func recoveryUnreachableFromLogs(logs []string) bool { + for _, l := range logs { + if logIndicatesRecoveryTargetUnreachable(l) { + return true + } + } + return false +} + +// recoveryTargetUnreachable inspects the target Cluster's bootstrap-recovery +// pods and reports whether recovery has definitively failed because the +// point-in-time target is past the last archived WAL. It reads the recovery +// container's log and matches the PostgreSQL "recovery ended before ..." +// FATAL - a signal unique to an unreachable target, so a transient recovery- +// pod crash (which never emits it) does NOT trip the guard and the recovery +// is left to converge or hit the restore deadline. Returns the inspected pod +// name for the operator-facing message. Nil-safe: with no Clientset wired it +// reports false so the deadline remains the backstop. +// +// Every recovery attempt for an unreachable target reproduces the same FATAL, +// so scanning the most recent pods (running or Failed, newest first) reliably +// catches it across reconciles without depending on any single pod surviving. +func (r *RestoreJobReconciler) recoveryTargetUnreachable(ctx context.Context, namespace, clusterName string) (unreachable bool, pod string, forbidden bool, err error) { + readLog := r.readPodLog + if readLog == nil { + readLog = r.readPodContainerLog + } + // No way to read logs (no Clientset wired and no injected reader): report + // not-unreachable so the deadline stays the backstop. + if r.Clientset == nil && r.readPodLog == nil { + return false, "", false, nil + } + podList := &corev1.PodList{} + if err := r.List(ctx, podList, + client.InNamespace(namespace), + client.MatchingLabels{cnpgClusterLabel: clusterName}, + ); err != nil { + return false, "", false, fmt.Errorf("list pods for cluster %s/%s: %w", namespace, clusterName, err) + } + logger := getLogger(ctx) + logs := make([]string, 0, cnpgRecoveryMaxInspectPods) + fatalPod := "" // newest FATAL-ing pod (pods are inspected newest-first) + forbiddenSeen := false + for _, p := range recoveryPodsToInspect(podList.Items) { + recoveryLog, readErr := readLog(ctx, p.Namespace, p.Name, cnpgRecoveryContainerName) + if readErr != nil { + // A log read can fail transiently (pod being GC'd, apiserver + // blip); don't fail the RestoreJob on it - skip this pod. But a + // Forbidden is NOT transient: it means the controller lacks the + // pods/log RBAC grant, which disables the RecoveryTargetUnreachable + // classification. Flag it so the caller can surface it (Warning + // Event + message) instead of failing with a bare generic reason. + if apierrors.IsForbidden(readErr) { + forbiddenSeen = true + logger.Info("cannot read recovery pod log to classify a stuck point-in-time restore - the pods/log RBAC grant is missing, so the RecoveryTargetUnreachable classification is unavailable and this restore falls back to the restore deadline", + "pod", p.Name, "error", readErr) + } else { + logger.Debug("skipping recovery pod log read", "pod", p.Name, "error", readErr) + } + continue + } + logs = append(logs, recoveryLog) + if fatalPod == "" && logIndicatesRecoveryTargetUnreachable(recoveryLog) { + fatalPod = p.Name + } + } + return recoveryUnreachableFromLogs(logs), fatalPod, forbiddenSeen, nil +} + +// recoveryPodsToInspect narrows a Cluster's pod list to the bootstrap-recovery +// pods worth reading a log from: it keeps only pods carrying the full-recovery +// container, orders them newest-first (the current/most-recent recovery +// attempt is the most likely to hold a fresh, complete replay log), and caps +// the result at cnpgRecoveryMaxInspectPods to bound the per-reconcile log +// reads. Pure and deterministic so the filter/order/cap contract - the part +// that would silently regress the fail-fast into a deadline hang if it drifted +// - is unit-testable without a live cluster. +func recoveryPodsToInspect(pods []corev1.Pod) []*corev1.Pod { + out := make([]*corev1.Pod, 0, len(pods)) + for i := range pods { + p := &pods[i] + for _, c := range p.Spec.Containers { + if c.Name == cnpgRecoveryContainerName { + out = append(out, p) + break + } + } + } + sort.Slice(out, func(i, j int) bool { + return out[i].CreationTimestamp.After(out[j].CreationTimestamp.Time) + }) + if len(out) > cnpgRecoveryMaxInspectPods { + out = out[:cnpgRecoveryMaxInspectPods] + } + return out +} + +// readPodContainerLog returns the tail of a pod container's log via the +// clientset (the controller-runtime cache client cannot read the log +// subresource). +func (r *RestoreJobReconciler) readPodContainerLog(ctx context.Context, namespace, podName, container string) (string, error) { + tail := int64(cnpgRecoveryLogTailLines) + req := r.Clientset.CoreV1().Pods(namespace).GetLogs(podName, &corev1.PodLogOptions{ + Container: container, + TailLines: &tail, + }) + stream, err := req.Stream(ctx) + if err != nil { + return "", err + } + defer stream.Close() + data, err := io.ReadAll(stream) + if err != nil { + return "", err + } + return string(data), nil +} + // recoveryBootstrapClusterState fetches the live cnpg.io Cluster and reports // whether its spec.bootstrap.recovery is populated - the signal that the chart // has re-rendered with our restore-shaped values and the operator is using the diff --git a/internal/backupcontroller/cnpgstrategy_controller_test.go b/internal/backupcontroller/cnpgstrategy_controller_test.go index 60707473b..b5fd98a9a 100644 --- a/internal/backupcontroller/cnpgstrategy_controller_test.go +++ b/internal/backupcontroller/cnpgstrategy_controller_test.go @@ -3,12 +3,14 @@ package backupcontroller import ( "context" + "fmt" "strings" "testing" "time" apiequality "k8s.io/apimachinery/pkg/api/equality" apierrors "k8s.io/apimachinery/pkg/api/errors" + apimeta "k8s.io/apimachinery/pkg/api/meta" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime" @@ -1347,6 +1349,237 @@ func TestCNPGClusterFullyGone(t *testing.T) { }) } +func TestLogIndicatesRecoveryTargetUnreachable(t *testing.T) { + cases := []struct { + name string + log string + want bool + }{ + { + name: "empty log", + log: "", + want: false, + }, + { + name: "healthy replay progress", + log: "LOG: restored log file \"000000010000000000000005\" from archive\nLOG: consistent recovery state reached", + want: false, + }, + { + name: "transient recovery-pod crash (API unreachable) does not match", + log: `{"level":"error","msg":"while building the manager","error":"failed to get server groups: Get \"https://10.96.0.1:443/api\": dial tcp 10.96.0.1:443: i/o timeout"}`, + want: false, + }, + { + name: "target unreachable FATAL matches", + log: "LOG: redo done at 0/50000A8\nFATAL: recovery ended before configured recovery target was reached\nLOG: startup process exited with exit code 1", + want: true, + }, + { + name: "target unreachable FATAL embedded in JSON log line matches", + log: `{"level":"info","record":{"error_severity":"FATAL","message":"recovery ended before configured recovery target was reached"}}`, + want: true, + }, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + if got := logIndicatesRecoveryTargetUnreachable(tc.log); got != tc.want { + t.Fatalf("logIndicatesRecoveryTargetUnreachable(%q) = %v, want %v", tc.log, got, tc.want) + } + }) + } +} + +// TestRecoveryUnreachableFromLogs: any recovery log carrying the unreachable- +// target FATAL classifies the (already deadline-expired) restore as +// target-unreachable; logs without it do not. +func TestRecoveryUnreachableFromLogs(t *testing.T) { + fatal := "LOG: redo done\nFATAL: " + cnpgRecoveryTargetUnreachableLog + healthy := "LOG: restored log file from archive\nLOG: consistent recovery state reached" + cases := []struct { + name string + logs []string + want bool + }{ + {"no logs", nil, false}, + {"only healthy/progress logs", []string{healthy, healthy}, false}, + {"a FATAL among others", []string{healthy, fatal}, true}, + {"all FATAL", []string{fatal, fatal}, true}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + if got := recoveryUnreachableFromLogs(tc.logs); got != tc.want { + t.Fatalf("recoveryUnreachableFromLogs = %v, want %v", got, tc.want) + } + }) + } +} + +// TestRecoveryPodsToInspect pins the filter/order/cap contract of the pod +// selection the fail-fast guard relies on: only full-recovery pods, newest +// first, capped at cnpgRecoveryMaxInspectPods. A regression here (wrong sort +// direction, off-by-one cap, broken container filter) would silently degrade +// the fail-fast back into a 30-minute deadline hang. +func TestRecoveryPodsToInspect(t *testing.T) { + recoveryPod := func(name string, ageSeconds int64) corev1.Pod { + return corev1.Pod{ + ObjectMeta: metav1.ObjectMeta{ + Name: name, + CreationTimestamp: metav1.NewTime(time.Unix(ageSeconds, 0)), + }, + Spec: corev1.PodSpec{Containers: []corev1.Container{{Name: cnpgRecoveryContainerName}}}, + } + } + + t.Run("no pods -> empty", func(t *testing.T) { + if got := recoveryPodsToInspect(nil); len(got) != 0 { + t.Fatalf("expected empty, got %d", len(got)) + } + }) + + t.Run("skips non-recovery pods (no full-recovery container)", func(t *testing.T) { + pods := []corev1.Pod{ + recoveryPod("rec-1", 100), + { + ObjectMeta: metav1.ObjectMeta{Name: "primary-newest", CreationTimestamp: metav1.NewTime(time.Unix(999, 0))}, + Spec: corev1.PodSpec{Containers: []corev1.Container{{Name: "postgres"}}}, + }, + } + got := recoveryPodsToInspect(pods) + if len(got) != 1 || got[0].Name != "rec-1" { + t.Fatalf("expected only the full-recovery pod, got %v", names(got)) + } + }) + + t.Run("newest-first order and cap at cnpgRecoveryMaxInspectPods", func(t *testing.T) { + // Seed two more recovery pods than the cap, out of order, plus a + // non-recovery pod that is the newest of all (must be excluded). The + // result must be exactly the cap-many newest recovery pods, newest-first. + n := cnpgRecoveryMaxInspectPods + 2 + var pods []corev1.Pod + for i := 0; i < n; i++ { + // age i*100 so higher i == newer. + pods = append(pods, recoveryPod(fmt.Sprintf("rec-%d", i), int64(i*100))) + } + pods = append(pods, corev1.Pod{ + ObjectMeta: metav1.ObjectMeta{Name: "primary", CreationTimestamp: metav1.NewTime(time.Unix(9_999_999, 0))}, + Spec: corev1.PodSpec{Containers: []corev1.Container{{Name: "postgres"}}}, + }) + got := recoveryPodsToInspect(pods) + want := make([]string, 0, cnpgRecoveryMaxInspectPods) + for i := 0; i < cnpgRecoveryMaxInspectPods; i++ { + want = append(want, fmt.Sprintf("rec-%d", n-1-i)) // newest-first + } + if gotNames := names(got); !equalStrings(gotNames, want) { + t.Fatalf("expected %v, got %v", want, gotNames) + } + }) +} + +func names(pods []*corev1.Pod) []string { + out := make([]string, len(pods)) + for i, p := range pods { + out[i] = p.Name + } + return out +} + +func equalStrings(a, b []string) bool { + if len(a) != len(b) { + return false + } + for i := range a { + if a[i] != b[i] { + return false + } + } + return true +} + +// recoveryTargetUnreachable is nil-safe when no Clientset is wired, so the +// deadline stays the backstop instead of the driver panicking. +func TestRecoveryTargetUnreachable_NilClientsetReportsFalse(t *testing.T) { + r := &RestoreJobReconciler{Client: newCNPGStrategyTestClient(t)} + unreachable, pod, forbidden, err := r.recoveryTargetUnreachable(context.Background(), "tenant", "postgres-app") + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if unreachable || pod != "" || forbidden { + t.Fatalf("expected (false, \"\", false) with no Clientset, got (%v, %q, %v)", unreachable, pod, forbidden) + } +} + +// TestRecoveryTargetUnreachable_ClassifiesFromLogs drives the log-based +// classification through an injected reader (the fake Clientset's GetLogs +// can't return specific content or a Forbidden), covering the three outcomes +// the deadline path branches on: the unreachable-target FATAL is present +// (-> unreachable, newest pod), it is absent (-> not unreachable), and the log +// read is Forbidden (-> forbidden flagged so the caller surfaces the missing +// pods/log RBAC instead of failing silently-generic). +func TestRecoveryTargetUnreachable_ClassifiesFromLogs(t *testing.T) { + const ( + ns = "tenant" + cluster = "postgres-app" + ) + recPod := func(name string, ageSeconds int64) client.Object { + return &corev1.Pod{ + ObjectMeta: metav1.ObjectMeta{ + Namespace: ns, + Name: name, + Labels: map[string]string{cnpgClusterLabel: cluster}, + CreationTimestamp: metav1.NewTime(time.Unix(ageSeconds, 0)), + }, + Spec: corev1.PodSpec{Containers: []corev1.Container{{Name: cnpgRecoveryContainerName}}}, + } + } + seed := func() []client.Object { return []client.Object{recPod("rec-old", 100), recPod("rec-new", 200)} } + fatalLog := "LOG: redo done\nFATAL: " + cnpgRecoveryTargetUnreachableLog + + t.Run("FATAL present -> unreachable, reports newest pod", func(t *testing.T) { + r := &RestoreJobReconciler{ + Client: newCNPGStrategyTestClient(t, seed()...), + readPodLog: func(context.Context, string, string, string) (string, error) { return fatalLog, nil }, + } + un, pod, forb, err := r.recoveryTargetUnreachable(context.Background(), ns, cluster) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if !un || forb || pod != "rec-new" { + t.Fatalf("got unreachable=%v pod=%q forbidden=%v, want (true, rec-new, false)", un, pod, forb) + } + }) + + t.Run("no FATAL -> not unreachable", func(t *testing.T) { + r := &RestoreJobReconciler{ + Client: newCNPGStrategyTestClient(t, seed()...), + readPodLog: func(context.Context, string, string, string) (string, error) { return "LOG: consistent recovery state reached", nil }, + } + un, _, forb, err := r.recoveryTargetUnreachable(context.Background(), ns, cluster) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if un || forb { + t.Fatalf("got unreachable=%v forbidden=%v, want (false, false)", un, forb) + } + }) + + t.Run("Forbidden log read -> forbidden flagged, not unreachable", func(t *testing.T) { + r := &RestoreJobReconciler{ + Client: newCNPGStrategyTestClient(t, seed()...), + readPodLog: func(context.Context, string, string, string) (string, error) { + return "", apierrors.NewForbidden(schema.GroupResource{Resource: "pods"}, "rec-new", fmt.Errorf("pods/log grant missing")) + }, + } + un, _, forb, err := r.recoveryTargetUnreachable(context.Background(), ns, cluster) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if un || !forb { + t.Fatalf("got unreachable=%v forbidden=%v, want (false, true)", un, forb) + } + }) +} + // testCNPGScheme returns a runtime.Scheme that knows the unstructured // HelmRelease GVK used by the dynamic-client tests above. func testCNPGScheme(t *testing.T) *runtime.Scheme { @@ -1876,6 +2109,93 @@ func TestReconcileCNPGRestore_RepeatInPlacePurgesStaleRecoveryCluster(t *testing }) } +// TestReconcileCNPGRestore_HealthyClusterSucceeds drives the reconcile to its +// success branch: with the target already purged (TargetPurged=True) and the +// recovery Cluster reporting healthy, the RestoreJob must reach phase +// Succeeded with Ready=True AND the new RecoveryConverged=True condition. +func TestReconcileCNPGRestore_HealthyClusterSucceeds(t *testing.T) { + const ( + ns = "tenant" + appName = "app" + clusterName = "postgres-app" + cnpgBkName = "cnpgbk" + ) + apiGroup := backupsv1alpha1.DefaultApplicationAPIGroup + strategyGroup := strategyv1alpha1.GroupVersion.Group + ctx := context.Background() + startedAt := metav1.NewTime(time.Now()) + + snap, err := marshalCNPGBackupSnapshot(newPostgresApp(appName, ns), nil) + if err != nil { + t.Fatalf("marshal snapshot: %v", err) + } + backup := &backupsv1alpha1.Backup{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: "bk"}, + Spec: backupsv1alpha1.BackupSpec{ + ApplicationRef: corev1.TypedLocalObjectReference{APIGroup: &apiGroup, Kind: postgresAppKind, Name: appName}, + StrategyRef: corev1.TypedLocalObjectReference{APIGroup: &strategyGroup, Kind: strategyv1alpha1.CNPGStrategyKind, Name: "cnpg-strategy"}, + DriverMetadata: map[string]string{ + cnpgServerNameKey: appName, + cnpgDestinationPathKey: "s3://bucket/" + appName + "/", + cnpgBackupNameKey: cnpgBkName, + }, + }, + Status: backupsv1alpha1.BackupStatus{UnderlyingResources: snap}, + } + strategy := &strategyv1alpha1.CNPG{ + ObjectMeta: metav1.ObjectMeta{Name: "cnpg-strategy"}, + Spec: strategyv1alpha1.CNPGSpec{Template: strategyv1alpha1.CNPGTemplate{ + BarmanObjectStore: strategyv1alpha1.BarmanObjectStoreTemplate{DestinationPath: "s3://bucket/"}, + }}, + } + // Healthy recovery Cluster created after StartedAt (this restore's own). + healthyCluster := &cnpgtypes.Cluster{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: clusterName, CreationTimestamp: metav1.NewTime(startedAt.Add(time.Minute))}, + Spec: cnpgtypes.ClusterSpec{Bootstrap: &cnpgtypes.BootstrapConfiguration{Recovery: &cnpgtypes.RecoverySource{Source: appName}}}, + Status: cnpgtypes.ClusterStatus{Phase: cnpgClusterHealthyPhase}, + } + sa := startedAt + restoreJob := &backupsv1alpha1.RestoreJob{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: "rj"}, + Spec: backupsv1alpha1.RestoreJobSpec{BackupRef: corev1.LocalObjectReference{Name: "bk"}}, + Status: backupsv1alpha1.RestoreJobStatus{ + StartedAt: &sa, + Phase: backupsv1alpha1.RestoreJobPhaseRunning, + // Purge already done for this restore, so reconcile skips straight + // to the wait-for-healthy / success path. + Conditions: []metav1.Condition{{ + Type: restoreCondTargetPurged, Status: metav1.ConditionTrue, Reason: "ClusterPurged", + LastTransitionTime: startedAt, Message: "purged", + }}, + }, + } + + c := newCNPGStrategyTestClient(t, backup, restoreJob, strategy, newPostgresApp(appName, ns), healthyCluster) + r := &RestoreJobReconciler{Client: c, Interface: dynamicfake.NewSimpleDynamicClient(testCNPGScheme(t))} + + rj := &backupsv1alpha1.RestoreJob{} + if err := c.Get(ctx, client.ObjectKey{Namespace: ns, Name: "rj"}, rj); err != nil { + t.Fatalf("get seeded RestoreJob: %v", err) + } + if _, err := r.reconcileCNPGRestore(ctx, rj, backup); err != nil { + t.Fatalf("reconcileCNPGRestore: %v", err) + } + + got := &backupsv1alpha1.RestoreJob{} + if err := c.Get(ctx, client.ObjectKey{Namespace: ns, Name: "rj"}, got); err != nil { + t.Fatalf("get RestoreJob after reconcile: %v", err) + } + if got.Status.Phase != backupsv1alpha1.RestoreJobPhaseSucceeded { + t.Fatalf("expected phase Succeeded, got %q (msg=%q)", got.Status.Phase, got.Status.Message) + } + if c := apimeta.FindStatusCondition(got.Status.Conditions, "Ready"); c == nil || c.Status != metav1.ConditionTrue { + t.Fatalf("expected Ready=True, got %+v", c) + } + if c := apimeta.FindStatusCondition(got.Status.Conditions, restoreCondRecoveryConverged); c == nil || c.Status != metav1.ConditionTrue { + t.Fatalf("expected RecoveryConverged=True, got %+v", c) + } +} + // newCNPGStrategyTestClient returns a fake client.Client wired up with // the schemes the CNPG-strategy reconciler needs. func newCNPGStrategyTestClient(t *testing.T, objs ...client.Object) client.Client { diff --git a/internal/backupcontroller/restorejob_controller.go b/internal/backupcontroller/restorejob_controller.go index 23b65279e..1a384dd7a 100644 --- a/internal/backupcontroller/restorejob_controller.go +++ b/internal/backupcontroller/restorejob_controller.go @@ -12,6 +12,7 @@ import ( "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/types" "k8s.io/client-go/dynamic" + "k8s.io/client-go/kubernetes" "k8s.io/client-go/rest" "k8s.io/client-go/tools/record" ctrl "sigs.k8s.io/controller-runtime" @@ -34,8 +35,18 @@ type RestoreJobReconciler struct { client.Client dynamic.Interface meta.RESTMapper - Scheme *runtime.Scheme - Recorder record.EventRecorder + Scheme *runtime.Scheme + Recorder record.EventRecorder + // Clientset reads Pod logs (the controller-runtime cache client cannot); + // the CNPG restore driver uses it to read a bootstrap-recovery pod's log + // and tell an unreachable point-in-time target apart from a transient + // recovery-pod failure. Wired in SetupWithManager; nil-safe at call sites. + Clientset kubernetes.Interface + // readPodLog is the seam the CNPG restore driver reads a recovery pod's log + // through. Defaults to readPodContainerLog (which uses Clientset); tests + // inject a stub so the log-classification path - including the Forbidden + // (missing pods/log RBAC) branch - is unit-testable without a live cluster. + readPodLog func(ctx context.Context, namespace, podName, container string) (string, error) CredentialsConfig BackupCredentialsConfig } @@ -165,6 +176,9 @@ func (r *RestoreJobReconciler) SetupWithManager(mgr ctrl.Manager) error { if r.Interface, err = dynamic.NewForConfig(cfg); err != nil { return err } + if r.Clientset, err = kubernetes.NewForConfig(cfg); err != nil { + return err + } var h *http.Client if h, err = rest.HTTPClientFor(cfg); err != nil { return err @@ -212,6 +226,14 @@ func (r *RestoreJobReconciler) handleProjectionError(ctx context.Context, rj *ba // fresh budget is what users expect after correcting the cause of the // previous failure. func (r *RestoreJobReconciler) markRestoreJobFailed(ctx context.Context, restoreJob *backupsv1alpha1.RestoreJob, message string) (ctrl.Result, error) { + return r.markRestoreJobFailedReason(ctx, restoreJob, "RestoreFailed", message) +} + +// markRestoreJobFailedReason is markRestoreJobFailed with a caller-chosen +// Ready-condition Reason so a driver can distinguish failure classes a tenant +// acts on differently (e.g. RecoveryTargetUnreachable, which points at the +// recoverable window rather than at the controller). +func (r *RestoreJobReconciler) markRestoreJobFailedReason(ctx context.Context, restoreJob *backupsv1alpha1.RestoreJob, reason, message string) (ctrl.Result, error) { logger := getLogger(ctx) now := metav1.Now() restoreJob.Status.CompletedAt = &now @@ -226,7 +248,7 @@ func (r *RestoreJobReconciler) markRestoreJobFailed(ctx context.Context, restore meta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ Type: "Ready", Status: metav1.ConditionFalse, - Reason: "RestoreFailed", + Reason: reason, Message: message, }) diff --git a/packages/system/backupstrategy-controller/templates/rbac.yaml b/packages/system/backupstrategy-controller/templates/rbac.yaml index 24d9f8d8a..0f548cc9c 100644 --- a/packages/system/backupstrategy-controller/templates/rbac.yaml +++ b/packages/system/backupstrategy-controller/templates/rbac.yaml @@ -26,6 +26,14 @@ rules: - apiGroups: [""] resources: ["pods"] verbs: ["get", "list", "watch"] +# Pods/log: the CNPG RestoreJob driver reads a bootstrap-recovery pod's log to +# tell an unreachable point-in-time target (recoveryTime past the last archived +# WAL) apart from a transient recovery-pod crash, and fail the RestoreJob fast. +# pods/log is a distinct RBAC subresource from pods; without this the GetLogs +# call is 403-Forbidden and the fail-fast silently degrades to a deadline hang. +- apiGroups: [""] + resources: ["pods/log"] + verbs: ["get"] # ConfigMaps: controller-runtime cache requires cluster-scoped list/watch; # create/update/delete is scoped to cozy-velero via a Role shipped by the # velero chart (packages/system/velero/templates/backupstrategy-controller-rbac.yaml) From b5d03f889b2558329d1e5f39a71145258eb04acc Mon Sep 17 00:00:00 2001 From: Andrey Kolkov Date: Wed, 22 Jul 2026 13:06:00 +0400 Subject: [PATCH 2/3] test(backups): reconcile-level test for the PITR deadline classification MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review of #3383 found the RecoveryTargetUnreachable classification branch in reconcileCNPGRestore was only covered through the pure helpers and recoveryTargetUnreachable directly, never through reconcileCNPGRestore itself — a mutation swapping the call-site reason back to the generic RestoreFailed kept the suite green. Add TestReconcileCNPGRestore_DeadlineClassifiesRecoveryTargetUnreachable: it backdates StartedAt past the restore deadline with a recoveryTime set and drives the real reconcile through the readPodLog seam, asserting all three deadline sub-paths — FATAL present (reason RecoveryTargetUnreachable on both RecoveryConverged and Ready), FATAL absent (generic timeout, no RecoveryTargetUnreachable), and a Forbidden log read (generic timeout + the missing-pods/log-RBAC note). Verified it fails when the call-site reason is reverted to the generic RestoreFailed. Co-Authored-By: Claude Opus 4.8 (1M context) Signed-off-by: Andrey Kolkov --- .../cnpgstrategy_controller_test.go | 192 +++++++++++++++++- 1 file changed, 190 insertions(+), 2 deletions(-) diff --git a/internal/backupcontroller/cnpgstrategy_controller_test.go b/internal/backupcontroller/cnpgstrategy_controller_test.go index b5fd98a9a..48d04168c 100644 --- a/internal/backupcontroller/cnpgstrategy_controller_test.go +++ b/internal/backupcontroller/cnpgstrategy_controller_test.go @@ -18,6 +18,7 @@ import ( "k8s.io/client-go/dynamic" dynamicfake "k8s.io/client-go/dynamic/fake" "k8s.io/client-go/kubernetes/scheme" + "k8s.io/client-go/tools/record" "k8s.io/utils/ptr" "sigs.k8s.io/controller-runtime/pkg/client" clientfake "sigs.k8s.io/controller-runtime/pkg/client/fake" @@ -1551,8 +1552,10 @@ func TestRecoveryTargetUnreachable_ClassifiesFromLogs(t *testing.T) { t.Run("no FATAL -> not unreachable", func(t *testing.T) { r := &RestoreJobReconciler{ - Client: newCNPGStrategyTestClient(t, seed()...), - readPodLog: func(context.Context, string, string, string) (string, error) { return "LOG: consistent recovery state reached", nil }, + Client: newCNPGStrategyTestClient(t, seed()...), + readPodLog: func(context.Context, string, string, string) (string, error) { + return "LOG: consistent recovery state reached", nil + }, } un, _, forb, err := r.recoveryTargetUnreachable(context.Background(), ns, cluster) if err != nil { @@ -2196,6 +2199,191 @@ func TestReconcileCNPGRestore_HealthyClusterSucceeds(t *testing.T) { } } +// TestReconcileCNPGRestore_DeadlineClassifiesRecoveryTargetUnreachable drives the +// full reconcileCNPGRestore deadline branch (the classification call site), which +// the pure-helper tests (TestRecoveryTargetUnreachable_*) do not exercise: +// swapping the RecoveryTargetUnreachable reason back to the generic RestoreFailed +// at that call site leaves them green. Each sub-case backdates StartedAt past the +// restore deadline with a recoveryTime set (so classification runs) and asserts +// the three outcomes the branch distinguishes: FATAL found, FATAL absent, and a +// Forbidden log read (missing pods/log RBAC). +func TestReconcileCNPGRestore_DeadlineClassifiesRecoveryTargetUnreachable(t *testing.T) { + const ( + ns = "tenant" + appName = "app" + clusterName = "postgres-app" + ) + apiGroup := backupsv1alpha1.DefaultApplicationAPIGroup + strategyGroup := strategyv1alpha1.GroupVersion.Group + ctx := context.Background() + + // StartedAt far past cnpgDefaultRestoreDeadline (30m) so the first reconcile + // enters the deadline-classification branch. + startedAt := metav1.NewTime(time.Now().Add(-72 * time.Hour)) + + snap, err := marshalCNPGBackupSnapshot(newPostgresApp(appName, ns), nil) + if err != nil { + t.Fatalf("marshal snapshot: %v", err) + } + mkBackup := func() *backupsv1alpha1.Backup { + return &backupsv1alpha1.Backup{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: "bk"}, + Spec: backupsv1alpha1.BackupSpec{ + ApplicationRef: corev1.TypedLocalObjectReference{APIGroup: &apiGroup, Kind: postgresAppKind, Name: appName}, + StrategyRef: corev1.TypedLocalObjectReference{APIGroup: &strategyGroup, Kind: strategyv1alpha1.CNPGStrategyKind, Name: "cnpg-strategy"}, + DriverMetadata: map[string]string{ + cnpgServerNameKey: appName, + cnpgDestinationPathKey: "s3://bucket/" + appName + "/", + }, + }, + Status: backupsv1alpha1.BackupStatus{UnderlyingResources: snap}, + } + } + strategy := &strategyv1alpha1.CNPG{ + ObjectMeta: metav1.ObjectMeta{Name: "cnpg-strategy"}, + Spec: strategyv1alpha1.CNPGSpec{Template: strategyv1alpha1.CNPGTemplate{ + BarmanObjectStore: strategyv1alpha1.BarmanObjectStoreTemplate{DestinationPath: "s3://bucket/"}, + }}, + } + // Recovery Cluster created after StartedAt (this restore's own -> not + // re-purged), so the reconcile flows past the purge block to the deadline + // check. Phase left empty (still wedged): the deadline check precedes the + // healthy check, so it fires regardless. + mkCluster := func() *cnpgtypes.Cluster { + return &cnpgtypes.Cluster{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: clusterName, CreationTimestamp: metav1.NewTime(startedAt.Add(time.Minute))}, + Spec: cnpgtypes.ClusterSpec{Bootstrap: &cnpgtypes.BootstrapConfiguration{Recovery: &cnpgtypes.RecoverySource{Source: appName}}}, + } + } + // A bootstrap-recovery pod for the cluster; recoveryTargetUnreachable lists + // these and reads each through the readPodLog seam. + mkPod := func() *corev1.Pod { + return &corev1.Pod{ + ObjectMeta: metav1.ObjectMeta{ + Namespace: ns, + Name: clusterName + "-full-recovery-abcde", + Labels: map[string]string{cnpgClusterLabel: clusterName}, + CreationTimestamp: metav1.NewTime(startedAt.Add(2 * time.Minute)), + }, + Spec: corev1.PodSpec{Containers: []corev1.Container{{Name: cnpgRecoveryContainerName}}}, + } + } + mkRestoreJob := func() *backupsv1alpha1.RestoreJob { + sa := startedAt + return &backupsv1alpha1.RestoreJob{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: "rj"}, + Spec: backupsv1alpha1.RestoreJobSpec{ + BackupRef: corev1.LocalObjectReference{Name: "bk"}, + // recoveryTime present -> the reconcile runs the classification. + Options: &runtime.RawExtension{Raw: []byte(`{"recoveryTime":"2026-01-01T00:00:00Z"}`)}, + }, + Status: backupsv1alpha1.RestoreJobStatus{ + StartedAt: &sa, + Phase: backupsv1alpha1.RestoreJobPhaseRunning, + // Purge already done -> reconcile reaches the deadline check. + Conditions: []metav1.Condition{{ + Type: restoreCondTargetPurged, Status: metav1.ConditionTrue, Reason: "ClusterPurged", + LastTransitionTime: startedAt, Message: "purged", + }}, + }, + } + } + + fatalLog := "LOG: redo done\nFATAL: " + cnpgRecoveryTargetUnreachableLog + + newReconciler := func(c client.Client, readLog func(context.Context, string, string, string) (string, error)) *RestoreJobReconciler { + return &RestoreJobReconciler{ + Client: c, + Interface: dynamicfake.NewSimpleDynamicClient(testCNPGScheme(t)), + Recorder: record.NewFakeRecorder(10), + readPodLog: readLog, + } + } + reconcileToFailed := func(t *testing.T, r *RestoreJobReconciler, c client.Client, backup *backupsv1alpha1.Backup) *backupsv1alpha1.RestoreJob { + t.Helper() + rj := &backupsv1alpha1.RestoreJob{} + if err := c.Get(ctx, client.ObjectKey{Namespace: ns, Name: "rj"}, rj); err != nil { + t.Fatalf("get seeded RestoreJob: %v", err) + } + res, err := r.reconcileCNPGRestore(ctx, rj, backup) + if err != nil { + t.Fatalf("reconcileCNPGRestore: %v", err) + } + if res.RequeueAfter != 0 { + t.Fatalf("terminal deadline failure must not requeue, got %+v", res) + } + got := &backupsv1alpha1.RestoreJob{} + if err := c.Get(ctx, client.ObjectKey{Namespace: ns, Name: "rj"}, got); err != nil { + t.Fatalf("get RestoreJob after reconcile: %v", err) + } + if got.Status.Phase != backupsv1alpha1.RestoreJobPhaseFailed { + t.Fatalf("expected Phase=Failed after deadline, got %q (msg=%q)", got.Status.Phase, got.Status.Message) + } + return got + } + + t.Run("recovery-target-unreachable FATAL -> RecoveryTargetUnreachable reason", func(t *testing.T) { + backup := mkBackup() + c := newCNPGStrategyTestClient(t, backup, mkRestoreJob(), strategy, newPostgresApp(appName, ns), mkCluster(), mkPod()) + r := newReconciler(c, func(context.Context, string, string, string) (string, error) { return fatalLog, nil }) + + got := reconcileToFailed(t, r, c, backup) + + // The mutation the review flagged: the call site must set reason + // RecoveryTargetUnreachable, not the generic RestoreFailed. + conv := apimeta.FindStatusCondition(got.Status.Conditions, restoreCondRecoveryConverged) + if conv == nil || conv.Status != metav1.ConditionFalse || conv.Reason != "RecoveryTargetUnreachable" { + t.Fatalf("expected RecoveryConverged=False reason=RecoveryTargetUnreachable, got %+v", conv) + } + if ready := apimeta.FindStatusCondition(got.Status.Conditions, "Ready"); ready == nil || ready.Reason != "RecoveryTargetUnreachable" { + t.Fatalf("expected Ready reason=RecoveryTargetUnreachable, got %+v", ready) + } + if !strings.Contains(got.Status.Message, "past the latest WAL archived") { + t.Errorf("message should explain the unreachable target, got %q", got.Status.Message) + } + }) + + t.Run("no FATAL -> generic deadline failure, not RecoveryTargetUnreachable", func(t *testing.T) { + backup := mkBackup() + c := newCNPGStrategyTestClient(t, backup, mkRestoreJob(), strategy, newPostgresApp(appName, ns), mkCluster(), mkPod()) + r := newReconciler(c, func(context.Context, string, string, string) (string, error) { + return "LOG: consistent recovery state reached", nil + }) + + got := reconcileToFailed(t, r, c, backup) + + if conv := apimeta.FindStatusCondition(got.Status.Conditions, restoreCondRecoveryConverged); conv != nil { + t.Fatalf("did not expect a RecoveryConverged condition on a generic timeout, got %+v", conv) + } + if ready := apimeta.FindStatusCondition(got.Status.Conditions, "Ready"); ready != nil && ready.Reason == "RecoveryTargetUnreachable" { + t.Fatalf("generic timeout must NOT be classified RecoveryTargetUnreachable, got %+v", ready) + } + if !strings.Contains(got.Status.Message, "deadline") { + t.Errorf("message should mention the deadline, got %q", got.Status.Message) + } + if strings.Contains(got.Status.Message, "pods/log RBAC") { + t.Errorf("a readable log must not report a Forbidden RBAC note, got %q", got.Status.Message) + } + }) + + t.Run("Forbidden log read -> generic failure with missing-RBAC note", func(t *testing.T) { + backup := mkBackup() + c := newCNPGStrategyTestClient(t, backup, mkRestoreJob(), strategy, newPostgresApp(appName, ns), mkCluster(), mkPod()) + r := newReconciler(c, func(context.Context, string, string, string) (string, error) { + return "", apierrors.NewForbidden(schema.GroupResource{Resource: "pods"}, "rec", fmt.Errorf("pods/log grant missing")) + }) + + got := reconcileToFailed(t, r, c, backup) + + if conv := apimeta.FindStatusCondition(got.Status.Conditions, restoreCondRecoveryConverged); conv != nil && conv.Reason == "RecoveryTargetUnreachable" { + t.Fatalf("a Forbidden log read must not yield a RecoveryTargetUnreachable classification, got %+v", conv) + } + if !strings.Contains(got.Status.Message, "pods/log RBAC") { + t.Errorf("Forbidden classification should surface the missing pods/log RBAC grant, got %q", got.Status.Message) + } + }) +} + // newCNPGStrategyTestClient returns a fake client.Client wired up with // the schemes the CNPG-strategy reconciler needs. func newCNPGStrategyTestClient(t *testing.T, objs ...client.Object) client.Client { From ad3f8b24877dee1e10bb35b01d4121c01ecbc656 Mon Sep 17 00:00:00 2001 From: Andrey Kolkov Date: Wed, 22 Jul 2026 15:31:12 +0400 Subject: [PATCH 3/3] fix(backups): check cluster health before the restore deadline (PITR) Addresses review CHANGES_REQUESTED on #3383. CRITICAL: reconcileCNPGRestore checked the restore deadline BEFORE the cluster-health check, so a reconcile that first observes "deadline elapsed" AFTER the recovery Cluster already reached a healthy state (a controller restart or stalled workqueue spanning restoreTimeoutSeconds) would mark an already-converged restore Failed / RecoveryTargetUnreachable. A false Failed can then escalate to data loss: a resubmitted RestoreJob's purge guard treats the recovered Cluster as a stale leftover and deletes it + its PVCs. Fix: check hasRecovery + cnpgClusterHealthy first and return Succeeded unconditionally when healthy, regardless of how late the reconcile runs; only a not-yet-healthy restore reaches the deadline/classification branch. Adds TestReconcileCNPGRestore_HealthyPastDeadlineSucceeds (StartedAt 72h past the deadline + healthy Cluster + recoveryTime set; the injected readPodLog fails the test if the classification path is entered, proving health short-circuits). MINOR: handle the deferred Close error on the pod-log reader (errcheck). Signed-off-by: Andrey Kolkov --- .../cnpgstrategy_controller.go | 104 +++++++++--------- .../cnpgstrategy_controller_test.go | 103 +++++++++++++++++ 2 files changed, 157 insertions(+), 50 deletions(-) diff --git a/internal/backupcontroller/cnpgstrategy_controller.go b/internal/backupcontroller/cnpgstrategy_controller.go index c39573809..1bfef308f 100644 --- a/internal/backupcontroller/cnpgstrategy_controller.go +++ b/internal/backupcontroller/cnpgstrategy_controller.go @@ -910,17 +910,56 @@ func (r *RestoreJobReconciler) reconcileCNPGRestore(ctx context.Context, restore return ctrl.Result{RequeueAfter: cnpgPollInterval}, nil } - // The restore deadline is the sole authority for "this restore is stuck". - // A recovery that CAN converge does so well within the deadline and reaches - // the healthy check below; only a genuinely wedged restore (most often a - // recoveryTime past the latest archived WAL) burns the whole window. We do - // NOT try to fail earlier off the recovery pod's FATAL: a valid near-now - // target hits the same "recovery ended before ... target ... reached" FATAL - // transiently - and repeatedly, for many attempts, on a slow archiver - - // before it converges, so any earlier trip wrongly rejects a recoverable - // restore (observed twice in CI). Instead we use that FATAL only to explain - // the failure precisely once the deadline has already elapsed. Tenants who - // want a fast rejection set a short spec.options.restoreTimeoutSeconds. + // Health wins unconditionally, and is checked BEFORE the deadline. A + // recovery that has reached a healthy Cluster is a success no matter how + // late the reconcile observes it: a reconcile gap longer than + // restoreTimeoutSeconds (a controller restart or a stalled workqueue that + // spans the window) must not flip an already-converged restore to Failed. + // Getting the order wrong is not just a cosmetic mislabel - a false Failed + // can be resubmitted, and the next RestoreJob's purge guard would then + // delete the already-recovered Cluster + PVCs to start over. + if hasRecovery { + healthy, herr := r.cnpgClusterHealthy(ctx, target.Namespace, clusterName) + if herr != nil { + return ctrl.Result{}, herr + } + if healthy { + now := metav1.Now() + restoreJob.Status.CompletedAt = &now + restoreJob.Status.Phase = backupsv1alpha1.RestoreJobPhaseSucceeded + // RecoveryConverged=True for symmetry with the False the + // unreachable-target path records, so .status.conditions tells the + // whole story rather than only ever showing the condition on failure. + apimeta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ + Type: restoreCondRecoveryConverged, + Status: metav1.ConditionTrue, + Reason: "RecoveryConverged", + Message: fmt.Sprintf("target cnpg.io Cluster %s/%s reached a healthy state", target.Namespace, clusterName), + }) + apimeta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ + Type: "Ready", + Status: metav1.ConditionTrue, + Reason: "RestoreCompleted", + Message: "target cnpg.io Cluster reached healthy state", + }) + if err := r.Status().Update(ctx, restoreJob); err != nil { + return ctrl.Result{}, err + } + return ctrl.Result{}, nil + } + } + + // Not (yet) healthy. Now the restore deadline is the authority for "this + // restore is stuck". A recovery that CAN converge does so within the + // deadline and is caught by the health check above; only a genuinely wedged + // restore (most often a recoveryTime past the latest archived WAL) burns the + // whole window. We do NOT fail earlier off the recovery pod's FATAL: a valid + // near-now target hits that same "recovery ended before ... target ... + // reached" FATAL transiently - and repeatedly, on a slow archiver - before + // it converges, so an earlier trip would wrongly reject a recoverable + // restore. The FATAL is used only to explain a failure the deadline has + // already declared. Tenants who want a fast rejection set a short + // spec.options.restoreTimeoutSeconds. deadline := options.effectiveRestoreDeadline() if restoreJob.Status.StartedAt != nil && time.Since(restoreJob.Status.StartedAt.Time) > deadline { classificationForbidden := false @@ -963,44 +1002,9 @@ func (r *RestoreJobReconciler) reconcileCNPGRestore(ctx context.Context, restore return r.markRestoreJobFailed(ctx, restoreJob, msg) } - if !hasRecovery { - return ctrl.Result{RequeueAfter: cnpgPollInterval}, nil - } - - // Recovery converged wins: mark success as soon as the Cluster is healthy, - // regardless of how many bootstrap-recovery pods crashed and were retried - // on the way (a slow archiver makes several transient failures normal). - healthy, err := r.cnpgClusterHealthy(ctx, target.Namespace, clusterName) - if err != nil { - return ctrl.Result{}, err - } - if !healthy { - // Still recovering. Keep waiting; the deadline above is the backstop. - return ctrl.Result{RequeueAfter: cnpgPollInterval}, nil - } - - now := metav1.Now() - restoreJob.Status.CompletedAt = &now - restoreJob.Status.Phase = backupsv1alpha1.RestoreJobPhaseSucceeded - // Set RecoveryConverged=True for symmetry with the False the unreachable- - // target path records, so .status.conditions tells the whole story rather - // than only ever showing the condition on failure. - apimeta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ - Type: restoreCondRecoveryConverged, - Status: metav1.ConditionTrue, - Reason: "RecoveryConverged", - Message: fmt.Sprintf("target cnpg.io Cluster %s/%s reached a healthy state", target.Namespace, clusterName), - }) - apimeta.SetStatusCondition(&restoreJob.Status.Conditions, metav1.Condition{ - Type: "Ready", - Status: metav1.ConditionTrue, - Reason: "RestoreCompleted", - Message: "target cnpg.io Cluster reached healthy state", - }) - if err := r.Status().Update(ctx, restoreJob); err != nil { - return ctrl.Result{}, err - } - return ctrl.Result{}, nil + // Within the deadline and not yet healthy (or the recovery Cluster is not + // chart-rendered yet): keep waiting. + return ctrl.Result{RequeueAfter: cnpgPollInterval}, nil } // cnpgRestoreTarget captures the resolved target for a CNPG restore. The @@ -1482,7 +1486,7 @@ func (r *RestoreJobReconciler) readPodContainerLog(ctx context.Context, namespac if err != nil { return "", err } - defer stream.Close() + defer func() { _ = stream.Close() }() // read-only log stream; nothing depends on the close error data, err := io.ReadAll(stream) if err != nil { return "", err diff --git a/internal/backupcontroller/cnpgstrategy_controller_test.go b/internal/backupcontroller/cnpgstrategy_controller_test.go index 48d04168c..d942bb5c3 100644 --- a/internal/backupcontroller/cnpgstrategy_controller_test.go +++ b/internal/backupcontroller/cnpgstrategy_controller_test.go @@ -2199,6 +2199,109 @@ func TestReconcileCNPGRestore_HealthyClusterSucceeds(t *testing.T) { } } +// TestReconcileCNPGRestore_HealthyPastDeadlineSucceeds is the regression guard +// for the health-before-deadline ordering: a recovery that has reached a +// healthy Cluster must be reported Succeeded even when the reconcile observing +// it lands AFTER the restore deadline has elapsed (e.g. a controller restart +// spanning the window). StartedAt is 72h in the past (well past the 30m default +// deadline) and a recoveryTime is set, so if the deadline branch ran first it +// would classify the restore Failed/RecoveryTargetUnreachable - a wrong verdict +// that can escalate to data loss on resubmit. The injected readPodLog fails the +// test if the classification path is entered at all, proving health short-circuits. +func TestReconcileCNPGRestore_HealthyPastDeadlineSucceeds(t *testing.T) { + const ( + ns = "tenant" + appName = "app" + clusterName = "postgres-app" + cnpgBkName = "cnpgbk" + ) + apiGroup := backupsv1alpha1.DefaultApplicationAPIGroup + strategyGroup := strategyv1alpha1.GroupVersion.Group + ctx := context.Background() + // Far past the 30m default deadline: this is the reconcile-gap case. + startedAt := metav1.NewTime(time.Now().Add(-72 * time.Hour)) + + snap, err := marshalCNPGBackupSnapshot(newPostgresApp(appName, ns), nil) + if err != nil { + t.Fatalf("marshal snapshot: %v", err) + } + backup := &backupsv1alpha1.Backup{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: "bk"}, + Spec: backupsv1alpha1.BackupSpec{ + ApplicationRef: corev1.TypedLocalObjectReference{APIGroup: &apiGroup, Kind: postgresAppKind, Name: appName}, + StrategyRef: corev1.TypedLocalObjectReference{APIGroup: &strategyGroup, Kind: strategyv1alpha1.CNPGStrategyKind, Name: "cnpg-strategy"}, + DriverMetadata: map[string]string{ + cnpgServerNameKey: appName, + cnpgDestinationPathKey: "s3://bucket/" + appName + "/", + cnpgBackupNameKey: cnpgBkName, + }, + }, + Status: backupsv1alpha1.BackupStatus{UnderlyingResources: snap}, + } + strategy := &strategyv1alpha1.CNPG{ + ObjectMeta: metav1.ObjectMeta{Name: "cnpg-strategy"}, + Spec: strategyv1alpha1.CNPGSpec{Template: strategyv1alpha1.CNPGTemplate{ + BarmanObjectStore: strategyv1alpha1.BarmanObjectStoreTemplate{DestinationPath: "s3://bucket/"}, + }}, + } + healthyCluster := &cnpgtypes.Cluster{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: clusterName, CreationTimestamp: metav1.NewTime(startedAt.Add(time.Minute))}, + Spec: cnpgtypes.ClusterSpec{Bootstrap: &cnpgtypes.BootstrapConfiguration{Recovery: &cnpgtypes.RecoverySource{Source: appName}}}, + Status: cnpgtypes.ClusterStatus{Phase: cnpgClusterHealthyPhase}, + } + sa := startedAt + restoreJob := &backupsv1alpha1.RestoreJob{ + ObjectMeta: metav1.ObjectMeta{Namespace: ns, Name: "rj"}, + Spec: backupsv1alpha1.RestoreJobSpec{ + BackupRef: corev1.LocalObjectReference{Name: "bk"}, + // recoveryTime set so the (wrongly-ordered) deadline branch would classify. + Options: &runtime.RawExtension{Raw: []byte(`{"recoveryTime":"2026-01-01T00:00:00Z"}`)}, + }, + Status: backupsv1alpha1.RestoreJobStatus{ + StartedAt: &sa, + Phase: backupsv1alpha1.RestoreJobPhaseRunning, + Conditions: []metav1.Condition{{ + Type: restoreCondTargetPurged, Status: metav1.ConditionTrue, Reason: "ClusterPurged", + LastTransitionTime: startedAt, Message: "purged", + }}, + }, + } + + c := newCNPGStrategyTestClient(t, backup, restoreJob, strategy, newPostgresApp(appName, ns), healthyCluster) + r := &RestoreJobReconciler{ + Client: c, + Interface: dynamicfake.NewSimpleDynamicClient(testCNPGScheme(t)), + // If the deadline/classification branch runs before the health check, + // it reaches the log reader - which must never happen for a healthy cluster. + readPodLog: func(context.Context, string, string, string) (string, error) { + t.Fatalf("classification (log read) ran for an already-healthy Cluster: health check must precede the deadline branch") + return "", nil + }, + } + + rj := &backupsv1alpha1.RestoreJob{} + if err := c.Get(ctx, client.ObjectKey{Namespace: ns, Name: "rj"}, rj); err != nil { + t.Fatalf("get seeded RestoreJob: %v", err) + } + if _, err := r.reconcileCNPGRestore(ctx, rj, backup); err != nil { + t.Fatalf("reconcileCNPGRestore: %v", err) + } + + got := &backupsv1alpha1.RestoreJob{} + if err := c.Get(ctx, client.ObjectKey{Namespace: ns, Name: "rj"}, got); err != nil { + t.Fatalf("get RestoreJob after reconcile: %v", err) + } + if got.Status.Phase != backupsv1alpha1.RestoreJobPhaseSucceeded { + t.Fatalf("expected phase Succeeded (healthy cluster past deadline), got %q (msg=%q)", got.Status.Phase, got.Status.Message) + } + if cond := apimeta.FindStatusCondition(got.Status.Conditions, "Ready"); cond == nil || cond.Status != metav1.ConditionTrue { + t.Fatalf("expected Ready=True, got %+v", cond) + } + if cond := apimeta.FindStatusCondition(got.Status.Conditions, restoreCondRecoveryConverged); cond == nil || cond.Status != metav1.ConditionTrue { + t.Fatalf("expected RecoveryConverged=True, got %+v", cond) + } +} + // TestReconcileCNPGRestore_DeadlineClassifiesRecoveryTargetUnreachable drives the // full reconcileCNPGRestore deadline branch (the classification call site), which // the pure-helper tests (TestRecoveryTargetUnreachable_*) do not exercise: