pg_rewind执行成功但将node3设为node2备库时PostgreSQL报错

算力阿峰

2026-8-9

PostgreSQL pg_rewind 使用问题排查与解决方案

环境背景

原有3节点部署：

node1(50.2)：主库
node2(50.3)、node3(50.4)：备库

将node2和node3提升为独立节点后，尝试用pg_rewind将node3配置为node2的备库，得到以下提示：

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

但启动node3的PostgreSQL备库模式时，出现如下错误日志：

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

问题解答

1. 是否只能通过`pg_basebackup`来将node3配置为node2的备库？

不是必须，但当前场景下pg_rewind未生效，需要先排查原因并修正后才能使用；如果修正成本过高，pg_basebackup是可靠的替代方案。

2. 两节点拥有共同祖先场景下，正确使用`pg_rewind`的方法

核心问题分析

当前pg_rewind提示“no rewind required”但备库启动失败，原因是：

node3提升为独立节点后生成了新的WAL记录，虽然和node2处于同一timeline，但node3的WAL位置（0/35EFB738）已经超过了node2当前的WAL刷新位置（0/2Fxxxxxx），导致node3尝试从node2拉取超前的WAL段，无法获取。
pg_rewind仅在目标节点（node3）的timeline分支落后于源节点（node2）时才会生效，若目标节点在同一timeline上走得更远，pg_rewind不会执行任何操作。

正确操作步骤

步骤1：停止目标节点（node3）

pg_ctl -D /path/to/node3/data stop -m fast

步骤2：确认节点WAL位置与timeline信息

在node2上执行SQL，获取当前timeline和WAL刷新位置：
```
SELECT timeline_id, pg_current_wal_flush_lsn();
```

在node3的data目录下，查看控制文件信息：

pg_controldata /path/to/node3/data | grep -E "Latest checkpoint location|Timeline ID"

步骤3：将node3回退到与node2的共同分支位置

如果node3的WAL位置超前于node2，需要先将其恢复到两者的最后共同WAL位置：

找到最后共同WAL位置（可通过原主库node1的备份、WAL归档或timeline历史文件确认）。

在node3的postgresql.conf中添加恢复参数（PostgreSQL 12+无需单独recovery.conf）：

restore_command = 'cp /path/to/wal/archive/%f %p'
recovery_target_lsn = '0/2Fxxxxxx' -- 替换为实际的共同WAL位置
recovery_target_action = 'promote'

启动node3完成恢复，恢复完成后node3会自动提升为独立节点，此时其WAL位置与共同位置一致。

步骤4：执行pg_rewind

停止node3，执行命令同步node2的数据：

pg_rewind -D /path/to/node3/data --source-server="host=node2 port=5432 user=postgres dbname=postgres"

此时pg_rewind会识别到node3的分支落后于node2，自动执行回退与数据同步。

步骤5：配置并启动备库

在node3的postgresql.conf中设置备库参数：

primary_conninfo = 'host=node2 port=5432 user=postgres password=your_password'
standby_mode = 'on'

启动node3：
```
pg_ctl -D /path/to/node3/data start
```

关键注意事项

源节点和目标节点必须启用wal_log_hints = on（PostgreSQL 13+默认开启），否则pg_rewind无法正常工作。
确保node2的WAL归档包含从共同祖先到当前的所有WAL文件，或node2仍保留这些WAL段未被回收。
若无法找到共同WAL位置，或node2的WAL已被回收，此时只能使用pg_basebackup重新搭建备库。

内容的提问来源于stack exchange，提问作者Niraj Nandane