祥积宫 无限进步

【DB2 数据库】08 模拟故障排查系列:事务日志打满(LOG FULL)实验

一、这篇文章要解决什么问题

前面的几篇实验,我已经把“表空间”和“容器”这一条线讲得比较完整了:

  • 表空间打满
  • ADD / EXTEND / AUTORESIZE
  • 容器权限异常
  • 容器路径异常

但在真实值班里,比“容器异常”更常见的一类故障,其实是:

事务日志打满

这类问题的典型现象通常是:

  • SQL 突然失败
  • 但磁盘不一定满
  • 表空间也不一定满
  • 最后发现真正被打满的是 DB2 日志

所以这篇文章要解决的核心问题是:

  • 什么情况下会出现 LOG FULL
  • 怎么通过实验把它稳定复现出来
  • 业务层会报什么错
  • 怎么判断根因确实是事务日志被占满
  • 恢复动作到底应该怎么做

二、实验环境

  • 操作系统:SUSE Linux Enterprise Server 12 SP5
  • DB2 版本:DB2 v9.7.0.6 Fix Pack 6
  • 实例:db2inst1
  • 数据库:TESTDB
  • 日志实验表:TLOG2
  • 实验表空间:USERSPACE1

这次实验专门没有继续把测试表放在前面的小表空间 TS4 上。

原因是我在实验中已经实际踩到一个很典型的问题:

如果测试表放在太小的表空间里,表空间本身会先满,实验就会偏成“表空间打满”,而不是“日志打满”。

所以最后把日志实验对象单独放到了:

USERSPACE1

这样可以尽量避免先被小表空间容量干扰。

三、实验前先打快照

因为这次要主动制造数据库故障,所以开始前建议先打一个快照:

12-准备做事务日志打满实验

这类实验的风险点主要在于:

  • 会持续制造大量未提交事务
  • 会让数据库返回错误码
  • 如果恢复步骤做乱了,快照能快速回到干净状态

四、先看 TESTDB 当前日志配置

正式开始前,我先确认了 TESTDB 当前日志相关参数。

执行后得到的关键配置如下:

Log buffer size (4KB)                        (LOGBUFSZ) = 256
Log file size (4KB)                         (LOGFILSIZ) = 1024
Number of primary log files                (LOGPRIMARY) = 13
Number of secondary log files               (LOGSECOND) = 4
Changed path to log files                  (NEWLOGPATH) =
Mirror log path                         (MIRRORLOGPATH) =
Block log on disk full                (BLK_LOG_DSK_FUL) = NO
Num. of active log files for 1 active UOW(NUM_LOG_SPAN) = 0
First log archive method                 (LOGARCHMETH1) = OFF
Second log archive method                (LOGARCHMETH2) = OFF

从这里可以看出几个非常关键的点:

1. 这是循环日志环境

因为:

  • LOGARCHMETH1 = OFF
  • LOGARCHMETH2 = OFF

所以这次实验更适合验证的是:

一个长事务长期不提交,导致可复用日志被占住,最后把日志打满。

2. 当前日志总量不算大

粗略估算一下:

  • LOGFILSIZ = 1024
  • 每页 4KB
  • 每个日志文件约 4MB

再结合:

  • LOGPRIMARY = 13
  • LOGSECOND = 4

所以整体日志量级大约就是六十多 MB,做实验非常合适。

五、实验前的日志基线

在真正制造故障前,我先看了数据库当前日志空间使用情况。

当时日志基线是:

Log space available to the database (Bytes)= 68066683
Log space used by the database (Bytes)     = 2888325

这说明实验开始前:

  • 已用日志不多
  • 可用日志空间还很充足

db2pd -db TESTDB -logs 还能看到:

Current Log Number            0
Pages Written                 86
Current LSN                   0x000000000637E4C2

以及当前日志文件主要还是最前面的这一批:

  • S0000000.LOG
  • S0000001.LOG
  • ...
  • S0000012.LOG

也就是说,这时候数据库整体日志状态很干净,非常适合开始做 LOG FULL 实验。

六、为什么日志实验表最终放到了 USERSPACE1

这次实验里,我一开始其实尝试过把日志实验表放在之前的小表空间上。

结果很快撞上了:

SQL0289N  Unable to allocate new pages in table space "TS4".  SQLSTATE=57011

这一步很值得记下来,因为它说明:

如果实验对象所在表空间太小,真正先出问题的不是日志,而是表空间本身。

