用Patroni崩溃的故事,或如何删除PostgreSQL集群

PostgreSQL没有开箱即用的高可用性。要实现HA,您需要投入一些精力,然后进行设置-付出努力。有几种工具可以帮助提高PostgreSQL的可用性,其中之一是Patroni。

乍一看,将Pa​​troni置于测试环境中,您会看到它是一个很棒的工具,以及如何轻松地处理我们破坏集群的尝试。但是实际上,在生产环境中,并非所有事物都总是如此优美和优雅。 Data Egret于2018年底开始使用Patroni,并获得了一些经验:如何诊断,配置它以及何时完全不依赖自动文件管理器。

在HighLoad ++上,Alexei Lesovsky使用示例和日志分析详细描述了与Patroni合作时出现的典型问题,以及克服这些问题的最佳实践。


本文不会:Patroni安装说明和配置示例;Patroni和PostgreSQL以外的问题;这些故事是基于他人的经验,但仅是数据白鹭自己解决的问题。

关于演讲者: Alexey Lesovsky(列索夫斯基)最初是系统管理员(Linux系统管理员),然后是网络开发人员(PostgreSQL数据库管理员)。自2014年以来,她一直在Data Egret工作。Data Egret从事PostgreSQL领域的咨询,帮助许多许多公司正确使用PostgreSQL,当然,在操作数据库方面也积累了丰富的经验。
本文所基于的报告称为“ Patroni故障案例或如何使PostgreSQL集群崩溃”,这是该演示文稿链接

在你开始之前


让我提醒您什么是Patroni,它的用途是什么,它可以做什么。

Patroni是开箱即用地构建HA的模板。所以它是写在文档中的,从我的角度来看-这是一个非常正确的说明。也就是说,帕特罗尼不是他设定的万灵药,它将解决所有问题。必须努力使它开始起作用并带来好处。

Patroni-代理服务。它与数据库一起安装在每台服务器上,并且是PostgreSQL的一种初始化系统:它启动,停止,重新启动,更改集群的配置和拓扑。

Patroni在DCS中存储“集群状态”。要存储集群状态及其当前视图,需要存储。Patroni将状态存储在外部系统中-分布式配置存储库。这可以是以下选项之一:Etcd,Consul,ZooKeeper或Etcd Kubernetes。

默认情况下启用Patroni AutoFile。安装Patroni之后,您将立即获得自动文件管理器。

另外,还有许多其他事情,例如:服务配置,创建新副本,备份等。但这一次将不在报告范围内。
Patroni的主要目的是提供可靠的自动文件管理器。
Patroni不必监视设备,发送通知,进行有关潜在事故预防的复杂工作等。要求集群保持运行状态,并且无论集群拓扑如何更改,应用程序都可以继续使用数据库。

但是,当我们开始将Patroni与PostgreSQL结合使用时,我们的系统会变得更加复杂。现在,除了数据库本身之外,当主服务器或副本服务器发生故障时,Patroni本身,群集状态的分布式存储或网络可能会崩溃。考虑所有选项,因为它们在理解其原因的难度方面变得越来越复杂。

问题1. DBMS和DCS在同一群集上


考虑最简单的情况:我们采用一个数据库集群,并将DCS部署在同一集群上。这个常见错误不仅与PostgreSQL和Patroni部署错误有关。这是体系结构的一般构造中的一个错误-将许多不同的组件整合到一个位置。

因此,进行了故障转移。我们开始了解发生了什么。在这里,我们对过渡发生的时间(即集群状态发生变化的时间点)感兴趣

故障转移何时发生?


失败并非总是立即发生;这可能很耗时。因此,它具有开始时间和结束时间。所有事件都被分为三个部分:“变节之前”,“期间”和“之后”。

首先,当feylover发生时,我们正在寻找原因。

pgdb-2 patroni: INFO: promoted self to leader by acquiring session lock
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2
pgdb-2 patroni: INFO: updated leader lock during promote
pgdb-2 patroni: server promoting
pgdb-2 patroni: INFO: cleared rewind state after becoming the leader
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2

上面是标准的Patroni日志,他在其中报告服务器角色已更改,向导的角色已从另一个角色移到该节点。

为什么会发生故障转移?


接下来,您需要了解哪些事件使主服务器的角色从一个节点转移到了另一个节点,以及旧主服务器发生了什么。

pgdb-2 patroni: patroni.utils.RetryFailedError: 'Exceeded retry deadline'
pgdb-2 patroni: ERROR: Error communicating with DCS
pgdb-2 patroni: INFO: demoted self because DCS is not accessible and i was a leader
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.

在这种情况下,一切都很简单:Error communicating with DCS-与配置存储系统交互时出错。船长意识到他不能与DCS合作,并说他不能再当船长而辞职。demoted self谈到这个。

feylover之前是什么?


如果查看feylover之前的事件,则可以看到成为向导继续存在问题的原因:

pgdb-2 patroni: ERROR: touch_member
                ... python trace 
pgdb-2 patroni: socket.timeout: timed out 
pgdb-2 patroni: During handling of the above exception, another exception occurred:
                ... python trace 
pgdb-2 patroni:   raise ReadTimeoutError(self, url, "Read timed out. (read timeout=%s)" % timeout_value) 
pgdb-2 patroni: urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host='127.0.0.1', port=8500): Read timed out. (read timeout=3.3333333333333335) 
pgdb-2 patroni: During handling of the above exception, another exception occurred:
                ... python trace 
pgdb-2 patroni:     raise MaxRetryError(_pool, url, error or ResponseError(cause)) 
pgdb-2 patroni: urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='127.0.0.1', port=8500): Max retries exceeded with url: /v1/kv/service/pgdb/members/pgdb-2?acquire=19598b72-c0d5-f066-5d24-09c1a9ad61ee&dc=maindb (Caused by ReadTimeoutError("HTTPConnectionPool(host='127.0.0.1', port=8500): Read timed out. (read timeout=3.3333333333333335)",)) 
pgdb-2 patroni: INFO: no action.  i am the leader with the lock 
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.

Patroni日志显示许多不同的超时错误。Patroni Agent无法使用DCS(在这种情况下,它是Consul,端口= 8500)。Patroni和数据库在同一主机上运行,​​而Consul服务器在同一主机上运行。在服务器上创建了负载之后,我们还为Consul服务器创建了问题,因为这些问题导致它们无法正常通信。

一切都恢复原状


过了一会儿,当负载减少时,我们的Patroni能够再次与代理进行通信,一切恢复了:

pgdb-2 patroni: INFO: promoted self to leader by acquiring session lock
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2
pgdb-2 patroni: INFO: updated leader lock during promote
pgdb-2 patroni: server promoting
pgdb-2 patroni: INFO: cleared rewind state after becoming the leader
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2

同一台pgdb-2服务器再次成为主服务器。有一个小小的“翻转”-在相对较短的时间内,他辞去了大师职务,然后再次将其置于自己身上。

这可以被视为误报,也可以被视为Patroni所做的一切正确的事实。

决断


我们自己决定问题在于Consul服务器与数据库位于同一硬件上。因此,CPU和磁盘上的任何负载(大量IO请求,临时文件,自动清理,迁移,备份等)也会影响与Consul群集的交互。我们决定不要将它与数据库放在同一设备上,并为Consul分配了单独的集群。

或者,你可以旋转参数ttlloop_waitretry_timeout,由于其增加设法生存短期峰值负荷。但是,如果负载很长,我们将超出这些参数,该方法将不起作用。

问题2。中断


第二个问题与第一个问题相似,因为我们再次遇到与DCS系统交互的问题:

maindb-1 patroni: ERROR: get_cluster 
maindb-1 patroni: Traceback (most recent call last):
                ... python trace 
maindb-1 patroni: RetryFailedError: 'Exceeded retry deadline' 
maindb-1 patroni: ERROR: Error communicating with DCS 
maindb-1 patroni: INFO: closed patroni connection to the postgresql cluster 
maindb-1 patroni: INFO: postmaster pid=214121 
... 
... 
maindb-1 patroni: INFO: demoted self because DCS is not accessible and i was a leader 
maindb-1 patroni: WARNING: Loop time exceeded, rescheduling immediately.

Patroni再次说,它无法与DCS进行交互,因此当前的主服务器不再是主服务器,并进入副本模式。旧的母版成为副本:

maindb-1 patroni: INFO: Lock owner: maindb-2; I am maindb-1 
maindb-1 patroni: INFO: does not have lock 
maindb-1 patroni: INFO: running pg_rewind from maindb-2 
maindb-1 patroni: INFO: running pg_rewind from user=postgres host=192.168.11.18 port=5432 ... 
maindb-1 patroni: servers diverged at WAL location 1FA/A38FF4F8 on timeline 6 
maindb-1 patroni: rewinding from last common checkpoint at 1FA/A38FF450 on timeline 6 
maindb-1 patroni: INFO: Lock owner: maindb-2; I am maindb-1 
maindb-1 patroni: INFO: running pg_rewind from maindb-2 in progress 
maindb-1 patroni: Done!

Patroni在这里按预期方式工作-启动pg_rewind以倒回事务日志,然后连接到新的主服务器并已经赶上新的主服务器。

feylover之前是什么?


让我们找到feylover之前的第一件事-导致它的错误。Patroni日志在这方面很方便:他以一定间隔写入相同的消息。您可以快速滚动它们,查看日志何时更改。此时,一些问题开始了。

在正常情况下,Patroni日志如下所示:

maindb-1 patroni: INFO: Lock owner: maindb-1; I am maindb-1
maindb-1 patroni: INFO: no action. i am the leader with the lock
maindb-1 patroni: INFO: Lock owner: maindb-1; I am maindb-1
maindb-1 patroni: INFO: no action. i am the leader with the lock

