一次达梦数据库凌晨宕机排查实录：从 SIGILL 一路挖到磁盘 IO 超时

记录一次达梦 DM8 生产库凌晨宕机的完整排查过程。整个排查从操作系统日志开始，经过 core dump 栈回溯、SQL 缓冲区提取、sar 性能数据核验，最终定位到磁盘 IO 超时。供同行参考。

注：本文数据已做脱敏处理，主机名、IP、业务表名等均为示例。

---

〇、故障概况

项目	内容
数据库	达梦 DM8，单机实例
故障时间	03:18:59
恢复时间	当日 09:00（人工重启）
历史故障	4 天前的 03:04:43 发生过完全相同的故障
业务影响	实例终止，业务中断约 5.7 小时

故障特征（三个疑点，是后续排查的起点）：

1. 数据库日志里没有任何正常的 shutdown 记录，戛然而止
2. 操作系统内核报的是 SIGILL（非法指令），而不是常见的 OOM 或被动 kill
3. 两次故障的崩溃指令地址完全相同（ip:768b9c）——说明不是随机故障

---

一、排查思路总览

┌─────────────────────────────────────────────────────────────┐
│ 第 1 步  看 OS 日志      →  进程"怎么死的"                    │
│          /var/log/messages ：发现 SIGILL，排除 OOM/磁盘/kill   │
├─────────────────────────────────────────────────────────────┤
│ 第 2 步  看 core 栈回溯  →  "死在哪一行代码"       ★关键转折   │
│          gdb bt full ：dm_sys_halt ← io_timeout_check        │
├─────────────────────────────────────────────────────────────┤
│ 第 3 步  挖 core 里的 SQL →  崩溃时数据库在干什么              │
│          提取 SQL 缓冲区 ：发现备份 JOB + 统计信息触发器       │
├─────────────────────────────────────────────────────────────┤
│ 第 4 步  看性能数据       →  "IO 到底有没有问题"      ★铁证    │
│          sar -d/-b/-q ：util 100%、await 497ms、IO 阻塞       │
├─────────────────────────────────────────────────────────────┤
│ 第 5 步  查 JOB 清单      →  "谁在制造这些 IO"                 │
│          SYSJOBS ：备份 02:00 + 统计信息 03:00 连续施压        │
└─────────────────────────────────────────────────────────────┘
                              ↓
                      根因：磁盘 IO 长期饱和

核心心法：先判断死因层次，再逐层向下挖。

• 进程死了 → 看 OS 日志
• 有 core → 看栈回溯（这一步最容易翻盘）
• 栈干净 → 看资源指标
• 有定时任务 → 对齐时间窗

---

二、第 1 步：看操作系统日志，先判断"怎么死的"

命令

grep -nE "dmserver|DmService|oom|killed|segfault|traps" /var/log/messages
grep -nE "Sep 15 0[0-9]:" /var/log/messages | grep -vE "audit|sysstat"

关键输出

Sep 15 03:18:59 dm01 kernel: traps: dm_tskwrk_thd[1391717] trap invalid opcode
                              ip:768b9c sp:7ff31a0e2920 error:0 in dmserver[737000+1ef1000]
Sep 15 03:18:59 dm01 audit:  ANOM_ABEND ... comm="dm_tskwrk_thd"
                              exe="/home/dmdba/dmdbms/bin/dmserver" sig=4 res=1
Sep 15 03:20:01 dm01 pcp-pmie: High 1-minute load average 1206load@dm01

这一层得到的结论

检查项	结论	依据
内存不足	❌ 排除	全程无 Out of memory / oom-killer
磁盘故障	❌ 排除（应用层未见）	无 I/O error、无文件系统报错
被人 kill	❌ 排除	无 kill 记录
异常退出方式	✅ SIGILL	sig=4 = 非法指令

同时记录了三个"疑点"：

• 崩溃线程名 dm_tskwrk_thd（达梦的任务线程，由 TASK_THREADS 参数控制，负责服务端任务调度执行）
• 崩溃后系统负载飙到 1206（64 核机器）
• 查历史日志发现 4 天前同一 ip (768b9c) 崩过一次

