Search Postgresql Archives

Re: PgbackRest PointTIme Recovery : server unable to start back

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

here the log outputs....

When I ran 

$sudo -u enterprisedb pgbackrest --stanza=Demo_Repo  --delta  --set=20240719-122703F_20240724-094727I --target-timeline=current --type=time "--target=2024-07-24 09:44:01.3255+05:30" --target-action=""  restore



The Edb server  log out put shows 
...........................................................................
................................................................
2024-07-23 15:34:12 IST ERROR:  syntax error at or near "selecct" at character 1
2024-07-23 15:34:12 IST STATEMENT:  selecct current_timestamp
2024-07-23 15:34:26 IST FATAL:  database "enterprisedb" does not exist
2024-07-24 09:38:20 IST FATAL:  database "enterprisedb" does not exist
2024-07-24 09:42:17 IST FATAL:  database "test1" does not exist
2024-07-24 09:43:56 IST FATAL:  database "enterprisedb" does not exist
2024-07-24 09:45:07 IST FATAL:  database "enterprisedb" does not exist
2024-07-24 09:45:16 IST ERROR:  relation "important_table" does not exist at character 58
2024-07-24 09:45:16 IST STATEMENT:  begin; drop table important_table; commit; select * from important_table;
2024-07-24 09:46:00 IST LOG:  checkpoint starting: time
2024-07-24 09:46:02 IST LOG:  checkpoint complete: wrote 16 buffers (0.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=1.506 s, sync=0.001 s, total=1.509 s; sync files=9, longest=0.001 s, average=0.001 s; distance=93 kB, estimate=171 kB; lsn=0/3C045768, redo lsn=0/3C045730
2024-07-24 09:47:27 IST LOG:  checkpoint starting: immediate force wait
2024-07-24 09:47:27 IST LOG:  checkpoint complete: wrote 2 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.001 s, sync=0.001 s, total=0.003 s; sync files=1, longest=0.001 s, average=0.001 s; distance=16106 kB, estimate=16106 kB; lsn=0/3D000060, redo lsn=0/3D000028
2024-07-24 09:47:27.788 P00   INFO: archive-push command begin 2.52.1: [pg_wal/00000009000000000000003C] --exec-id=34036-c1d6de0b --log-level-console=info --log-level-file=debug --pg1-path=/var/lib/edb/as16/data --pg-version-force=16 --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-24 09:47:28.130 P00   INFO: pushed WAL file '00000009000000000000003C' to the archive
2024-07-24 09:47:28.230 P00   INFO: archive-push command end: completed successfully (444ms)



When  I ran       $ sudo systemctl start edb-as-16.service

4-07-26 11:32:56 IST LOG:  starting PostgreSQL 16.3 (EnterpriseDB Advanced Server 16.3.0) on x86_64-pc-linux-gnu, compiled by gcc (GCC) 11.4.1 20231218 (Red Hat 11.4.1-3), 64-bit
2024-07-26 11:32:56 IST LOG:  listening on IPv4 address "0.0.0.0", port 5444
2024-07-26 11:32:56 IST LOG:  listening on IPv6 address "::", port 5444
2024-07-26 11:32:56 IST LOG:  listening on Unix socket "/tmp/.s.PGSQL.5444"
2024-07-26 11:32:56 IST LOG:  database system was interrupted; last known up at 2024-07-24 09:47:27 IST
2024-07-26 11:32:56 IST LOG:  starting point-in-time recovery to 2024-07-24 09:44:01.3255+05:30
2024-07-26 11:32:56 IST LOG:  starting backup recovery with redo LSN 0/3D000028, checkpoint LSN 0/3D000060, on timeline ID 9
2024-07-26 11:32:56.475 P00   INFO: archive-get command begin 2.52.1: [00000009.history, pg_wal/RECOVERYHISTORY] --exec-id=43293-1d583a8e --log-level-console=info --log-level-file=debug --pg1-path=/var/lib/edb/as16/data --pg-version-force=16 --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:56.709 P00   INFO: found 00000009.history in the repo1: 16-1 archive
2024-07-26 11:32:56.809 P00   INFO: archive-get command end: completed successfully (335ms)
2024-07-26 11:32:56 IST LOG:  restored log file "00000009.history" from archive
2024-07-26 11:32:56.816 P00   INFO: archive-get command begin 2.52.1: [00000009000000000000003D, pg_wal/RECOVERYXLOG] --exec-id=43295-55c5d6f7 --log-level-console=info --log-level-file=debug --pg1-path=/var/lib/edb/as16/data --pg-version-force=16 --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:56.999 P00   INFO: found 00000009000000000000003D in the repo1: 16-1 archive
2024-07-26 11:32:57.099 P00   INFO: archive-get command end: completed successfully (285ms)
2024-07-26 11:32:57 IST LOG:  restored log file "00000009000000000000003D" from archive
2024-07-26 11:32:57 IST LOG:  redo starts at 0/3D000028
2024-07-26 11:32:57.114 P00   INFO: archive-get command begin 2.52.1: [00000009000000000000003E, pg_wal/RECOVERYXLOG] --exec-id=43297-34867c05 --log-level-console=info --log-level-file=debug --pg1-path=/var/lib/edb/as16/data --pg-version-force=16 --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:57.282 P00   INFO: found 00000009000000000000003E in the repo1: 16-1 archive
2024-07-26 11:32:57.382 P00   INFO: archive-get command end: completed successfully (270ms)
2024-07-26 11:32:57 IST LOG:  restored log file "00000009000000000000003E" from archive
2024-07-26 11:32:57.400 P00   INFO: archive-get command begin 2.52.1: [00000009000000000000003F, pg_wal/RECOVERYXLOG] --exec-id=43299-e2db2e1b --log-level-console=info --log-level-file=debug --pg1-path=/var/lib/edb/as16/data --pg-version-force=16 --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:57.521 P00   INFO: unable to find 00000009000000000000003F in the archive
2024-07-26 11:32:57.621 P00   INFO: archive-get command end: completed successfully (222ms)
2024-07-26 11:32:57 IST LOG:  completed backup recovery with redo LSN 0/3D000028 and end LSN 0/3D000100
2024-07-26 11:32:57 IST LOG:  consistent recovery state reached at 0/3D000100
2024-07-26 11:32:57 IST LOG:  database system is ready to accept read-only connections
2024-07-26 11:32:57.632 P00   INFO: archive-get command begin 2.52.1: [00000009000000000000003F, pg_wal/RECOVERYXLOG] --exec-id=43301-f613dae9 --log-level-console=info --log-level-file=debug --pg1-path=/var/lib/edb/as16/data --pg-version-force=16 --repo1-host=10.10.20.7 --repo1-host-user=postgres --stanza=Demo_Repo
2024-07-26 11:32:57.761 P00   INFO: unable to find 00000009000000000000003F in the archive
2024-07-26 11:32:57.861 P00   INFO: archive-get command end: completed successfully (231ms)
2024-07-26 11:32:57 IST LOG:  redo done at 0/3E000060 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.75 s
2024-07-26 11:32:57 IST FATAL:  recovery ended before configured recovery target was reached
2024-07-26 11:32:57 IST LOG:  startup process (PID 43292) exited with exit code 1


ONLY inference  I can make is 

  INFO  unable to find   00000009000000000000003F in the archive    ( This means  the  EDB server  (10.10.20.6  ) unable to push the archives to the   Repo server(10.10.20.7 ) ?    Is that the reason for the  recovery and start backing of edb server fails ?


the pg_hba.conf   entry in the EDB Server machine is as 

host    all             all             127.0.0.1/32            ident
host    all             all             10.10.20.7/32          scram-sha-256
#host    all             all              10.10.20.7/32          trust
# IPv6 local connections:
host    all             all             ::1/128                 ident
#host    all             all             10.10.20.7/24           trust

# Allow replication connections from localhost, by a user with the
# replication privilege.
local   replication     all                                     peer
host    replication     all             10.10.20.7/32           scram-sha-256
host    replication     all             127.0.0.1/32            ident
host    replication     all             ::1/128                 ident


Do I have to change anything in pg_hba.conf ?


my EDB Server conf as  this 

archive_mode = on
archive_command = 'pgbackrest --stanza=Demo_Repo  archive-push %p'
log_filename = 'postgresql.log'
max_wal_senders = 5
wal_level = replica


Any help ?

Krishane




On Fri, Jul 26, 2024 at 10:45 AM Muhammad Ikram <mmikram@xxxxxxxxx> wrote:
Hi KK CHN

Could you check server logs ?
Your service trace suggests that it started server and then failure happened

ul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced Server 16.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process exited, code=exited, status=1/FAILURE



Regards,
Ikram


On Fri, Jul 26, 2024 at 10:04 AM KK CHN <kkchn.in@xxxxxxxxx> wrote:
List, 

I am following the   PTR  on RHEL9 EPAS16.
I am able to do a  backup(Full, diff and incr)  and   restore from a full backup  and restart of EPAS16 works fine. 

But when I do an incremental backup  after doing the   procedures mentioned in the PTR section of the above  reference link and  try  restoring the EDB database from the INCR backup   and then starting up the  EPAS16 the server  always results in dead state 

 My repo server is another machine.  If  I do  a  full restore  on the DB server  ( sudo -u enterprisedb pgbackrest --stanza=Demo_Repo  --delta restore) it works  and the server starts without any issue.  
Restoring  from  Incremental backup tty output shows successful but edb service start  results in  failure. 

Any help is much appreciated. 

Krishane. 




STEPS followed:

after dropping  the table  pg-primary ⇒ Drop the important table ([section]
stopped the EDB server.

$ sudo -u enterprisedb pgbackrest --stanza=Demo_Repo    --delta  --set=20240719-122703F_20240724-094727I --target-timeline=current --type=time "--target=2024-07-24 09:44:01.3255+05:30" --target-action=""  restore
.....................................................

2024-07-26 09:48:06.343 P00   INFO: restore command end: completed successfully (1035ms)


But    

[root@rservice01 ~]# sudo systemctl start edb-as-16.service
[root@service01 ~]# sudo systemctl status edb-as-16.service
× edb-as-16.service - EDB Postgres Advanced Server 16
     Loaded: loaded (/etc/systemd/system/edb-as-16.service; disabled; preset: disabled)
     Active: failed (Result: exit-code) since Fri 2024-07-26 09:48:50 IST; 8s ago
   Duration: 242ms
    Process: 41903 ExecStartPre=/usr/edb/as16/bin/edb-as-16-check-db-dir ${PGDATA} (code=exited, status=0/SUCCESS)
    Process: 41908 ExecStart=/usr/edb/as16/bin/edb-postgres -D ${PGDATA} (code=exited, status=1/FAILURE)
   Main PID: 41908 (code=exited, status=1/FAILURE)
        CPU: 331ms

Jul 26 09:48:48 service01 systemd[1]: Starting EDB Postgres Advanced Server 16...
Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST LOG:  redirecting log output to logging collector process
Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST HINT:  Future log output will appear in directory "log".
Jul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced Server 16.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main process exited, code=exited, status=1/FAILURE
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Killing process 41909 (edb-postgres) with signal SIGKILL.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Failed with result 'exit-code'.
[root@service01 ~]#

why is it unable to perform a restore and recovery  from an incr  backup ?







On The Repo Server
[root@service02 ~]#  sudo -u postgres pgbackrest --stanza=Demo_Repo info
stanza: Demo_Repo
    status: ok
    cipher: aes-256-cbc

    db (current)
        wal archive min/max (16): 000000020000000000000021/0000000B0000000000000041

        full backup: 20240719-122703F
            timestamp start/stop: 2024-07-19 12:27:03+05:30 / 2024-07-19 12:27:06+05:30
            wal start/stop: 00000002000000000000002A / 00000002000000000000002A
            database size: 61.7MB, database backup size: 61.7MB
            repo1: backup size: 9.6MB

        incr backup: 20240719-122703F_20240719-123353I
            timestamp start/stop: 2024-07-19 12:33:53+05:30 / 2024-07-19 12:33:56+05:30
            wal start/stop: 00000002000000000000002C / 00000002000000000000002C
            database size: 61.7MB, database backup size: 6.4MB
            repo1: backup size: 6.2KB
            backup reference list: 20240719-122703F

        diff backup: 20240719-122703F_20240719-123408D
            timestamp start/stop: 2024-07-19 12:34:08+05:30 / 2024-07-19 12:34:10+05:30
            wal start/stop: 00000002000000000000002E / 00000002000000000000002E
            database size: 61.7MB, database backup size: 6.4MB
            repo1: backup size: 6.4KB
            backup reference list: 20240719-122703F

        incr backup: 20240719-122703F_20240723-110212I
            timestamp start/stop: 2024-07-23 11:02:12+05:30 / 2024-07-23 11:02:15+05:30
            wal start/stop: 000000070000000000000038 / 000000070000000000000038
            database size: 48MB, database backup size: 6.4MB
            repo1: backup size: 9.8KB
            backup reference list: 20240719-122703F, 20240719-122703F_20240719-123408D

        incr backup: 20240719-122703F_20240723-141818I
            timestamp start/stop: 2024-07-23 14:18:18+05:30 / 2024-07-23 14:18:22+05:30
            wal start/stop: 00000008000000000000003C / 00000008000000000000003C
            database size: 75.4MB, database backup size: 33.8MB
            repo1: backup size: 4.7MB
            backup reference list: 20240719-122703F, 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I

        incr backup: 20240719-122703F_20240724-094727I
            timestamp start/stop: 2024-07-24 09:47:27+05:30 / 2024-07-24 09:47:30+05:30
            wal start/stop: 00000009000000000000003D / 00000009000000000000003D
            database size: 62MB, database backup size: 11.5MB
            repo1: backup size: 72KB
            backup reference list: 20240719-122703F, 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-110212I, 20240719-122703F_20240723-141818





--
Muhammad Ikram

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Index of Archives]     [Postgresql Jobs]     [Postgresql Admin]     [Postgresql Performance]     [Linux Clusters]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Databases]     [Postgresql & PHP]     [Yosemite]

  Powered by Linux