检查锁的所有者,如果更改了,可能会发生Patroni应该响应的事件。在这种情况下,一切都与我们息息相关。

滚动到错误开始出现的位置,我们看到一个自动过滤器发生了。由于错误与与DCS的交互有关,因此我们还查看了Consul日志-那里发生了什么。大致比较了faylover的时间和领事日志中的时间,我们发现领事集群中的邻居开始怀疑其他参与者的存在:

maindb-2 consul[11581]: serf: EventMemberFailed: maindb-1 192.168.11.19
maindb-2 consul[11581]: [INFO] serf: EventMemberFailed: maindb-1 192.168.11.19
maindb-2 consul[11581]: memberlist: Suspect maindb-1 has failed, no acks received
maindb-2 consul[11581]: [INFO] memberlist: Suspect maindb-1 has failed, no acks received

如果查看其他Consul代理的日志,它还表明存在网络崩溃:Consul群集的所有成员都相互怀疑。这就是failover的动力。

如果我们看一下更早的条目,我们将看到,PostgreSQL的代理领事系统具有沟通困难(deadline reachedRPC failed):

maindb-1 consul: memberlist: Suspect lbs-4 has failed, no acks received
maindb-1 consul: [ERR] yamux: keepalive failed: i/o deadline reached
maindb-1 consul: yamux: keepalive failed: i/o deadline reached
maindb-1 consul: [ERR] consul: "KVS.List" RPC failed to server 192.168.11.115:8300: rpc error making call: EOF
maindb-1 consul: [ERR] http: Request GET /v1/kv/service/sam_prod/?recurse=1, error: rpc error making call: EOF from=192.168.11.19
maindb-1 consul: [ERR] consul: "KVS.List" RPC failed to server 192.168.11.115:8300: rpc error making call: EOF
maindb-1 consul: [ERR] agent: Coordinate update error: rpc error making call: EOF
maindb-1 consul: [ERR] http: Request GET /v1/kv/service/sam_prod/?recurse=1, error: rpc error making call: EOF from=192.168.11.19


决断


最简单的答案是修复网络这很容易建议,但是情况可能会有所不同,而这并非总是可能的。该系统可以存在于数据中心,而我们不能影响设备。需要其他选择。

有些解决方案选项不与网络一起使用:

  • Consul-checks: [].
    , . , Consul- . .
  • raft_multiplier.
    Consul-, 5 ( staging-). Consul-. - .
  • renice -n -10 consul.
    . renice . Consul-, .
  • consul?
    Consul- . Patroni Consul- , : - , Patroni . etcd, , etcd . Patroni etcd-. - , , , Consul.
  • ttl, loop_wait, retry_timeout.
    , . Patroni .


问题3.节点丢失


如果使用的是Patroni,那么您将熟悉patronictl list命令,该命令显示集群的当前状态:

$ patronictl list

+-----------------+-------------------------+--------------+--------+---------+-----------+
|     Cluster     |          Member         |     Host     |  Role  |  State  | Lag in MB |
+-----------------+-------------------------+--------------+--------+---------+-----------+
| patroni_cluster | pg01.dev.zirconus.local | 10.202.1.101 |        | running |    0.0    |
| patroni_cluster | pg03.dev.zirconus.local | 10.202.1.103 | Leader | running |    0.0    |
+-----------------+-------------------------+--------------+--------+---------+-----------+


乍一看,这样的结论似乎很正常-有一个主副本,但没有复制滞后。但是,直到我们知道在该群集中应该有3个节点而不是2个节点之前,此图片才是正常的。

为什么会发生故障转移?


我们知道发生了一个自动文件管理器,此后一个副本消失了。我们需要找出她失踪的原因,并把她带回来。

我们再次研究日志以了解为何出现自动文件管理器:

pg02 patroni[1425]: ERROR: failed to update leader lock
pg02 patroni[1425]: INFO: demoted self because failed to update leader lock in DCS
pg02 patroni[1425]: WARNING: Loop time exceeded, rescheduling immediately.
pg02 patroni[1425]: INFO: Lock owner: None; I am pg02.dev.zirconus.local
pg02 patroni[1425]: INFO: not healthy enough for leader race
pg02 patroni[1425]: INFO: starting after demotion in progress

主pg02无法更新主密钥ERROR: failed to update leader lock

然后,db03的第二个副本成为主副本,这里的一切都井井有条:

pg03 patroni[9648]: INFO: promoted self to leader by acquiring session lock
pg03 patroni[9648]: server promoting
pg03 patroni[9648]: INFO: cleared rewind state after becoming the leader

那老主人呢?


决定成为副本的pg02首先回滚事务日志。在这里,我们需要查看不在群集中的副本日志。打开Patroni日志,发现在连接到集群的过程中,该阶段出现了问题pg_rewind

