From: Samuel VISCAPI <samuel.viscapi@xelians.fr>
To: Alvaro Herrera <alvherre@alvh.no-ip.org>
CC: "pgsql-admin@lists.postgresql.org" <pgsql-admin@lists.postgresql.org>
Subject: RE: 2nd PostgreSQL server in WAL shipping cluster fails to start
Thread-Topic: 2nd PostgreSQL server in WAL shipping cluster fails to start
Thread-Index: AdtifmqCI/mjxc4zTd6+dTy4ZYsnWQACMquABBvf7qA=
Date: Thu, 30 Jan 2025 09:54:26 +0000
Message-ID: 
 <MR2P264MB014775B1000AD1C59C5EA584FEE92@MR2P264MB0147.FRAP264.PROD.OUTLOOK.COM>
References: 
 <MR2P264MB0147200E004CB5C9FC761ACCFE132@MR2P264MB0147.FRAP264.PROD.OUTLOOK.COM>
 <202501091111.ds3gg5ae7kyc@alvherre.pgsql>
In-Reply-To: <202501091111.ds3gg5ae7kyc@alvherre.pgsql>
Accept-Language: fr-FR, en-US
Content-Language: fr-FR
x-ms-exchange-antispam-messagedata-chunkcount: 1
x-ms-exchange-antispam-messagedata-0: 
 =?iso-8859-1?Q?/lfEPusFw1H092JiSkhY/V/h5yI99MMJ6hO3lY7wFElNPfD5LFdyroWqiB?=
 =?iso-8859-1?Q?dbvpTxaGLggUwK4c61sQyFkTeYCUpVEOQM34LjDu2FKx6ZUrHIclzQaKpd?=
 =?iso-8859-1?Q?B/SIhfq8+WzrZH6mu2SpgPlkTkmaNq47H+b1dScDLupVfEerZ0cMhxXCUH?=
 =?iso-8859-1?Q?sg0Nr0kzTVEPWLyW6+Mpwp8UpzGTclWH9nIwqIdpALr/aRwl5kvEElMM0G?=
 =?iso-8859-1?Q?pG/ADaDaoGxfF/jDOUSNs1kf+Tm5PGWOOdLOrT3q/73S6wGMTbknE/M6RA?=
 =?iso-8859-1?Q?DQPTcW+9mzGWGwVMxxuvgYe2IgDqYBGgJT7kJlrsJREfFvRMsPoK2ilfrO?=
 =?iso-8859-1?Q?Tj7AB1RK5OUK7aLOiuM0IqVOfBghGOOfnIMpirIPDYmaOwPkc45POmUVrC?=
 =?iso-8859-1?Q?Jea4TxZrUG/cBABopw/nXkJtPab2vxAOiVomv2reXVLDiqJank+FHzorbx?=
 =?iso-8859-1?Q?PNlRN3WSZKL+LFGfA703Ng6/MGxbYwO8jwOs3DGtxDCjdR3kx+y1xsELdz?=
 =?iso-8859-1?Q?g7rRZCdCTkkIbP3bi2iBQtW03FHNs7dJ2ZmvIpTNhq8OOR/9sKpEcgkD1I?=
 =?iso-8859-1?Q?76cEW7/4DLhS5XM1neBAHaNH86zOb9K+YdBOoj+Sf2U9nyAUl3oGcpaB+f?=
 =?iso-8859-1?Q?x5gmfDp9QiZr8uGDrtvNJIuifIu8uTZMnQhttoo4i4H4H0Egl59ARSpn/h?=
 =?iso-8859-1?Q?T40gcynNXqmiYctm9Z4zW4uV2tdV122gFWgjr8Z/XcJEyzZHTvXxbztzeB?=
 =?iso-8859-1?Q?yGC3Rv6wRr4QuV2Y+lsvRFosQ1SFCcLzIw4woyjroFhpVwgzkuZ+kJlDWa?=
 =?iso-8859-1?Q?/g+qC5eOhpmgN/6nmJuQ2xLod9qpU4QMj11gh8z7YUpdD2jcLjfBnC3vK6?=
 =?iso-8859-1?Q?R+dhwfW1RrlcCPPSq0w7chTYPdvW6/n4PZkTWx0pf2Cv5H3ubp6oJ1A1cU?=
 =?iso-8859-1?Q?bwCgyMfNcVu3v80h6E0U+hK6Ra7irX/quTwdSBTOZ/knss2n5oQxLrFP45?=
 =?iso-8859-1?Q?gYAl3NQ5Q9VJ7BFYcV1DHk2vzkuuUQi9yieZ+qZq1hv+QImEJBVkHuJdy0?=
 =?iso-8859-1?Q?0WEyWViCK43K9IQwFCKqKnZrokZzI1PDWKpsSQa+Jh59bDJQ5pnlgIDVUI?=
 =?iso-8859-1?Q?pYng7VhZ/gNcn+UKok2+2KjMG3SrMzz+vfwh99QpNIt8eICqXlqwaZJ7Zz?=
 =?iso-8859-1?Q?qYAD0qPFcJDLganSDGk3rC0ItaomnPngIX0usW/4RBrb8ELABDgE1V5Vbd?=
 =?iso-8859-1?Q?S59SlF3AQcnHXzgUqx9szYIVffB/dbOoBRA6F+czj9474K5UmSmcNMsxPa?=
 =?iso-8859-1?Q?apNExIJsJ6LWzDFn9IaXFuTaAxTxpSe4amlLDsaBByfoVqWjd/e18uSCVS?=
 =?iso-8859-1?Q?jjbRNZBOH8boL/AkUeqZPqX/POgGJi4AnVnCP4jgKELJdJXs37t3AqsC5E?=
 =?iso-8859-1?Q?to4qiMFQdTGiSRDt2bHyASHgQTTJ077M75NiwRj5Wo/0COgpZRR/M8bAeb?=
 =?iso-8859-1?Q?77U9DoK5las3a3a0d6WIlNGOVI8J9CFlCweWmhiVN7QOTy/lShwUAaFMzs?=
 =?iso-8859-1?Q?Ri27xdDczoz4BTrmKYuGIgH1Wn1H/nO34XU7pWHIt/5wyM7SOa9NYCxvO5?=
 =?iso-8859-1?Q?ZrXmAQ9uY5WcAyLFiVqUK7/OqX67IW1XsgqavPb6+bKo4R2dbpMdZ8zzcb?=
 =?iso-8859-1?Q?M72APdR4qLEovUKxVfBnLEC8ymDCsxfw912NFDpK?=
