Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Startup from backup fails #2821

Closed
jonathon2nd opened this issue Dec 19, 2024 · 2 comments
Closed

Startup from backup fails #2821

jonathon2nd opened this issue Dec 19, 2024 · 2 comments

Comments

@jonathon2nd
Copy link

Please, answer some short questions which should help us to understand your problem / question better?

  • Which image of the operator are you using? ghcr.io/zalando/spilo-16:3.3-p1
  • Where do you run it - cloud or metal? Kubernetes or OpenShift? Bare Metal K8s
  • Are you running Postgres Operator in production? yes
  • Type of issue? Bug report

Something happened and all postgres pods had an issue. So I deleted them all and their pvs to create fresh from backup. But I am getting the following logs from the first pod and it fails to start, even though it states that it completes the restore from backup.

2024-12-18 23:58:34,872 - bootstrapping - INFO - Figuring out my environment (Google? AWS? Openstack? Local?)
2024-12-18 23:58:36,876 - bootstrapping - INFO - Could not connect to 169.254.169.254, assuming local Docker setup
2024-12-18 23:58:36,877 - bootstrapping - INFO - No meta-data available for this provider
2024-12-18 23:58:36,878 - bootstrapping - INFO - Looks like you are running local
2024-12-18 23:58:36,917 - bootstrapping - INFO - Configuring crontab
2024-12-18 23:58:36,917 - bootstrapping - INFO - Skipping creation of renice cron job due to lack of SYS_NICE capability
2024-12-18 23:58:36,937 - bootstrapping - INFO - Configuring log
2024-12-18 23:58:36,937 - bootstrapping - INFO - Configuring patroni
2024-12-18 23:58:36,951 - bootstrapping - INFO - Writing to file /run/postgres.yml
2024-12-18 23:58:36,952 - bootstrapping - INFO - Configuring certificate
2024-12-18 23:58:36,952 - bootstrapping - INFO - Generating ssl self-signed certificate
2024-12-18 23:58:37,441 - bootstrapping - INFO - Configuring standby-cluster
2024-12-18 23:58:37,442 - bootstrapping - INFO - Configuring wal-e
2024-12-18 23:58:37,442 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_S3_PREFIX
2024-12-18 23:58:37,443 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_S3_PREFIX
2024-12-18 23:58:37,443 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_ACCESS_KEY_ID
2024-12-18 23:58:37,444 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_SECRET_ACCESS_KEY
2024-12-18 23:58:37,444 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_S3_ENDPOINT
2024-12-18 23:58:37,445 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_ENDPOINT
2024-12-18 23:58:37,445 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_REGION
2024-12-18 23:58:37,445 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_DISABLE_S3_SSE
2024-12-18 23:58:37,446 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_DISABLE_S3_SSE
2024-12-18 23:58:37,446 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_S3_FORCE_PATH_STYLE
2024-12-18 23:58:37,447 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_DOWNLOAD_CONCURRENCY
2024-12-18 23:58:37,447 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_UPLOAD_CONCURRENCY
2024-12-18 23:58:37,448 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/USE_WALG_BACKUP
2024-12-18 23:58:37,448 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/USE_WALG_RESTORE
2024-12-18 23:58:37,449 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_LOG_DESTINATION
2024-12-18 23:58:37,449 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/PGPORT
2024-12-18 23:58:37,450 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/BACKUP_NUM_TO_RETAIN
2024-12-18 23:58:37,451 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/TMPDIR
2024-12-18 23:58:37,451 - bootstrapping - INFO - Configuring pam-oauth2
2024-12-18 23:58:37,452 - bootstrapping - INFO - Writing to file /etc/pam.d/postgresql
2024-12-18 23:58:37,452 - bootstrapping - INFO - Configuring pgbouncer
2024-12-18 23:58:37,452 - bootstrapping - INFO - No PGBOUNCER_CONFIGURATION was specified, skipping
2024-12-18 23:58:37,452 - bootstrapping - INFO - Configuring bootstrap
2024-12-18 23:58:37,452 - bootstrapping - INFO - Configuring pgqd
2024-12-18 23:58:39,179 WARNING: Kubernetes RBAC doesn't allow GET access to the 'kubernetes' endpoint in the 'default' namespace. Disabling 'bypass_api_service'.
2024-12-18 23:58:39,255 INFO: No PostgreSQL configuration items changed, nothing to reload.
2024-12-18 23:58:39,260 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:58:39,299 INFO: trying to bootstrap (without leader)
INFO: 2024/12/18 23:58:39.854826 Selecting the latest backup...
INFO: 2024/12/18 23:58:39.855374 Backup to fetch will be searched in storages: [default]
INFO: 2024/12/18 23:58:40.078194 LATEST backup is: 'base_0000003F0000000F0000007F'
INFO: 2024/12/18 23:58:40.441662 Finished extraction of part_003.tar.lz4
INFO: 2024/12/18 23:58:47.407068 Finished extraction of part_001.tar.lz4
INFO: 2024/12/18 23:58:47.483398 Finished extraction of pg_control.tar.lz4
INFO: 2024/12/18 23:58:47.483460 
Backup extraction complete.
2024-12-18 23:58:47,517 INFO: replica has been created using wal_e
2024-12-18 23:58:47,519 INFO: bootstrapped (without leader)
2024-12-18 23:58:48 UTC [109]: [1-1] 676361b8.6d 0     LOG:  Auto detecting pg_stat_kcache.linux_hz parameter...
2024-12-18 23:58:48 UTC [109]: [2-1] 676361b8.6d 0     LOG:  pg_stat_kcache.linux_hz is set to 1000000
2024-12-18 23:58:48 UTC [109]: [3-1] 676361b8.6d 0     LOG:  redirecting log output to logging collector process
2024-12-18 23:58:48 UTC [109]: [4-1] 676361b8.6d 0     HINT:  Future log output will appear in directory "../pg_log".
2024-12-18 23:58:48,338 INFO: postmaster pid=109
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:58:49,260 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:58:49,260 INFO: not healthy enough for leader race
2024-12-18 23:58:49,286 INFO: bootstrap (without leader) in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:58:59,335 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:58:59,335 INFO: not healthy enough for leader race
2024-12-18 23:58:59,336 INFO: bootstrap (without leader) in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:09,259 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:59:09,259 INFO: not healthy enough for leader race
2024-12-18 23:59:09,259 INFO: bootstrap (without leader) in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:19,335 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:59:19,335 INFO: not healthy enough for leader race
2024-12-18 23:59:19,335 INFO: bootstrap (without leader) in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:29,336 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:59:29,336 INFO: not healthy enough for leader race
2024-12-18 23:59:29,336 INFO: bootstrap (without leader) in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:37,837 INFO: establishing a new patroni heartbeat connection to postgres
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:38,640 INFO: establishing a new patroni heartbeat connection to postgres
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:39,260 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:59:39,260 INFO: not healthy enough for leader race
2024-12-18 23:59:39,260 INFO: bootstrap (without leader) in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:48,038 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:59:48,039 INFO: Still starting up as a standby.
2024-12-18 23:59:48,040 INFO: establishing a new patroni heartbeat connection to postgres
2024-12-18 23:59:48,235 INFO: establishing a new patroni heartbeat connection to postgres
2024-12-18 23:59:48,335 WARNING: Retry got exception: connection problems
2024-12-18 23:59:48,335 WARNING: Failed to determine PostgreSQL state from the connection, falling back to cached role
2024-12-18 23:59:48,336 WARNING: Failed to determine PostgreSQL state from the connection, falling back to cached role
2024-12-18 23:59:48,336 INFO: Error communicating with PostgreSQL. Will try again later
/var/run/postgresql:5432 - rejecting connections
2024-12-18 23:59:58,138 INFO: Lock owner: ; I am acid-fp-0
2024-12-18 23:59:58,138 INFO: Still starting up as a standby.
2024-12-18 23:59:58,138 INFO: establishing a new patroni heartbeat connection to postgres
2024-12-18 23:59:58,742 INFO: establishing a new patroni heartbeat connection to postgres
2024-12-18 23:59:58,744 WARNING: Retry got exception: connection problems
2024-12-18 23:59:58,745 WARNING: Failed to determine PostgreSQL state from the connection, falling back to cached role
2024-12-18 23:59:58,745 WARNING: Failed to determine PostgreSQL state from the connection, falling back to cached role
2024-12-18 23:59:58,746 INFO: Error communicating with PostgreSQL. Will try again later

