当前位置: 代码网 > it编程>数据库>Mysql > MySQL备份失败告警的排查与解决方法

MySQL备份失败告警的排查与解决方法

2026年09月16日 Mysql 我要评论
一次生产告警的完整排查记录。起因只是一条内容含糊的「mysql 备份失败」告警,最终却挖出了数据库被内核反复杀死 6 次、监控零告警、以及长达 14 小时的「零备份」状态。前置说明:数据脱敏与时间约定

一次生产告警的完整排查记录。起因只是一条内容含糊的「mysql 备份失败」告警,最终却挖出了数据库被内核反复杀死 6 次、监控零告警、以及长达 14 小时的「零备份」状态。

前置说明:数据脱敏与时间约定

本文所有可识别信息均已脱敏,仅保留无标识性的技术细节。

脱敏策略

类别处理方式
日期一律用 t 日 表示(相对时间轴)
时刻一律用相对时间表示(t+0t+36st+8h
星期保留(对分析必要),但去掉具体日期
ip / 主机名 / 域名替换为示例值 / 占位符
数据库账号、库名、表名替换为占位符
产品版本号泛化为大版本(8.0.x
lsn、表空间 id、进程 pid用占位符替代
容量、磁盘大小、数据量取约数
内存数值与配置参数值原样保留(技术核心,且无标识性)

时间约定

  • t 日 = 故障发生当天(某个周五)
  • t+0 = 备份任务启动时刻
  • 该主机上的时钟不稳定(见 §3.1 与 §12.7),因此本文一律使用相对时间轴,不引用绝对时刻

一、告警

企业微信告警群里收到这样一条消息:

【报警中】服务器 <db-host>
====================
告警规则:mysql全库备份
告警级别:warning
主机名称:<db-host>
告警详情:mysql备份失败
告警状态:firing
触发时间:t 日(定时检查时刻)
发送时间:t 日(同上)

典型的「一句话告警」——只有结论,没有原因

大多数人看到这种告警的第一反应是:登服务器,看看备份脚本是不是报错了、磁盘是不是满了、备份目录权限对不对。

这次的经验是:这个反应方向,从一开始就错了。

二、第一轮:先别急着登服务器

2.1 先分清这是「原因性告警」还是「结果性告警」

告警触发时刻是一个精确到秒的整点,这是重要线索。先去看监控规则本身,发现计划任务里有两类任务:

# 备份任务:每周固定一天,凌晨执行一次
<备份调度>   /path/to/mysql_backup.sh

# 检查任务:同一天,上午和下午各检查一次
<检查调度>   /path/to/mysql_backup_monitor.sh

故障当天正好是执行备份的那个周五

结论:备份任务在凌晨执行,这条告警只是「约 8 小时后的一次事后检查」。

告警时间 = 检查时间,而不是故障时间。 这一条认知直接决定接下来该查哪段日志。

2.2 判断影响面

只有这一台机器告警,同批次其他实例正常。

结论:大概率是单机局部问题,不需要在集群范围排查。

2.3 第一轮系统体检(全部只读)

# 基础环境
date; hostname; uptime; free -m
# 磁盘与 inode(最高频元凶)
df -ht
df -i
# mysql 是否健在
systemctl status mysqld --no-pager
ps -ef | grep -ei "mysqld|mysqldump|xtrabackup" | grep -v grep
ss -lntp | grep 3306
# oom 迹象
dmesg -t | grep -i -e "oom|killed process" | tail -10
# 计划任务与脚本定位
crontab -l
grep -ril -e "mysqldump|xtrabackup" /etc/cron* /root /opt /scripts 2>/dev/null

2.4 第一轮就出现了反常信号

 load average: 7.5, 7.4, 7.2
              total   used   free  shared buff/cache  available
mem:           7980   7320    133      15        526        385
swap:          2047    660   1387
指标数值判断
物理内存7980 mb(约 8 gb)
可用内存385 mb🔴 危险
swap 已用660 mb🟠
连续运行时长约 8 个月未重启
磁盘/ 使用 23%、数据盘 32%、inode 1%排除磁盘因素

磁盘完全健康,但内存只剩 385 mb。 问题方向立刻转向内存。

三、关键转折:告警时间 ≠ 故障时间

3.1 一个差点被忽略的坑:dmesg -t时间不可信

查 oom 记录时发现一件事:同一个事件,三个来源给出了两个时间。

来源显示时间
dmesg -t时刻 a
/var/log/messages时刻 b
systemctl status(journal)时刻 b + 2 秒

判定方法:比对两处日志的 mem-info 明细。

来源显示时间active_anoninactive_anonslab_reclaimablefree
dmesg -t时刻 a15847883124341664425697
/var/log/messages时刻 b15847883124341664425697

数字完全一致 → 这是同一个事件,只是时间戳不同。

最终以 /var/log/messages 和 journal 为准,理由有三:

  1. 两者互相印证,都指向时刻 b
  2. 时刻 b 正好是备份任务启动后的 36 秒
  3. mysqld 新进程的启动时间正是同一个整点

dmesg -t 为什么不准?

dmesg -t 的时间 = 内核记录的启动时刻(btime)+ 开机以来的单调时间。如果系统时钟在启动之后被 ntp 校正过,btime 不会同步更新,于是所有 dmesg -t 的时间都会整体偏移

这台机器上偏移了约 29 分钟,而且这个偏移在更早的一次 oom 上同样存在,偏移量恒定

经验:在时钟不稳定的机器上,涉及时间取证的场景一律以 journalctl / /var/log/messages 为准,不要用 dmesg -t

3.2 修正后的时间线

t+0s        备份脚本启动
t+0s        ★ 脚本第一件事:删除上一周的备份目录
t+16s       清理完成
t+18s       xtrabackup 启动
t+20s       executing lock instance for backup ...
t+20s → t+34s    14 秒空档(初始化本地 innodb、创建 logfile)
t+36s       ★ mysqld 被内核 oom killer 杀死
t+38s       xtrabackup 报错:104 / 2013 连接中断
t+38s       备份脚本判定失败
t+8h        监控脚本检查发现失败,推送告警

备份任务不是故障原因,它是「正好撞上故障」的那个动作。

四、证据链:mysqld 被 oom killer 杀死

4.1 内核留下的原始证据

内核 oom 现场会打印所有进程的内存快照,其中 mysqld 那一行:

[ <pid> ]  <uid>  <pid>  total_vm   rss    nr_ptes  swapents  oom_score_adj  name
[ <pid> ]   <uid>  <pid>   <...>   1832259   5008     416460         0        mysqld
                                    ↑rss(页)          ↑swapents(页)
指标页数换算
rss(驻留物理内存)1,832,2596.99 gb
swapents(已换出到 swap)416,4601.59 gb
合计真实内存需求8.58 gb
物理内存总量2,097,0167.98 gb

mysqld 想要 8.58 gb,机器只有 7.98 gb。

同时:

free swap  = 0kb            ← 2 gb swap 一个字节都不剩
inactive_anon:312434        ← 1.19 gb 想换出去但没地方放

swap 满 → 内核无法回收匿名页 → 只能启动 oom killer。

4.2 一个容易算错的账:rss ≠ 真实内存需求

排查内存问题时,ps 看到的 rss 只是物理内存部分,被换出到 swap 的部分不在里面。

真实内存需求 = rss + vmswap
# 正确的取值方法
pid=$(cat /path/to/mysql.pid)
grep -e "vmrss|vmswap" /proc/$pid/status

本次:

  • oom 时:6.99 gb + 1.59 gb = 8.58 gb
  • 排查时:6.72 gb + 0.29 gb = 7.01 gb

只看 rss 会低估 20% 以上的实际需求。

4.3 顺带发现:这台机器长期在疯狂换页

swap cache stats: add ~1.6e8, delete ~1.6e8

1.6 亿页 × 4 kb ≈ 600+ gb 累计换页量,开机约 8 个月 → 平均每天换页 2 gb 以上

这不是偶发峰值,而是长期状态。

五、更严重的发现:数据库已经被打挂 6 次

排查过程中翻历史日志,看到了这样一串记录——在过去约三周内,mysqld 被内核杀死过 6 次

5.1 逐条核对时段

#时段星期是否备份时段
1凌晨周五✅ 备份启动后约 50 秒
2上午周三
3凌晨周一
4夜间周三
5上午周一
6凌晨周五✅ 备份启动后 36 秒

5.2 一个必须诚实修正的判断

排查早期,看到「有几次 oom 都落在凌晨同一时刻」,很容易得出**「是备份把数据库打挂的」**这个结论。

但逐条核对星期后发现:6 次里只有 2 次发生在备份时段,另外 4 次(周一、周三、白天、夜间)与备份毫无关系。

另外,oom 现场进程表里 xtrabackup 自身的 rss 只有 约 120 mb——xtrabackup 是文件级复制,不经过 buffer pool,它自己不占内存。

修正后的准确表述:

mysqld 长期处于内存临界状态,任意一个额外动作都可能把它推过阈值。每周备份是其中一类触发因素,而不是唯一原因。

这个修正很重要——它决定了后续的投入方向:要解决的是「内存不够」,而不是「备份脚本有 bug」。

5.3 最严重的监控盲区

数据库被内核杀死 6 次,监控系统一条告警都没有。

唯一的间接信号是「备份失败」——而且延迟约 8 小时。如果这 6 次里有任何一次发生在白天业务高峰,影响面会完全不同。

六、处置一:给数据库加 oom 护栏

6.1 原理

linux oom killer 选择受害者时,会给每个进程算一个 badness 分数:

分数 ≈ 该进程占用内存的比例 × 1000  +  oom_score_adj

分数最高者被杀。mysqld 独占整机约 90% 内存,天然最高——内核日志里它的分数是 877,全场第一。

6.2 操作

# 保护当前 mysqld 进程
pid=$(cat /path/to/mysql.pid)
echo -500 > /proc/$pid/oom_score_adj

# 保护 mysqld_safe(守护壳),让未来自动重启的 mysqld 继承
echo -500 > /proc/<mysqld_safe_pid>/oom_score_adj

为什么要设 mysqld_safe

oom_score_adj 是进程属性,fork 出的子进程会继承父进程的值

mysqld_safe (设为 -500)
   └── mysqld 崩溃 → mysqld_safe 自动重新拉起新的 mysqld
        └── 新 mysqld 自动继承 -500 ✅

6.3 为什么是-500而不是-1000

-1000 表示「内核绝对不许杀它」。听起来更安全,但在这台机器上反而危险

mysqld         约 7 gb   ← 唯一的"大块头"
其余所有进程   约 0.2 gb ← 全是几十 mb 的小角色

如果 mysqld 变成「杀不得」,内核会发现杀了别人也救不回内存,可能引发连锁杀进程,甚至杀掉 sshd 让人失去登录能力。

-500 留了余地:既让 mysqld 排到后面,又不至于让内核「无路可走」。

6.4 更完整的方案:替罪羊机制

护栏的价值在于改变最坏结果的形态

没有护栏有护栏
内存爆掉时mysqld 被杀 → 数据库宕机、业务中断、备份失败得不明不白备份进程被杀 → 备份失败告警,数据库活着

配合备份脚本里的这一行(子进程继承):

echo 500 > /proc/$$/oom_score_adj     # 备份进程主动当替罪羊

完整分工:

mysqld    : -500   → 尽量别杀我
备份进程  : +500   → 我是可以牺牲的

本次事故恰好是反过来的:数据库被杀,备份反而「失败得不明不白」。

6.5 一个必须知道的限制

/proc/<pid>/oom_score_adj 只存在于内核内存里,不落盘。

情况是否失效
mysqld 被 oom 杀掉后自动重启❌(除非父进程 mysqld_safe 也设了,可继承)
执行 service mysql restart❌ 失效
机器重启❌ 失效

要持久化,需要靠:systemd drop-in(oomscoreadjust)、patch init.d 脚本、或者每分钟 cron 自愈脚本兜底。

⚠️ 如果 crontab 是配置管理工具(ansible 等)下发的,手工 crontab -e 加的条目会被下次同步覆盖——要走配置管理流程,或写到独立的 /etc/cron.d/ 文件里。

七、处置二:buffer pool 4g → 3g

7.1 先算清楚 buffer pool 到底占了多少

select @@innodb_buffer_pool_size/1024/1024 as bufpool_mb;
show global status where variable_name in
 ('innodb_buffer_pool_pages_data','innodb_buffer_pool_pages_free','innodb_buffer_pool_pages_total');
bufpool_mb     = 4096
pages_total    = 262144     × 16 kb = 4096 mb
pages_data     = 261744     × 16 kb = 4090 mb
pages_free     =    175     × 16 kb =  2.7 mb

占用率 = 261744 ÷ 262144 = 99.93%

三个结论:

#含义
池子已被彻底填满 → 调小它一定能把内存还给系统(不会出现「池子本来没填满、调了也省不出」的情况)
⚠️工作集已超过 4 gb(池子 100% 占用仍有持续物理读)→ 调小后物理读会增加,性能会降
🔴反向印证异常:池子只要 4 gb,mysqld 却占了 6.7 gb

7.2 执行在线调整

set global innodb_buffer_pool_size = 3221225472;   -- 3 gb

参数说明:

  • 3221225472 = 3 × 1024³,即 3 gb
  • 调整粒度 = innodb_buffer_pool_chunk_size × innodb_buffer_pool_instances = 128m × 8 = 1 gb,所以必须是整数 gb
  • 从 mysql 5.7.5 起支持在线伸缩,不需要重启、不中断业务

验证:

select @@innodb_buffer_pool_size/1024/1024 as bufpool_mb;
show status like 'innodb_buffer_pool_resize_status';

缩容过程中状态会显示进度:

buffer pool 7 : withdrawing blocks. (8177/8192)

这句的含义:8 个 buffer pool instance 逐个回收,7 是最后一个(编号 0~7),8177/8192 是完成度——看到这个说明已经跑到 99.8% 了。

8192 页 × 16 kb = 128 mb,正是待回收的 1024 mb chunk 分摊到单个 instance 的分量。

等它变成 completed resizing buffer pool at ... 才算完。

7.3 实测效果

指标改前改后变化
memavailable304 mb1353 mb+1049 mb
used7406 mb6357 mb−1049 mb
mysqld vmrss6.72 gb5.72 gb−1.00 gb
swap used745 mb745 mb无变化(没产生新交换)

预测 vs 实际:

预测归还:65,136 页 × 16 kb = 1,017 mb
实际归还:1,053,856 kb       = 1,029 mb

误差 12 mb。 说明「buffer pool 100% 占用」这个判断是准确的。

7.4 持久化(千万别漏)

cp -a /etc/my.cnf /etc/my.cnf.bak.$(date +%y%m%d_%h%m%s)
sed -i 's/^innodb-buffer-pool-size[[:space:]]*=.*/innodb-buffer-pool-size = 3g/' /etc/my.cnf
# 确认只改了一行
diff $(ls -t /etc/my.cnf.bak.* | head -1) /etc/my.cnf
# ★ 确认 mysql 能正确解析(防止文件写坏导致下次起不来)
/usr/local/mysql/bin/my_print_defaults mysqld | grep -i "buffer-pool-size"

最后一条必须输出 --innodb-buffer-pool-size=3g

set global 只改运行时,不持久化。 不写 my.cnf,下次重启就全回退了。

7.5 代价:性能确实会降

对比调整前后的 vmstat

指标4g 池3g 池变化
磁盘读 bi1.6~2.5 mb/s11~14 mb/s↑ 约 6 倍
cpu 空闲 id45%~72%10%~26%↓ 大幅下降
i/o 等待 wa0%~6%8%~17%

原因:工作集超过 4 gb,池子只剩 3 gb → 缓存命中率下降 → 反复读磁盘。

这是「用性能换安全」。 但它同时说明:真正的解是扩内存,而不是把池子调回 4g(调回去就又回到 oom 边缘)。

八、处置三:发现「零备份」状态

8.1 一个反直觉的发现

准备重跑备份前,先看了一眼备份产物目录:

/data/backup/data/<当天日期>/
├── my.cnf              14,298 b   ← 是脚本拷过来的配置文件
└── xtrabackup_logfile  12.7 mb    ← 只有日志文件

没有 .ibd、没有 ibdata1、没有 xtrabackup_checkpoints。这是一份完全不可用的残骸。

翻备份脚本的日志,第一行就写明了原因:

[<时间>]  removing expired backup data: /data/backup/data/<上周日期>

8.2 问题出在清理策略

备份脚本的清理逻辑:

for target in $(find "${base_path}/data" -maxdepth 1 -mindepth 1 -type d -mtime +5); do
    rsync -a --delete "$empty_dir/" "$target/"
    rmdir "$target"
done
  • 备份周期:每周一次
  • 清理阈值:-mtime +5(6 天以上)

上周的备份此时已经 7 天 → 每次运行都会先把上一份删掉,再建新的。

🔴 结论:只要本次备份失败,就一份备份都不剩。

本次故障中,脚本启动第一件事就删掉了上一周的备份,然后自己失败了 → 该实例在约 14 小时内处于「零备份」状态。

8.3 这个发现的性质变了

❌ 不是「备份失败」级别的问题
✅ 是「数据保护空窗」级别的问题

「先删后建」是备份策略里的经典反模式。 正确做法:

  1. 先建新备份
  2. 本次备份成功并校验通过后,再清理过期备份
  3. 至少保留 2 份

九、备份脚本的问题清单

完整读了一遍备份脚本后,整理出 8 个问题:

#缺陷影响严重度
1清理策略「先删后建」,阈值比备份周期还短,实际只保留 1 份备份失败 = 零备份🔴
2无内存闸门内存不足时硬跑,可能打挂数据库🔴
3无完整性校验(只看退出码)坏备份被判定为成功🟠
4失败无即时告警最长 8 小时后才由检查脚本发现🟠
5使用裸 mysql 命令,cron 的 path 下找不到超时延长逻辑从未生效🟡
6cp my.cnf $backup_dir 无条件执行失败目录里也有文件,易被误判为「有内容」🟡
7备份与数据库同盘该盘故障则库与备份同时丢失🟠
8--safe-slave-backup 是空操作实例并非从库,属历史遗留配置🟡

9.1 关于第 5 条的细节

脚本里有一段「临时延长网络超时」的逻辑,日志显示:

extended timeouts to 3600s. original read: unknown, write: unknown

unknown 说明取原值的命令执行失败了——脚本用的是裸 mysql 命令,而 cron 的 path 只有 /usr/bin:/bin,找不到装在自定义目录下的客户端。于是:

  • 原值为空 → set global 没执行
  • 回滚步骤也因为值为空被跳过

修复:脚本里所有 mysql 改成绝对路径。

顺带一提:脚本的失败信息里写着类似 check pt-kill whitelist if 104/2013 error persists 的提示——说明作者之前也遇到过 104/2013 连接中断,并且一直在往「连接被掐断」的方向排查(怀疑 pt-kill、网络超时)。而这次终于拿到了答案:是内核把数据库杀掉了,跟 pt-kill 完全无关。

9.2 一个安全提醒

不要用 bash -x 调试这个脚本。

脚本会 source 一个存放凭据的 .env 文件,bash -x 会把 db_user=xxx / db_pass=yyy 明文打进日志

调试应该用「外层包装脚本 + 脚本自身的日志文件」,而不是 -x

十、监控脚本的 fail-open 问题

读监控脚本时发现一个更隐蔽的缺陷:

last_line=$(tail -n 1 "$log_file" 2>/dev/null)
case "$last_line" in
  *"mysql full_backup failed"*)  cur_status="failed"  ;;
  *"mysql full_backup succeed"*) cur_status="success" ;;
  *)                             cur_status="success" ;;   # ← 危险