💡 经验：SIGILL 在数据库场景里很反常。它有两种完全不同的来源——要么是二进制/CPU 指令集问题，要么是程序自己主动触发的 trap。光看 OS 日志分辨不了，必须看 core 栈。

---

三、第 2 步：用 gdb 看 core，判断"死在哪"（关键转折）

命令

gdb /home/dmdba/dmdbms/bin/dmserver core.xxx

(gdb) bt full
(gdb) info registers
(gdb) x/i $pc

关键输出

[Current thread is 1 (LWP 1391717)]

(gdb) bt full
#0  0x0000000000768b9c in dm_sys_halt_low_inner ()       ← 达梦「系统停机」函数
#1  0x000000001d0bc39 in ntsk_io_timeout_check ()        ← IO 超时检查
#2  0x000000001dd6a09 in ntsk_process ()
#3  0x000000001dd712c in ntsk_process_thrd ()
#4  0x000000001c6a438 in tpool_thrd_pc_worker_thread_start ()
#5  0x000000001c6bb38 in tpool_worker_thread ()          ← 线程池工作线程
#6  0x00007ff3a77bef1b in ?? () from /usr/lib64/libpthread.so.0
#7  0x00007ff3a73e51a0 in clone () from /usr/lib64/libc.so.6

(gdb) info registers
rip    0x768b9c   0x768b9c <dm_sys_halt_low_inner+332>
eflags 0x10246    [ PF ZF IF RF ]

(gdb) x/i $pc
=> 0x768b9c <dm_sys_halt_low_inner+332>:    ud2

💥 这一层直接把结论翻了过来

ud2 是 x86 的「未定义指令」，编译器专门用它来实现 __builtin_trap()——也就是"故意触发一个非法指令异常"。

所以：

这不是"崩溃"，是达梦主动执行的保护性停机（dm_sys halt）。

那个 SIGILL 是达梦自己要求的。

从下往上读调用链，语义非常清晰：

线程池工作线程
   └─ 任务处理（ntsk_process）
        └─ IO 超时检查（ntsk_io_timeout_check）
             └─ 系统停机（dm_sys_halt_low_inner）
                  └─ ud2  → SIGILL

与官方文档互相印证

达梦官方 FAQ 中记载的停机日志形态：

[FATAL] check page io timeout overtime 3 times of io TIMEOUT. please check the disk
[FATAL] code=-1. dm_sys halt now!!

原话解释是：

"磁盘故障导致写 redo 一直写不进去，等待了 IO_TIMEOUT 3 次以后还是失败，直接 halt。"

至此，所有疑点全部解释通了 🎯

之前的疑点	真相
为什么是 SIGILL	ud2 是停机代码主动触发的 trap
为什么两次 ip 完全相同	停机代码路径固定，不是随机内存错误
为什么没有优雅 shutdown 日志	压根不是正常关闭
为什么负载飙到 1206	IO 阻塞导致大量进程堆积在 D 状态

💡 经验：core dump 的价值就在这一步。"崩溃"和"主动停机"是完全不同的两件事，前者要查代码 bug，后者要查资源。如果没有回头看栈，很容易在南辕北辙的方向上浪费时间。

---

四、第 3 步：从 core 里挖 SQL，看崩溃时数据库在干什么

达梦的 core 里可以提取出各线程的 SQL 缓冲区。提取出来的内容形如：

!#%&*^$@[1391710]:CREATE OR REPLACE TRIGGER "SYSJOB"."JOB增量备份"
AFTER TIMER ON DATABASE FOR EACH 1 WEEK 1, 2, 3, 4, 5, 6
AT TIME '02:00:00' FROM DATETIME '2024-01-18 16:44:57'
...
   BAKUPSTR = 'BACKUP DATABASE INCREMENT WITH BACKUPDIR ''/dbdata/dmbak''
               BACKUPSET ''/dbdata/dmbak/DB_..._<时间戳>''
               COMPRESSED LEVEL 4  PARALLEL 8 ';

两个关键发现

① 线程编号分布暴露了崩溃线程的身份

