PITR restore not work

[sonphzz]

Description

I used the autobase ansible role to install my Postgresql Cluster with 4 instances ( 1 master - 3 replicas). I took some full-backup and tried to restore it. The scenario is:

• Change value in table of database to number A1
• Take full-backup at time T1
• Change value in table of database to number A2
• Take full-backup at time T2
• pgbackrest info

stanza: an-prod-cluster
    status: ok
    cipher: none

    db (current)
        wal archive min/max (16): 0000000300000001000000AC/0000000A00000001000000D1

        full backup: 20250908-095316F
            timestamp start/stop: 2025-09-08 09:53:16+00 / 2025-09-08 09:53:59+00
            wal start/stop: 0000000300000001000000AC / 0000000300000001000000AC
            database size: 3.1GB, database backup size: 3.1GB
            repo1: backup size: 1.2GB

        full backup: 20250908-102905F -> This is backup at T1
            timestamp start/stop: 2025-09-08 10:29:05+00 / 2025-09-08 10:29:48+00
            wal start/stop: 0000000500000001000000B6 / 0000000500000001000000B6
            database size: 3.1GB, database backup size: 3.1GB
            repo1: backup size: 1.2GB

        full backup: 20250908-104107F -> This is backup at T2
            timestamp start/stop: 2025-09-08 10:41:07+00 / 2025-09-08 10:41:49+00
            wal start/stop: 0000000500000001000000B8 / 0000000500000001000000B8
            database size: 3.1GB, database backup size: 3.1GB
            repo1: backup size: 1.2GB

        full backup: 20250908-105049F
            timestamp start/stop: 2025-09-08 10:50:49+00 / 2025-09-08 10:51:31+00
            wal start/stop: 0000000700000001000000C4 / 0000000700000001000000C4
            database size: 3.1GB, database backup size: 3.1GB
            repo1: backup size: 1.2GB

        diff backup: 20250908-105049F_20250909-030001D
            timestamp start/stop: 2025-09-09 03:00:01+00 / 2025-09-09 03:00:04+00
            wal start/stop: 0000000A00000001000000CF / 0000000A00000001000000D0
            database size: 3.1GB, database backup size: 49.2MB
            repo1: backup size: 36.4KB
            backup reference total: 1 full

• Modify and run ansible roles to restore to T1 time

# vars/main.yml
patroni_cluster_bootstrap_method: "pgbackrest"
postgresql_restore_command: "/usr/bin/pgbackrest --stanza={{ pgbackrest_stanza }} archive-get %f %p"
pgbackrest_patroni_cluster_restore_command: '/usr/bin/pgbackrest --stanza={{ pgbackrest_stanza }} --type=time --target="2025-09-08 10:29:48+00" --delta restore'

# ansible command
ansible-playbook -i inventory deploy_pgcluster.yml -t point_in_time_recovery -e disable_archive_command=false
# ansible stuck at this step
TASK [patroni : Wait for the PostgreSQL start command to complete] ***********************************************************************************
changed: [12.0.10.236]
FAILED - RETRYING: [12.0.10.236]: Wait for PostgreSQL recovery to complete (WAL apply) (2880 retries left).
FAILED - RETRYING: [12.0.10.236]: Wait for PostgreSQL recovery to complete (WAL apply) (2879 retries left).

• Here is the logs i collected

# /var/log/pgbackrest/***-restore.log
-------------------PROCESS START-------------------
2025-09-09 03:00:52.938 P00   INFO: restore command begin 2.56.0: --delta --exec-id=2430762-ac82cb85 --link-all --log-level-console=info --log-level-file=detail --log-path=/var/log/pgbackrest --pg1-path=/var/lib/postgresql/16/main --process-max=4 --recovery-option=recovery_target_action=promote --repo1-path=/an-prod-db/var/lib/pgbackrest --repo1-s3-bucket=anonymaus-pgbackrest --repo1-s3-endpoint=s3.us-east-1.amazonaws.com --repo1-s3-key=<redacted> --repo1-s3-key-secret=<redacted> --repo1-s3-region=us-east-1 --repo1-type=s3 --spool-path=/var/spool/pgbackrest --stanza=an-prod-cluster --target="2025-09-08 10:29:48+00" --target-action=promote --type=time
2025-09-09 03:00:53.239 P00   INFO: repo1: restore backup set 20250908-095316F, recovery will start at 2025-09-08 09:53:16
2025-09-09 03:00:53.239 P00 DETAIL: check '/var/lib/postgresql/16/main' exists
2025-09-09 03:00:53.239 P00 DETAIL: remove 'global/pg_control' so cluster will not start if restore does not complete

