Problem partial restore with restore from backup created from replica

[Dsolik]

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