Description
I am restoring one database from a backup created from replica. I get an error:FATAL:could not access status of transaction 22638639.
Can you tell me what the error might be?
[backup_user@backup-srv ~]$ pg_probackup-14 version
pg_probackup-14 2.5.15 (PostgreSQL 14.11)
[backup_user@backup-srv ~]$ pg_probackup-14 show -B /mnt/backup_store/pg_probackup
BACKUP INSTANCE ' Instance-p3'
Instance Version ID Recovery Time Mode WAL Mode TLI Time Data WAL Zratio Start LSN Stop LSN Status
Instance-p3 14 SPO1HU 2025-01-06 15:16:49+03 DELTA STREAM 3/3 13m:21s 2784MB 3312MB 2.43 2D80/C3E5E0F0 2D81/914168E8 OK
Instance-p3 14 SPNQ7Y 2025-01-06 13:05:51+03 FULL STREAM 3/0 2h:5m 791GB 3968MB 2.64 2D7F/D924F80 2D80/474F1B8 OK
[backup_user@backup-srv ~]$ time pg_probackup-14 restore -B /mnt/backup_store/pg_probackup -D /data/restore/test/ --instance=Instance-p3 -j8 --no-validate --remote-proto=ssh --remote-host=Instance-p3 --remote-user=postgres --db-include=db -i SPNQ7Y
WARNING: Backup SPNQ7Y is used without validation.
INFO: Restoring the database from backup SPNQ7Y on Instance-p3
INFO: Start restoring backup files. PGDATA size: 2091GB
INFO: Backup files are restored. Transfered bytes: 14GB, time elapsed: 32s
INFO: Restore incremental ratio (less is better): 1% (14GB/2091GB)
INFO: Syncing restored files to disk
INFO: Restored backup files are synced, time elapsed: 6s
INFO: Restore of backup SPNQ7Y completed.
real 0m39.162s
user 0m42.144s
sys 0m18.860s
bash-4.2$ ls -bla /data/restore/test/
total 340
drwxr-xr-x. 20 postgres postgres 4096 Jan 7 12:04 .
drwxr-xr-x. 3 postgres postgres 4096 Jan 7 12:03 ..
-rw-rw-r--. 1 postgres postgres 247 Jan 7 12:03 backup_label
-rw-------. 1 postgres postgres 225 Jan 7 12:03 backup_label.old
-rw-------. 1 postgres postgres 138549 Jan 7 12:03 backup_manifest
drwx------. 23 postgres postgres 4096 Jan 7 12:03 base
-rw-r-----. 1 postgres postgres 30 Jan 7 12:03 current_logfiles
drwx------. 2 postgres postgres 4096 Jan 7 12:04 global
drwx------. 2 postgres postgres 4096 Jan 7 12:03 log
-rw-------. 1 postgres postgres 1214 Jan 7 12:03 patroni.dynamic.json
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_commit_ts
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_dynshmem
-rw-------. 1 postgres postgres 302 Jan 7 12:03 pg_hba.conf
-rw-------. 1 postgres postgres 246 Jan 7 12:03 pg_hba.conf.backup
-rw-------. 1 postgres postgres 1636 Jan 7 12:03 pg_ident.conf
-rw-------. 1 postgres postgres 1636 Jan 7 12:03 pg_ident.conf.backup
drwx------. 4 postgres postgres 4096 Jan 7 12:03 pg_logical
drwx------. 4 postgres postgres 4096 Jan 7 12:03 pg_multixact
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_notify
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_replslot
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_serial
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_snapshots
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_stat
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_stat_tmp
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_subtrans
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_tblspc
drwx------. 2 postgres postgres 4096 Jan 7 12:03 pg_twophase
-rw-------. 1 postgres postgres 3 Jan 7 12:03 PG_VERSION
drwx------. 2 postgres postgres 16384 Jan 7 12:04 pg_wal
drwx------. 2 postgres postgres 4096 Jan 7 12:04 pg_xact
-rw-------. 1 postgres postgres 184 Jan 7 12:04 postgresql.auto.conf
-rw-------. 1 postgres postgres 28770 Jan 7 12:04 postgresql.base.conf
-rw-------. 1 postgres postgres 28770 Jan 7 12:04 postgresql.base.conf.backup
-rw-r--r--. 1 postgres postgres 1751 Jan 7 12:04 postgresql.conf
-rw-r--r--. 1 postgres postgres 1751 Jan 7 12:04 postgresql.conf.backup
bash-4.2$ cat /data/restore/test/backup_label
START WAL LOCATION: 2D7F/D924F80 (file 0000000300002D7F0000000D)
CHECKPOINT LOCATION: 2D7F/15D1B9E8
BACKUP METHOD: streamed
BACKUP FROM: standby
START TIME: 2025-01-06 10:59:58 MSK
LABEL: 2025-01-06 10:59:58+03 with pg_probackup
START TIMELINE: 3
bash-4.2$ rm /data/restore/test/backup_label
bash-4.2$ nano /data/restore/test/postgresql.conf
bash-4.2$ cat /data/restore/test/postgresql.conf
Do not edit this file manually!
It will be overwritten by Patroni!
include 'postgresql.base.conf'
archive_command = 'mkdir -p ../wal_archive && test ! -f ../wal_archive/%f && cp %p ../wal_archive/%f'
archive_mode = 'on'
archive_timeout = '1800s'
auto_explain.log_min_duration = '5000'
autovacuum_analyze_scale_factor = '0.01'
autovacuum_max_workers = '8'
cluster_name = 'postgres_cluster'
effective_cache_size = '90GB'
hot_standby = 'on'
listen_addresses = '0.0.0.0'
log_checkpoints = 'on'
log_connections = 'on'
log_disconnections = 'on'
log_line_prefix = '%t [%p]: [%l-1] app=%a,user=%u,db=%d,client=%h '
log_lock_waits = 'on'
log_min_duration_statement = '5000'
log_replication_commands = 'on'
maintenance_work_mem = '2GB'
max_connections = '2000'
max_locks_per_transaction = '64'
max_prepared_transactions = '0'
max_replication_slots = '5'
max_standby_archive_delay = '600s'
max_standby_streaming_delay = '600s'
max_wal_senders = '10'
max_worker_processes = '8'
pgaudit.log = 'role,ddl'
port = '5433'
shared_buffers = '32GB'
shared_preload_libraries = 'pg_stat_statements,auto_explain,pgaudit'
track_commit_timestamp = 'off'
track_io_timing = 'on'
wal_keep_size = '128MB'
wal_level = 'replica'
wal_log_hints = 'on'
work_mem = '64MB'
hba_file = '/data/db/pg_hba.conf'
ident_file = '/data/db/pg_ident.conf'
recovery.conf
#primary_conninfo = 'user=repl passfile=/var/lib/pgsql/pgpass host=Instance-p1 port=5432 sslmode=prefer application_name=Instance-p3 gssencmode=prefer channel_binding=prefer'
#primary_slot_name = 'Instance_p3'
#recovery_target = ''
#recovery_target_lsn = ''
#recovery_target_name = ''
#recovery_target_time = ''
#recovery_target_timeline = 'latest'
#recovery_target_xid = ''
#restore_command = 'cp ../wal_archive/%f %p'
bash-4.2$ chmod 700 /data/restore/test/
bash-4.2$ /usr/pgsql-14/bin/pg_ctl -D /data/restore/test/ start
waiting for server to start....2025-01-07 12:17:22 MSK [30551]: [1-1] app=,user=,db=,client= LOG: pgaudit extension initialized
2025-01-07 12:17:22 MSK [30551]: [2-1] app=,user=,db=,client= LOG: redirecting log output to logging collector process
2025-01-07 12:17:22 MSK [30551]: [3-1] app=,user=,db=,client= HINT: Future log output will appear in directory "log".
........................................................... stopped waiting
pg_ctl: server did not start in time
-bash-4.2$ cat /data/restore/test/log/postgresql-Tue.log
2025-01-07 12:17:22 MSK [30551]: [4-1] app=,user=,db=,client= LOG: starting PostgreSQL 14.10 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-44), 64-bit
2025-01-07 12:17:22 MSK [30551]: [5-1] app=,user=,db=,client= LOG: listening on IPv4 address "0.0.0.0", port 5433
2025-01-07 12:17:22 MSK [30551]: [6-1] app=,user=,db=,client= LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5433"
2025-01-07 12:17:22 MSK [30551]: [7-1] app=,user=,db=,client= LOG: listening on Unix socket "/tmp/.s.PGSQL.5433"
2025-01-07 12:17:22 MSK [30555]: [1-1] app=,user=,db=,client= LOG: database system was interrupted while in recovery at log time 2025-01-06 12:55:33 MSK
2025-01-07 12:17:22 MSK [30555]: [2-1] app=,user=,db=,client= HINT: If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target.
2025-01-07 12:17:22 MSK [30555]: [3-1] app=,user=,db=,client= LOG: creating missing WAL directory "pg_wal/archive_status"
2025-01-07 12:17:22 MSK [30555]: [4-1] app=,user=,db=,client= LOG: database system was not properly shut down; automatic recovery in progress
2025-01-07 12:17:22 MSK [30555]: [5-1] app=,user=,db=,client= LOG: redo starts at 2D7F/F40BE768
2025-01-07 12:18:03 MSK [30555]: [6-1] app=,user=,db=,client= LOG: file "pg_xact/0523" doesn't exist, reading as zeroes
2025-01-07 12:18:03 MSK [30555]: [7-1] app=,user=,db=,client= CONTEXT: WAL redo at 2D7F/F40C03E0 for Transaction/COMMIT: 2025-01-06 12:55:33.090833+03
2025-01-07 12:25:32 MSK [30555]: [8-1] app=,user=,db=,client= FATAL: could not access status of transaction 22638639
2025-01-07 12:25:32 MSK [30555]: [9-1] app=,user=,db=,client= DETAIL: Could not read from file "pg_multixact/offsets/0159" at offset 114688: read too few bytes.
2025-01-07 12:25:32 MSK [30555]: [10-1] app=,user=,db=,client= CONTEXT: WAL redo at 2D7F/F4300FC8 for MultiXact/CREATE_ID: 22638639 offset 56640969 nmembers 2: 1379267147 (keysh) 1379267149 (keysh)
2025-01-07 12:25:34 MSK [30551]: [8-1] app=,user=,db=,client= LOG: startup process (PID 30555) exited with exit code 1
2025-01-07 12:25:34 MSK [30551]: [9-1] app=,user=,db=,client= LOG: aborting startup due to startup process failure
2025-01-07 12:25:39 MSK [30551]: [10-1] app=,user=,db=,client= LOG: database system is shut down