operator logs
pp-postgres-operator-55ff458857-2hjqj_postgres-operator.log
@jonathon2nd
Copy link
Author

ugh, PITR recovering is also not working this morning. Have targeted this time yesterday and the day before. So something really got messed up for this. Will create blank cluster and restore a logical backup created by backup cronjob for when PITR fails.

---
apiVersion: acid.zalan.do/v1
kind: postgresql
metadata:
  labels:
    team: acid
  name: acid-fp-restore
  namespace: postgres
spec:
  dockerImage: ghcr.io/zalando/spilo-16:3.3-p1
  clone:
    cluster: "acid-fp"
    timestamp: "2024-12-17T16:47:49+00:00"
    uid: "69d79ade-6cfe-4a02-b164-25b77cf76e24"
    s3_wal_path: "s3://preprod-postgres-operator-k8s/spilo/acid-fp/wal/14/"
    s3_endpoint: "https://s3.wasabisys.com"
    s3_force_path_style: true
  allowedSourceRanges:
  - 10.0.0.0/8
  databases:
    ...

  enableMasterLoadBalancer: false
  enableReplicaLoadBalancer: false
  enableConnectionPooler: true # enable/disable connection pooler deployment
  enableReplicaConnectionPooler: false # set to enable connectionPooler for replica service

  enableLogicalBackup: true
  logicalBackupSchedule: 0 0 1 * *
  numberOfInstances: 3
  postgresql:
    version: "14"
    parameters:  # Expert section
      hot_standby_feedback: "on"
      shared_buffers: "32MB"
      max_connections: "100"
      log_statement: "all"
  resources:
    limits:
      cpu: 500m
      memory: 1Gi
    requests:
      cpu: 100m
      memory: 100Mi
  teamId: acid
  users:
    ...
  volume:
    size: 20Gi

  patroni:
    synchronous_mode: true

