一个奇异的WAL文件分裂案例__在过去八年我使用Postgres流复制的过程中，我遇到过大约两次这样的场景：由于一个WAL文件已经在主服务器上被移除，后备机上的复制无法继续，因此它会执行B计划，也就是尝试使用restore_command来取得相关的WAL文件（假定归档已被设置好并且工作正常），但是在重放取得的文件时，我们听到了另一个牢骚：“No such file or directory.”: 世界上功能最强大的开源数据库...

## 原文作者

* 原文作者：Richard Yen
* 原文链接：http://richyen.com/replication/postgres/2019/01/22/split_wal_files.html

## 译者简介

彭煜玮（ywpeng@whu.edu.cn）：武汉大学计算机学院副教授、硕士生导师。现任中国计算机学会数据库专业委员会委员、ACM SIGMOD中国分部委员、PostgreSQL中国用户协会常务委员。著有《PostgreSQL数据库内核分析》一书，译著包括《由浅入深PostgreSQL》、《PostgreSQL 9.X之巅》、《PostgreSQL文档》、《Greenplum文档》等。

![](/images/news/2019/20190129_2213_01.jpg =600x449)

## 引言

在过去八年我使用Postgres流复制的过程中，我遇到过大约两次这样的场景：由于一个WAL文件已经在主服务器上被移除，后备机上的复制无法继续，因此它会执行B计划，也就是尝试使用`restore_command`来取得相关的WAL文件（假定归档已被设置好并且工作正常），但是在重放取得的文件时，我们听到了另一个牢骚：“No such file or directory.”什么？文件确实在那里啊？ls命令显示它就在归档里。如此这般下来，备机在复制工作上一点进展也没有。到底发生了什么？下面是从日志中截取的一段：

```
2017-07-19 16:35:19 AEST [111282]: [96-1] user=,db=,client=  (0:00000)LOG:  restored log file "0000000A000000510000004D" from archive
scp: /archive/xlog//0000000A000000510000004E: No such file or directory
2017-07-19 16:35:20 AEST [114528]: [1-1] user=,db=,client=  (0:00000)LOG:  started streaming WAL from primary at 51/4D000000 on timeline 10
2017-07-19 16:35:20 AEST [114528]: [2-1] user=,db=,client=  (0:XX000)FATAL:  could not receive data from WAL stream: ERROR:  requested WAL segment 0000000A000000510000004D has already been removed

scp: /archive/xlog//0000000B.history: No such file or directory
scp: /archive/xlog//0000000A000000510000004E: No such file or directory
2017-07-19 16:35:20 AEST [114540]: [1-1] user=,db=,client=  (0:00000)LOG:  started streaming WAL from primary at 51/4D000000 on timeline 10
2017-07-19 16:35:20 AEST [114540]: [2-1] user=,db=,client=  (0:XX000)FATAL:  could not receive data from WAL stream: ERROR:  requested WAL segment 0000000A000000510000004D has already been removed

scp: /archive/xlog//0000000B.history: No such file or directory
scp: /archive/xlog//0000000A000000510000004E: No such file or directory
2017-07-19 16:35:25 AEST [114550]: [1-1] user=,db=,client=  (0:00000)LOG:  started streaming WAL from primary at 51/4D000000 on timeline 10
2017-07-19 16:35:25 AEST [114550]: [2-1] user=,db=,client=  (0:XX000)FATAL:  could not receive data from WAL stream: ERROR:  requested WAL segment 0000000A000000510000004D has already been removed
```

## 到底怎么了？

我个人还没能准确地重现这一现象，但是我们已经发现，当一个WAL项跨越了两个WAL文件时就会发生这种现象。因为有些WAL项会跨越两个文件，Postgres的归档重放内部并不知道它同时需要两个文文件来成功地重放该事件并且继续进行流复制。在上面的例子中，从`pg_controldata`的输出可以观察到一个额外的细节，有些情况下看起来像这样：`Minimum recovery ending location: 51/4DFFED10`。因此当启动后备服务器（在维护性关机或者其他类似情况之后）时，它无疑需要文件`0000000A000000510000004D`才能继续下去，所以它将尝试从归档获取其内容并且重放之。后备服务器能够顺利地恢复所有相关的WAL文件，直到它到达51/4D文件的尾部，在这个位置上它就再也找不到更多WAL文件来重放了。此时toggling机制开始介入，它会启动`walsender`以及`walreceiver`进行来执行流复制。

在`walreceiver`启动时，它会检查现在的情况并且发现它需要从51/4DFFED10开始流重放，因此它会要求`walsender`取得`0000000A000000510000004D`的内容并且发送过来。不过，这个动作花了较长时间（可能由于流量太大或者`wal_keep_segments`配置不当）并且`0000000A000000510000004D`文件已经不见了。不管是`walsender`还是`walreceiver`都不知道`LSN 51/4DFFED10`实际不存在于`0000000A000000510000004D`中，而是在`0000000A000000510000004E`中。而且`0000000A000000510000004D`已经不存在了，所以也无法通过扫描`0000000A000000510000004D`来发现实际需要的是`0000000A000000510000004E`。

## 可能的解决方案

在我遇到的一个场景中，较新的文件（上面例子中的`0000000A000000510000004E`）还没有被填满。该场景是一个流量较低的开发环境，用户只需要简单地对主服务器发出一个`pg_switch_xlog()`就好。

当然，这并不是一种非常靠得住的解决方案，因为它需要人工干预。最后，更可靠的解决方案是使用一个复制槽，这样Postgres总是会保持所需的WAL文件并且不会过早地移动或者删除它们。虽然[流复制槽也有它们的缺陷](http://richyen.com/replication/postgres/2019/01/08/zombie_transactions.html)，但在使用得当时它们可以通过最小的配置微调来确保可靠的复制。

特别感谢Andres Freund和Kuntal Ghosh在分析和确定这一解决方案时给予的帮助。

![CENTER_PostgreSQL_Community](/images/news/2016/pg_bot_banner.jpg)