Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1sXENw-002ZoP-Hs for pgsql-general@arkaria.postgresql.org; Fri, 26 Jul 2024 06:25:00 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1sXENv-006USl-1l for pgsql-general@arkaria.postgresql.org; Fri, 26 Jul 2024 06:24:59 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1sXENu-006USF-Ju for pgsql-general@lists.postgresql.org; Fri, 26 Jul 2024 06:24:58 +0000 Received: from mail-yw1-x1135.google.com ([2607:f8b0:4864:20::1135]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.94.2) (envelope-from ) id 1sXENr-001Wbf-6t for pgsql-general@postgresql.org; Fri, 26 Jul 2024 06:24:58 +0000 Received: by mail-yw1-x1135.google.com with SMTP id 00721157ae682-65f880c56b1so17045537b3.3 for ; Thu, 25 Jul 2024 23:24:54 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1721975093; x=1722579893; darn=postgresql.org; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:from:to:cc:subject:date:message-id:reply-to; bh=BN7B8hJq5grAUOgpoCJZ+9oB2d5YJbwVeZlyNtba3Ek=; b=l5lorzId+F1E5XZDBpknyaf4LlczJoHnu/2C3pYCRpFf3D7b64SJJuGKaz0u5bPnpZ kFfgq7v8xpIUVSt1BApzkICcilIdBlz+kkUXNBYXiQ9mP+h2Jj3/9fcF/tW8/K3ZcZ8F oXgCJzBSSjQbdDRpwfrvYQi2tBB89RtvdI3A0fhyXQvHpdWTfBzeBG/uE0dIepmgwAY8 1j8YxHRXaRlFJh01xbgvBm/KndMRRJSrkdal9uh55mdat/VpV6fnpp7U0+TAxAZGNIFG kkc5xR3Ww0D34yDO748QEPt3rjFm6i6N3Uj6A2qrt5TH/4lVclglGxylQ0wZOWjN5QII vPcg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1721975093; x=1722579893; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=BN7B8hJq5grAUOgpoCJZ+9oB2d5YJbwVeZlyNtba3Ek=; b=Zg3k2mxn7sgbmcz09xR8yGdgo5x6GT6KpRWMNu5wvliHP7YaUPq4Qo1WAJE5ifk+8g aVpNG+m5f64iysI6tYWy4zop2XB9dZHHATzyOhVF1TBrIeeSjoScG7OBo6c2L3olu4Vo 2S7TeTEELQUVEyrrDOqQ2aJpfgv9/Wb66tGpysi09t9YgU5MIlKAzntZsERQCi8iIJ5j 7d4WZv1Ujm3gIcLSBrpXZDrMKZWXWqMpqEyY3gjISRadRhp0GRYZ66DQcl4Kk+OPpazR KI3kxsKwNztuSU+wEQhI+HqZZfJOEEqwgBvUtes6LyS7fwztKe3JJZ8LX3NPxG/JW+Ap CfdA== X-Gm-Message-State: AOJu0YybkmDaQrbNmkNaRxBZGFeDNADmq9r9F82BvVmd4vaf54qnsdR6 saLkIrHVkCiZs2ZG7A28q3Wy3rvDJz3QrXSv2dePmNqjso8kFnfofiKIMRjNCId1x8amTXahy+5 /atwcXk4Cp57Gl7rOU71Ia1UXq4J6cE/q X-Google-Smtp-Source: AGHT+IGxq8LvEqcRDLWqLcuU0Z4a/j0dhsKgDx6Ly8XfAmGitdKZdwb7K03dwkL26ahxs9wTI4ntGtnFmY8bwlgYfvE= X-Received: by 2002:a81:bf4e:0:b0:648:3fb2:753b with SMTP id 00721157ae682-67512028191mr58584057b3.24.1721975092713; Thu, 25 Jul 2024 23:24:52 -0700 (PDT) MIME-Version: 1.0 References: In-Reply-To: From: KK CHN Date: Fri, 26 Jul 2024 12:03:49 +0530 Message-ID: Subject: Re: PgbackRest PointTIme Recovery : server unable to start back To: Muhammad Ikram Cc: pgsql-general Content-Type: multipart/alternative; boundary="000000000000b6a553061e209124" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --000000000000b6a553061e209124 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable here the log outputs.... When I ran $sudo -u enterprisedb pgbackrest --stanza=3DDemo_Repo --delta --set=3D20240719-122703F_20240724-094727I --target-timeline=3Dcurrent --type=3Dtime "--target=3D2024-07-24 09:44:01.3255+05:30" --target-action=3Dpromote 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=3D1.506 s, sync=3D0.001 s= , total=3D1.509 s; sync files=3D9, longest=3D0.001 s, average=3D0.001 s; dist= ance=3D93 kB, estimate=3D171 kB; lsn=3D0/3C045768, redo lsn=3D0/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=3D0.001 s, sync=3D0.001 s= , total=3D0.003 s; sync files=3D1, longest=3D0.001 s, average=3D0.001 s; distance=3D16106 kB, estimate=3D16106 kB; lsn=3D0/3D000060, redo lsn=3D0/3D= 000028 2024-07-24 09:47:27.788 P00 INFO: archive-push command begin 2.52.1: [pg_wal/00000009000000000000003C] --exec-id=3D34036-c1d6de0b --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_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 544= 4 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=3D43293-1d583a8e --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_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=3D43295-55c5d6f7 --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_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=3D43297-34867c05 --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_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=3D43299-e2db2e1b --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_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=3D43301-f613dae9 --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_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-25= 6 #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 =3D on archive_command =3D 'pgbackrest --stanza=3DDemo_Repo archive-push %p' log_filename =3D 'postgresql.log' max_wal_senders =3D 5 wal_level =3D replica Any help ? Krishane On Fri, Jul 26, 2024 at 10:45=E2=80=AFAM Muhammad Ikram = 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=3Dexited, status=3D1/FAILURE > > > > Regards, > Ikram > > > On Fri, Jul 26, 2024 at 10:04=E2=80=AFAM KK CHN wrot= e: > >> List, >> >> Reference: https://pgbackrest.org/user-guide-rhel.html#pitr >> I am following the PTR on RHEL9 EPAS16. >> I am able to do a backup(Full, diff and incr) and restore from a ful= l >> 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 t= he >> EPAS16 the server always results in dead state >> >> My repo server is another machine. If I do a full restore on the D= B >> server ( sudo -u enterprisedb pgbackrest --stanza=3DDemo_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 *=E2=87=92* Drop the important tab= le >> ([section] >> stopped the EDB server. >> >> $ sudo -u enterprisedb pgbackrest --stanza=3DDemo_Repo --delta >> --set=3D20240719-122703F_20240724-094727I --target-timeline=3Dcurrent >> --type=3Dtime "--target=3D2024-07-24 09:44:01.3255+05:30" >> --target-action=3Dpromote 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 >> =C3=97 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=3D/usr/edb/as16/bin/edb-as-16-check-db-d= ir >> ${PGDATA} (code=3Dexited, status=3D0/SUCCESS) >> Process: 41908 ExecStart=3D/usr/edb/as16/bin/edb-postgres -D ${PGDAT= A} >> (code=3Dexited, status=3D1/FAILURE) >> Main PID: 41908 (code=3Dexited, status=3D1/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=3Dexited, status=3D1/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=3DDemo_Repo in= fo >> 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 > > --000000000000b6a553061e209124 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
here the log outputs....
<= br>
When I ran=C2=A0