esac

默认分支是 success(fail-open)。 只要最后一行既不匹配 failed 也不匹配 succeed,它就当成功处理

什么情况下会这样?

场景最后一行监控判定
🔴 备份进程被 pkill 掐断xtrabackup 的某条 notesuccess(误报)
🔴 脚本在凭据检查处 exit 1error: env file not found!success(误报)
🔴 脚本启动后立刻被杀workflow started...success(误报)

「误报成功」比「漏报」更危险——它会让人以为问题解决了。

另一个盲区:

[ -f "$log_file" ] || exit 0     # 日志不存在就静默退出

备份压根没跑(日志文件不存在)时,不告警。

修复建议

  1. 默认分支改成 failed(fail-closed),或者更严格:只认显式的 succeed 标记
  2. 日志文件不存在时应该告警,而不是静默退出
  3. 验收不能只看监控推送的「已恢复」消息——必须人工核对 xtrabackup_checkpoints

十一、补跑备份成功

11.1 前置动作

xtrabackup 拒绝写入非空的 --target-dir,而备份脚本的目标目录是当天日期,重跑会撞上凌晨留下的残骸目录。

mv /data/backup/data/<当天日期> /data/backup/data/<当天日期>.failed

mv 而不是 rm,保留现场。
顺带确认:新名字的 mtime 是当天,不会被 -mtime +5 的清理逻辑误删