# /var/log/postgresql/postgresql-Tue.log
2025-09-09 03:01:25 UTC [2430818-9]  LOG:  consistent recovery state reached at 1/AC000138
2025-09-09 03:01:25.147 P00   INFO: archive-get command begin 2.56.0: [0000000300000001000000AE, pg_wal/RECOVERYXLOG] --archive-async --archive-get-queue-max=1GiB --exec-id=2430839-53c997be --log-level-console=info --log-level-file=detail --log-path=/var/log/pgbackrest --pg1-path=/var/lib/postgresql/16/main --process-max=4 --repo1-path=/an-prod-db/var/lib/pgbackrest --repo1-s3-bucket=anonymaus-pgbackrest --repo1-s3-endpoint=s3.us-east-1.amazonaws.com --repo1-s3-key=<redacted> --repo1-s3-key-secret=<redacted> --repo1-s3-region=us-east-1 --repo1-type=s3 --spool-path=/var/spool/pgbackrest --stanza=an-prod-cluster
2025-09-09 03:01:25.249 P00   INFO: unable to find 0000000300000001000000AE in the archive asynchronously
2025-09-09 03:01:25.249 P00   INFO: archive-get command end: completed successfully (104ms)
2025-09-09 03:01:25 UTC [2430818-10]  LOG:  redo done at 1/AD000148 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.25 s
2025-09-09 03:01:25 UTC [2430818-11]  FATAL:  recovery ended before configured recovery target was reached
2025-09-09 03:01:25 UTC [2430814-6]  LOG:  startup process (PID 2430818) exited with exit code 1
2025-09-09 03:01:25 UTC [2430814-7]  LOG:  terminating any other active server processes
2025-09-09 03:01:25 UTC [2430814-8]  LOG:  shutting down due to startup process failure
2025-09-09 03:01:25 UTC [2430814-9]  LOG:  database system is shut down

The cluster is down and can't restore anymore. Can you help me find the issue hrere ?

[sonphzz]

Other question ❓
What is value should I set for postgresql_exists inside inventory when I wanna restore from PITR or restore from last backup ?
Thanks

[vitabaks]

Hi @sonphzz

Can you help me find the issue hrere ?

According to the log, the required WAL segment is missing from the repository, so recovery to the specified point in time is not possible. In your case, you could try selecting an earlier recovery target. If this is a test server without any load, we also recommend running pgbench in at least one thread to simulate activity — this can increase the chances of successful PITR.

What is value should I set for postgresql_exists inside inventory

Set this to true in all cases where Postgres is already deployed. This will disable the pre-check, preventing deploy_pgcluster from failing if the data directory is present.

---

Free Support Discontinuation Notice

[sonphzz]

@vitabaks Thanks for your answer

• About the Works on Ubuntu and CentOS but fails on OracleLinux #1 question, I take a full backup 2,3 times to have 3 full backups with different timestamps. Then try to restore to one of them and verify the data. Im not sure why the WAL can miss because I saw the log WAL file pushed successfully to my S3 bucket without any error.
  Here is the current status of pgbackrest info

