[Bug]: Replica permanently stuck in wal-restore loop after failover: walreceiver never reconnects, operator reports cluster healthy, burns CPU indefinitely

What happened?

After a failover, a demoted primary became permanently stuck in archive-restore-only mode. The walreceiver was killed ~5 minutes after starting and never reconnected. The replica has been stuck for 40+ hours, burning ~9.7 CPU cores continuously while the operator reports the cluster as fully healthy (readyInstances: 3, phase: "Cluster in healthy state").

Context

We performed a node migration on 2026-04-04: scaled the cluster from 3→6 instances (to provision fresh replicas on new nodes), promoted a new-node instance to primary, cordoned the old nodes, destroyed the old instances one at a time, then patched back to 3 instances. This completed successfully by ~02:45 UTC.

Approximately 28 hours later (2026-04-05 ~06:01 UTC), a separate failover occurred. The logs show a contested switchover -- the operator set pod-18 as the target primary, but pod-17 also briefly attempted to promote itself:

1. 06:01:02Z -- Pod-17 logs "Setting myself as primary" and "I'm the target primary, wait for the wal_receiver to be terminated"
2. 06:01:02Z -- Walreceiver FATAL: "replication terminated by primary server" -- "End of WAL reached on timeline 48 at 412/D80000A0", "could not send end-of-streaming message to primary: SSL connection has been closed unexpectedly"
3. 06:01:03Z -- "I'm the target primary, applying WALs and promoting my instance" -- pod-17 tried to promote
4. 06:04-06:05Z -- Smart shutdown of pod-17 failed twice ("pg_ctl: server does not shut down")
5. 06:11:28Z -- Pod-17 finally realizes pod-18 won the promotion: "This is an old primary instance, waiting for the switchover to finish"
6. 06:11:29Z -- Runs pg_rewind against pod-18, restarts as replica

The cause of the switchover at 06:01 is unclear from available logs. It may have been triggered by a health check failure exacerbated by our aggressive wal_receiver_timeout: 5s / wal_sender_timeout: 5s settings.

Sequence of events (2026-04-05)

06:11:28Z -- Instance manager on pod-17 detects switchover completed, runs pg_rewind against pod-18, demotes to replica, starts postmaster.

06:11:31Z -- Walreceiver starts streaming from primary at 412/D9000000 on timeline 49. consistent recovery state reached at 412/D90000A0.

06:11:32Z -- Instance manager begins synchronizing replication slots. Fails with:

ERROR: cannot advance replication slot to 412/D9000000, minimum is 412/D9000028 (SQLSTATE 55000)

Pod-17's local HA slot was already at 412/D9000028 (advanced during its brief time as primary), but the primary-side slot reported 412/D9000000. The instance manager tried to move it backwards. This error repeated every 30 seconds for 5 minutes.

06:16:39.474Z -- The walreceiver is killed:

FATAL: terminating walreceiver process due to administrator command (57P01)

This is only ~5 minutes after the walreceiver started. With wal_receiver_timeout: 5s (PostgreSQL default is 60s), the walreceiver had very little tolerance for any disruption.

06:16:40Z onward -- PostgreSQL falls back to restore_command (wal-restore). An infinite loop begins:

1. wal-restore downloads 32 WAL files in parallel from object storage (maxParallel: 32 prefetch)
2. WAL file restored successfully (it exists in the archive because the primary is actively archiving)
3. Reaches end of WAL, requests next segment
4. wal-restore sets end-of-wal-stream flag (prefetched file not found)
5. Next invocation: detects flag, returns error to signal PostgreSQL to try streaming
6. PostgreSQL tries streaming -- fails (timeline divergence: replica on timeline 49, archive has timeline 50)
7. Falls back to restore_command again → goto step 1

This cycle repeats every ~10 seconds, indefinitely.

Why the walreceiver never reconnects

wal-restore logs show: "Refusing to restore future timeline history file" (clusterTimeline=49, fileTimeline=50). The primary moved to a newer timeline during the failover. Even when the end-of-wal-stream escape hatch fires, the walreceiver cannot negotiate a streaming connection because the timelines diverge. PostgreSQL falls back to archive restore, which succeeds (the archive has the WAL files), and the cycle repeats.

CPU impact

The wal-restore loop burns ~9.7 CPU cores on the replica pod:

Each restore_command invocation spawns /controller/manager wal-restore which downloads 32 WAL files in parallel from object storage (snappy decompression), even when requesting the same WAL segment repeatedly. There is no backoff, deduplication, or circuit breaker. This also incurs unnecessary object storage API costs.

Replication state on primary

-- pg_replication_slots on primary (pod-18):
 slot_name                    | active | restart_lsn    | lag
 _cnpg_demo_pg_common_17     | false  | 412/D9C40000   | 1220 MB
 _cnpg_demo_pg_common_16     | true   | 413/26008FF8   | 0 bytes

-- pg_stat_replication on primary:
-- Only pod-16 connected (streaming, async, caught up)
-- Pod-17 is absent

