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 1sXEtv-002dXL-CQ for pgsql-general@arkaria.postgresql.org; Fri, 26 Jul 2024 06:58:03 +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 1sXEtt-006wVo-Um for pgsql-general@arkaria.postgresql.org; Fri, 26 Jul 2024 06:58:01 +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 1sXEtt-006wVg-HE for pgsql-general@lists.postgresql.org; Fri, 26 Jul 2024 06:58:01 +0000 Received: from mail-lj1-x22d.google.com ([2a00:1450:4864:20::22d]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.94.2) (envelope-from ) id 1sXEtq-001Wqg-5G for pgsql-general@postgresql.org; Fri, 26 Jul 2024 06:58:00 +0000 Received: by mail-lj1-x22d.google.com with SMTP id 38308e7fff4ca-2ef2c109eabso10634011fa.0 for ; Thu, 25 Jul 2024 23:57:58 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1721977077; x=1722581877; 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=TJWjOOWkmy5hEPq6P5pDRpoF5XndjoWoW9eJS73VJa0=; b=W9Ypj0pcMKyb4Nr/ZNYW9ZYF7WnAXLLS4lBoGZqkUF/fEALkluhTZ/fxkzVEWhODKs eZepQVBUsy0qohOVBXszoeTNEp7O2DmLEa8dEN0rVBW72R2m5v1/4UDU7XpKxxylbiav gAWG6U/ux7CHEspqKQ9rrPK5oHr69L1Vly6rOcfXe64aXIZs8yTkS1QV2ykjwc4glGmV 92tAosX7YXngzUJsNJ7wdfIl4ekAlybg338oPS7zbHHAcsennN6U07zP1LqCan8pm/6c BhynUFKFeNFzsSgXHehmsOeO14eLuukpIt5oTEIH0p8y9Rj/7HSWEeGR4HqPtNlXY2Xk rACw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1721977077; x=1722581877; 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=TJWjOOWkmy5hEPq6P5pDRpoF5XndjoWoW9eJS73VJa0=; b=SCXxHIm23t4l2MO+/0G45dv7yMz3Sl1Fi3EaOEfiYNQPqIZ8u0yakuCVeQPWKBSKeM eZFc/Pcg7g4aK9u0Xf8tsWcESC0Vitq98wUY0PgAEl8gFBAcVQG+ls/apntiJx4FSKgt h7cQSSJdcQG3h6yJC0mqG8heI/yw9YQPes8sX4JeIYdsYq+7Z+5CKLF/ZSy2QZ13ZLCO 0v5wDLg9054wxhDF6xos9hEvoDhSa0vMOgVWcl8duFJDHhUJ8tBhYCdhP356Y5TNBnnp rCUC6LOuTsKMwmSNPXjKZMXFMT/M4XNRxMWBrTmdIWz5Djc4sQ0Tl6svpYszXZblBSVc R0CQ== X-Gm-Message-State: AOJu0YwPj772mai2o9AzV4HlCF3oaKgkyqmmeqNSdV7z7lzUy4Ocotiw P1anwnUn38zzbOLCznHx4IorIaNtnCNEvYeC320yYk+OBynUcraKsihHXER1Ni/46x7fhvSEGeY uWwCOxcug2ey+hE2cnP8xBbsnLqAke4QE X-Google-Smtp-Source: AGHT+IHt0qguidDQ1N19Bx7E70/aHc07yicfkbgk1RBUrZ+Bion5mMxtS/zjnvjMFye+ssFFwNKnLVCmaRobuHEj664= X-Received: by 2002:a05:651c:85:b0:2ef:2c0f:283e with SMTP id 38308e7fff4ca-2f03db7f77dmr28281541fa.12.1721977076804; Thu, 25 Jul 2024 23:57:56 -0700 (PDT) MIME-Version: 1.0 References: In-Reply-To: From: Muhammad Ikram Date: Fri, 26 Jul 2024 11:57:39 +0500 Message-ID: Subject: Re: PgbackRest PointTIme Recovery : server unable to start back To: KK CHN Cc: pgsql-general Content-Type: multipart/alternative; boundary="000000000000f970d5061e21071e" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --000000000000f970d5061e21071e Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable I don't think it has anything to do with the pg_hba.conf file. Archive seems missing. I will suggest taking a full backup, as you have mentioned that you are able to take full backup. Regards, Ikram On Fri, Jul 26, 2024 at 11:24=E2=80=AFAM KK CHN wrote: > 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, avera= ge=3D0.001 > s; distance=3D93 kB, estimate=3D171 kB; lsn=3D0/3C045768, redo lsn=3D0/3C= 045730 > 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/= 3D000028 > 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_Re= po > 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 Advance= d > 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.544= 4" > 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_Re= po > 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-55c5d6f= 7 > --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_Re= po > 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-34867c0= 5 > --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_Re= po > 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-e2db2e1= b > --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_Re= po > 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-onl= y > connections > 2024-07-26 11:32:57.632 P00 INFO: archive-get command begin 2.52.1: > [00000009000000000000003F, pg_wal/RECOVERYXLOG] --exec-id=3D43301-f613dae= 9 > --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_Re= po > 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 exi= t > code 1 > > > ONLY inference I can make is > > INFO unable to find 00000009000000000000003F in the archive ( Thi= s > 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 =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 Serve= r >> 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 wro= te: >> >>> 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 >>> 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=3DDemo_Repo --de= lta >>> 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 ta= ble >>> ([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-= dir >>> ${PGDATA} (code=3Dexited, status=3D0/SUCCESS) >>> Process: 41908 ExecStart=3D/usr/edb/as16/bin/edb-postgres -D ${PGDA= TA} >>> (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 proces= s >>> 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 backu= p >>> ? >>> >>> >>> >>> >>> >>> >>> >>> On The Repo Server >>> [root@service02 ~]# sudo -u postgres pgbackrest --stanza=3DDemo_Repo i= nfo >>> 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-1= 9 >>> 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-1= 9 >>> 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-1= 9 >>> 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-2= 3 >>> 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-2= 3 >>> 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-2= 4 >>> 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 >> >> --=20 Muhammad Ikram --000000000000f970d5061e21071e Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
I don't think it has anything to do with the pg_h= ba.conf file. Archive seems missing. I will suggest taking a full backup, a= s you have mentioned that you are able to take full backup.