Content-Type: text/plain; charset="iso-8859-1"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-OriginatorOrg: xelians.fr
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-AuthSource: MR2P264MB0147.FRAP264.PROD.OUTLOOK.COM
X-MS-Exchange-CrossTenant-Network-Message-Id: 
 567b70d4-a8ca-49eb-3a97-08dd411414d8
X-MS-Exchange-CrossTenant-originalarrivaltime: 30 Jan 2025 09:54:26.0948
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 6fc1c04c-4bce-498f-bdd2-4a407cbd7dcd
X-MS-Exchange-CrossTenant-mailboxtype: HOSTED
X-MS-Exchange-CrossTenant-userprincipalname: 
 kBjd+4/xdFaPsBDC2+y7XHnB+fLB38Lrnrmx7HwKRjP/5Ul8isYs7tptmFZXfTpNgnuPC7gHALAwusfW5S39nvaKmPLbuwjqWXymZw5LUHg=
X-MS-Exchange-Transport-CrossTenantHeadersStamped: MRZP264MB1733
List-Id: <pgsql-admin.lists.postgresql.org>
List-Help: <https://lists.postgresql.org/manage/>
List-Subscribe: <https://lists.postgresql.org/manage/>
List-Post: <mailto:pgsql-admin@lists.postgresql.org>
List-Owner: <mailto:pgsql-admin-owner@lists.postgresql.org>
List-Archive: <https://www.postgresql.org/list/pgsql-admin>
Archived-At: 
 <https://www.postgresql.org/message-id/MR2P264MB014775B1000AD1C59C5EA584FEE92%40MR2P264MB0147.FRAP264.PROD.OUTLOOK.COM>
Precedence: bulk

Dear Alvaro and Anton,

Thank you for your quick replies, really appreciated. I ran some more tests=
 today and the results are as follows:

Available disk space on primary server : 101GB free in the data directory. =
I believe some cleaning up has been done, I need to check with my colleague=
s about that.
Wal_sender_timeout : #wal_sender_timeout =3D 60s
Wal_keep_segments : not present in postgresql.conf
Networking issues : none at the moment, the primary server can ping the ser=
ver in standby mode by its IP address. Name resolution doesn't work though.
Monitor replication lag between the two nodes:
- Primary node :=20

SELECT pg_current_wal_lsn();
 pg_current_wal_lsn
--------------------
 18/B6C404B8

- Standby node : TODO when the node is up again

I'm tempted to give the pgbasebackup command a go: https://www.postgresql.o=
rg/docs/13/app-pgbasebackup.html

pg_basebackup -h primary_host -D /some_app/data -U postgres -v -P

@Alvaro Herrera : the archive_command is indeed set in the primary server, =
as follows:

archive_command =3D 'test ! -f /some_app/data/mnt/server/archivedir/%f && c=
p %p /some_app/data/mnt/server/archivedir/%f'

There are some files in the pg_wal directory but they only amount to 289MB.=
 If I need to rebuild the replica from scratch, could I use the pg_baseback=