11.2 要不要先重启?

调参后可用内存约 1.3 gb。评估:

备份增量 ≈ 1.8 gb(按上次 oom 的差额估算)
当前余量 = available 1.3 gb + swap 空闲 1.3 gb ≈ 2.6 gb

够,但只有 40% 余量,所以决定:加护栏直接跑,而不是先重启(重启要等窗口,且护栏已经把最坏结果兜住了)。

后来实测证明这个估算偏保守——xtrabackup 自身 rss 只有约 120 mb,那 1.8 gb 的差额更可能是 mysqld 自身长期累积的结果,而不是备份造成的。

11.3 包装脚本(不改原脚本)

cat > /tmp/run_backup_safe.sh <<'eof'
#!/bin/bash
# 1) 内存爆时优先杀我(子进程继承),保 mysqld
echo 500 > /proc/$$/oom_score_adj
# 2) 内存闸门
avail=$(awk '/memavailable/{print int($2/1024)}' /proc/meminfo)
echo "[$(date '+%f %t')] 启动前 memavailable = ${avail} mb"
if [ "$avail" -lt 1000 ]; then
    echo "[$(date '+%f %t')] 【中止】可用内存仅 ${avail}mb(阈值 1000mb),放弃备份以免打挂数据库"
    exit 1
fi
free -m
echo "[$(date '+%f %t')] ===== 备份开始 ====="
nice -n 19 ionice -c2 -n7 /bin/bash /data/backup/mysql_backup.sh
rc=$?
echo "[$(date '+%f %t')] ===== 备份结束,退出码 = $rc ====="
free -m
exit $rc
eof
chmod +x /tmp/run_backup_safe.sh
nohup /tmp/run_backup_safe.sh > /tmp/backup_run_$(date +%m%d_%h%m).log 2>&1 &