<= /div>

Regards,
Ikram


On Fr= i, Jul 26, 2024 at 11:24=E2=80=AFAM KK CHN <kkchn.in@gmail.com> wrote:
here the= log outputs....

When I ran=C2=A0

$s= udo -u enterprisedb pgbackrest --stanza=3DDemo_Repo =C2=A0--delta =C2=A0--s= et=3D20240719-122703F_20240724-094727I --target-timeline=3Dcurrent --type= =3Dtime "--target=3D2024-07-24 09:44:01.3255+05:30" --target-acti= on=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&= quot; at character 1
2024-07-23 15:34:12 IST STATEMENT: =C2=A0selecct cu= rrent_timestamp
2024-07-23 15:34:26 IST FATAL: =C2=A0database "ente= rprisedb" does not exist
2024-07-24 09:38:20 IST FATAL: =C2=A0datab= ase "enterprisedb" does not exist
2024-07-24 09:42:17 IST FATA= L: =C2=A0database "test1" does not exist
2024-07-24 09:43:56 I= ST FATAL: =C2=A0database "enterprisedb" does not exist
2024-07= -24 09:45:07 IST FATAL: =C2=A0database "enterprisedb" does not ex= ist
2024-07-24 09:45:16 IST ERROR: =C2=A0relation "important_table&= quot; does not exist at character 58
2024-07-24 09:45:16 IST STATEMENT: = =C2=A0begin; drop table important_table; commit; select * from important_ta= ble;
2024-07-24 09:46:00 IST LOG: =C2=A0checkpoint starting: time
202= 4-07-24 09:46:02 IST LOG: =C2=A0checkpoint complete: wrote 16 buffers (0.1%= ); 0 WAL file(s) added, 0 removed, 0 recycled; write=3D1.506 s, sync=3D0.00= 1 s, total=3D1.509 s; sync files=3D9, longest=3D0.001 s, average=3D0.001 s;= distance=3D93 kB, estimate=3D171 kB; lsn=3D0/3C045768, redo lsn=3D0/3C0457= 30
2024-07-24 09:47:27 IST LOG: =C2=A0checkpoint starting: immediate for= ce 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, avera= ge=3D0.001 s; distance=3D16106 kB, estimate=3D16106 kB; lsn=3D0/3D000060, r= edo lsn=3D0/3D000028
2024-07-24 09:47:27.788 P00 =C2=A0 INFO: archive-pu= sh command begin 2.52.1: [pg_wal/00000009000000000000003C] --exec-id=3D3403= 6-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.1= 30 P00 =C2=A0 INFO: pushed WAL file '00000009000000000000003C' to t= he archive
2024-07-24 09:47: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 systemct= l start edb-as-16.service