pg02 patroni[1425]: INFO: running pg_rewind from pg03
pg02 patroni[1425]: INFO: running pg_rewind from user=postgres host=10.202.1.103 port=5432 ...
pg02 patroni[1425]: servers diverged at WAL location 33F/68E6AD10 on timeline 28
pg02 patroni[1425]: could not open file "/data/pgdb/11/pg_wal/0000001C0000033F00000059": No such file or directory
pg02 patroni[1425]: could not find previous WAL record at 33F/59FFE368 pg02 patroni[1425]: Failure, exiting
pg02 patroni[1425]: ERROR: Failed to rewind from healty master: pg03
pg02 patroni[1425]: WARNING: Postgresql is not running.

要连接到群集,节点必须从向导请求事务日志并从中捕获向导。在这种情况下,没有事务日志(No such file or directory),并且副本无法启动。因此,PostgreSQL因错误而停止。您需要了解为什么没有事务日志。

让我们看看WAL的新主人:

LOG: checkpoint complete:
wrote 62928 buffers (16.0%); 0 WAL file(s) added, 0 removed, 23 recycled;
write=12.872 s, sync=0.020 s, total=13.001 s;
sync files=16, longest=0.009 s, average=0.001 s;
distance=520220 kB, estimate=520220 kB

事实证明,在运行时pg_rewind,出现了一个检查点,并且某些旧的事务日志已重命名当旧的主服务器尝试连接到新的主服务器并请求这些日志时,它们已经被重命名,它们根本不存在。

根据时间戳,这些事件之间的时间间隔实际上为150 ms。

2019-08-26 00:06:11,369 LOG: checkpoint complete
2019-08-26 00:06:11,517 INFO: running pg_rewind

但这足以使副本无法连接并无法赚钱。

决断


最初,我们使用复制插槽。尽管在操作的第一阶段我们关闭了插槽,但此解决方案对我们来说似乎不错。我们认为,如果插槽中会积聚许多沃尔玛分段,则主机可能会倒下。经历了一段时间没有插槽的痛苦之后,我们意识到我们需要它们并退回它们。

问题在于,当向导进入副本状态时,向导将删除插槽和wal段以及它们。为了解决这个问题,我们增加了参数wal_keep_segments。默认情况下,它等于8个细分,我们提高wal_keep_segments到1000个。我们在上分配了16 GB的空间wal_keep_segments,现在,在切换时,所有节点上始终有16 GB的事务日志。

对于长期维护任务也是如此。假设我们需要更新其中一个副本(软件,OS等),然后将其关闭。当我们关闭副本时,该插槽也会被删除。如果使用较小的参数值wal_keep_segments,则对于长时间不存在副本的情况,它将请求那些甚至可能不会出现在向导中的事务日志-则副本将无法连接。因此,我们保留了大量的杂志。

问题4.数据丢失


在生产基地进行了故障转移。我们检查了集群:一切都正常,所有副本都就位,没有复制滞后,日志中也没有错误。但是产品团队报告数据库中没有足够的数据 -它们在一个源中,但是不在数据库中。您需要了解发生了什么事。

我们立即意识到这是pg_rewind他们的麻烦,但是我们需要找出原因。

故障转移何时发生?


我们总是可以在日志中找到feylover发生的时间,谁成为了新的母版,谁是原先的母版以及何时他想成为副本的母版。

pgdb-1 patroni[17836]: INFO: promoted self to leader by acquiring session lock
pgdb-1 patroni[17836]: server promoting
pgdb-1 patroni[17836]: INFO: cleared rewind state after becoming the leader
pgdb-1 patroni[17836]: INFO: Lock owner: pgdb-1; I am pgdb-1

从日志中,我们可以确定丢失了多少事务日志。

就像这样:旧的向导重新启动,通过自动运行重新启动后,启动了Patroni,然后启动了PostgreSQL。PostgreSQL决定成为Patroni集群的成员,并启动了一个过程pg_rewind该过程又删除了部分事务日志,下载了新的日志并进行了连接。

Patroni的工作完全符合预期。群集恢复:在feylover 3个节点之后剩下3个节点。但是部分数据丢失了,您需要了解它是什么部分。

在旧主人的日志中查找发生的时刻pg_rewind

pgdb-2 patroni[4149]: INFO: running pg_rewind from pgdb-1
pgdb-2 patroni[4149]: Lock owner: pgdb-1; I am pgdb-2
pgdb-2 patroni[4149]: Deregister service pgdb/pgdb-2
pgdb-2 patroni[4149]: running pg_rewind from pgdb-1 in progress
pgdb-2 patroni[4149]: running pg_rewind from user=replica host=10.10.1.31 port=5432 ...
pgdb-2 patroni[4149]: servers diverged at WAL location 0/5AD1BFD8 on timeline 66
pgdb-2 patroni[4149]: rewinding from last common checkpoint at 0/59DD1070 on timeline 66
pgdb-2 patroni[4149]: Done!