up command above for that purpose ?

And you are obviously right about the error message in French. Please find =
it below:

2025-01-09 09:46:35.742 CET [3147382] FATAL:  n'a pas pu recevoir des donn=
=E9es du flux de WAL : ERREUR:  le segment demand=E9 du journal de transact=
ion, 000000010000000D000000D6, a d=E9j=E0 =E9t=E9 supprim=E9
2025-01-09 09:46:40.745 CET [3147395] LOG:  d=E9marr=E9 le flux des journau=
x depuis le principal =E0 D/D6000000 sur la timeline 1
2025-01-09 09:46:40.745 CET [3147395] FATAL:  n'a pas pu recevoir des donn=
=E9es du flux de WAL : ERREUR:  le segment demand=E9 du journal de transact=
ion, 000000010000000D000000D6, a d=E9j=E0 =E9t=E9 supprim=E9
2025-01-09 09:46:45.749 CET [3147397] LOG:  d=E9marr=E9 le flux des journau=
x depuis le principal =E0 D/D6000000 sur la timeline 1
2025-01-09 09:46:45.749 CET [3147397] FATAL:  n'a pas pu recevoir des donn=
=E9es du flux de WAL : ERREUR:  le segment demand=E9 du journal de transact=
ion, 000000010000000D000000D6, a d=E9j=E0 =E9t=E9 supprim=E9
2025-01-09 09:46:50.753 CET [3147424] LOG:  d=E9marr=E9 le flux des journau=
x depuis le principal =E0 D/D6000000 sur la timeline 1
2025-01-09 09:46:50.753 CET [3147424] FATAL:  n'a pas pu recevoir des donn=
=E9es du flux de WAL : ERREUR:  le segment demand=E9 du journal de transact=
ion, 000000010000000D000000D6, a d=E9j=E0 =E9t=E9 supprim=E9

Thanks again for your help.

Best regards,

Samuel

-----Message d'origine-----
De=A0: Alvaro Herrera <alvherre@alvh.no-ip.org>=20
Envoy=E9=A0: jeudi 9 janvier 2025 12:11
=C0=A0: Samuel VISCAPI <samuel.viscapi@xelians.fr>
Cc=A0: pgsql-admin@lists.postgresql.org
Objet=A0: Re: 2nd PostgreSQL server in WAL shipping cluster fails to start

On 2025-Jan-09, Samuel VISCAPI wrote:

> Dear all,
>=20
> Some years ago I set up a two PostgreSQL 13 nodes cluster on Debian 11. T=
his cluster uses the Write-Ahead Log Shipping method. I've just been told t=
he second server (in standby mode) is down and refuses to start again with =
the following error message (roughly translated from French) :
>=20
> 2025-01-09 09:46:35.742 CET [3147382] FATAL:  could not receive data=20
> from WAL stream: ERROR:  segment requested from transaction journal,=20
> 000000010000000D000000D6, has already been removed
> 2025-01-09 09:46:40.745 CET [3147395] LOG:  journal flow started from=20
> primary at D/D6000000 on timeline 1
> 2025-01-09 09:46:40.745 CET [3147395] FATAL:  could not receive data=20
> from WAL stream : ERROR:  segment requested from transaction journal,=20
> 000000010000000D000000D6, has already been removed
> 2025-01-09 09:46:45.749 CET [3147397] LOG: journal flow started from=20
> primary at D/D6000000 on timeline 1
> 2025-01-09 09:46:45.749 CET [3147397] FATAL:  could not receive data=20
> from WAL stream : ERROR:  segment requested from transaction journal,=20
> 000000010000000D000000D6, has already been removed
> 2025-01-09 09:46:50.753 CET [3147424] LOG:  journal flow started from=20
> primary at D/D6000000 on timeline 1
> 2025-01-09 09:46:50.753 CET [3147424] FATAL:  could not receive data=20
> from WAL stream : ERROR:  segment requested from transaction journal,=20
> 000000010000000D000000D6, has already been removed

This means the standby is requesting a segment that was already removed.
You may be able to find those files in a WAL archive, if you have archive_c=
ommand set in the primary.  If you do, then it would work to copy those to =
the standby's pg_wal/ subdirectory.  If you don't have them, then the repli=
ca must be rebuilt.


Note that it's not a good idea to translate the error messages when posting=
 -- that is, it's better to post exactly what the log file has.
For helpfulness you could post a translation for the lines separately.
But the developers can find the translated messages in the source code, if =
they need them ... but if you translate them yourself, there's no way to kn=
ow exactly which ones they are.  Sometimes subtle differences are important=
 cues.

--=20
=C1lvaro Herrera               48=B001'N 7=B057'E  -  https://www.Enterpris=
eDB.com/