stanza: an-prod-cluster
    status: ok
    cipher: none

    db (current)
        wal archive min/max (16): 000000010000000000000001/0000000100000008000000E3

        full backup: 20250911-024756F
            timestamp start/stop: 2025-09-11 02:47:56+00 / 2025-09-11 02:48:43+00
            wal start/stop: 000000010000000200000012 / 000000010000000200000012
            database size: 3.4GB, database backup size: 3.4GB
            repo1: backup size: 1.3GB

        diff backup: 20250911-024756F_20250911-030001D
            timestamp start/stop: 2025-09-11 03:00:01+00 / 2025-09-11 03:00:07+00
            wal start/stop: 000000010000000200000014 / 000000010000000200000014
            database size: 3.4GB, database backup size: 2GB
            repo1: backup size: 10.6MB
            backup reference total: 1 full

        diff backup: 20250911-024756F_20250912-030001D
            timestamp start/stop: 2025-09-12 03:00:01+00 / 2025-09-12 03:00:53+00
            wal start/stop: 0000000100000003000000B0 / 0000000100000003000000B1
            database size: 3.9GB, database backup size: 3.8GB
            repo1: backup size: 644.1MB
            backup reference total: 1 full

        diff backup: 20250911-024756F_20250913-030001D
            timestamp start/stop: 2025-09-13 03:00:01+00 / 2025-09-13 03:00:40+00
            wal start/stop: 000000010000000500000008 / 00000001000000050000000A
            database size: 4GB, database backup size: 3.8GB
            repo1: backup size: 689.9MB
            backup reference total: 1 full

        full backup: 20250914-030001F
            timestamp start/stop: 2025-09-14 03:00:01+00 / 2025-09-14 03:01:04+00
            wal start/stop: 000000010000000600000079 / 00000001000000060000007C
            database size: 4.1GB, database backup size: 4.1GB
            repo1: backup size: 1.4GB

        diff backup: 20250914-030001F_20250915-030001D
            timestamp start/stop: 2025-09-15 03:00:01+00 / 2025-09-15 03:00:31+00
            wal start/stop: 0000000100000007000000D3 / 0000000100000007000000D3
            database size: 4.1GB, database backup size: 3.9GB
            repo1: backup size: 443.2MB
            backup reference total: 1 full

        diff backup: 20250914-030001F_20250916-030002D
            timestamp start/stop: 2025-09-16 03:00:02+00 / 2025-09-16 03:00:34+00
            wal start/stop: 0000000100000008000000C7 / 0000000100000008000000C7
            database size: 4.2GB, database backup size: 4.1GB
            repo1: backup size: 645.5MB
            backup reference total: 1 full

This backup info generate by pgbackrest cron job, not taken by my manual action.

[sonphzz]

@vitabaks I have other question and need your support and advice here, this is my postgresql_parameters:

postgresql_parameters:
  - { option: "max_connections", value: "1500" }
  - { option: "superuser_reserved_connections", value: "3" }
  - { option: "password_encryption", value: "{{ postgresql_password_encryption_algorithm }}" }
  - { option: "ssl", value: "{{ 'on' if tls_cert_generate | bool else 'off' }}" }
  - { option: "ssl_prefer_server_ciphers", value: "{{ 'on' if tls_cert_generate | bool else 'off' }}" }
  - { option: "ssl_cert_file", value: "{{ tls_dir }}/{{ tls_cert }}" }
  - { option: "ssl_key_file", value: "{{ tls_dir }}/{{ tls_privatekey }}" }
  - { option: "ssl_ca_file", value: "{{ tls_dir }}/{{ tls_ca_cert }}" }
  - { option: "ssl_min_protocol_version", value: "TLSv1.2" }
  - { option: "max_locks_per_transaction", value: "128" }
  - { option: "max_prepared_transactions", value: "0" }
  - { option: "huge_pages", value: "off" }
  - { option: "shared_buffers", value: "512MB" }
  - { option: "effective_cache_size", value: "1GB" }
  - { option: "work_mem", value: "16MB" }
  - { option: "maintenance_work_mem", value: "64MB" }
  - { option: "checkpoint_timeout", value: "15min" }
  - { option: "checkpoint_completion_target", value: "0.9" }
  - { option: "min_wal_size", value: "1GB" }
  - { option: "max_wal_size", value: "2GB" }
  - { option: "wal_buffers", value: "16MB" }
  - { option: "default_statistics_target", value: "100" }
  - { option: "seq_page_cost", value: "1" }
  - { option: "random_page_cost", value: "1.1" }
  - { option: "effective_io_concurrency", value: "200" }
  - { option: "synchronous_commit", value: "on" }
  - { option: "autovacuum", value: "on" }
  - { option: "autovacuum_max_workers", value: "2" }
  - { option: "autovacuum_vacuum_scale_factor", value: "0.1" }
  - { option: "autovacuum_analyze_scale_factor", value: "0.05" }
  - { option: "autovacuum_vacuum_cost_limit", value: "200" }
  - { option: "autovacuum_vacuum_cost_delay", value: "10" }
  - { option: "autovacuum_naptime", value: "30s" }
  - { option: "max_files_per_process", value: "1000" }
  - { option: "archive_mode", value: "on" }
  - { option: "archive_timeout", value: "1800s" }
  - { option: "archive_command", value: "cd ." }
  - { option: "wal_level", value: "logical" }
  - { option: "wal_keep_size", value: "1GB" }
  - { option: "max_wal_senders", value: "5" }
  - { option: "max_replication_slots", value: "5" }
  - { option: "hot_standby", value: "on" }
  - { option: "wal_log_hints", value: "on" }
  - { option: "wal_compression", value: "on" }
  - { option: "shared_preload_libraries", value: "pg_stat_statements,auto_explain" }
  - { option: "pg_stat_statements.max", value: "5000" }
  - { option: "pg_stat_statements.track", value: "all" }
  - { option: "pg_stat_statements.track_utility", value: "false" }
  - { option: "pg_stat_statements.save", value: "true" }
  - { option: "auto_explain.log_min_duration", value: "10s" }
  - { option: "auto_explain.log_analyze", value: "true" }
  - { option: "auto_explain.log_buffers", value: "true" }
  - { option: "auto_explain.log_timing", value: "false" }
  - { option: "auto_explain.log_triggers", value: "true" }
  - { option: "auto_explain.log_verbose", value: "true" }
  - { option: "auto_explain.log_nested_statements", value: "true" }
  - { option: "auto_explain.sample_rate", value: "0.01" }
  - { option: "track_io_timing", value: "on" }
  - { option: "log_lock_waits", value: "on" }
  - { option: "log_temp_files", value: "0" }
  - { option: "track_activities", value: "on" }
  - { option: "track_activity_query_size", value: "2048" }
  - { option: "track_counts", value: "on" }
  - { option: "track_functions", value: "all" }
  - { option: "log_checkpoints", value: "on" }
  - { option: "logging_collector", value: "on" }
  - { option: "log_truncate_on_rotation", value: "on" }
  - { option: "log_rotation_age", value: "1d" }
  - { option: "log_rotation_size", value: "0" }
  - { option: "log_line_prefix", value: "%t [%p-%l] %r %q%u@%d " }
  - { option: "log_filename", value: "postgresql-%a.log" }
  - { option: "log_directory", value: "{{ postgresql_log_dir }}" }
  - { option: "hot_standby_feedback", value: "on" }
  - { option: "max_standby_streaming_delay", value: "30s" }
  - { option: "wal_receiver_status_interval", value: "10s" }
  - { option: "idle_in_transaction_session_timeout", value: "10min" }
  - { option: "jit", value: "off" }
  - { option: "max_worker_processes", value: "2" }
  - { option: "max_parallel_workers", value: "1" }
  - { option: "max_parallel_workers_per_gather", value: "1" }
  - { option: "max_parallel_maintenance_workers", value: "1" }
  - { option: "tcp_keepalives_count", value: "5" }
  - { option: "tcp_keepalives_idle", value: "300" }
  - { option: "tcp_keepalives_interval", value: "30" }

---

❓ Question

• My postgresql has 8G Ram and 4CPU, with this configuration my master and other slaves alwasy getting burst disk space. For example, normamly my diskspace is around ~32% (of 50GB) and after this log it's growing to 100% very very fast. I have ask GPT and he give me some change at work_mem, temp_file_limit and increase current diskspace. Can you have advice from you with this issue ?