线程 TID 区间	数量	说明
< 140 万	仅 2 个	1391710、1391720 —— dmserver 启动时创建的系统 JOB 线程
≥ 191 万	1541 个	业务连接线程

而崩溃线程 TID = 1391717，正好夹在 1391710 和 1391720 之间，属于系统 JOB 线程组。并且它没有任何 SQL 记录——说明崩溃时它不在执行用户 SQL，而是在跑 JOB 内部逻辑。

② 挖出了 JOB 定义

-- ① 增量备份作业（每周一至周六 02:00）
CREATE OR REPLACE TRIGGER "SYSJOB"."JOB增量备份"
AFTER TIMER ON DATABASE FOR EACH 1 WEEK 1, 2, 3, 4, 5, 6
AT TIME '02:00:00'
...  BACKUP DATABASE INCREMENT
     WITH BACKUPDIR '/dbdata/dmbak'
     COMPRESSED LEVEL 4  PARALLEL 8

-- ② 系统自动统计信息触发器（每天 03:00）
CREATE OR REPLACE TRIGGER SYS.SYSTRG$_AUTO_STAT
AFTER TIMER ON DATABASE FOR EACH 1 DAY
FROM TIME '3:00' FOR EACH 1439 MINUTE
FROM DATETIME '2023/9/20'  MAX_RUN_DURATION 10800
BEGIN  SP_STALE_STAT_REGATHER();  END;

💡 经验：很多人以为 SYSJOBS.SYSJOBS 就是全部作业。其实 SYSTRG$_AUTO_STAT 这类系统触发器在 SYS 模式下，不在这个视图里，平时根本看不到。查作业时两个地方都要看。

---

五、第 4 步：用 sar 验证"IO 到底有没有问题"（铁证）

命令

sar -d -f /var/log/sa/sa15 -s 02:00:00 -e 04:00:00   # 磁盘 IO
sar -b -f /var/log/sa/sa15 -s 02:00:00 -e 04:00:00   # IO 吞吐
sar -q -f /var/log/sa/sa15 -s 02:00:00 -e 04:00:00   # 负载与队列

关键输出：磁盘已经彻底饱和

02时00分01秒  dev8-32  174.58  106996  3407  ... 
02时50分01秒  dev8-32   96.04   83151  2257  ...

03时00分01秒  dev8-32  168.37  190182  2038  ...
03时10分02秒  dev8-32  165.01   95055   593  0.00  579.66  81.97  497.23  100.02
03时20分04秒  dev8-32  230.49  102496 28135  0.00  566.76  83.83  364.19  100.02
03时30分02秒  dev8-32  266.52       0 168722  0.00  633.07  37.70  141.96   31.02
03时40分01秒  dev8-32    0.00       0     0   ...

整理成表格：

时间区间	tps	读 MB/s	写 MB/s	await(ms)	aqu-sz	%util
02:00-02:50	74~232	46~178	2~6	—	—	—
03:00-03:10	165	95	0.6	497	82	100.02
03:10-03:20	230	102	28	364	84	100.02
03:20-03:30	266	0.02	168	142	38	31

await 364~497 毫秒——健康磁盘这个值应该是个位数毫秒（<10ms）。这块盘已经慢了整整两个数量级。

而 崩溃时刻 03:18:59，正好落在 03:10-03:20 这个 100% 饱和区间里。

关键输出：负载的真相

03时10分02秒   runq-sz=1   plist-sz=2680   ldavg-1=1205.74   blocked=2
03时20分04秒   runq-sz=0   plist-sz=831    ldavg-1=1.06

runq-sz 只有 1，但负载高达 1205.74！

这说明那 1200 多个"负载"不是在跑 CPU，而是全部卡在等磁盘（D 状态不可中断睡眠）。这是教科书级的 IO 阻塞型高负载，跟 CPU 一点关系都没有。

另一个细节：崩溃前线程数 plist-sz=2680，崩溃后骤降到 831——一下子消失 1849 个线程，与 core 里 dump 出的 1543 个线程记录完全吻合。

💡 经验：看到 load average 高，先别急着说"CPU 不够"。一定要对照 runq-sz——如果 runq 很小而负载很大，那就是 IO 阻塞，加 CPU 没用。