# overwrite custom properties for connection pooler deployments
  connectionPooler:
    numberOfInstances: 2
#    mode: "transaction"
#    schema: "pooler"
#    user: "pooler"
    resources:
      requests:
        cpu: 300m
        memory: 100Mi
      limits:
        cpu: "1"
        memory: 500Mi

2024-12-19 17:22:50,236 - bootstrapping - INFO - Figuring out my environment (Google? AWS? Openstack? Local?)
2024-12-19 17:22:52,241 - bootstrapping - INFO - Could not connect to 169.254.169.254, assuming local Docker setup
2024-12-19 17:22:52,242 - bootstrapping - INFO - No meta-data available for this provider
2024-12-19 17:22:52,243 - bootstrapping - INFO - Looks like you are running local
2024-12-19 17:22:52,281 - bootstrapping - INFO - Configuring log
2024-12-19 17:22:52,281 - bootstrapping - INFO - Configuring pam-oauth2
2024-12-19 17:22:52,281 - bootstrapping - INFO - Writing to file /etc/pam.d/postgresql
2024-12-19 17:22:52,281 - bootstrapping - INFO - Configuring pgbouncer
2024-12-19 17:22:52,281 - bootstrapping - INFO - No PGBOUNCER_CONFIGURATION was specified, skipping
2024-12-19 17:22:52,281 - bootstrapping - INFO - Configuring certificate
2024-12-19 17:22:52,281 - bootstrapping - INFO - Generating ssl self-signed certificate
2024-12-19 17:22:52,841 - bootstrapping - INFO - Configuring crontab
2024-12-19 17:22:52,841 - bootstrapping - INFO - Skipping creation of renice cron job due to lack of SYS_NICE capability
2024-12-19 17:22:52,853 - bootstrapping - INFO - Configuring wal-e
2024-12-19 17:22:52,854 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_S3_PREFIX
2024-12-19 17:22:52,854 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_S3_PREFIX
2024-12-19 17:22:52,855 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_ACCESS_KEY_ID
2024-12-19 17:22:52,855 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_SECRET_ACCESS_KEY
2024-12-19 17:22:52,856 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_S3_ENDPOINT
2024-12-19 17:22:52,856 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_ENDPOINT
2024-12-19 17:22:52,857 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_REGION
2024-12-19 17:22:52,858 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_DISABLE_S3_SSE
2024-12-19 17:22:52,858 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_DISABLE_S3_SSE
2024-12-19 17:22:52,859 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_S3_FORCE_PATH_STYLE
2024-12-19 17:22:52,859 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_DOWNLOAD_CONCURRENCY
2024-12-19 17:22:52,860 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_UPLOAD_CONCURRENCY
2024-12-19 17:22:52,860 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/USE_WALG_BACKUP
2024-12-19 17:22:52,861 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/USE_WALG_RESTORE
2024-12-19 17:22:52,861 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_LOG_DESTINATION
2024-12-19 17:22:52,862 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/PGPORT
2024-12-19 17:22:52,862 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/BACKUP_NUM_TO_RETAIN
2024-12-19 17:22:52,863 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/TMPDIR
2024-12-19 17:22:52,863 - bootstrapping - INFO - Configuring standby-cluster
2024-12-19 17:22:52,864 - bootstrapping - INFO - Configuring pgqd
2024-12-19 17:22:52,864 - bootstrapping - INFO - Configuring bootstrap
2024-12-19 17:22:52,865 - bootstrapping - WARNING - Invalid WALE_S3_ENDPOINT, the format is protocol+convention://hostname:port, but got https://s3.wasabisys.com
2024-12-19 17:22:52,865 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/WALE_S3_PREFIX
2024-12-19 17:22:52,866 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/WALG_S3_PREFIX
2024-12-19 17:22:52,866 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/AWS_ACCESS_KEY_ID
2024-12-19 17:22:52,867 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/AWS_SECRET_ACCESS_KEY
2024-12-19 17:22:52,867 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/WALE_S3_ENDPOINT
2024-12-19 17:22:52,867 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/AWS_ENDPOINT
2024-12-19 17:22:52,868 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/WALE_DISABLE_S3_SSE
2024-12-19 17:22:52,869 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/WALG_DISABLE_S3_SSE
2024-12-19 17:22:52,869 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/AWS_S3_FORCE_PATH_STYLE
2024-12-19 17:22:52,869 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/USE_WALG_BACKUP
2024-12-19 17:22:52,870 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/USE_WALG_RESTORE
2024-12-19 17:22:52,870 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/WALE_LOG_DESTINATION
2024-12-19 17:22:52,871 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-fp/TMPDIR
2024-12-19 17:22:52,871 - bootstrapping - INFO - Configuring patroni
2024-12-19 17:22:52,883 - bootstrapping - INFO - Writing to file /run/postgres.yml
2024-12-19 17:22:54,742 WARNING: Kubernetes RBAC doesn't allow GET access to the 'kubernetes' endpoint in the 'default' namespace. Disabling 'bypass_api_service'.
2024-12-19 17:22:54,771 INFO: No PostgreSQL configuration items changed, nothing to reload.
2024-12-19 17:22:54,776 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:22:54,816 INFO: trying to bootstrap a new cluster
2024-12-19 17:22:54,817 INFO: Running custom bootstrap script: envdir "/run/etc/wal-e.d/env-clone-acid-fp" python3 /scripts/clone_with_wale.py --recovery-target-time="2024-12-17T16:47:49+00:00"
2024-12-19 17:22:54,969 INFO: Trying s3://preprod-postgres-operator-k8s/spilo/acid-fp/wal/14/ for clone
INFO: 2024/12/19 17:22:55.144650 List backups from storages: [default]
2024-12-19 17:22:55,322 INFO: cloning cluster acid-fp-restore using wal-g backup-fetch /home/postgres/pgdata/pgroot/data base_0000003F0000000F0000007F
INFO: 2024/12/19 17:22:55.436490 Selecting the backup with name base_0000003F0000000F0000007F...
INFO: 2024/12/19 17:22:55.437713 Backup to fetch will be searched in storages: [default]
INFO: 2024/12/19 17:22:56.208721 Finished extraction of part_003.tar.lz4
INFO: 2024/12/19 17:23:03.389015 Finished extraction of part_001.tar.lz4
INFO: 2024/12/19 17:23:03.459955 Finished extraction of pg_control.tar.lz4
INFO: 2024/12/19 17:23:03.460043 
Backup extraction complete.
2024-12-19 17:23:04,074 maybe_pg_upgrade INFO: No PostgreSQL configuration items changed, nothing to reload.
2024-12-19 17:23:04,143 maybe_pg_upgrade INFO: Cluster version: 14, bin version: 14
2024-12-19 17:23:04,143 maybe_pg_upgrade INFO: Trying to perform point-in-time recovery
2024-12-19 17:23:04,143 maybe_pg_upgrade INFO: Running custom bootstrap script: true
2024-12-19 17:23:04,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:23:04,775 INFO: not healthy enough for leader race
2024-12-19 17:23:04,935 INFO: bootstrap in progress
2024-12-19 17:23:04,939 maybe_pg_upgrade INFO: postmaster pid=107
2024-12-19 17:23:04 UTC [107]: [1-1] 67645678.6b 0     LOG:  Auto detecting pg_stat_kcache.linux_hz parameter...
2024-12-19 17:23:04 UTC [107]: [2-1] 67645678.6b 0     LOG:  pg_stat_kcache.linux_hz is set to 500000
/var/run/postgresql:5432 - no response
2024-12-19 17:23:04 UTC [107]: [3-1] 67645678.6b 0     LOG:  redirecting log output to logging collector process
2024-12-19 17:23:04 UTC [107]: [4-1] 67645678.6b 0     HINT:  Future log output will appear in directory "../pg_log".
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:23:14,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:23:14,775 INFO: not healthy enough for leader race
2024-12-19 17:23:14,775 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:23:24,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:23:24,775 INFO: not healthy enough for leader race
2024-12-19 17:23:24,776 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:23:34,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:23:34,775 INFO: not healthy enough for leader race
2024-12-19 17:23:34,775 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:23:44,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:23:44,835 INFO: not healthy enough for leader race
2024-12-19 17:23:44,835 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:23:54,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:23:54,835 INFO: not healthy enough for leader race
2024-12-19 17:23:54,835 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:24:04,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:24:04,775 INFO: not healthy enough for leader race
2024-12-19 17:24:04,776 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:24:14,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:24:14,775 INFO: not healthy enough for leader race
2024-12-19 17:24:14,776 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:24:24,775 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:24:24,775 INFO: not healthy enough for leader race
2024-12-19 17:24:24,775 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
2024-12-19 17:24:34,835 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:24:34,835 INFO: not healthy enough for leader race
2024-12-19 17:24:34,836 INFO: bootstrap in progress
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - rejecting connections
/var/run/postgresql:5432 - no response
Traceback (most recent call last):
  File "/scripts/maybe_pg_upgrade.py", line 51, in perform_pitr
    raise Exception('Point-in-time recovery failed')