Monitoring blind spot

• cnpg_pg_replication_lag on pod-17 reports 0 throughout the entire 40+ hour incident
• The metric is computed locally on the replica (pg_last_wal_replay_lsn() vs received), but the replica hasn't received new WAL via streaming
• The primary's pg_stat_replication and slot status show the real picture (1.2 GB behind and growing -- 1,252 MB at time of writing, up from 1,220 MB an hour earlier), but this isn't surfaced in CNPG monitoring metrics. The slot's wal_status: reserved means WAL is accumulating on the primary and cannot be reclaimed, so this will eventually cause disk pressure on the primary too
• kubectl cnpg status / cluster CR shows: phase: "Cluster in healthy state", readyInstances: 3, healthy: [all three pods]

What I expected

1. The instance manager should detect that a replica's walreceiver has been down and take corrective action (restart, re-clone, etc.)
2. The replication slot sync should handle SQLSTATE 55000 (cannot advance backwards) as a no-op, not an error that short-circuits sync of remaining slots
3. The wal-restore loop should have backoff when repeatedly restoring the same WAL segment
4. The cluster should not report as "healthy" when a replica has no active walreceiver and its replication slot on the primary is inactive with growing lag

Source code analysis

Slot sync -- infrastructure/postgresmanager.go L89: Update() calls pg_replication_slot_advance() without checking if the target LSN is behind the current position. The error propagates up and short-circuits sync of remaining slots.

wal-restore -- walrestore/cmd.go L88-L92: The end-of-wal-stream flag mechanism only returns one error, then succeeds on the next call if the archive has the WAL file. This defeats the purpose when the primary is actively archiving.

Instance controller -- IsWALReceiverActive() at probes.go L568 exists and is populated into the status struct at L561, but it is only consumed during promotion/switchover (instance_controller.go L1232, replicas.go L147/261/321). It is never used for replica health monitoring. The reconcile loop only checks IsDBUp (ping), which passes because PostgreSQL is running.

Potential contributing factors

• wal_receiver_timeout: 5s and wal_sender_timeout: 5s -- these are well below the PostgreSQL defaults of 60s. The tight timeouts likely caused the walreceiver to be killed much sooner than it would with default settings. We believe this is a key reason the bug may have evaded testing -- most deployments use the 60s defaults, giving the walreceiver enough time to stabilize after a failover before timeout. With 5s timeouts, the walreceiver had almost no grace period.
• maxParallel: 32 on WAL restore -- amplifies the CPU cost of the stuck loop (32 parallel downloads from object storage every ~10 seconds)
• Active WAL archiving by the primary -- the end-of-wal-stream escape hatch is designed for when the archive runs out of WAL files. When the primary is actively archiving, the archive always has the requested file, so the escape hatch is defeated on the very next call.

Cluster resource

apiVersion: postgresql.cnpg.io/v1
kind: Cluster
metadata:
  name: <redacted>
  namespace: db
spec:
  instances: 3
  imageCatalogRef:
    apiGroup: postgresql.cnpg.io
    kind: ImageCatalog
    major: 18
    name: custom-postgres-images
  # PostgreSQL 18.3
  failoverDelay: 30
  switchoverDelay: 30
  primaryUpdateStrategy: unsupervised
  enablePDB: false
  replicationSlots:
    highAvailability:
      enabled: true
      slotPrefix: _cnpg_
    synchronizeReplicas:
      enabled: true
    updateInterval: 30
  backup:
    barmanObjectStore:
      azureCredentials:
        connectionString:
          key: AZURE_STORAGE_CONNECTION_STRING
          name: <redacted>
      destinationPath: <redacted>
      serverName: <redacted>
      wal:
        compression: snappy
        maxParallel: 32
    target: prefer-standby
  postgresql:
    parameters:
      hot_standby_feedback: "on"
      wal_receiver_timeout: 5s
      wal_sender_timeout: 5s
      wal_receiver_status_interval: 5s
      max_replication_slots: "64"
      max_wal_senders: "24"
      wal_level: logical
      max_connections: "1000"
      shared_buffers: 30GB
      # (other tuning parameters omitted for brevity)
    shared_preload_libraries:
    - pgaudit
    - pg_stat_statements
    - auto_explain
    - pg_cron
    - timescaledb
  resources:
    limits:
      cpu: 30000m
      memory: 120Gi
    requests:
      cpu: 30000m
      memory: 120Gi
  storage:
    size: 250Gi
  walStorage:
    size: 64Gi
  affinity:
    nodeSelector:
      kubernetes.azure.com/agentpool: <redacted>

Relevant log output