$sudo -u enterprisedb pgbackre= st --stanza=3DDemo_Repo =C2=A0--delta =C2=A0--set=3D20240719-122703F_202407= 24-094727I --target-timeline=3Dcurrent --type=3Dtime "--target=3D2024-= 07-24 09:44:01.3255+05:30" --target-action=3Dpromote =C2=A0restore
=



The Edb server=C2=A0 log = out put shows=C2=A0
.........................................= ..................................
..............................= ..................................
2024-07-23 15:34:12 IST ERROR:= =C2=A0syntax error at or near "selecct" at character 1
2024-0= 7-23 15:34:12 IST STATEMENT: =C2=A0selecct current_timestamp
2024-07-23 = 15:34:26 IST FATAL: =C2=A0database "enterprisedb" does not exist<= br>2024-07-24 09:38:20 IST FATAL: =C2=A0database "enterprisedb" d= oes not exist
2024-07-24 09:42:17 IST FATAL: =C2=A0database "test1&= quot; does not exist
2024-07-24 09:43:56 IST FATAL: =C2=A0database "= ;enterprisedb" does not exist
2024-07-24 09:45:07 IST FATAL: =C2=A0= database "enterprisedb" does not exist
2024-07-24 09:45:16 IST= ERROR: =C2=A0relation "important_table" does not exist at charac= ter 58
2024-07-24 09:45:16 IST STATEMENT: =C2=A0begin; drop table import= ant_table; commit; select * from important_table;
2024-07-24 09:46:00 IS= T LOG: =C2=A0checkpoint starting: time
2024-07-24 09:46:02 IST LOG: =C2= =A0checkpoint complete: wrote 16 buffers (0.1%); 0 WAL file(s) added, 0 rem= oved, 0 recycled; write=3D1.506 s, sync=3D0.001 s, total=3D1.509 s; sync fi= les=3D9, longest=3D0.001 s, average=3D0.001 s; distance=3D93 kB, estimate= =3D171 kB; lsn=3D0/3C045768, redo lsn=3D0/3C045730
2024-07-24 09:47:27 I= ST LOG: =C2=A0checkpoint starting: immediate force wait
2024-07-24 09:47= :27 IST LOG: =C2=A0checkpoint complete: wrote 2 buffers (0.0%); 0 WAL file(= s) added, 0 removed, 1 recycled; write=3D0.001 s, sync=3D0.001 s, total=3D0= .003 s; sync files=3D1, longest=3D0.001 s, average=3D0.001 s; distance=3D16= 106 kB, estimate=3D16106 kB; lsn=3D0/3D000060, redo lsn=3D0/3D000028
202= 4-07-24 09:47:27.788 P00 =C2=A0 INFO: archive-push command begin 2.52.1: [p= g_wal/00000009000000000000003C] --exec-id=3D34036-c1d6de0b --log-level-cons= ole=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --p= g-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres= --stanza=3DDemo_Repo
2024-07-24 09:47:28.130 P00 =C2=A0 INFO: pushed WA= L file '00000009000000000000003C' to the archive
2024-07-24 09:4= 7:28.230 P00 =C2=A0 INFO: archive-push command end: completed successfully = (444ms)



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