---

六、第 5 步：查 JOB 清单，确认"谁在制造这些 IO"

命令

SELECT * FROM SYSJOB.SYSJOBS;

输出

ID	NAME	ENABLE	USERNAME	CREATETIME
1729338414	全备	1	SYSDBA	2024-10-19 19:46:53
1729338417	删除备份	1	SYSDBA	2024-10-19 19:48:38
1729338416	增量备份	1	SYSDBA	2024-10-19 19:48:02

注意：这里并没有"统计信息收集"这个作业——因为它是 SYS 模式下的系统触发器 SYSTRG$_AUTO_STAT，不在这个视图里。

（顺带印证：core 里的 SF_JOB_EXECING_SET(1729338416, ...) 正好等于"增量备份"的 ID，两边完美互证。）

IO 来源时间链闭合

02:00 ─────────────── 增量备份启动（读数据 + 写备份集）
                       sar -b: bread/s 持续 46~178 MB/s
02:50 ─────────────── 备份收尾
03:00 ─────────────── SYSTRG$_AUTO_STAT 触发，统计信息全表扫描
                       sar -d: 读 95~102 MB/s 持续 20 分钟
                       ← 磁盘 100% 饱和，await 冲到 497ms
03:18:59 ──────────── 达梦某次 IO 等待超时 → dm_sys halt → SIGILL
03:20-03:30 ───────── 纯写 168 MB/s、读≈0（崩溃后写 core dump 的特征）

从 02:00 到 03:20，整整 80 分钟，磁盘一直处于 100% 饱和。

---

七、根因结论

因果链

磁盘 IO 长期饱和（await 364~497ms，util 100%）
        ↓
达梦的 IO 超时检查（ntsk_io_timeout_check）连续 3 次超时
        ↓
调用 dm_sys_halt_low_inner() 主动停机保护
        ↓
执行 ud2 陷阱指令 → 内核 SIGILL（sig=4）
        ↓
实例终止，业务中断

责任划分

角色	责任
磁盘设备	🔴 根本原因：await 400~500ms、100% 饱和，性能严重不足
02:00 增量备份	🟠 主要加压因素：开启并维持了 80 分钟的 IO 高压
03:00 统计信息收集	🟠 最后一根稻草：接续备份继续全库扫描
达梦数据库	⚪ 无责：按 IO_TIMEOUT 机制保护性停机，行为正确
架构	🔴 备份目录与数据文件、redo 同在 /dbdata（同一块盘），备份读写直接与数据库抢盘

一句话总结

磁盘扛不住凌晨的 IO 叠加，达梦检测到 IO 超时后按设计主动停机保护。备份是重要参与者，但真凶是"单盘承载全部 IO"这个架构。

八、处置方案（按性价比排序）

① 隔离 IO —— 最快见效 ⭐

lsblk; df -h          # 确认挂载关系

本次案例中发现同机器上另一块盘全时段 IO 为 0（完全空闲），把备份目录 /dbdata/dmbak 挪过去即可立刻隔离压力。

② 错开时间窗

增量备份 02:00  →  统计信息收集 03:00

两者至少间隔 2 小时。如果统计信息收集确认不需要，可以直接关掉：

-- 查看监控开关（默认 0 = 不监控，此时统计任务本身是空转）
SELECT * FROM V$DM_INI WHERE PARA_NAME='AUTO_STAT_OBJ';

-- 关闭触发器：0=失效（可随时恢复），2=彻底删除
SP_CREATE_AUTO_STAT_TRIGGER(0,0,0,0,'','',0,0);

③ 降低备份强度

COMPRESSED LEVEL 4  →  1~2     （4 级压缩非常吃 CPU）
PARALLEL 8          →  2~4     （并行度太高会拉起大量线程）

④ 临时止血：放大 IO_TIMEOUT

SELECT * FROM V$DM_INI WHERE PARA_NAME='IO_TIMEOUT';
SP_SET_PARA_VALUE(1, 'IO_TIMEOUT', 300);   -- 动态参数，无需重启

这只是拖延战术，为排查争取时间，不能替代根治。

⑤ 评估磁盘本身

