KingbaseES 数据库WAL日志暴增问题处理

故障现象：

kingbase数据库容量不足100G，业务繁忙程度小，但是每天产生112283个WAL日志，每个日志16M，生成约1.7T的归档日志

分析过程：

思路一：从数据库日志入手，分析过程如下：

sys_log日志：

2024-06-02 23:54:05.497 CST            31303        61b580b0.7a47    18224        2021-12-12 12:55:12 CST        0    LOG    0    checkpoints are occurring too frequently (4 seconds apart)
2024-06-02 23:54:09.025 CST            31303        61b580b0.7a47    18225        2021-12-12 12:55:12 CST        0    LOG    0    checkpoints are occurring too frequently (4 seconds apart)
2024-06-02 23:54:12.763 CST            31303        61b580b0.7a47    18226        2021-12-12 12:55:12 CST        0    LOG    0    checkpoints are occurring too frequently (3 seconds apart)
2024-06-02 23:54:16.491 CST            31303        61b580b0.7a47    18227        2021-12-12 12:55:12 CST        0    LOG    0    checkpoints are occurring too frequently (4 seconds apart)

数据库出现大量的checkpoints are occurring too frequently，怀疑是checkpoint太频繁，加上数据库开启了full page write。如果业务频繁，更改的页面较多，这有可能就是生产wal日志太多的原因。建议调整影响checkpoint动作的参数，减少checkpoint频率，从而达到减少wal日志生产量的效果。

参考参数说明：

  • checkpoint_timeout： 定义：该参数用于指定自上次checkpoint之后经过的时间（以秒为单位）。当超过指定的时间间隔后，系统会执行checkpoint操作。 注意事项：该参数控制的是自动检查点的执行间隔，但检查点还有其他触发机制，如WAL日志数量累积到一定数量时也会触发。设置较大的间隔可能会增加恢复时间，而较小的间隔则可能增加I/O负载。

  • checkpoint_completion_target： 定义：该参数用于指定在执行checkpoint时，系统需要将脏数据刷新到磁盘的百分比目标。 注意事项：如果设置为较低的值，可能会增加checkpoint的频率，但减少了每次checkpoint的I/O负载。如果设置为较高的值，可能会减少checkpoint的频率，但增加了每次checkpoint的I/O负载。这个参数的选择需要根据系统的磁盘性能和负载情况进行权衡。

  • checkpoint_flush_after： 定义：当checkpoint执行时，如果已经刷新了超过该参数指定大小的数据，数据库会尝试强制执行一次OS的文件写（fsync）。 注意事项：这个参数有助于控制checkpoint过程中I/O的均匀分布，避免一次性写入大量数据导致系统负载过高。

  • max_wal_size： 定义：该参数用于指定WAL（Write-Ahead Logging）日志文件的最大大小。当WAL文件大小达到此值时，将触发一个checkpoint，即使checkpoint_timeout还未到期。 注意事项：这个参数与checkpoint_timeout，共同影响checkpoint的频率。如果WAL文件增长迅速，可能需要调整此参数以控制checkpoint的频率。

处理结果：

根据业务调整完成上述参数，发现WAL日志依旧没有减少。

思路二：从WAL日志入手，分析过程如下：

sys_waldump工具分析WAL日志：

每个产生的wal日志内容大部分全是以下内容

rmgr: Heap        len (rec/tot):      8/    54, tx:  147532344, lsn: 7BA/BBF6EF10, prev 7BA/BBF6EED8, desc: LOCK off 44: xid 147532344: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99119/101982 blk 460
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532342, lsn: 7BA/BBF6EF48, prev 7BA/BBF6EF10, desc: LOCK off 13: xid 147532342: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99118/100829 blk 492
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532339, lsn: 7BA/BBF6EF80, prev 7BA/BBF6EF48, desc: LOCK off 44: xid 147532339: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99115/100252 blk 450
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532345, lsn: 7BA/BBF6EFB8, prev 7BA/BBF6EF80, desc: LOCK off 37: xid 147532345: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99116/468640 blk 508
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532341, lsn: 7BA/BBF6EFF0, prev 7BA/BBF6EFB8, desc: LOCK off 57: xid 147532341: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99120/106598 blk 454
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532343, lsn: 7BA/BBF6F028, prev 7BA/BBF6EFF0, desc: LOCK off 5: xid 147532343: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99117/102556 blk 467
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532344, lsn: 7BA/BBF6F060, prev 7BA/BBF6F028, desc: LOCK off 45: xid 147532344: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99119/101982 blk 460
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532342, lsn: 7BA/BBF6F098, prev 7BA/BBF6F060, desc: LOCK off 14: xid 147532342: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99118/100829 blk 492
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532339, lsn: 7BA/BBF6F0D0, prev 7BA/BBF6F098, desc: LOCK off 45: xid 147532339: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99115/100252 blk 450
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532345, lsn: 7BA/BBF6F108, prev 7BA/BBF6F0D0, desc: LOCK off 38: xid 147532345: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99116/468640 blk 508
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532343, lsn: 7BA/BBF6F140, prev 7BA/BBF6F108, desc: LOCK off 6: xid 147532343: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99117/102556 blk 467
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532344, lsn: 7BA/BBF6F178, prev 7BA/BBF6F140, desc: LOCK off 46: xid 147532344: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99119/101982 blk 460
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532342, lsn: 7BA/BBF6F1B0, prev 7BA/BBF6F178, desc: LOCK off 15: xid 147532342: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99118/100829 blk 492
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532339, lsn: 7BA/BBF6F1E8, prev 7BA/BBF6F1B0, desc: LOCK off 46: xid 147532339: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99115/100252 blk 450
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532345, lsn: 7BA/BBF6F220, prev 7BA/BBF6F1E8, desc: LOCK off 39: xid 147532345: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99116/468640 blk 508
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532343, lsn: 7BA/BBF6F258, prev 7BA/BBF6F220, desc: LOCK off 7: xid 147532343: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99117/102556 blk 467
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532344, lsn: 7BA/BBF6F290, prev 7BA/BBF6F258, desc: LOCK off 47: xid 147532344: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99119/101982 blk 460
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532342, lsn: 7BA/BBF6F2C8, prev 7BA/BBF6F290, desc: LOCK off 16: xid 147532342: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99118/100829 blk 492
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532339, lsn: 7BA/BBF6F300, prev 7BA/BBF6F2C8, desc: LOCK off 47: xid 147532339: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99115/100252 blk 450
rmgr: Heap        len (rec/tot):      8/    54, tx:  147532345, lsn: 7BA/BBF6F338, prev 7BA/BBF6F300, desc: LOCK off 40: xid 147532345: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/99116/468640 blk 508