Exception: Point-in-time recovery failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/scripts/maybe_pg_upgrade.py", line 140, in <module>
    main()
  File "/scripts/maybe_pg_upgrade.py", line 87, in main
    perform_pitr(upgrade, cluster_version, bin_version, config['bootstrap'])
  File "/scripts/maybe_pg_upgrade.py", line 70, in perform_pitr
    raise Exception('Point-in-time recovery failed.\nLOGS:\n--\n' + logs)
Exception: Point-in-time recovery failed.
LOGS:
--
If you are not restoring from a backup, try removing the file ""/home/postgres/pgdata/pgroot/data/backup_label"".
Be careful: removing ""/home/postgres/pgdata/pgroot/data/backup_label"" will result in a corrupt cluster if restoring from a backup.",,,,,,,"","startup",,0
2024-12-19 17:24:36.576 UTC,,,107,,67645678.6b,6,,2024-12-19 17:23:04 UTC,,0,LOG,00000,"startup process (PID 110) exited with exit code 1",,,,,,,,,"","postmaster",,0
2024-12-19 17:24:36.576 UTC,,,107,,67645678.6b,7,,2024-12-19 17:23:04 UTC,,0,LOG,00000,"aborting startup due to startup process failure",,,,,,,,,"","postmaster",,0
2024-12-19 17:24:36.577 UTC,,,107,,67645678.6b,8,,2024-12-19 17:23:04 UTC,,0,LOG,00000,"database system is shut down",,,,,,,,,"","postmaster",,0