这层包装做了四件事:

  1. oom_score_adj = 500 → 内存爆时死的是备份,不是数据库
  2. 内存闸门 → 不足 1 gb 直接放弃,不硬跑
  3. nice -n 19 ionice -c2 -n7 → 最低 cpu/io 优先级,尽量不干扰业务
  4. 日志落盘 → 断线也能查

用原脚本而不是手工跑 xtrabackup,这样日志里会正常写下 mysql full_backup succeed监控脚本才认

11.4 护栏分工验证(关键)

mysqld         oom_score_adj = -500     ← 数据库被保护
mysqld_safe    oom_score_adj = -500     ← 自动重启也继承保护
备份脚本(bash)  oom_score_adj =  500     ← 备份主动当替罪羊
xtrabackup     oom_score_adj =  500     ← 子进程继承

11.5 结果

项目结果
耗时约 31 分钟
退出码0
xtrabackupcompleted ok!
脚本日志末行mysql full_backup succeed
备份产物约 160 gb(与数据目录体积吻合)
运行期 mysqld rss5.76 gb → 5.77 gb(几乎不动

全程无 oom,护栏没有被用上。

完整性校验(xtrabackup_checkpoints):

backup_type = full-backuped        ← 全量,非增量
from_lsn    = 0                    ← 从 lsn 0 开始 = 完整全量
to_lsn      = <有具体数值>          ← 备份一致性点
last_lsn    = <大于 to_lsn,正常>   ← redo 复制到的位置
flushed_lsn = <有具体数值>
redo_memory = 0
redo_frames = 0

redo 日志复制范围连续无断档——这是备份能恢复的前提。

11.6 别急着--prepare

xtrabackup 的备份是未 prepare 状态,恢复前必须执行:

xtrabackup --prepare --use-memory=256m --target-dir=/data/backup/data/<当天日期>

--prepare 会按 my.cnf 里的 innodb_buffer_pool_size 分配内存(此时是 3g),在内存紧张的机器上必须加 --use-memory 限制。

关键认知:备份存在 ≠ 备份可恢复。

而且——过去每周的备份都在下一周被自动删掉了,从来没有任何一份备份被验证过能不能恢复

十二、继续深挖:那 3 gb 内存去哪儿了

12.1 做减法

mysqld 实际内存            6.13 gb   (rss 5.85 + swap 0.28)
  ├─ innodb_buffer_pool    2.99 gb   (195,781 页 × 16kb)
  └─ buffer pool 之外      3.14 gb   ← 问题所在

一个 3 gb buffer pool 的实例,正常总共应该占 4~4.5 gb,现在占了 6.13 gb。

12.2 用 performance_schema 找归属

select event_name, current_alloc
from sys.memory_global_by_current_bytes
order by current_alloc desc limit 20;

(注意:sys 视图的列名在不同版本间有差异,遇到 unknown column 时改用底层表
performance_schema.memory_summary_global_by_event_name 更稳,或直接 select *。)

结果:

memory/innodb/buf_buf_pool                    3.07 gib    ← buffer pool(正常)
memory/mysys/io_cache                         1.09 gib    ← 🔴 头号异常
memory/performance_schema/table_handles       72.50 mib
memory/sql/table                              70.16 mib
memory/temptable/physical_ram                 61.00 mib
memory/performance_schema/* (其余 8 项)       ~233 mib
memory/innodb/* (log_buffer 等)             ~128 mib
memory/sql/dd::* / table_share                 ~48 mib

账对上了:3.07 + 1.09 + 0.30 + 0.30 + 0.13 + 约 1.4(pfs 未覆盖部分)≈ 6.13 gib。

12.3 头号异常:memory/mysys/io_cache≈ 1.1 gib

io_cache 是什么:mysql 内部的文件顺序读写缓存结构,主要出现在:

  • filesort 排序落盘、大查询排序
  • load data infile / select ... into outfile
  • alter table 拷贝表
  • binlog dump 线程(每个连上来的从库各分配一个)
  • 复制 sql/io 线程读 relay log

量化它:

select event_name,
       current_count_used                             as 块数,
       round(current_number_of_bytes_used/1048576,1)  as 总计mb,
       round(current_number_of_bytes_used/current_count_used/1024,1) as 平均kb,
       round(high_number_of_bytes_used/1048576,1)     as 历史峰值mb
from performance_schema.memory_summary_global_by_event_name
where event_name like '%io_cache%';
memory/mysys/io_cache  |  约 1600 块  |  ~1.1 gb  |  平均约 690 kb  |  历史峰值 ~1.5 gb

形态:不是「一个超大块」,而是「大量中等大小的块」——说明来自大量重复的、规模相近的操作。

周转量:

累计分配   约 68 万块   /  约 35 gb
累计释放   约 67.7 万块 /  约 34 gb
当前持有   约 1600 块   /  ~1.1 gb

15 小时里分配了约 68 万次(约 12.6 次/秒)。

12.4 一个未解的矛盾

按线程统计:

select round(sum(current_number_of_bytes_used)/1048576,1)
from performance_schema.memory_summary_by_thread_by_event_name
where event_name='memory/mysys/io_cache';
全局mb     = 约 1160
线程合计mb = null      ← null = 零行!

sum() 在零行上返回 null。也就是说:全局计数器说有约 1.1 gb,但没有任何存活线程持有它。

全局 io_cache                              ~1.1 gb
所有线程内存合计(全部类型)                 ~170 mb
                                          ─────────
                                   约 900 mb 无归属

这块内存无法通过「kill 连接」释放——因为它不属于任何线程。

12.5 关于「是不是内存泄漏」,必须诚实

观测到的数据:

采样点io_cache块数
采样 1~1.10 gb1640
采样 2~1.16 gb1724
采样 3~1.09 gb1628
采样 4~1.09 gb1628

数值会回落(1724 → 1628),且在 5 分钟观测窗口内完全不变。

所以这不是「只增不减」的硬性内存泄漏。 早期一度得出「确认泄漏」的结论,被这组数据推翻了。

准确表述:mysql 里长期驻留约 1.1 gb 的 io_cache(波动 1.1~1.5 gb),且没有任何线程对它负责。

12.6 真正要命的发现:增长不在 io_cache

采样点mysqld 总内存buffer poolbuffer pool 之外
调参前7.01 gb4.09 gb2.92 gb
调参后约 1 小时6.13 gb2.99 gb3.14 gb

约 2 小时内「buffer pool 之外」涨了约 220 mb(约 110 mb/小时),而 io_cache 在这期间基本持平。

io_cache 是一块「大但稳定」的常驻开销,不是增长源。真正在涨的东西,当时还没有找到。

这一步的诚实结论比强行给一个答案更重要。

12.7 顺带发现的两个问题

① 负载异常:一条 select 在 15 小时内执行了约 154 万次

select left(digest_text,60) as 语句, count_star as 执行次数,
       sum_sort_merge_passes as 归并排序次数,
       sum_created_tmp_disk_tables as 磁盘临时表次数,
       sum_sort_rows as 排序行数
from performance_schema.events_statements_summary_by_digest
order by sum_sort_merge_passes desc limit 10;
select `id`,`account_id`,`account_name`,`city_id`...  |  约 154 万次

约 28.6 次/秒,持续不断。 这是应用里的轮询循环在打数据库,值得让开发排查。

② 这台机器的时钟不稳定

测试时钟稳定性时发现:

某时刻  →  [select sleep(300)]  →  now() 只前进了 60 秒

select sleep(300) 正常返回(说明确实睡了 300 秒),但前后 now() 只差 60 秒 → 系统时钟在这期间被往回拨了约 4 分钟

这和最初发现的「dmesg -t 比 rsyslog 慢 29 分钟」是同一类现象。

这台机器的时钟稳定性有问题,会影响所有日志时间取证的可靠性,建议单独排查(ntp 配置、虚拟化时钟源)。

十三、结论与遗留问题

13.1 已经确定的

结论依据
故障根因是内核 oom killer 杀死 mysqld,备份只是触发器之一oom 现场内存数据、日志时间线
数据库历史上已被杀死 6 次,其中 4 次与备份无关journal 记录逐条核对时段
数据库被杀死 6 次,监控零告警只有「备份失败」这一个间接信号
备份脚本「先删后建」导致故障期间零备份约 14 小时脚本日志第 2 行
buffer pool 4g → 3g 回收约 1.0 gb,预测误差 12 mb调整前后实测
备份已补跑成功(completed ok,退出码 0)checkpoints + 日志
io_cache 长期占用约 1.1 gb,峰值约 1.5 gbpfs 全局计数器
应用侧有一条 select 在 15 小时内执行了约 154 万次digest 统计

13.2 还没确定的

待查项说明
❓ 「buffer pool 之外」那约 110 mb/小时 的增长是什么已排除 io_cache、磁盘、连接数
❓ io_cache 的约 1.1 gb 为什么没有线程归属pfs 记账局限?还是无主内存?
❓ 约 700 个连接(全部来自同一台应用服务器)是否合理需要应用侧确认连接池配置
❓ 时钟不稳会不会影响后续所有日志取证建议单独排查 ntp / 虚拟化时钟
❓ 该 mysql 小版本是否存在 io_cache 相关的已知问题需查官方 bug 库与 release notes

不建议现在就下「根因已完全找到」的结论。

13.3 已识别但尚未执行的行动项

优先级事项
🔴 高查清「buffer pool 之外」内存的增长源
🔴 高补齐告警:mysqld 进程存活、内存水位、swap 使用率、oom 事件、io_cache 水位
🟠 中修复备份脚本 8 项缺陷(先删后建 / 内存闸门 / 完整性校验 / 即时告警 / 路径 / 异盘)
🟠 中修复监控脚本 fail-open 缺陷
🟠 中安排一次恢复演练--prepare + 恢复到测试实例)
🟠 中备份产物迁至异盘/异地
🟡 低排期内存扩容至 16 gb
🟡 低延长系统日志保留周期(当时只剩 2 条 oom 记录)
🟡 低排查系统时钟不稳

十四、经验总结

14.1 告警处理

1. 先分清「原因性告警」和「结果性告警」

本次告警在上午发出,真实故障在凌晨发生,相隔约 8 小时。先看监控规则的判定逻辑和触发时刻,再决定查哪段日志。

2. 别被「告警标题」带走方向

标题是「mysql 备份失败」,实际故障是「数据库被内核杀死」。
告警标题描述的是「被发现的症状」,不是「故障本身」。

3. 只有一台机器告警 → 先按单机问题排查

影响面能大幅缩小排查范围。

14.2 内存问题排查

4. rss 不是真实内存需求,rss + vmswap 才是

本次 oom 时 mysqld 的 rss 是 6.99 gb,但加上 1.59 gb 的 swap,真实需求是 8.58 gb,而机器只有 7.98 gb。只看 rss 会严重低估。

5. 用「做减法」定位内存去向

mysqld 总内存 − buffer pool 真实占用 = 待解释的部分

再用 performance_schemamemory_global_by_current_bytes 把它拆开。
先用全局视图找大头,再用按线程视图找归属。

6. set global 一定要顺手持久化

在线调参只改运行时。不写配置文件,下次重启全回退。 写完后用 my_print_defaults 验证语法,避免配置文件写坏导致下次起不来。

7. 调小 buffer pool 是有性能代价的

本次调整后磁盘读涨了约 6 倍、cpu 空闲从 45%~72% 掉到 10%~26%。
这是「用性能换安全」,不是免费的。 同期就该把「扩内存」排上日程。

8. dmesg -t 在时钟不稳的机器上不可信

这类机器上做时间取证,一律以 journalctl / /var/log/messages 为准。
判定同一事件的方法:比对两处日志的细节数字(如 mem-info)是否完全一致。

14.3 变更操作

9. 先加护栏,再动手

在任何涉及内存/资源的变更之前,先花 30 秒加上 oom 护栏。
它不能阻止故障,但能改变故障的形态——把「数据库宕机」变成「备份失败」,这两件事的成本差一个量级。

10. 护栏要成对使用

被保护的(数据库)  : oom_score_adj = -500
可牺牲的(备份进程): oom_score_adj = +500

只保护一方没有意义——如果整个系统只有一个大块头,内核无路可走时可能引发杀进程风暴。

11. 变更前先备份配置,变更后先验证语法

cp -a /etc/my.cnf /etc/my.cnf.bak.$(date +%y%m%d_%h%m%s)
# ... 修改 ...
/usr/local/mysql/bin/my_print_defaults mysqld | grep -i <改动的参数>

14.4 备份与监控

12. 「先删后建」是备份策略的经典反模式

清理动作必须放在本次备份成功并校验通过之后,且至少保留 2 份。
否则一次失败就等于把仅有的保护也一起弄没了。

13. 「任务返回 0」不等于「备份可用」

必须校验:

  • mysqldump:结尾有 dump completed on ... + gzip -t 通过
  • xtrabackup:xtrabackup_checkpointsbackup_type / from_lsn / to_lsn 完整 + 日志有 completed ok!
  • 最终标准:做过一次恢复演练

14. 监控脚本要 fail-closed,不要 fail-open

本次监控脚本的 case 默认分支是 success——备份进程被掐断、脚本早期退出,都会被判定为「备份已恢复」,推送一条假的好消息。

「误报成功」比「漏报」更危险。

15. 补告警时优先补「过程指标」而不是「结果指标」

本次的最大盲区是:数据库被内核杀死 6 次,没有任何独立告警,只靠「备份失败」这个 8 小时后才发出的结果指标间接暴露。

应该直接监控:进程存活、内存水位、swap 使用率、oom 事件。

14.5 沟通与记录

16. 及时修正自己的判断

本次排查中,有两个判断被后续数据推翻:

  • 「有 3 次 oom 落在备份时段」→ 逐条核对后是 2 次
  • 「确认是内存泄漏」→ 数据表明数值会回落,不是单调泄漏

发现说重了就说重了。 一个被修正过的准确结论,比一个听起来很确定的错误结论有价值得多。

17. 保留证据

  • 变更前后的对照数据(本次的 available 304 mb → 1353 mb 就是最有力的证明)
  • 日志原文(尤其是失败时刻的原始报错)
  • 时间线(用「谁在什么时候做了什么」的格式)

本次排查过程中,有一条被忽略很久的线索:登录时反复出现的「有新邮件」提示。翻到最后一封是 ntp 的定时任务邮件,没有备份失败邮件——这个「没有」本身也是信息:说明备份脚本失败时不发通知,完全依赖 8 小时后的检查脚本。

附录 a:命令速查

a.1 内存体检

{
echo "================ 内存体检 $(date '+%f %t') ================"
echo; echo "【1】整机内存"; free -m
echo; echo "【2】mysqld 实际内存"
pid=$(cat /path/to/mysql.pid)
grep -e "vmrss|vmswap|vmsize" /proc/$pid/status
rss=$(grep vmrss  /proc/$pid/status | awk '{print $2}')
swp=$(grep vmswap /proc/$pid/status | awk '{print $2}')
awk -v r=$rss -v s=$swp 'begin{printf ">>> 合计 %.2f gb\n", (r+s)/1048576}'
echo; echo "【3】swap 抖动"; vmstat 1 3
echo; echo "【4】oom 记录"; grep -h "killed process" /var/log/messages | tail -10
echo; echo "【5】内存 top10"; ps aux --sort=-rss | head -11
}

a.2 mysql 内存归属

-- 全局内存分布
select event_name, current_alloc
from sys.memory_global_by_current_bytes
order by current_alloc desc limit 20;

-- 底层表版本(避免 sys 视图列名差异)
select event_name,
       round(current_number_of_bytes_used/1048576,1) as mb,
       current_count_used as blocks
from performance_schema.memory_summary_global_by_event_name
where current_number_of_bytes_used > 0
order by current_number_of_bytes_used desc limit 20;

-- buffer pool 真实占用
select @@innodb_buffer_pool_size/1024/1024 as bufpool_mb;
show global status where variable_name in
 ('innodb_buffer_pool_pages_data','innodb_buffer_pool_pages_free','innodb_buffer_pool_pages_total');

-- 连接数与峰值
show global status where variable_name in
 ('threads_connected','threads_running','max_used_connections','uptime');

-- 连接来源分布
select user, host, count(*) as conns
from information_schema.processlist
group by user, host order by conns desc limit 20;

-- 排序/临时表大户
select left(digest_text,60) as stmt, count_star,
       sum_sort_merge_passes, sum_created_tmp_disk_tables, sum_sort_rows
from performance_schema.events_statements_summary_by_digest
order by sum_sort_merge_passes desc limit 10;

a.3 oom 护栏

# 查看
for p in $(pgrep -f 'mysqld|mysqld_safe'); do
  printf "%-15s pid=%-7s adj=%s\n" "$(cat /proc/$p/comm)" "$p" "$(cat /proc/$p/oom_score_adj)"
done

# 设置
pid=$(cat /path/to/mysql.pid)
echo -500 > /proc/$pid/oom_score_adj

# 每分钟自愈脚本(防重启失效)
cat > /usr/local/sbin/mysql_oom_guard.sh <<'eof'
#!/bin/bash
pidf=/path/to/mysql.pid
adj=-500
pid=$(cat "$pidf" 2>/dev/null)
[ -n "$pid" ] && [ -d "/proc/$pid" ] || exit 0
cur=$(cat "/proc/$pid/oom_score_adj" 2>/dev/null)
if [ "$cur" != "$adj" ]; then
    echo "$adj" > "/proc/$pid/oom_score_adj" 2>/dev/null
    logger -t mysql_oom_guard "mysqld($pid) oom_score_adj: ${cur:-na} -> $adj"
fi
eof
chmod +x /usr/local/sbin/mysql_oom_guard.sh

a.4 buffer pool 在线调整

-- 调整(注意必须是 chunk_size × instances 的整数倍,本例为 1 gb)
set global innodb_buffer_pool_size = 3221225472;   -- 3 gb

-- 确认
select @@innodb_buffer_pool_size/1024/1024 as bufpool_mb;
show status like 'innodb_buffer_pool_resize_status';
# 持久化 + 验证
cp -a /etc/my.cnf /etc/my.cnf.bak.$(date +%y%m%d_%h%m%s)
sed -i 's/^innodb-buffer-pool-size[[:space:]]*=.*/innodb-buffer-pool-size = 3g/' /etc/my.cnf
grep -n "innodb-buffer-pool-size" /etc/my.cnf
/usr/local/mysql/bin/my_print_defaults mysqld | grep -i "buffer-pool-size"

a.5 备份验收

# 进程
pgrep -af 'xtrabackup|mysql_backup' || echo "已结束"

# 任务退出码
tail -6 /tmp/backup_run_*.log

# 脚本日志末行(必须是 succeed)
tail -5 /data/backup/log/$(date +%y%m%d)/mysql_backup_3306.log

# ★ 完整性校验
cat /data/backup/data/$(date +%y%m%d)/xtrabackup_checkpoints
grep -i "completed ok" /data/backup/log/$(date +%y%m%d)/mysql_backup_3306.log
ls /data/backup/data/$(date +%y%m%d)/ | wc -l
du -sh /data/backup/data/$(date +%y%m%d)

附录 b:完整时间线

全部使用相对时间轴:t+0 = 备份任务启动时刻

b.1 故障发生(t 日凌晨)

相对时间事件
t+0s备份脚本启动,第一件事:删除上一周的备份
t+16s清理完成;网络超时延长逻辑执行失败(original read: unknown
t+18sxtrabackup 启动,识别服务端参数
t+20sexecuting lock instance for backup ...
t+20s → t+34s14 秒空档(初始化本地 innodb、创建 logfile)——压力最高的窗口
t+36s💀 mysqld 被内核 oom killer 杀死
t+38sxtrabackup 报 104 / 2013 连接中断
t+38s脚本判定失败,写入 mysql full_backup failed
t+8h监控脚本检查发现失败,推送告警

b.2 应急处置(同日白天)

相对时间动作关键结果
t+10.8h系统体检磁盘正常;available 仅 385 mb
t+11h采集 mysql 参数buffer pool 4gmax_connections 10000max_allowed_packet 1g
t+11.1h采集 oom 现场发现 dmesg -t 与 rsyslog 时间不一致(约 29 分钟偏差)
t+13h复查内存available 降至 237 mb,问题在恶化
t+13.9h加 oom 护栏mysqld / mysqld_safe 均设为 -500
t+13.9hbuffer pool 4g → 3g回收 约 1.0 gbavailable 304 → 1353 mb
t+14h持久化 my.cnfdiff 确认只改一行;my_print_defaults 验证通过
t+14.1h读取备份脚本逻辑发现清理策略为「先删后建」
t+14.2h挪走凌晨的残骸目录xtrabackup 要求目标目录为空
t+14.2h带护栏补跑备份包装脚本:内存闸门 + oom 替罪羊 + 低优先级
t+14.5h备份进行中mysqld rss 稳定在 5.77 gb,未上涨
t+14.7h备份完成约 160 gb,退出码 0,completed ok!
t+15h内存复查available 1185 mb;mysqld 6.13 gb
t+15.2h内存归属分析锁定 io_cache ≈ 1.1 gib
t+15.3h泄漏量化累计分配约 68 万次,当前持有约 1600 块
t+15.4h泄漏速率观测5 分钟内数值完全不变 → 推翻「单调泄漏」判断

b.3 内存账本对照

阶段availablemysqld 总内存buffer poolbuffer pool 之外
初始体检385 mb~6.6 gb4.09 gb
复查(最低点)237 mb7.01 gb4.09 gb2.92 gb
调参后1353 mb6.01 gb3.00 gb3.01 gb
备份中1142 mb6.06 gb2.99 gb
备份结束1259 mb6.06 gb2.99 gb
调参后约 1 小时1185 mb6.13 gb2.99 gb3.14 gb

写在最后

这次事件的起点,是一条只有 6 个字有效信息的告警:

告警详情:mysql备份失败

如果当时按字面意思去查备份脚本、查磁盘、查权限,大概率会陷入「手动跑一遍备份成功了 → 告警消除 → 下周照旧」的循环。

真正让事情有进展的,是三个「不按直觉走」的动作:

  1. 问了一句「这个告警是什么时候、按什么规则发出来的」——发现它比故障晚了 8 小时
  2. 算了一笔账「rss + swap 到底是多少」——发现数据库的真实内存需求已经超过物理内存
  3. 在动手改参数之前,先花 30 秒加了护栏——保证了后续所有操作的最坏结果都是可控的

以及一条贯穿全程的原则:

数据推翻结论时,改结论,不要改数据。

本次排查中有两个判断被自己推翻——「有 3 次 oom 落在备份时段」和「确认是内存泄漏」。修正它们让结论变得更弱,但也变得更真。

一条准确的、承认边界的结论,比一条听起来很确定的错误结论有用得多。

以上就是mysql备份失败告警的排查与解决方法的详细内容,更多关于mysql备份失败告警的资料请关注代码网其它相关文章!

(0)

相关文章:

版权声明:本文内容由互联网用户贡献,该文观点仅代表作者本人。本站仅提供信息存储服务,不拥有所有权,不承担相关法律责任。 如发现本站有涉嫌抄袭侵权/违法违规的内容, 请发送邮件至 2386932994@qq.com 举报,一经查实将立刻删除。

发表评论

验证码:
Copyright © 2017-2026  代码网 保留所有权利. 粤ICP备2024248653号
站长QQ:2386932994 | 联系邮箱:2386932994@qq.com