您需要在事务日志中找到该位置,从而停止了旧的主数据库。

pgdb-2 patroni[4149]: INFO: Local timeline=66 lsn=0/5BDA8EB8
pgdb-2 patroni[4149]: INFO: master_timeline=67
...
pgdb-2 patroni[4149]: servers diverged at WAL location 0/5AD1BFD8 on timeline 66
postgres=# select pg_wal_lsn_diff('0/5BDA8EB8','0/5AD1BFD8');
pg_wal_lsn_diff
----------------
17354464

在这种情况下,它是标记0 / 5BDA8EB8。需要第二个标记-0 / 5AD1BFD8-来找到旧主机与新主机之间的距离。使用函数pg_wal_lsn_diff ,我们比较这两个标记,我们得到17 MB。

是否存在17 MB的数据大量丢失,每个人都可以自己决定。对于某些人来说,这是微不足道的,但是对于某些人来说,这是很多不可接受的。每个人自己根据业务需求确定。

决断


首先,您需要确定重启系统后是否始终需要Patroni自动启动。大多数情况下,我们应该去找旧的主机,看看它与当前状态有何不同,也许要检查事务日志的各个部分。您需要了解是否会丢失此数据,或者需要在独立模式下运行旧向导来提取数据。只有在此之后,才决定如何处理数据,然后将此节点作为副本连接到我们的集群。

另外,还有一个参数maximum_lag_on_failover,默认值为1 Mb。它的工作方式是:如果副本比复制滞后时间落后1 MB,则该副本不参与选举。如果突然发生故障转移,Patroni将查看哪些副本位于后面,而那些副本在大量事务日志之后不能成为主副本。这是一项很好的安全功能,可以防止丢失太多数据。

但是存在一个问题:复制滞后会以一定的时间间隔进行更新,ttl默认值为30 s。 DCS中副本的复制延迟值很可能是一个值,但实际上它完全不同,或者根本没有延迟。这不是实时值;它并不总是反映真实情况,也不值得将复杂的逻辑与其联系起来。

“损失”的风险始终存在:

  • 最坏的情况是:maximum_lag_on_failover + ttl
  • 在一般情况下:maximum_lag_on_failover + (loop_wait / 2)

当您计划实施Patroni并评估可能损失的数据量时,请考虑以下公式以大致表示可能的损失。

好消息是,“损失”中的后台流程可能会产生WAL。这些数据很容易被忽略和丢失,没有问题。

如果设置为set maximum_lag_on_failover则日志显示为以下内容,即发生feylover,您需要选择一个新向导:

pgdb-1 patroni[6202]: INFO: Lock owner: None; I am pgdb-1
pgdb-1 patroni[6202]: INFO: not healthy enough for leader race
pgdb-1 patroni[6202]: INFO: changing primary_conninfo and restarting in progress
...
pgdb-1 patroni[6202]: INFO: following a different leader because i am not the healthiest node
pgdb-1 patroni[6202]: INFO: following a different leader because i am not the healthiest node

仿制者只是看得出自己not healthy enough for leader race,而拒绝参加领导力竞赛。因此,它只是等待选择新的向导来连接它。这是防止数据丢失的另一种措施。

问题5:驱动器


产品团队写道,该应用程序在使用PostgreSQL时遇到问题。同时,您无法输入主服务器,因为它无法通过SSH使用,但也不会发生自动文件管理器。然后,主机被强制重新引导,从而启动了自动文件管理器。尽管可以进行手动转换。

重新启动后,我们去查看主机发生了什么。



我们事先了解了磁盘的问题;通过监视,我们知道了在哪里进行挖掘。

在PostgreSQL日志中,我们看到以下内容:

[COMMIT] LOG: duration: 1138.868 ms statement: COMMIT
...
[] WARNING: autovacuum worker started without a worker entry
...
[SELECT] LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp11247.983", size 532996096
...

表面上所有指示磁盘问题的迹象:提交持续一秒钟,autovacuum运行时间很长而且很奇怪,并且磁盘上有临时文件。

我们查看了系统dmesg-内核消息日志,发现其中一个磁盘有问题:

md/raid10:md2: sde3: rescheduling sector 351273392
blk_update_request: I/O error, dev sde, sector 64404728
md/raid10:md2: sde3: rescheduling sector 63161592
blk_update_request: I/O error, dev sde, sector 64404760
...
md2 : active raid10 sda3[0] sdc3[2] sdd3[3] sdb3[1] sdh3[7] sdf3[5] sdg3[6]
      15623340032 blocks super 1.2 512K chunks 2 near-copies [8/7] [UUUUUUU_]
      bitmap: 58/59 pages [232KB], 131072KB chunk

