关键字:
RWC、sys_waldump、问题分析、金仓数据库
一、概述
KES RWC 提供了视图和系统函数方便用户观测集群状态,但遇到集群故障时,仅能借此进行定性分析,定量分析依赖于更多的信息。本文通过模拟主备复制过程的延迟故障,介绍的二进制工具sys_waldump如何协助用户分析故障发生的原因。
二、二进制工具sys_waldump
sys_waldump该工具以人类可读的形式显式了WAL的信息,需要注意的是该工具只能由安装该服务器的用户运行,因为要求对数据目录的只读访问。此处我们通过一个示例展示工作的使用方式,有关工具的详细参数,可以阅读KES的产品手册。
三、使用sys_waldump分析延迟原因
我们首先构造一个备机与主机同步出现延迟的测试用例。
- 主机创建一张数据表并写入数据
- 备机开启显式事务查询此数据表,但事务不提交
- 主机删除数据表
- 查看主备同步状态。
执行完步骤1-3后,通过视图sys_stat_replication查看集群同步状态如下:
test=# select * from sys_stat_replication; pid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | backend_xmin | state | sent_lsn | write_lsn | flush_lsn | replay_lsn | write_lag | flush_l ag | replay_lag | sync_priority | sync_state | reply_time -------+----------+---------+------------------+-------------+-----------------+-------------+-------------------------------+--------------+-----------+-----------+-----------+-----------+------------+-----------------+----------- ------+-----------------+---------------+------------+------------------------------- 14116 | 10 | system | internal_backup | 127.0.0.1 | | 9132 | 2024-08-15 18:07:24.471971+08 | | streaming | 0/70A94E8 | 0/70A94E8 | 0/70A94E8 | 0/70A8FD0 | 00:00:00.000187 | 00:00:00.0 18688 | 00:00:02.021809 | 0 | async | 2024-08-15 18:18:43.582958+08 (1 row) |
观察sent_lsn和replay_lsn列发现二者对应的WAL位置不同,且replay_lag发现有一定延迟。但write_lsn和flush_lsn与sent_lsn一致。这说明备机已经接收到主机同步的日志,但是在回放过程遇到了阻塞。
我们进一步观察二者相差的字节数,发现相差不多,此时若想进一步了解备机的同步位置,需要采集更多信息。
test=# select * from sys_wal_lsn_diff('0/70A94E8', '0/70A8FD0'); sys_wal_lsn_diff ------------------ 1304 (1 row) |
首先解析备机wal日志,执行指令分别观察主机和备机的wal日志。
./sys_waldump data/sys_wal/000000010000000000000007 |
执行日志后发现主备二者的日志信息相同,这进一步验证了上文的想法:日志同步没问题,问题出现在了日志回放上。因此我们进一步分析日志信息,在测试过程中我们获取了表的oid信息,通过检索oid定位我们关心的日志位置,然后通过lsn进一步分析。
可以看到,主机日志位置对应的信息是:
rmgr: Standby len (rec/tot): 42/ 42, tx: 0, lsn: 0/070A94E8, prev 0/070A9310, desc: RUNNING_XACTS nextXid 1122 latestCompletedXid 12898351 oldestRunningXid 1122 |
而备机仅回放到了该条日志:
rmgr: Standby len (rec/tot): 42/ 42, tx: 1121, lsn: 0/070A8FD0, prev 0/070A8FA8, desc: LOCK xid 1121 db 14651 rel 16441 rmgr: Heap len (rec/tot): 54/ 54, tx: 1121, lsn: 0/070A9000, prev 0/070A8FD0, desc: DELETE off 47 flags 0x00 KEYS_UPDATED , blkref #0: rel 1663/14651/1247 blk 13 |
这说明了可能是主机的日志信息造成了备机回放过程的阻塞,通过分析主备同步机制可知,主机发送的Standby信息的确会影响备机回放过程,由此,问题定位完成。
通过KES提供的sys_waldump工具,我们可以方便快速的分析复制过程中遇到的问题,提高了问题的响应速度,优化了用户体验。