4-07-26 11:32:56 IST LOG= : =C2=A0starting PostgreSQL 16.3 (EnterpriseDB Advanced Server 16.3.0) on x= 86_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 &= quot;0.0.0.0", port 5444
2024-07-26 11:32:56 IST LOG: =C2=A0listeni= ng on IPv6 address "::", port 5444
2024-07-26 11:32:56 IST LOG= : =C2=A0listening on Unix socket "/tmp/.s.PGSQL.5444"
2024-07-= 26 11:32:56 IST LOG: =C2=A0database system was interrupted; last known up a= t 2024-07-24 09:47:27 IST
2024-07-26 11:32:56 IST LOG: =C2=A0starting po= int-in-time recovery to 2024-07-24 09:44:01.3255+05:30
2024-07-26 11:32:= 56 IST LOG: =C2=A0starting backup recovery with redo LSN 0/3D000028, checkp= oint LSN 0/3D000060, on timeline ID 9
2024-07-26 11:32:56.475 P00 =C2=A0= INFO: archive-get command begin 2.52.1: [00000009.history, pg_wal/RECOVERY= HISTORY] --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_Repo2024-07-26 11:32:56.709 P00 =C2=A0 INFO: found 00000009.history in the re= po1: 16-1 archive
2024-07-26 11:32:56.809 P00 =C2=A0 INFO: archive-get c= ommand end: completed successfully (335ms)
2024-07-26 11:32:56 IST LOG: = =C2=A0restored log file "00000009.history" from archive
2024-0= 7-26 11:32:56.816 P00 =C2=A0 INFO: archive-get command begin 2.52.1: [00000= 009000000000000003D, pg_wal/RECOVERYXLOG] --exec-id=3D43295-55c5d6f7 --log-= level-console=3Dinfo --log-level-file=3Ddebug --pg1-path=3D/var/lib/edb/as1= 6/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 =C2=A0 INFO= : found 00000009000000000000003D in the repo1: 16-1 archive
2024-07-26 1= 1:32:57.099 P00 =C2=A0 INFO: archive-get command end: completed successfull= y (285ms)
2024-07-26 11:32:57 IST LOG: =C2=A0restored log file "000= 00009000000000000003D" from archive
2024-07-26 11:32:57 IST LOG: = =C2=A0redo starts at 0/3D000028
2024-07-26 11:32:57.114 P00 =C2=A0 INFO:= archive-get command begin 2.52.1: [00000009000000000000003E, pg_wal/RECOVE= RYXLOG] --exec-id=3D43297-34867c05 --log-level-console=3Dinfo --log-level-f= ile=3Ddebug --pg1-path=3D/var/lib/edb/as16/data --pg-version-force=3D16 --r= epo1-host=3D10.10.20.7 --repo1-host-user=3Dpostgres --stanza=3DDemo_Repo2024-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: archiv= e-get command end: completed successfully (270ms)
2024-07-26 11:32:57 IS= T LOG: =C2=A0restored log file "00000009000000000000003E" from ar= chive
2024-07-26 11:32:57.400 P00 =C2=A0 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 --r= epo1-host-user=3Dpostgres --stanza=3DDemo_Repo
2024-07-26 11:32:57.521 P= 00 =C2=A0 INFO: unable to find 00000009000000000000003F in the archive
2= 024-07-26 11:32:57.621 P00 =C2=A0 INFO: archive-get command end: completed = successfully (222ms)
2024-07-26 11:32:57 IST LOG: =C2=A0completed backup= recovery with redo LSN 0/3D000028 and end LSN 0/3D000100
2024-07-26 11:= 32:57 IST LOG: =C2=A0consistent recovery state reached at 0/3D000100
202= 4-07-26 11:32:57 IST LOG: =C2=A0database system is ready to accept read-onl= y connections
2024-07-26 11:32:57.632 P00 =C2=A0 INFO: archive-get comma= nd 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 =C2=A0 INFO: unable to find 00000009000000000000003F in the arc= hive
2024-07-26 11:32:57.861 P00 =C2=A0 INFO: archive-get command end: c= ompleted successfully (231ms)
2024-07-26 11:32:57 IST LOG: =C2=A0redo do= ne 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 config= ured recovery target was reached
2024-07-26 11:32:57 IST LOG: =C2=A0star= tup process (PID 43292) exited with exit code 1


ONLY inference=C2=A0 I can make is=C2=A0