2025-09-19 00:06:45 UTC [3297938-5] [local] anonymaus@an-prod-db ERROR: could not write to file "base/pgsql_tmp/pgsql_tmp3297938.18": No space left on device 
2025-09-19 00:06:45 UTC [3293808-7] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.0", size 1073741824 
2025-09-19 00:06:45 UTC [3297938-7] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.0", size 1073741824 
2025-09-19 00:06:45 UTC [3293808-8] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.20", size 97714176 
2025-09-19 00:06:45 UTC [3293808-9] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.19", size 177561600 
2025-09-19 00:06:45 UTC [3293808-10] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.18", size 481763328 
2025-09-19 00:06:45 UTC [3293808-11] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.17", size 1073741824 
2025-09-19 00:06:45 UTC [3293808-12] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.16", size 1073741824 
2025-09-19 00:06:45 UTC [3293808-13] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.15", size 1073741824 
2025-09-19 00:06:45 UTC [3293808-14] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.14", size 1073741824 
2025-09-19 00:06:45 UTC [3293808-15] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.13", size 1073741824 
2025-09-19 00:06:46 UTC [3293808-16] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.12", size 1073741824 
2025-09-19 00:06:46 UTC [3293808-17] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.11", size 1073741824 
2025-09-19 00:06:46 UTC [3293808-18] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.10", size 1073741824 
2025-09-19 00:06:46 UTC [3293808-19] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.9", size 1073741824 
2025-09-19 00:06:46 UTC [3293808-20] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.7", size 397616 
2025-09-19 00:06:46 UTC [3293808-21] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.8", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-8] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.20", size 480870400 
2025-09-19 00:06:46 UTC [3293808-22] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.4", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-9] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.19", size 560709632 
2025-09-19 00:06:46 UTC [3293808-23] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.3", size 1060731494 
2025-09-19 00:06:46 UTC [3293808-24] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.5", size 1073741824 
2025-09-19 00:06:46 UTC [3293808-25] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3293808.1", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-10] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.18", size 886358016 
2025-09-19 00:06:46 UTC [3297938-11] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.17", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-12] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.16", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-13] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.15", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-14] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.14", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-15] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.13", size 1073741824 
2025-09-19 00:06:46 UTC [3297938-16] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.12", size 1073741824 
2025-09-19 00:06:47 UTC [3297938-17] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.11", size 1073741824 
2025-09-19 00:06:47 UTC [3297938-18] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.10", size 1073741824 
2025-09-19 00:06:47 UTC [3297938-19] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.9", size 1073741824 
2025-09-19 00:06:47 UTC [3297938-20] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.7", size 397616 
2025-09-19 00:06:47 UTC [3297938-21] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.8", size 1073741824 
2025-09-19 00:06:47 UTC [3297938-22] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.4", size 1073741824 
2025-09-19 00:06:47 UTC [3297938-23] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.3", size 1060731494 
2025-09-19 00:06:47 UTC [3297938-24] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.5", size 1073741824 
2025-09-19 00:06:47 UTC [3297938-25] [local] anonymaus@an-prod-db LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp3297938.1", size 1073741824 
2025-09-19 00:07:39 UTC [3018832-1686] LOG: checkpoint complete: wrote 1605 buffers (2.4%); 0 WAL file(s) added, 1 removed, 21 recycled; write=453.090 s, sync=0.009 s, total=453.195 s; sync files=83, longest=0.003 s, average=0.001 s; distance=46672 kB, estimate=87397 kB; lsn=C/76F7D08, redo lsn=B/F41560F0

[vitabaks]

This is a very large temporary file (1 GB), which usually indicates the need to optimize queries. Otherwise, you may need to consider moving to a larger instance with more memory.

Please check our support packages https://autobase.tech/docs/support

[sonphzz]

@vitabaks Below is the metrics related to disk space and memory usage when issue happen. I just wonder why should I increase the work_mem and set temp_file_limit in this case ?