2024-12-19 17:24:37,567 ERROR: /scripts/maybe_pg_upgrade.py script failed
2024-12-19 17:24:37,647 INFO: removing initialize key after failed attempt to bootstrap the cluster
2024-12-19 17:24:37,661 INFO: renaming data directory to /home/postgres/pgdata/pgroot/data.failed
Traceback (most recent call last):
  File "/usr/local/bin/patroni", line 8, in <module>
    sys.exit(main())
  File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 344, in main
    return patroni_main(args.configfile)
  File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 232, in patroni_main
    abstract_main(Patroni, configfile)
  File "/usr/local/lib/python3.10/dist-packages/patroni/daemon.py", line 174, in abstract_main
    controller.run()
  File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 192, in run
    super(Patroni, self).run()
  File "/usr/local/lib/python3.10/dist-packages/patroni/daemon.py", line 143, in run
    self._run_cycle()
  File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 201, in _run_cycle
    logger.info(self.ha.run_cycle())
  File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1989, in run_cycle
    info = self._run_cycle()
  File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1806, in _run_cycle
    return self.post_bootstrap()
  File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1690, in post_bootstrap
    self.cancel_initialization()
  File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1683, in cancel_initialization
    raise PatroniFatalException('Failed to bootstrap cluster')
patroni.exceptions.PatroniFatalException: Failed to bootstrap cluster
/etc/runit/runsvdir/default/patroni: finished with code=1 signal=0
/etc/runit/runsvdir/default/patroni: sleeping 30 seconds
2024-12-19 17:25:08,653 WARNING: Kubernetes RBAC doesn't allow GET access to the 'kubernetes' endpoint in the 'default' namespace. Disabling 'bypass_api_service'.
2024-12-19 17:25:08,687 INFO: No PostgreSQL configuration items changed, nothing to reload.
2024-12-19 17:25:08,740 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:25:08,761 INFO: waiting for leader to bootstrap
2024-12-19 17:25:18,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:25:18,739 INFO: waiting for leader to bootstrap
2024-12-19 17:25:28,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:25:28,739 INFO: waiting for leader to bootstrap
2024-12-19 17:25:38,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:25:38,739 INFO: waiting for leader to bootstrap
2024-12-19 17:25:48,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:25:48,739 INFO: waiting for leader to bootstrap
2024-12-19 17:25:58,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:25:58,740 INFO: waiting for leader to bootstrap
2024-12-19 17:26:08,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:26:08,739 INFO: waiting for leader to bootstrap
2024-12-19 17:26:18,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:26:18,739 INFO: waiting for leader to bootstrap
2024-12-19 17:26:28,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:26:28,739 INFO: waiting for leader to bootstrap
2024-12-19 17:26:38,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:26:38,739 INFO: waiting for leader to bootstrap
2024-12-19 17:26:48,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:26:48,739 INFO: waiting for leader to bootstrap
2024-12-19 17:26:58,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:26:58,739 INFO: waiting for leader to bootstrap
2024-12-19 17:27:08,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:27:08,739 INFO: waiting for leader to bootstrap
2024-12-19 17:27:18,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:27:18,739 INFO: waiting for leader to bootstrap
2024-12-19 17:27:28,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:27:28,739 INFO: waiting for leader to bootstrap
2024-12-19 17:27:38,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:27:38,739 INFO: waiting for leader to bootstrap
2024-12-19 17:27:48,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:27:48,739 INFO: waiting for leader to bootstrap
2024-12-19 17:27:58,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:27:58,739 INFO: waiting for leader to bootstrap
2024-12-19 17:28:08,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:28:08,739 INFO: waiting for leader to bootstrap
2024-12-19 17:28:18,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:28:18,739 INFO: waiting for leader to bootstrap
2024-12-19 17:28:28,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:28:28,739 INFO: waiting for leader to bootstrap
2024-12-19 17:28:38,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:28:38,739 INFO: waiting for leader to bootstrap
2024-12-19 17:28:48,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:28:48,739 INFO: waiting for leader to bootstrap
2024-12-19 17:28:58,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:28:58,739 INFO: waiting for leader to bootstrap
2024-12-19 17:29:08,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:29:08,739 INFO: waiting for leader to bootstrap
2024-12-19 17:29:18,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:29:18,739 INFO: waiting for leader to bootstrap
2024-12-19 17:29:28,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:29:28,739 INFO: waiting for leader to bootstrap
2024-12-19 17:29:38,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:29:38,739 INFO: waiting for leader to bootstrap
2024-12-19 17:29:48,739 INFO: Lock owner: ; I am acid-fp-restore-0
2024-12-19 17:29:48,739 INFO: waiting for leader to bootstrap

@jonathon2nd
Copy link
Author

Restore from logical backup worked, because PITR failed just going to close as it wont get anywhere

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@jonathon2nd