pg_rewind succeed but postgresql showing error when trying to make standby with common ancestor

220 views Asked by At

Have 3 node setup: node1(50.2), node2(50.3) and node3(50.4). node1(50.2) is primary and node2(50.3) and node3(50.4) are standby. I promoted node2 and node3 to make them independent. When i try to make the node3 slave of node2, using pg_rewind, it says below:

pg_rewind: connected to server
pg_rewind: source and target cluster are on the same timeline
pg_rewind: no rewind required

After this, when i start postgresql on the node3 in standby mode, i get below:

Dec 09 04:19:40 fsrstandby.for.com postmaster[6054]: 2022-12-09 04:19:40 UTCLOG:  entering standby mode
Dec 09 04:19:40 fsrstandby.for.com postmaster[6054]: 2022-12-09 04:19:40 UTCLOG:  consistent recovery state reached
at 0/35EFB738
Dec 09 04:19:40 fsrstandby.for.com postmaster[6054]: 2022-12-09 04:19:40 UTCLOG:  invalid record length at 0/35EFB738: wanted 24, got 0
Dec 09 04:19:40 fsrstandby.for.com postmaster[6053]: 2022-12-09 04:19:40 UTCLOG:  database system is ready to accept read-only connections
Dec 09 04:19:40 fsrstandby.for.com systemd[1]: Started PostgreSQL 14 database server.
Dec 09 04:19:40 fsrstandby.for.com postmaster[6058]: 2022-12-09 04:19:40 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:19:40 fsrstandby.for.com postmaster[6058]: 2022-12-09 04:19:40 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F12A7D8
Dec 09 04:19:40 fsrstandby.for.com postmaster[6061]: 2022-12-09 04:19:40 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:19:40 fsrstandby.for.com postmaster[6061]: 2022-12-09 04:19:40 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F12A7D8
Dec 09 04:19:45 fsrstandby.for.com postmaster[6075]: 2022-12-09 04:19:45 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:19:45 fsrstandby.for.com postmaster[6075]: 2022-12-09 04:19:45 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F13D5B8
Dec 09 04:19:50 fsrstandby.for.com postmaster[6636]: 2022-12-09 04:19:50 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:19:50 fsrstandby.for.com postmaster[6636]: 2022-12-09 04:19:50 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F13D5F0
Dec 09 04:19:55 fsrstandby.for.com postmaster[6886]: 2022-12-09 04:19:55 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:19:55 fsrstandby.for.com postmaster[6886]: 2022-12-09 04:19:55 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F13D5F0
Dec 09 04:19:57 fsrstandby.for.com postmaster[6053]: 2022-12-09 04:19:57 UTCLOG:  received fast shutdown request
Dec 09 04:19:57 fsrstandby.for.com systemd[1]: Stopping PostgreSQL 14 database server...
Dec 09 04:19:57 fsrstandby.for.com postmaster[6053]: 2022-12-09 04:19:57 UTCLOG:  aborting any active transactions
Dec 09 04:19:57 fsrstandby.for.com postmaster[6055]: 2022-12-09 04:19:57 UTCLOG:  shutting down
Dec 09 04:19:57 fsrstandby.for.com postmaster[6053]: 2022-12-09 04:19:57 UTCLOG:  database system is shut down
Dec 09 04:19:57 fsrstandby.for.com systemd[1]: postgresql-14.service: Succeeded.
Dec 09 04:19:57 fsrstandby.for.com systemd[1]: Stopped PostgreSQL 14 database server.
Dec 09 04:20:05 fsrstandby.for.com systemd[1]: Starting PostgreSQL 14 database server...
Dec 09 04:20:05 fsrstandby.for.com postmaster[7177]: 2022-12-09 04:20:05 UTCLOG:  starting PostgreSQL 14.4 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 8.5.0 20210514 (Red Hat 8.5.0-10), 64-bit
Dec 09 04:20:05 fsrstandby.for.com postmaster[7177]: 2022-12-09 04:20:05 UTCLOG:  listening on IPv4 address "0.0.0.0", port 5432
Dec 09 04:20:05 fsrstandby.for.com postmaster[7177]: 2022-12-09 04:20:05 UTCLOG:  listening on IPv6 address "::", port 5432
Dec 09 04:20:05 fsrstandby.for.com postmaster[7177]: 2022-12-09 04:20:05 UTCLOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
Dec 09 04:20:05 fsrstandby.for.com postmaster[7177]: 2022-12-09 04:20:05 UTCLOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
Dec 09 04:20:05 fsrstandby.for.com postmaster[7177]: postmaster: could not write external PID file "/var/run/14-data.pid": Permission denied
Dec 09 04:20:05 fsrstandby.for.com postmaster[7196]: 2022-12-09 04:20:05 UTCLOG:  database system was shut down in recovery at 2022-12-09 04:19:57 UTC
Dec 09 04:20:05 fsrstandby.for.com postmaster[7196]: 2022-12-09 04:20:05 UTCLOG:  entering standby mode
Dec 09 04:20:05 fsrstandby.for.com postmaster[7196]: 2022-12-09 04:20:05 UTCLOG:  consistent recovery state reached
at 0/35EFB738
Dec 09 04:20:05 fsrstandby.for.com postmaster[7196]: 2022-12-09 04:20:05 UTCLOG:  invalid record length at 0/35EFB738: wanted 24, got 0
Dec 09 04:20:05 fsrstandby.for.com postmaster[7177]: 2022-12-09 04:20:05 UTCLOG:  database system is ready to accept read-only connections
Dec 09 04:20:05 fsrstandby.for.com systemd[1]: Started PostgreSQL 14 database server.
Dec 09 04:20:05 fsrstandby.for.com postmaster[7200]: 2022-12-09 04:20:05 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:20:05 fsrstandby.for.com postmaster[7200]: 2022-12-09 04:20:05 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F13D5F0
Dec 09 04:20:05 fsrstandby.for.com postmaster[7217]: 2022-12-09 04:20:05 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:20:05 fsrstandby.for.com postmaster[7217]: 2022-12-09 04:20:05 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F13D5F0
Dec 09 04:20:20 fsrstandby.for.com postmaster[7477]: 2022-12-09 04:20:20 UTCLOG:  started streaming WAL from primary at 0/35000000 on timeline 2
Dec 09 04:20:20 fsrstandby.for.com postmaster[7477]: 2022-12-09 04:20:20 UTCFATAL:  could not receive data from WAL
stream: ERROR:  requested starting point 0/35000000 is ahead of the WAL flush position of this server 0/2F13F3D0

Is pg_basebackup only solution to form the standby for node3 with node2? How to use pg_rewind in the case where both the node from common ancestor?

0

There are 0 answers