// Instance manager -- switchover and demotion (06:11:28-06:11:30)
{"logger":"instance-manager","msg":"Switchover completed","currentPrimary":"<cluster>-18","targetPrimary":"<cluster>-18","pod":"<cluster>-17","ts":"2026-04-05T06:11:28.967682805Z"}
{"logger":"instance-manager","msg":"Starting up pg_rewind","pod":"<cluster>-17","ts":"2026-04-05T06:11:29.502484826Z"}
{"logger":"instance-manager","msg":"Demoting instance","pod":"<cluster>-17","ts":"2026-04-05T06:11:30.049614898Z"}
{"logger":"instance-manager","msg":"postmaster started","postMasterPID":"45","pod":"<cluster>-17","ts":"2026-04-05T06:11:30.063907908Z"}

// PostgreSQL -- startup and streaming (06:11:30-06:11:31)
{"error_severity":"LOG","_msg":"entering standby mode","backend_type":"startup","pod":"<cluster>-17","ts":"2026-04-05T06:11:31.577Z"}
{"error_severity":"LOG","_msg":"consistent recovery state reached at 412/D90000A0","pod":"<cluster>-17","ts":"2026-04-05T06:11:31.582Z"}
{"error_severity":"LOG","_msg":"database system is ready to accept read-only connections","pod":"<cluster>-17","ts":"2026-04-05T06:11:31.582Z"}
{"error_severity":"LOG","_msg":"started streaming WAL from primary at 412/D9000000 on timeline 49","backend_type":"walreceiver","pod":"<cluster>-17","ts":"2026-04-05T06:11:31.596Z"}

// Instance manager -- slot sync errors (06:11:32-06:16:32, every 30s)
{"logger":"instance-manager","msg":"synchronizing replication slots","err":"ERROR: cannot advance replication slot to 412/D9000000, minimum is 412/D9000028 (SQLSTATE 55000)","pod":"<cluster>-17","ts":"2026-04-05T06:11:32.982617149Z"}
// ... repeated every 30 seconds through 06:16:32 ...

// PostgreSQL -- walreceiver killed (06:16:39)
{"error_severity":"FATAL","_msg":"terminating walreceiver process due to administrator command","sql_state_code":"57P01","backend_type":"walreceiver","process_id":"199","pod":"<cluster>-17","ts":"2026-04-05T06:16:39.474Z"}

// PostgreSQL -- falls back to archive restore (06:16:40)
{"error_severity":"LOG","_msg":"restored log file \"0000003100000412000000D9\" from archive","pod":"<cluster>-17","ts":"2026-04-05T06:16:40.218Z"}
{"error_severity":"LOG","_msg":"invalid record length at 412/D90000A0: expected at least 24, got 0","pod":"<cluster>-17","ts":"2026-04-05T06:16:40.247Z"}
{"error_severity":"LOG","_msg":"waiting for WAL to become available at 412/D90000B8","pod":"<cluster>-17","ts":"2026-04-05T06:16:40.370Z"}

// wal-restore -- infinite loop (every ~10 seconds for 40+ hours, still ongoing)
{"logger":"wal-restore","msg":"Set end-of-wal-stream flag as one of the WAL files to be prefetched was not found","pod":"<cluster>-17"}
{"logger":"wal-restore","msg":"end-of-wal-stream flag found.Exiting with error once to let Postgres try switching to streaming replication","pod":"<cluster>-17"}
// ... repeating every ~10 seconds since 06:16:40 Apr 5 ...

// wal-restore -- timeline divergence (prevents streaming reconnection)
{"logger":"wal-restore","msg":"Refusing to restore future timeline history file","clusterTimeline":49,"fileTimeline":50,"pod":"<cluster>-17"}

// wal-restore -- parallel download on every cycle (CPU burn source)
{"logger":"wal-restore","msg":"WAL restore command completed (parallel)","walName":"0000003100000412000000D9","maxParallel":32,"successfulWalRestore":32,"downloadTotalTime":3.193,"pod":"<cluster>-17"}

# Operator status -- considers cluster healthy throughout the 40+ hour incident
$ kubectl get cluster <cluster> -o jsonpath='{.status.phase}'
Cluster in healthy state

$ kubectl get cluster <cluster> -o jsonpath='{.status.instancesStatus.healthy}'
["<cluster>-16","<cluster>-17","<cluster>-18"]

Recovery required kubectl cnpg destroy, not just pod delete

Deleting the pod was insufficient to recover. The recreated pod immediately entered CrashLoopBackOff with:

PANIC: could not locate a valid checkpoint record at 412/D9000028

The data directory's pg_controldata pointed to a checkpoint on timeline 49, but the WAL files available were from timeline 31 -- the 40 hours of stuck wal-restore had left the data directory in an unrecoverable state. We had to run kubectl cnpg destroy <cluster> 17 to delete the PVCs and force a full re-clone from the primary. The replacement instance (pod-22) came up streaming and healthy within 60 seconds.

Environment

• CNPG operator: 1.29.0 (ghcr.io/cloudnative-pg/cloudnative-pg:1.29.0)
• PostgreSQL: 18.3 (custom image, arm64)
• Kubernetes: 1.34.4
• Cloud: Azure AKS
• Installation: Helm