4-07-26 11:32:56 IST LOG: =C2=A0starting PostgreSQL 1= 6.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: =C2=A0listening on IPv4 address "0.0.0.0", port 5444=
2024-07-26 11:32:56 IST LOG: =C2=A0listening on IPv6 address "::&q= uot;, port 5444
2024-07-26 11:32:56 IST LOG: =C2=A0listening on Unix soc= ket "/tmp/.s.PGSQL.5444"
2024-07-26 11:32:56 IST LOG: =C2=A0da= tabase system was interrupted; last known up at 2024-07-24 09:47:27 IST
= 2024-07-26 11:32:56 IST LOG: =C2=A0starting point-in-time recovery to 2024-= 07-24 09:44:01.3255+05:30
2024-07-26 11:32:56 IST LOG: =C2=A0starting ba= ckup recovery with redo LSN 0/3D000028, checkpoint LSN 0/3D000060, on timel= ine ID 9
2024-07-26 11:32:56.475 P00 =C2=A0 INFO: archive-get command be= gin 2.52.1: [00000009.history, pg_wal/RECOVERYHISTORY] --exec-id=3D43293-1d= 583a8e --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/va= r/lib/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --rep= o1-host-user=3Dpostgres --stanza=3DDemo_Repo
2024-07-26 11:32:56.709 P00= =C2=A0 INFO: found 00000009.history in the repo1: 16-1 archive
2024-07-= 26 11:32:56.809 P00 =C2=A0 INFO: archive-get command end: completed success= fully (335ms)
2024-07-26 11:32:56 IST LOG: =C2=A0restored log file "= ;00000009.history" from archive
2024-07-26 11:32:56.816 P00 =C2=A0 = INFO: archive-get command begin 2.52.1: [00000009000000000000003D, pg_wal/R= ECOVERYXLOG] --exec-id=3D43295-55c5d6f7 --log-level-console=3Dinfo --log-le= vel-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D1= 6 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_Re= po
2024-07-26 11:32:56.999 P00 =C2=A0 INFO: found 0000000900000000000000= 3D in the repo1: 16-1 archive
2024-07-26 11:32:57.099 P00 =C2=A0 INFO: a= rchive-get command end: completed successfully (285ms)
2024-07-26 11:32:= 57 IST LOG: =C2=A0restored log file "00000009000000000000003D" fr= om archive
2024-07-26 11:32:57 IST LOG: =C2=A0redo starts at 0/3D000028<= br>2024-07-26 11:32:57.114 P00 =C2=A0 INFO: archive-get command begin 2.52.= 1: [00000009000000000000003E, pg_wal/RECOVERYXLOG] --exec-id=3D43297-34867c= 05 --log-level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/li= b/edb/as16/data --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-h= ost-user=3Dpostgres --stanza=3DDemo_Repo
2024-07-26 11:32:57.282 P00 =C2= =A0 INFO: found 00000009000000000000003E in the repo1: 16-1 archive
2024= -07-26 11:32:57.382 P00 =C2=A0 INFO: archive-get command end: completed suc= cessfully (270ms)
2024-07-26 11:32:57 IST LOG: =C2=A0restored log file &= quot;00000009000000000000003E" from archive
2024-07-26 11:32:57.400= P00 =C2=A0 INFO: archive-get command begin 2.52.1: [0000000900000000000000= 3F, pg_wal/RECOVERYXLOG] --exec-id=3D43299-e2db2e1b --log-level-console=3Di= nfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-versi= on-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stan= za=3DDemo_Repo
2024-07-26 11:32:57.521 P00 =C2=A0 INFO: unable to find 0= 0000009000000000000003F in the archive
2024-07-26 11:32:57.621 P00 =C2= =A0 INFO: archive-get command end: completed successfully (222ms)
2024-0= 7-26 11:32:57 IST LOG: =C2=A0completed backup recovery with redo LSN 0/3D00= 0028 and end LSN 0/3D000100
2024-07-26 11:32:57 IST LOG: =C2=A0consisten= t recovery state reached at 0/3D000100
2024-07-26 11:32:57 IST LOG: =C2= =A0database system is ready to accept read-only connections
2024-07-26 1= 1:32:57.632 P00 =C2=A0 INFO: archive-get command begin 2.52.1: [00000009000= 000000000003F, pg_wal/RECOVERYXLOG] --exec-id=3D43301-f613dae9 --log-level-= console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as16/data= --pg-version-force=3D16 --repo1-host=3D10.10.20.7 --repo1-host-user=3Dpost= gres --stanza=3DDemo_Repo
2024-07-26 11:32:57.761 P00 =C2=A0 INFO: unabl= e to find 00000009000000000000003F in the archive
2024-07-26 11:32:57.86= 1 P00 =C2=A0 INFO: archive-get command end: completed successfully (231ms)<= br>2024-07-26 11:32:57 IST LOG: =C2=A0redo 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: =C2=A0recovery ended before configured recovery target was reach= ed
2024-07-26 11:32:57 IST LOG: =C2=A0startup process (PID 43292) exited= with exit code 1