=C2=A0 INFO=C2=A0 unable to find=C2=A0 =C2=A0000000090000000000000= 03F in the archive=C2=A0 =C2=A0 ( This means=C2=A0 the=C2=A0 EDB server=C2= =A0 (10.10.20.6=C2=A0 ) unable 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 recove= ry and start backing of edb server 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<= /a> =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 r= eplication =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<= br>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 anything in pg_h= ba.conf ?


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

archive_mode =3D on
archive_comm= and =3D 'pgbackrest --stanza=3DDemo_Repo =C2=A0archive-push %p'
= log_filename =3D 'postgresql.log'
max_wal_senders =3D 5
wal_l= evel =3D replica


Any help ?

=
Krishane




<= div class=3D"gmail_quote">
On Fri, Jul= 26, 2024 at 10:45=E2=80=AFAM Muhammad Ikram <mmikram@gmail.com> wrote:
Hi KK C= HN

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

ul 26 09:48:49 service01 systemd[1]: Started EDB Postgr= es Advanced Server 16.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.s= ervice: Main process exited, code=3Dexited, status=3D1/FAILURE


Regards,
Ikram


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

I am following the=C2=A0= =C2=A0PTR=C2=A0 on RHEL9 EPAS16.
I am able to do a=C2=A0 bac= kup(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 doin= g the=C2=A0 =C2=A0procedures mentioned in the PTR section of the above=C2= =A0 reference 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 serv= er=C2=A0 always results in dead state=C2=A0

=C2=A0= My repo server is another machine.=C2=A0 If=C2=A0 I do=C2=A0 a=C2=A0 full r= estore=C2=A0 on the DB server=C2=A0 ( sudo -u enterprisedb pgbackrest --sta= nza=3DDemo_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 Increm= ental backup tty output shows successful but edb service start=C2=A0 result= s in=C2=A0 failure.=C2=A0

Any help is much app= reciated.=C2=A0

Krishane.=C2=A0




STEPS followed:

after dropping=C2=A0 the table=C2=A0 pg-primary=C2=A0=E2=87=92<= span style=3D"color:rgb(0,0,0);font-family:Avenir,Corbel,sans-serif;font-si= ze:14.6667px;text-align:justify;background-color:rgb(248,248,248)">=C2=A0Dr= op the important table ([section]
stopped the EDB server.

$ sudo -u enterprisedb pgbackrest --stanza=3DD= emo_Repo=C2=A0 =C2=A0 --delta=C2=A0 --set=3D20240719-122703F_20240724-09472= 7I --target-timeline=3Dcurrent --type=3Dtime "--target=3D2024-07-24 09= :44:01.3255+05:30" --target-action=3Dpromote =C2=A0restore
.= ....................................................

2024-07-= 26 09:48:06.343 P00 =C2=A0 INFO: restore command end: completed successfull= y (1035ms)


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

[root@rservice01 ~]# sudo systemctl start edb-= as-16.service
[root@service01 ~]# sudo systemctl status edb-as-16.servic= e
=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; disable= d; preset: disabled)
=C2=A0 =C2=A0 =C2=A0Active: failed (Result: = exit-code) since Fri 2024-07-26 09:48:50 IST; 8s ago
=C2=A0 =C2=A0Durati= on: 242ms
=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 ${P= GDATA} (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: 331= ms

Jul 26 09:48:48 service01 systemd[1]: Starting EDB Postgres Advan= ced Server 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 proc= ess
Jul 26 09:48:48 service01 edb-postgres[41908]: 2024-07-26 09:48:48 I= ST HINT: =C2=A0Future log output will appear in directory "log".<= br>Jul 26 09:48:49 service01 systemd[1]: Started EDB Postgres Advanced Serv= er 16.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: Main pro= cess exited, code=3Dexited, status=3D1/FAILURE
Jul 26 09:48:50 service01= systemd[1]: edb-as-16.service: Killing process 41909 (edb-postgres) with s= ignal SIGKILL.
Jul 26 09:48:50 service01 systemd[1]: edb-as-16.service: = Failed with result 'exit-code'.
[root@service01 ~]#

why is it unable=C2=A0to perform a restore and recovery=C2= =A0 from an incr=C2=A0 backup ?







On The Repo Server
[root@service02 ~]# =C2=A0sudo -u postgres pg= backrest --stanza=3DDemo_Repo info
stanza: Demo_Repo
=C2=A0 =C2=A0 st= atus: ok
=C2=A0 =C2=A0 cipher: aes-256-cbc

=C2=A0 =C2=A0 db (curr= ent)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 wal archive min/max (16): 0000000200000= 00000000021/0000000B0000000000000041

=C2=A0 =C2=A0 =C2=A0 =C2=A0 ful= l backup: 20240719-122703F
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 tim= estamp 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: 0000000200000000= 0000002A / 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



--
Muhammad Ikram

--000000000000f970d5061e21071e--