xlog分析如下：

rmgr: Heap
rmgr代表Resource Manager，即资源管理器。在这里，它是“Heap”，意味着这是一个与堆表相关的操作。

len (rec/tot): 8/54
len代表日志记录的长度。rec是实际日志记录的长度（这里是8字节），而tot可能是与这条记录相关的总长度（这里是54字节）。

tx: 147532345
这是与这条WAL记录关联的事务ID。

lsn: 7BA/BBF6F108
lsn（Log Sequence Number）是WAL记录的位置。这允许数据库知道在复制或恢复时应该从哪里开始或停止。

prev 7BA/BBF6F0D0
这是前一条WAL记录的位置。它有助于确保在恢复或复制时按照正确的顺序应用记录。

desc: LOCK off 38: xid 147532345: flags 0 LOCK_ONLY EXCL_LOCK KEYS_UPDATED
这部分提供了关于操作的详细描述。
LOCK off 38: 这可能表示锁定的偏移量或其他与锁定相关的信息。
xid 147532345: 这是与锁相关的事务ID，与前面提到的tx相同。
flags 0: 这可能是一个标志字段，用于指示锁的各种属性或行为。在这里，它的值是0，可能表示没有特殊的标志被设置。
LOCK_ONLY: 这可能表示这个WAL记录仅与锁定相关，不涉及数据的实际修改。
EXCL_LOCK: 表示这是一个排他锁（exclusive lock），意味着其他事务在持有此锁的事务释放锁之前不能访问被锁定的资源。
KEYS_UPDATED: 这可能表示与锁相关的某些键（可能是索引或其他数据结构中的键）已被更新。

blkref #0: rel 1663/99116/468640 blk 508
这部分提供了关于涉及的表和块的详细信息。
rel 1663/99116/468640: 这是被锁定的关系的OID（Object ID）。在数据库中，关系可以是一个表、视图、索引等。这里的OID由三个部分组成：数据库OID（通常是固定的1663，代表系统数据库）、模式OID（在这里是99116）和对象OID（在这里是468640）。
blk 508: 这是被锁定的块号。在堆表中，数据通常被存储在多个块中，每个块都有自己的块号。

总的来说，这条WAL记录描述了一个与特定堆表上的排他锁相关的操作。这个锁可能是在更新某些键或执行其他与锁定相关的操作时设置的。

常见排他锁的场景：

  1. 1.INSERT、UPDATE、DELETE时，它会首先获取这些数据的排他锁，以确保在事务完成之前，没有其他事务可以对这些数据进行写操作或加上其他类型的锁。

  2. SELECT语句中使用FOR UPDATE来显式地获取排他锁，例如SELECT * FROM table_name FOR UPDATE;

问题确认：

由于数据库开启了全日志，可以查看到具体SQL，通过查看0:02--10:37 数据库有 3000多个for update语句，满足条件2

复现场景：

通过for update语句去查询t1表

imagepng

查看生产的相关wal日志信息，与问题wal日志信息一致，问题确认。

imagepng

问题结论

业务在0:02--10:37时间段内，执行了 3000多个for update语句，导致了wal日志猛增。

根本原因

数据库在执行for update的时候，会把所有筛选出来的行都添加一个排他锁，有多少行就会添加多少个排他锁，每个排他锁会在wal日志中记录一条记录，如果select的结果集很大，就会造成wal条数增大，从而增加WAL的生成量。

解决方式及建议

  1. 首先建议业务调整，尽量不适用for update语句，通过对目标数据进行串行dml，或者调整使用for update语句的频率；

  2. 其次建议对for update的结果进行最小化控制，因为wal日志生成量与for update的结果集有关系。

posted @ 2024-07-26 11:06  KINGBASE研究院  阅读(186)  评论(0)  编辑  收藏  举报