ONLY inferen= ce=C2=A0 I can make is=C2=A0

=C2=A0 INFO=C2=A0 una= ble to find=C2=A0 =C2=A000000009000000000000003F in the archive=C2=A0 =C2= =A0 ( This means=C2=A0 the=C2=A0 EDB server=C2=A0 (10.10.20.6=C2=A0 ) unabl= e to push the archives to the=C2=A0 =C2=A0Repo server(10.10.20.7 ) ?=C2=A0 = =C2=A0 Is that the reason for the=C2=A0 recovery and start backing of edb s= erver fails ?


the pg_hba.conf=C2=A0= =C2=A0entry in the EDB Server machine is as=C2=A0

host =C2=A0 =C2=A0all =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 all =C2=A0= =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 127.0.0= .1/32 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0ident
host =C2=A0 =C2= =A0all =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 all =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 10.10.20.7/32 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0scram-sha-256
#host =C2=A0 =C2=A0all =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 all =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A010.10.20.7/32 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0trust
# IPv6 local connections:
host =C2= =A0 =C2=A0all =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 all =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 ::1/128 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 ident
#host =C2=A0 =C2=A0all =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 all =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 10.10.20.7/24 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = trust

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


Do I have to change anyth= ing in pg_hba.conf ?


my EDB Server = conf as=C2=A0 this=C2=A0

archive_mode =3D on
ar= chive_command =3D 'pgbackrest --stanza=3DDemo_Repo =C2=A0archive-push %= p'
log_filename =3D 'postgresql.log'
max_wal_senders =3D = 5
wal_level =3D replica


Any help ?

Krishane



<= /div>
O= n Fri, Jul 26, 2024 at 10:45=E2=80=AFAM Muhammad Ikram <mmikram@gmail.com> wrote:
Hi KK CHN
=

Could you check server logs ?
Your service tr= ace suggests that it started server and then failure happened
ul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advan= ced Server 16.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: = Main process exited, code=3Dexited, status=3D1/FAILURE

=


Regards,
Ikram

<= /div>

On Fri, Jul 26, 2024 at 10:04=E2=80=AFAM KK CHN <kkchn.in@gmail.com> wrote:
=
List,=C2=A0

I am following the=C2=A0 =C2=A0P= TR=C2=A0 on RHEL9 EPAS16.
I am able to do a=C2=A0 backup(Full= , diff and incr)=C2=A0 and=C2=A0 =C2=A0restore from a full backup=C2=A0 and= restart of EPAS16 works fine.=C2=A0
But when I do an incremental backup=C2=A0 after doing the=C2= =A0 =C2=A0procedures mentioned in the PTR section of the above=C2=A0 refere= nce link and=C2=A0 try=C2=A0 restoring the EDB database=C2=A0from the INCR = backup=C2=A0=C2=A0 and then starting up the=C2=A0 EPAS16 the server=C2=A0 a= lways results in dead state=C2=A0

=C2=A0My repo se= rver is another machine.=C2=A0 If=C2=A0 I do=C2=A0 a=C2=A0 full restore=C2= =A0 on the DB server=C2=A0 ( sudo -u enterprisedb pgbackrest --stanza=3DDem= o_Repo=C2=A0 --delta restore) it works=C2=A0 and the server starts without = any issue.=C2=A0=C2=A0
Restoring=C2=A0 from=C2=A0 Incremental bac= kup tty output shows successful but edb service start=C2=A0 results in=C2= =A0 failure.=C2=A0

Any help is much appreciate= d.=C2=A0

Krishane.=C2=A0

=


STEPS followed:

=
after dropping=C2=A0 the table=C2=A0 pg-primary=C2=A0=E2=87=92=C2=A0Drop the = important table ([section]
stopped the EDB server.
=
$ sudo -u enterprisedb pgbackrest --stanza=3DDemo_Rep= o=C2=A0 =C2=A0 --delta=C2=A0 --set=3D20240719-122703F_20240724-094727I --ta= rget-timeline=3Dcurrent --type=3Dtime "--target=3D2024-07-24 09:44:01.= 3255+05:30" --target-action=3Dpromote =C2=A0restore
........= .............................................

2024-07-26 09:4= 8:06.343 P00 =C2=A0 INFO: restore command end: completed successfully (1035= ms)


But=C2=A0 =C2=A0=C2=A0

[root@rservice01 ~]# sudo systemctl start edb-as-16.se= rvice
[root@service01 ~]# sudo systemctl status edb-as-16.service
=C3= =97 edb-as-16.service - EDB Postgres Advanced Server 16
=C2=A0 =C2=A0 = =C2=A0Loaded: loaded (/etc/systemd/system/edb-as-16.service; disabled; pres= et: disabled)
=C2=A0 =C2=A0 =C2=A0Active: failed (Result: exit-co= de) since Fri 2024-07-26 09:48:50 IST; 8s ago
=C2=A0 =C2=A0Duration: 242= ms
=C2=A0 =C2=A0 Process: 41903 ExecStartPre=3D/usr/edb/as16/bin/edb-as-= 16-check-db-dir ${PGDATA} (code=3Dexited, status=3D0/SUCCESS)
=C2=A0 =C2= =A0 Process: 41908 ExecStart=3D/usr/edb/as16/bin/edb-postgres -D ${PGDATA} = (code=3Dexited, status=3D1/FAILURE)
=C2=A0 =C2=A0Main PID: 41908 (code= =3Dexited, status=3D1/FAILURE)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 CPU: 331ms
Jul 26 09:48:48 service01 systemd[1]: Starting EDB Postgres Advanced S= erver 16...
Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09= :48:48 IST LOG: =C2=A0redirecting log output to logging collector processJul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 IST HI= NT: =C2=A0Future log output will appear in directory "log".
Ju= l 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=3Dexited, status=3D1/FAILURE
Jul 26 09:48:50 service01 syst= emd[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: Faile= d with result 'exit-code'.
[root@service01 ~]#
why is it unable=C2=A0to perform a restore and recovery=C2=A0 f= rom an incr=C2=A0 backup ?



=




On T= he Repo Server
[root@service02 ~]# =C2=A0sudo -u postgres pgbackr= est --stanza=3DDemo_Repo info
stanza: Demo_Repo
=C2=A0 =C2=A0 status:= ok
=C2=A0 =C2=A0 cipher: aes-256-cbc

=C2=A0 =C2=A0 db (current)<= br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 wal archive min/max (16): 000000020000000000= 000021/0000000B0000000000000041

=C2=A0 =C2=A0 =C2=A0 =C2=A0 full bac= kup: 20240719-122703F
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 timestam= p start/stop: 2024-07-19 12:27:03+05:30 / 2024-07-19 12:27:06+05:30
=C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 wal start/stop: 00000002000000000000= 002A / 00000002000000000000002A
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 database size: 61.7MB, database backup size: 61.7MB
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 repo1: backup size: 9.6MB

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

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

= =C2=A0 =C2=A0 =C2=A0 =C2=A0 incr backup: 20240719-122703F_20240723-110212I<= br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 timestamp start/stop: 2024-07-= 23 11:02:12+05:30 / 2024-07-23 11:02:15+05:30
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 wal start/stop: 000000070000000000000038 / 00000007000000= 0000000038
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 database size: 48MB= , database backup size: 6.4MB
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = repo1: backup size: 9.8KB
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 back= up reference list: 20240719-122703F, 20240719-122703F_20240719-123408D
<= br>=C2=A0 =C2=A0 =C2=A0 =C2=A0 incr backup: 20240719-122703F_20240723-14181= 8I
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 timestamp start/stop: 2024-= 07-23 14:18:18+05:30 / 2024-07-23 14:18:22+05:30
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 wal start/stop: 00000008000000000000003C / 00000008000= 000000000003C
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 database size: 7= 5.4MB, database backup size: 33.8MB
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 repo1: backup size: 4.7MB
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 backup reference list: 20240719-122703F, 20240719-122703F_20240719-1234= 08D, 20240719-122703F_20240723-110212I

=C2=A0 =C2=A0 =C2=A0 =C2=A0 i= ncr backup: 20240719-122703F_20240724-094727I
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 timestamp start/stop: 2024-07-24 09:47:27+05:30 / 2024-07= -24 09:47:30+05:30
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 wal start/s= top: 00000009000000000000003D / 00000009000000000000003D
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 database size: 62MB, database backup size: 11.5= MB
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 repo1: backup size: 72KB=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 backup reference list: 20240719-= 122703F, 20240719-122703F_20240719-123408D, 20240719-122703F_20240723-11021= 2I, 20240719-122703F_20240723-141818





--
Muhammad Ikram

--000000000000b6a553061e209124--