监控叫醒之前,日志已经停了三分钟:一次 systemd “自动重启”的 OOM 排查
凌晨 2:21 被监控叫醒,告警是 demo-service 不可用。等登录上去看,进程还活着,systemd 显示它刚“自动重启”过,但业务日志停在 2:17:02,仿佛中间凭空断了三分钟。
服务没有“无故”重启这回事。把现象拆成可执行的排查流程:先按时间线推进,先看系统状态再看应用日志,全程只读命令,不碰任何配置。
现象与现场保护
故障现象如下:
- systemd 托管 Java 服务 demo-service,配置了
Restart=always - 凌晨 2:21 监控告警服务不可用
- 进程后来被 systemd 拉起来了,但日志从 2:17:02 起中断
先把现场日志复制到 /tmp/diagnose,避免后续操作覆盖证据:
mkdir -p /tmp/diagnose
journalctl --since "02:00" --until "02:30" -k > /tmp/diagnose/kernel.log
journalctl --since "02:00" --until "02:30" -u demo-service > /tmp/diagnose/service.log
free -h
df -h
先确认系统有没有重启
排除整机重启的可能:
uptime
who -b
last reboot
systemctl status demo-service
系统未重启,demo-service 的 systemd 状态里出现了典型的三连行:
Main process exited, code=killed, status=9/KILL
Failed with result 'signal'
Scheduled restart job, restart counter is at 3
status=9/KILL 说明主进程是被外部用 SIGKILL 强杀的,不是自己崩的。谁杀的,要看内核日志。
systemd 日志与内核日志:凶手是 OOM Killer
查服务自身的日志:
journalctl -u demo-service --since "02:00" --until "02:30"
日志在 2:17:02 戛然而止,随后 systemd 开始重启服务。再看内核日志:
journalctl -k --since "02:00" --until "02:30"
找到关键行:
Out of memory: Killed process ... (java) total-vm ... anon-rss:1402420kB
oom-kill:constraint=CONSTRAINT_NONE
constraint=CONSTRAINT_NONE 说明是全局内存不足触发的 OOM,不是 cgroup 限制导致的。被选中的牺牲品是 Java 进程,原因只可能是内存耗尽时内核按策略挑中了它。
定位定时任务:谁在凌晨两点吃内存
服务是 Restart=always,拉起来是 systemd 的正常动作,不是故障根源。真正的问题是内存为什么在 2:17 耗尽。
用登录记录和审计排查是否有人为操作:
last
history
ausearch -m USER_CMD -ts 02:00 -te 02:30 # auditd 可用时
没有人为操作。继续查定时任务:
crontab -l
cat /etc/crontab
ls /etc/cron.d/
在 /etc/crontab 里发现:
0 2 * * * root /opt/backup/backup_db.sh
时间线一下子对上了:
- 2:00 备份脚本启动
- 2:00–2:16 脚本内
mysqldump --all-databases一次性申请大量内存,内存水位持续走高 - 2:16 内存进入高峰
- 2:17:02 OOM Killer 触发,选中 Java 进程杀掉
- systemd 检测到进程退出,
Restart=always自动拉起 demo-service
root cause 明确:备份脚本 mysqldump 内存申请过大触发系统级 OOM,被杀的是 Java 服务,systemd 的自动重启只是掩盖了故障表象。
缓解:让 OOM Killer 尽量别选中服务
先做最小干预,调低服务被 OOM Killer 选中的概率。编辑 demo-service 的 unit 文件,加入:
[Service]
OOMScoreAdjust=-500
RestartSec=10
分数范围 -1000 到 1000,越小的值越不容易被杀,默认值是 0。-500 意味着只有在极端情况下内核才会优先杀它,同时把重启间隔从默认值拉开,避免拉起后立即再被杀。
重新加载并重启服务:
systemctl daemon-reload
systemctl restart demo-service
这只是缓解,备份脚本还在,内存压力还在,下一次内存峰值仍可能误伤其他进程。
治本:给备份脚本降内存和降优先级
备份脚本才是源头。优化方向是降低 mysqldump 对内存的瞬时占用,并让内核资源紧张时它能主动让路:
nice -n 10 ionice -c2 -n7 mysqldump \
--all-databases \
--max-allowed-packet=64M \
--set-gtid-purged=OFF \
> /backup/dump.sql
要点:
nice -n 10:降低 CPU 调度优先级,不影响内存,但能让它不和其他生产进程抢 CPUionice -c2 -n7:best-effort 调度且优先级最低,备份 IO 不再挤占业务 IO--max-allowed-packet:限制单次网络传输包大小,避免大字段查询一次拉爆内存--set-gtid-purged=OFF:不去读取全局 GTID 信息,减少额外内存开销
更彻底的做法是按库拆分备份,或换成 mydumper 这类并行备份工具;如果系统支持,直接给备份进程套 cgroup 内存上限最稳妥。脚本执行时间也可以错开业务低峰更深的时段。
验证:第二天看这三个地方
次日确认问题是否真的消失:
journalctl -k --since "yesterday 02:00" --until "yesterday 03:00" | grep -i oom
systemctl status demo-service
- 内核日志里不再有
Out of memory: Killed process - demo-service 的 restart counter 不再增长
- Prometheus 里看
process_resident_memory_bytes,确认 Java 进程内存恢复平稳
退出码对照与排错方向
排查 systemd 服务被杀,先认退出码,再决定查哪类日志:
code=killed, status=9/KILL:SIGKILL 强杀。优先查内核 OOM 日志、人为 kill、自动化平台操作- 日志中断但进程没退出:查磁盘是否写满、网络连接是否断开、JVM 是否长时间 Full GC 导致日志线程卡死
Restart=always且反复重启:服务本身启动即崩溃,systemd 每次拉起都失败,看启动阶段的业务日志
收尾的一些工程建议
- journald 日志开启持久化,否则重启丢失上下文
- auditd 规则至少覆盖 sudo 调用:
auditctl -w /usr/bin/sudo -p x -k sudo_cmd - sudo 操作、cron 变更、服务启停尽量统一记录到审计平台
- 脚本一律
set -eu,避免 mysqldump 失败后脚本不退出、继续跑后续逻辑 - 脚本里不要直接
systemctl restart,确有需要必须写清原因再操作 - 资源密集任务用
nice/ionice/ cgroup 限制,不要裸奔 - 容器或物理机上 Java 的
-Xmx不要超过总内存的 70%,留出系统页缓存和其他进程的余量
事故复盘落到三个问题上:触发点是什么(内存峰值)、为什么选中这个进程当牺牲品(Java 进程内存占用大且没有调 OOMScoreAdjust)、需要哪些自动化和降级手段(备份错峰、资源隔离、OOM 监控)。
接手新项目时,先把这三件事查一遍:systemd 里有没有不合理的自动重启配置、机器有没有 OOM 监控、cron 里有没有会和业务抢资源的定时任务。很多“半夜自动重启”的根源,都是第三件事。