服务器上的磁盘子系统是一个包含8个磁盘的软件Raid,但缺少一个。该行sda3[0] sdc3[2] sdd3[3] sdb3[1] sdh3[7] sdf3[5] sdg3[6]不见了sde[4]相对而言,一个磁盘掉了下来,这导致了磁盘问题,并且应用程序在使用PostgreSQL集群时遇到了问题。

决断


在这种情况下,Patroni将无法提供帮助,因为Patroni没有任务来监视服务器和磁盘的状态。在出现问题期间,Patroni继续与DCS集群进行交互,并且没有遇到任何困难。在这种情况下,需要外部监视。

问题6:集群模拟器


这是最奇怪的问题之一。我研究了很长时间,重新阅读了很多日志,并将其称为“集群模拟器”。

问题是老主人不能成为正常的提示。Patroni运行它,表明该节点作为副本存在,但同时它不是普通副本,现在您将了解原因。

与前面的情况一样,这一切都始于磁盘问题:

14:48:55.601 [COMMIT] LOG: duration: 1478.118 ms statement: COMMIT
14:48:56.287 [COMMIT] LOG: duration: 1290.203 ms statement: COMMIT
14:48:56.287 [COMMIT] LOG: duration: 1778.465 ms statement: COMMIT
14:48:56.287 [COMMIT] LOG: duration: 1778.449 ms statement: COMMIT

连接断开:

14:48:58.078 [idle in transaction] LOG: could not send data to client: Broken pipe
14:48:58.078 [idle] LOG: could not send data to client: Broken pipe
14:48:58.078 [idle] FATAL: connection to client lost
14:48:58.107 [idle in transaction] FATAL: connection to client lost

长期以来人们对响应和阻止各种严重性的期望很高:

14:49:26.929 [UPDATE waiting] LOG: process 4298 acquired ExclusiveLock on tuple (2,10) of relation 52082 of database 50587 after 52487.463 ms
14:49:26.929 [UPDATE waiting] STATEMENT: UPDATE sessions SET lastaccess='1565005714' WHERE sessionid=...
14:49:27.929 [UPDATE waiting] LOG: process 4298 still waiting for ShareLock on transaction 364118337 after 1000.088 ms
14:49:27.929 [UPDATE waiting] DETAIL: Process holding the lock: 4294. Wait queue: 4298.

通常,磁盘存在明显的问题,包括临时文件。

但是对我来说最神秘的是-它飞进来了immediate shutdown request

14:49:34.102 MSK 5335 @ from [] LOG: received immediate shutdown request
14:49:34.689 [authentication] WARNING: terminating connection because of crash of another server process
14:49:34.689 [authentication] DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory

PostgreSQL具有三种关闭模式:

  • 当我们等待所有客户端自行断开连接时,非常优美。
  • 快速,当我们告诉客户断开连接时,因为我们将要关闭。
  • 立即,它不会告诉客户端必须断开连接,而只是将其关闭并向所有客户端发送RST消息(TCP信号表明连接已中断)。

PostgreSQL后台进程不相互发送立即关闭请求信号,而仅响应它们。这是紧急重启,发送者尚不清楚。如果是kill -9,那么我会在日志中看到它,但是它不存在。

进一步了解后,我发现Patroni在相当长的一段时间内未写入日志-54秒钟根本没有消息。在此期间,其中一个副本被“升级”,并出现了自动文件管理器:

pgsql03 patroni: 14:48:25,000 INFO: Lock owner: pgsql03; I am pgsql03 
pgsql03 patroni: 14:48:25,013 INFO: no action.  i am the leader with the lock 
pgsql03 patroni: 14:48:37,159 INFO: Lock owner: pgsql03; I am pgsql03 
pgsql03 patroni: 14:49:31,155 WARNING: Exception hened during processing of request from 10.1.0.12 
pgsql03 patroni: 14:49:31,297 WARNING: Exception hened during processing of request from 10.1.0.11 
pgsql03 patroni: 14:49:31,298 WARNING: Exception hened during processing of request from 10.1.0.11

帕特罗尼在这里再次运作得非常好,没有老主人,因此开始选举新主人。

pgsql01 patroni: 14:48:57,136 INFO: promoted self to leader by acquiring session lock
pgsql01 patroni: server promoting
pgsql01 patroni: 14:48:57,214 INFO: cleared rewind state after becoming the leader
pgsql01 patroni: 14:49:05,013 INFO: Lock owner: pgsql01; I am pgsql01
pgsql01 patroni: 14:49:05,023 INFO: updated leader lock during promote

pgsql01成为新的领导者,而第二个副本只是存在问题。她诚实地尝试重新配置:

pgsql02 patroni: 14:48:57,124 INFO: Could not take out TTL lock 
pgsql02 patroni: 14:48:57,137 INFO: following new leader after trying and failing to obtain lock 
pgsql02 patroni: 14:49:05,014 INFO: Lock owner: pgsql01; I am pgsql02 
pgsql02 patroni: 14:49:05,025 INFO: changing primary_conninfo and restarting in progress 
pgsql02 patroni: 14:49:15,011 INFO: Lock owner: pgsql01; I am pgsql02
pgsql02 patroni: 14:49:15,014 INFO: changing primary_conninfo and restarting in progress 
pgsql02 patroni: 14:49:25,011 INFO: Lock owner: pgsql01; I am pgsql02 
pgsql02 patroni: 14:49:25,014 INFO: changing primary_conninfo and restarting in progress 
pgsql02 patroni: 14:49:35,011 INFO: Lock owner: pgsql01; I am pgsql02 
pgsql02 patroni: 14:49:35,014 INFO: changing primary_conninfo and restarting in progress

她尝试更改recovery.conf,重新启动PostgreSQL,连接到新向导。每隔10秒就会有一条她正在尝试的消息,但不能发送。

同时,相同的立即关闭信号也传到了旧主机上。向导启动了紧急重启,恢复也停止了。副本无法连接到主数据库,因为它处于关闭模式。

14:49:34.293 [idle] LOG:  received replication command: IDENTIFY_SYSTEM 
WARNING:  terminating connection because of crash of another server process 
DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 
14:49:35.232 FATAL:  could not receive data from WAL stream: server closed the connection unexpectedly             
        This probably means the server terminated abnormally 
        before or while processing the request. 
14:49:35.232 LOG:  record with incorrect prev-link 142D46/315602C at 14CF/CF38C160 
14:49:35.305 FATAL: could not connect to the primary server: FATAL: the database system is shutting down 
14:49:40.241 FATAL: could not connect to the primary server: FATAL: the database system is shutting down

在某个时候,副本可以正常工作,但是复制没有开始。

14:50:14.024 [] LOG:  record with incorrect prev-link 142D46/315602C at 14CF/CF38C160 
14:50:14.028 [] LOG:  fetching timeline history file for timeline 72 from primary server 
14:50:14.104 [] FATAL:  could not start WAL streaming: ERROR:  requested starting point 14CF/CF000000 on timeline 71 is not in this server's history        
DETAIL:  This server's history forked from timeline 71 at 14CF/CEC32E40. 
14:50:14.104 [] LOG:  new timeline 72 forked off current database system timeline 71 before current recovery point 14CF/CF38C160

我有一个假设:在recovery.conf中是旧主服务器的地址。当新的母版已经出现时,第二个副本尝试连接到旧的母版。当Patroni在第二个副本上启动时,该节点已启动,但无法通过复制进行连接。形成了一个复制滞后,看起来像这样:

+-----------------+----------+--------------+--------+---------+-----------+
|     Cluster     |  Member  |     Host     |  Role  |  State  | Lag in MB |
+-----------------+----------+--------------+--------+---------+-----------+
| patroni_cluster |  pgsql01 | 10.2.200.151 | Leader | running |       0.0 |
| patroni_cluster |  pgsql02 | 10.2.200.152 |        | running |    9153.0 |
| patroni_cluster |  pgsql03 | 10.2.200.153 |        | running |       0.0 |
+-----------------+----------+--------------+--------+---------+-----------+

也就是说,所有三个节点都在适当的位置,但第二个节点在后面。由于事务日志不同,因此无法开始复制。向导提供的事务日志(在recovery.conf中指示)根本不适合当前节点。PostgreSQL每5秒报告一次错误

14:50:44.143 FATAL:  could not start WAL streaming: ERROR:  requested starting point 14CF/CF000000 on timeline 71 is not in this server's history        
         DETAIL:  This server's history forked from timeline 71 at 14CF/CEC32E40. 
14:50:44.143 LOG:  new timeline 72 forked off current database system timeline 71 before current recovery point 14CF/ CF38C160

在这里,我犯了一个错误,并且没有检验我的假设,即我们正在连接到错误的主服务器。我刚刚在副本上重新启动了Patroni。老实说,我已经结束了它,并认为我必须重做它,但是仍然决定尝试重新启动它。

15:14:13.511 LOG: consistent recovery state reached at 14CF/A3F657B0
15:14:13.511 LOG: database system is ready to accept read only connections

恢复开始,甚至数据库打开,它准备接受连接,复制开始:

15:14:17.072 LOG: record with incorrect prev-link 142D46/315602C at 14CF/CF38C160
15:14:17.077 LOG: started streaming WAL from primary at 14CF/CF000000 on timeline 72
15:14:17.536 LOG: invalid record length at 14CF/CF38C160: wanted 24, got 1

但是一分钟后,她因出错而摔倒了terminating walreceiver process due to administrator command-副本表示事务日志不适合她。

15:15:27.823 FATAL: terminating walreceiver process due to administrator command
15:15:27.895 LOG: invalid record length at 14CF/CF38C160: wanted 24, got 1
15:15:27.895 LOG: invalid record length at 14CF/CF38C160: wanted 24, got 1

而且我没有重启PostgreSQL,而是重启了Patroni,希望它能够神奇地启动数据库。复制再次开始,但是数据库在同一位置打开:

15:17:33.553 LOG: consistent recovery state reached at 14CF/A3F657B0
15:17:33.554 LOG: database system is ready to accept read only connections

事务日志中的标记是不同的,它们与上一次启动尝试中的标记不同-事务日志的位置更早:

15:17:37.299 LOG: invalid contrecord length 5913 at 14CF/CEFFF7B0
15:17:37.304 LOG: started streaming WAL from primary at 14CF/CE000000 on timeline 72

复制再次停止,并且错误消息有所不同,并且再次没有提供足够的信息:

15:18:12.208 FATAL: terminating walreceiver process due to administrator command
15:18:12.240 LOG: record with incorrect prev-link 60995000/589DF000 at 14CF/CEFFF7B0
15:18:12.240 LOG: record with incorrect prev-link 60995000/589DF000 at 14CF/CEFFF7B0

为了进行实验,请重新启动,然后在同一位置打开底座:

15:21:25.135 LOG: consistent recovery state reached at 14CF/A3F657B0
15:21:25.135 LOG: database system is ready to accept read only connections

然后,我想到了一个想法:如果我重新启动PostgreSQL,则在当前向导的这一点上,我将执行一个检查点,以将事务日志中的该点稍微向前移动,并从另一时刻开始恢复。

启动Patroni,在主服务器上建立了几个检查点,在副本服务器打开时在副本服务器上建立了几个重启点:

15:22:43.727 LOG: invalid record length at 14D1/BCF3610: wanted 24, got 0
15:22:43.731 LOG: started streaming WAL from primary at 14D1/B000000 on timeline 72

它可以正常工作-复制从另一个地方开始,不再中断。但是对我来说,这是我仍在绞尽脑汁的最神秘的问题之一。特别是那个奇怪的立即关闭请求。

由此我们可以得出结论:Patroni可以按计划进行工作并且没有错误,但这并不是绝对保证一切都井井有条。faylover之后,您应该始终仔细检查集群是否一切正常:副本数正确,没有复制滞后。

摘要


基于这些以及许多其他类似的问题,我制定了一些一般性建议,建议您在操作Patroni时要谨记。

  • 使用Patroni时,必须进行监视。您始终需要知道何时会出现自动文件,因为如果您不知道自己具有自动文件,就无法控制群集。
  •  在每次feylover之后,始终检查集群。您必须确保:副本始终是当前编号;没有复制延迟;与Patroni和DCS系统进行的流复制相关的日志中没有错误。

Patroni是一个非常好的工具,但是不管怎么说,这都不是灵丹妙药。自动化可以成功进行,但是同时,自动化对象可以处于半工作状态。无论如何,您需要了解PostgreSQL和复制的工作方式,Patroni如何管理PostgreSQL以及如何确保节点之间的交互。为了能够修复双手出现的问题,这是必需的。

诊断步骤


碰巧我们与不同的客户一起工作,大多数情况下他们没有ELK堆栈,您必须通过打开2个选项卡和6个控制台来整理日志:在每个节点的一个Patroni选项卡中,在另一个-Consul或PostgreSQL日志中。诊断所有这些都很困难。

我开发了以下方法。我总是看着发生故障转移的时间。对我来说,这是一个分水岭。我看一下在feylover之前,期间和之后发生的事情。故障转移有两个时间戳-开始和结束。在日志中,我查看了feylover之前的内容,也就是说,我正在寻找原因。这样就可以了解发生了什么以及将来可以做什么,因此在相同情况下不会发生过渡。

为此,我看:

  • 首先,Patroni日志。
  • PostgreSQL DCS , Patroni.
  • — , .


自动文件管理器还有许多其他产品:stolon,repmgr,pg_auto_failover,PAF。我尝试了所有4种工具,我认为Patroni是当今市场上最好的工具。

我推荐帕特罗尼吗?当然,是的,因为我喜欢Patroni,所以我认为我学会了烹饪方法。

如果您有兴趣查看Patroni的其他问题,除了文章中描述的问题,您可以随时访问页面https://github.com/zalando/patroni/issues。有很多不同的故事。尽管其中有一半是来自盲人用户,他们询问愚蠢的问题却不打扰简单的搜索,但在那里仍然讨论了有趣的问题,并且通过讨论,在必要时打开了修复错误的任务。

感谢Zalando开发此项目,并感谢开始研究此产品的两个人:Alexander Kukushkin和Alexey Klyukin。非常感谢所有Patroni贡献者。

这份报告之后,我们记录了一次简短的采访,其中Alex试图将他的报告适合一个理事会,并告诉了为什么参加会议并在会议上发言。武装起来,检查一下Saint HighLoad ++的方法。


HighLoad++ 6-7 . , . , ( , ). - , , , .

Saint HighLoad++! , , PostgreSQL: , PostgreSQL JSON ; PostgreSQL 13, ; .

All Articles