smartctl -a /dev/sdc | grep -E "Reallocated|Pending|Uncorrectable|Wear"
iostat -x 1 30        # 业务高峰现场观察

await 400~500ms 且 util 100%，要么是单块机械盘到了物理极限，要么是阵列/SSD 出了问题。这是长期必须解决的事。

⑥ 补齐另外两个 JOB 的调度时间

案例中还有"全备"“删除备份"两个作业，需要确认它们是否也叠在凌晨，避免"三连击”。

---

九、经验总结

🔑 三条最重要

1. SIGILL ≠ 一定是崩溃，先看 core 栈

程序中 ud2 是"主动 trap"的惯用手法。是"崩溃"还是"主动停机"，决定了后续完全不同的排查方向。 前者查代码 bug，后者查资源。

2. 看到 load average 高，一定要对照 runq-sz

现象	判断
runq-sz 高 + 负载高	CPU 不够
runq-sz 低 + 负载高	IO 阻塞（大量进程卡在 D 状态）

3. 磁盘指标看 await 和 %util，不要只看吞吐量

await 是个位数毫秒才算健康。这次 497ms，是一个明确到不能再明确的红灯。

🔧 排查清单（可复用）

# ── 1. OS 层：怎么死的 ──────────────────────
grep -nE "dmserver|DmService|oom|killed|segfault|traps" /var/log/messages

# ── 2. core 层：死在哪 ─────────────────────
gdb <dmserver路径> core.xxx
(gdb) bt full
(gdb) info registers
(gdb) x/i $pc

# ── 3. 资源层：有没有瓶颈 ───────────────────
sar -d -f /var/log/sa/sa15 -s HH:MM:00 -e HH:MM:00
sar -b -f /var/log/sa/sa15 -s HH:MM:00 -e HH:MM:00
sar -q -f /var/log/sa/sa15 -s HH:MM:00 -e HH:MM:00
iostat -x 1 30

# ── 4. 存储健康 ────────────────────────────
smartctl -a /dev/sdX | grep -E "Reallocated|Pending|Uncorrectable|Wear"
dmesg -T | grep -iE "error|fail|timeout|reset"

# ── 5. 硬件/链路（共享存储）─────────────────
multipath -ll

-- ── 6. 数据库层：作业与参数 ────────────────
SELECT * FROM SYSJOB.SYSJOBS;
SELECT ID, NAME, START_TIME, END_TIME, ERRCODE, ERRINFO
  FROM SYSJOB.SYSJOBHISTORIES2 ORDER BY START_TIME DESC LIMIT 20;

-- 系统触发器（不在 SYSJOBS 视图里，容易漏）
SELECT * FROM SYSTEXTS WHERE ID=(SELECT ID FROM SYSOBJECTS
       WHERE NAME='SYSTRG$_AUTO_STAT' AND SUBTYPE$='TRIG');

SELECT * FROM V$DM_INI WHERE PARA_NAME IN
       ('AUTO_STAT_OBJ','IO_TIMEOUT','TASK_THREADS','WORKER_THREADS');

⚠️ 两个容易踩的坑

坑 1：只看 SYSJOB.SYSJOBS 会漏掉系统触发器

SYSTRG$_AUTO_STAT（自动统计信息收集）在 SYS 模式下，不在作业视图里。它由 SP_CREATE_AUTO_STAT_TRIGGER() 创建，常见于建库脚本或前任 DBA 的配置，很容易变成"谁都没配，但它一直在跑"的幽灵任务。

坑 2：备份"跑完了"不等于"影响结束了"

备份虽然在 02:17 就结束了，但它把磁盘 IO 压力延续传递给了 03:00 的后续任务。排查时要把时间窗放宽，看的是"整体 IO 曲线"，而不是单个任务的生命周期。

---

十、参考

• 达梦官方 FAQ - 故障处理：dm_sys halt now!! 与 IO_TIMEOUT
• 达梦社区案例：DSC 集群因共享存储 IO 超时导致实例终止（处置方式同为"调整备份窗口，避开高负载时段"）

---

本文记录的是生产环境真实故障，数据已脱敏。欢迎交流指正。