所以后来我把日志实验表重新建成:

create table TLOG2(id int not null, c1 varchar(3000)) in USERSPACE1

再查询确认:

DB2INST1  TLOG2  USERSPACE1

这样实验方向就被拉正了:

后面如果再出故障,更大概率就是日志满,而不是小表空间先满。

七、这次故障是怎么构造的

这次实验没有去改日志参数,而是用了最贴近生产、也最经典的一种方式:

构造一个很大的、长期不提交的事务。

1. 先进入非自动提交模式

执行:

db2 +c

这个动作的意义是:

  • 关闭自动提交
  • 后面成功执行的 insert 不会自动 commit
  • 这样日志就会持续被当前这笔事务占住

2. 先插入一条未提交数据做基线验证

db2 => 提示符下执行:

insert into TLOG2 values (1, repeat('L',3000))
select count(*) from TLOG2

返回结果:

1
-----------
          1

这说明:

  • 数据已经写进当前事务
  • 但还没有提交
  • 长事务环境已经搭好了

八、通过分批大插入,持续吃日志

为了让日志稳定上涨,我没有一次性塞到极限,而是分批插入,每批 5000 行大字段数据。

使用的核心语句形式是:

insert into TLOG2
select 100000 + row_number() over(order by c1.colname, c2.colname),
       repeat('B',3000)
from syscat.columns c1, syscat.columns c2
fetch first 5000 rows only

后面又继续换不同 ID 区间重复执行,例如:

insert into TLOG2
select 200000 + row_number() over(order by c1.colname, c2.colname),
       repeat('C',3000)
from syscat.columns c1, syscat.columns c2
fetch first 5000 rows only

这样做有两个好处:

  • 一次插入的数据足够大,能明显消耗日志
  • 不同批次 ID 不冲突,便于观察和控制

在第二轮之后,当前未提交事务里已经能看到:

select count(*) from TLOG2

1
-----------
      10001

也就是说:

  • 当前事务里已经有 10001 条数据
  • 但这些数据都还没有提交

九、日志是怎么一步步被吃掉的

在另一个会话里,我同步观察日志空间。

1. 第一轮之后

日志状态很快变成:

Log space available to the database (Bytes)= 52087339
Log space used by the database (Bytes)     = 18867669

和实验前相比,说明:

  • 已用日志明显上涨
  • 可用日志明显下降

同时 db2pd -db TESTDB -logs 显示:

Current Log Number            4
Pages Written                 468
Current LSN                   0x00000000074FCD89

这说明当前事务已经开始占用多个日志文件。

2. 第二轮之后

继续插入未提交数据后,再看日志:

Log space available to the database (Bytes)= 36163635
Log space used by the database (Bytes)     = 34791373

这时候已经进入很危险的区域了:

  • 已用日志大约三十多 MB
  • 可用日志也只剩三十多 MB

说明实验方向完全正确,只要继续压事务,日志就会越来越接近上限。

十、一个很有价值的细节:为什么日志空间不是立刻变化

这次实验过程中,我还观察到一个非常有意思的现象:

有时候 insert 语句已经开始跑了,但 log space used 并不是立刻明显上涨。

这个现象其实很正常。

原因可以简单理解成两层:

1. SQL 前半段可能先在“算结果”

像这次使用的语句里包含:

  • select
  • row_number() over(order by ...)
  • 排序

所以 DB2 在真正把数据大量写入目标表之前,前面可能会先经历:

  • 读系统目录表
  • 生成结果集
  • 排序
  • 计算行号

也就是说:

语句前半段更多在准备数据,后半段才是真正大量写入和消耗日志。

2. 日志统计本身也不是逐行实时展示

db2 get snapshot for database 看到的是某一个时间点的统计值,并不是“每写一行就立即刷新给你看”。

所以很多时候会表现成:

  • 前面看起来没怎么变
  • 过一会儿突然跳一截

这不是 DB2 没记日志,而是:

真正的大量日志消耗发生在语句执行的后半段,而且统计展示也是按快照时点看的。

这个现象很值得记下来,因为它能帮你避免误判:

不是日志没涨,而是你看的那个瞬间,它还没进入大量写日志阶段。

十一、最终是怎么把日志真正打满的

在继续执行下一轮插入时,终于出现了这次实验的目标错误:

SQL0964C  The transaction log for the database is full.  SQLSTATE=57011

这就是非常标准的:

LOG FULL

同时,再看数据库日志空间快照:

Log space available to the database (Bytes)= 715187
Log space used by the database (Bytes)     = 70239821

这组数字几乎已经把问题写在脸上了:

  • 可用日志只剩不到 1MB
  • 已用日志已经到 70MB+

这一步就能非常明确地下结论:

打满的不是表空间,而是事务日志。

十二、这次故障为什么会发生

这次实验的根因其实非常典型:

  • 数据量很大
  • 事务一直不提交
  • 这些事务写过的日志无法及时释放和复用
  • 最终把数据库可用日志空间占满

所以这类故障的关键不是“单条 SQL 很大”,而是:

大事务 + 长时间不提交

这也是生产里最常见的 LOG FULL 根因之一。

十三、恢复动作其实很简单

既然根因是一笔长期不提交的大事务把日志占住了,那么最直接的恢复动作就是:

结束这笔事务。

在这次实验里,我执行的是:

rollback
terminate

这里的意义非常直接:

  • rollback:回滚当前未提交的大事务
  • terminate:结束当前 CLP 会话

这一步本质上就是:

把那笔一直占着日志不放的大事务彻底撤销掉。

十四、回滚后日志是怎么恢复的

回滚之后,再看日志空间,数值已经明显恢复:

Log space available to the database (Bytes)= 67543941
Log space used by the database (Bytes)     = 3411067

这和实验前的基线已经很接近了,说明:

  • 被占住的日志空间已经释放回来了
  • 数据库重新回到正常可用状态

十五、回滚后,数据也没有留下来

这一步同样非常关键。

因为这次实验里,所有大批量插入都一直没有 commit,所以在 rollback 之后,再查:

db2 "select count(*) from TLOG2"

1
-----------
          0

  1 record(s) selected.

这说明:

  • 那整批为了实验插进去的数据并没有留下来
  • 回滚彻底撤销了这笔长事务

也就是说,这次恢复是很干净的:

  • 日志释放了
  • 事务撤销了
  • 表数据也没残留

十六、这次实验到底证明了什么

到这里,这次 LOG FULL 实验已经验证了下面几个非常关键的结论:

1. 日志打满,不一定是磁盘满

很多人第一反应会以为:

是不是磁盘空间不够了

但这次实验里,真正的问题是:

数据库内部可用事务日志被长事务占满了

2. 日志打满,不一定是表空间满

前面我就专门踩到了这个坑:

  • 如果测试表放在太小的表空间里
  • 先报的就可能是 SQL0289N

所以区分“表空间满”和“日志满”非常重要。

3. 复现 LOG FULL 最经典的方法,就是长事务不提交

这比盲目去改日志参数更有教学意义,也更贴近真实生产故障。

4. SQL0964C 是非常典型的日志满错误码

这次实验里,真正命中的核心报错就是:

SQL0964C  The transaction log for the database is full.  SQLSTATE=57011

以后只要在生产里看到这个错误码,就要立刻往:

  • 长事务
  • 未提交事务
  • 日志空间不足

这几个方向去想。

5. 恢复的关键动作,不一定是“扩日志”,而可能只是“结束长事务”

这次实验里,真正有效的恢复动作不是去改配置,而是:

rollback

这说明排障时,真正重要的是先看清:

到底是谁占住了日志。

十七、实验结束后的收尾

这次实验做完后,最简单的收尾动作是:

db2 "drop table TLOG2"
db2 terminate

如果你还想后面继续做日志类实验,也可以先保留 TLOG2,不着急删。

十八、把这篇文章压缩成三句话

最后把这次实验压缩成三句话:

  1. LOG FULL 最典型的根因之一,是大事务长期不提交。
  2. 复现这类故障时,要避免被小表空间先打满,实验对象最好放到更合适的表空间里。
  3. 恢复的关键动作,往往不是先改配置,而是先结束占住日志的事务。

十九、下一篇最自然写什么

如果继续沿着 DB2 运维故障排查这条线往下写,下一篇最自然的方向有两个:

  • NUM_LOG_SPAN / 长事务约束实验
  • 实例未启动 / 异常退出实验

如果更偏值班实战,我会更推荐下一篇写:

【DB2 数据库】09 模拟故障排查系列:DB2 实例未启动与启动失败排查实验

因为做到这里,表空间、容器、日志这三类高频故障已经基本都有代表实验了,下一步很适合转到另一类更基础也更高频的故障:

实例起不来

Linux