NAVY82·OPS 运维故障排查案例集
blog.navy82.icu / index / 11 ↑ 返回索引
#11 2026-09-18 故障排查 / OOM / 内存 / systemd 阅读 –

1.6G 小内存服务器 OOM 根因定位 · dnf 元数据解析 + 87% 日志污染

根因定位OOM ×2swap 闲置已优化止血

2 核 1.6 GB 服务器 15 分钟负载高达 30，内核两次 OOM 杀进程，系统日志 87% 被同一服务刷屏。先用负载三元组「0.05 / 5.92 / 30.44」的撕裂形状把排查窗口锁定到 10:50~11:00，再从内核 OOM 完整进程任务表中找出真凶：dnf makecache 单进程 780 MB（占内存 48%）解析 EPEL 元数据撑爆整机 —— 而日志里 `invoked oom-killer` 那行写的 httpd 只是无辜的触发者。同时挖出 swap 被 swappiness=0 完全闲置、btwaf 僵尸服务 2.5 小时重启 1473 次、以及 13 天日志空洞。

本案例目录

CHART 01 // 故障时间线

timeline · 2026-09-18
08:41boot系统启动 · 日志开始记录起点
09:17dnfdnf makecache 开始拉取仓库元数据（含 EPEL 20MB）内存开始爬升
09:28OOM #1httpd 缺页触发 oom-killer · 杀 dnf（780.8MB）load 冲高
10:54OOM #2AliYunDunMonitor 触发 · 再杀 dnf（718.7MB）kswapd0 颠簸
11:11观测uptime 显示 0.05 / 5.92 / 30.44 · 锁定时间窗排查起点
11:2x处置停定时器 + 移除 EPEL + 停僵尸服务 + 调 swap/THP止血完成

CHART 02 // OOM 时刻进程内存快照

tasks state · memory in pages
dnf780.8 MBrss 183997 页 · 占 1.6G 总内存 48%真凶
mysqld191.4 MBrss 49008 页 · 数据库正常
BT-Panel77.6 MBrss 17573 页 · 面板正常
firewalld23.3 MBrss 5973 页正常
php-fpm21.7 MB单 worker · 多池共存正常
httpd18.4 MB触发者 · 仅在做文件读取缺页无辜
AliYunDunMonitor16.6 MB第二次 OOM 的触发者无辜

CHART 03 // 内存水位与放大因素

mem-info · amplifiers
active_anon454 MB116231 页 · 活跃匿名内存—
inactive_anon880 MB225318 页 · 非活跃匿名内存—
free51.8 MB13254 页 · 跌破 DMA32 低水位线 54.5MB触发 OOM
Free swap= Total1 GB swap 一个字节未用 · swappiness=0缓冲放弃
anon_thp242 MB透明大页放大占用 · THP=always放大因素

服务器：[业务服务器]（主机名已隐去）· 故障日期：2026-09-18 现象：15 分钟负载高达 30（2 核机器）、内核两次 OOM 杀进程、系统日志 87% 被同一服务刷屏 脱敏说明：主机名、服务器 IP、客户域名、云实例 ID 等敏感信息均已隐去，日志中相关字段已替换为占位符。

环境与系统信息

项目 信息
服务器 [业务服务器]（阿里云 ECS，主机名已隐去）
规格 2 vCPU / 1.6 GB 内存 / 40 GB 系统盘
操作系统 CentOS Stream 9 · 内核 5.14.0
Web 服务 Apache 2.4.62（event MPM）· 多版本 PHP-FPM（5.3 / 5.6 / 7.3 / 8.2）
数据库 MySQL 5.7.44
面板 宝塔面板（自定义端口 + 安全入口）
承载业务 9 个企业站点
故障日期 2026-09-18

故障现象

接手时的第一手观测：

$ uptime
 11:11:05 up  2:29,  0 users,  load average: 0.05, 5.92, 30.44

三个负载值撕裂得很厉害：1 分钟负载 0.05（几乎空闲），15 分钟负载却高达 30.44。2 核机器上的 30 意味着 15 倍超载。

同时 kswapd0 累计消耗了 15 分 39 秒 CPU —— 这是内存颠簸（thrashing）的典型特征：

$ ps aux --sort=-%cpu | head -3
USER   PID %CPU %MEM    VSZ   RSS TTY  STAT START   TIME COMMAND
root    53 10.4  0.0      0     0 ?    S    08:41  15:39 [kswapd0]

而在系统日志里，87% 的内容来自同一个服务：

$ wc -l < /var/log/messages ; grep -c btwaf /var/log/messages
13984
12176

排查过程

① 用负载三元组给故障「定时」

load average 的三个值分别是一分钟、五分钟、十五分钟的指数滑动平均。三者递减的形状本身就是时间线索：

采样 1 分钟 5 分钟 15 分钟
11:11:05 0.05 5.92 30.44
11:26:53 0.17 0.30 10.45
11:33:33 1.05 0.59 7.31

1 分钟已回落到 0.05，说明压力刚刚过去；15 分钟仍有 30，说明压力峰值就在十几分钟前。据此把排查窗口锁定在 10:50 ~ 11:00，直接去看那个时间段的系统日志，避免在 14 小时的运行日志里大海捞针。

这个技巧在本例中一步命中 —— 峰值正是 10:54:57 的内核 OOM 事件。

② 解剖内核 OOM 日志

内核在触发 OOM 时会把当时全部进程的内存快照打印出来，这是最硬的证据。先从「谁申请内存失败」看起：

[Fri Sep 18 09:28:15 2026] httpd invoked oom-killer: gfp_mask=0x140cca(GFP_HIGHUSER_MOVABLE|__GFP_COMP), order=0, oom_score_adj=0
[Fri Sep 18 09:28:15 2026] CPU: 0 PID: 23359 Comm: httpd Kdump: loaded Tainted: G  OE
[Fri Sep 18 09:28:15 2026] Hardware name: Alibaba Cloud Alibaba Cloud ECS, BIOS 0.0.0 02/06/2015

调用栈显示 httpd 是在读取文件缺页时分配不出一个 page：

[Fri Sep 18 09:28:15 2026] Call Trace:
[Fri Sep 18 09:28:15 2026]  dump_header+0x4b/0x260
[Fri Sep 18 09:28:15 2026]  oom_kill_process+0xff/0x1c0
[Fri Sep 18 09:28:15 2026]  out_of_memory+0xee/0x330
[Fri Sep 18 09:28:15 2026]  __alloc_pages_slowpath.constprop.0+0xa58/0xc60
[Fri Sep 18 09:28:15 2026]  __alloc_pages+0x21c/0x250
[Fri Sep 18 09:28:15 2026]  folio_alloc+0x12/0x30
[Fri Sep 18 09:28:15 2026]  __filemap_get_folio+0x189/0x2e0
[Fri Sep 18 09:28:15 2026]  filemap_fault+0x4d5/0x8b0
[Fri Sep 18 09:28:15 2026]  do_read_fault+0x11b/0x1c0
[Fri Sep 18 09:28:15 2026]  __handle_mm_fault+0x2fb/0x650
[Fri Sep 18 09:28:15 2026]  handle_mm_fault+0xfb/0x270
[Fri Sep 18 09:28:15 2026]  asm_exc_page_fault+0x22/0x30
[Fri Sep 18 09:28:15 2026]  </TASK>

关键判断：filemap_fault 意味着 httpd 只是在做最普通的文件读取。它不是元凶，只是恰好在此刻申请内存的「压垮骆驼的最后一根稻草」。

接着看内存水位：

[Fri Sep 18 09:28:15 2026] Mem-Info:
[Fri Sep 18 09:28:15 2026] active_anon:116231 inactive_anon:225318 isolated_anon:0
                            active_file:2010 inactive_file:9368 isolated_file:0
                            unevictable:235 dirty:0 writeback:0
                            slab_reclaimable:9375 slab_unreclaimable:15268
                            mapped:8621 shmem:17487 pagetables:2438
                            free:13254 free_pcp:104 free_cma:0
[Fri Sep 18 09:28:15 2026] Node 0 active_anon:464924kB inactive_anon:901272kB active_file:8376kB
        inactive_file:37220kB ... anon_thp:247808kB ... all_unreclaimable? no
[Fri Sep 18 09:28:15 2026] Node 0 DMA32 free:46496kB min:44616kB low:55768kB high:66920kB

换算成人话：

项目 原始值 换算
active_anon 116231 页 454 MB 活跃匿名内存
inactive_anon 225318 页 880 MB 非活跃匿名内存
页缓存合计 11378 页 44 MB（几乎被榨干）
free 13254 页 仅 51.8 MB 空闲
anon_thp 247808 kB 242 MB 透明大页

Node 0 DMA32 free:46496kB 对比 low:55768kB —— 空闲内存已跌破内核低水位线，这就是内核启动 OOM 杀手的判定条件。

③ 找出真正吃内存的进程

内核紧接着打印了完整的任务表，这是判决书：

[Fri Sep 18 10:54:54 2026] Tasks state (memory values in pages):
[Fri Sep 18 10:54:54 2026] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[Fri Sep 18 10:54:54 2026] [    612]     0   612    32560     5973   151552        0             0 firewalld
[Fri Sep 18 10:54:54 2026] [   1629]     0  1629    11186     5040   126976        0             0 BT-Notice
[Fri Sep 18 10:54:54 2026] [   2092]  1001  2092   366501    49008   663552        0             0 mysqld
[Fri Sep 18 10:54:54 2026] [   3165]     0  3165    66505    17573   286720        0             0 BT-Panel
[Fri Sep 18 10:54:54 2026] [   4402]     0  4402    37415     4247   352256        0             0 AliYunDunMonito
[Fri Sep 18 10:54:54 2026] [  23304]  1000 23304   362704     3161   376832        0             0 httpd
[Fri Sep 18 10:54:54 2026] [  27513]     0 27513   258382   183997  1679360        0             0 dnf

注意 rss 列的单位是页（page，4 KB）。按 RSS 排序后一目了然：

     780.8 MB  dnf              ← 第 1 次 OOM (09:28)
     718.7 MB  dnf              ← 第 2 次 OOM (10:54)
     191.4 MB  mysqld
      77.6 MB  BT-Panel
      23.3 MB  firewalld
      21.7 MB  php-fpm
      19.8 MB  BT-Notice
      18.4 MB  httpd
      16.6 MB  AliYunDunMonitor

dnf 一个进程 780 MB，占 1.6 GB 总内存的 48%，其余所有服务（MySQL、面板、Apache、PHP-FPM、云监控 agent）挤在剩下 800 MB 里。

判决与执行：

[Fri Sep 18 10:54:54 2026] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,
        mems_allowed=0,global_oom,task_memcg=/system.slice/dnf-makecache.service,task=dnf,pid=27513,uid=0
[Fri Sep 18 10:54:54 2026] Out of memory: Killed process 27513 (dnf)
        total-vm:1033528kB, anon-rss:735988kB, file-rss:0kB, shmem-rss:0kB,
        UID:0 pgtables:1640kB oom_score_adj:0

global_oom + constraint=CONSTRAINT_NONE 说明这是整机物理内存耗尽，不是 cgroup 限额触发。所有进程 oom_score_adj 都是 0，内核按「谁最大杀谁」的规则选中了 dnf。

④ 被忽视的放大因素：swap 完全没用

在同一份 OOM 日志里，有三行极易被跳过但极其关键：

[Fri Sep 18 09:28:15 2026] 0 pages in swap cache
[Fri Sep 18 09:28:15 2026] Free swap  = 1049596kB
[Fri Sep 18 09:28:15 2026] Total swap = 1049596kB

Free swap == Total swap == 1 GB，一个字节都没用。 检查确认：

$ sysctl vm.swappiness
vm.swappiness = 0

vm.swappiness = 0 让内核宁可触发 OOM 也不换页。这台机器明明配了 1 GB swap，却在内存耗尽时完全用不上 —— 等于主动放弃了唯一的缓冲垫。这是本次故障中最可惜的一点。

⑤ dnf 为什么能吃到 780 MB

从 dnf 自己的日志看，它跑的这 11 分钟几乎不耗 CPU（累计仅 21.4 秒 CPU 时间），全部卡在内存与元数据解析上：

2026-09-18T09:17:07 systemd[1]: Starting dnf makecache...
2026-09-18T09:17:08 dnf[23813]: CentOS Stream 9 - BaseOS                    8.9 MB
2026-09-18T09:17:10 dnf[23813]: CentOS Stream 9 - AppStream                  28 MB
2026-09-18T09:17:17 dnf[23813]: CentOS Stream 9 - CRB                       8.3 MB
2026-09-18T09:17:19 dnf[23813]: CentOS Stream 9 - Extras packages          22 kB
2026-09-18T09:17:22 dnf[23813]: Extra Packages for Enterprise Linux 9      20 MB
2026-09-18T09:28:19 systemd[1]: dnf-makecache.service: Failed with result 'oom-kill'.
2026-09-18T09:28:19 systemd[1]: dnf-makecache.service: Consumed 21.395s CPU time.

第二次几乎一模一样：

2026-09-18T10:42:43 systemd[1]: Starting dnf makecache...
2026-09-18T10:42:55 dnf[27513]: Extra Packages for Enterprise Linux 9 - x86_64  20 MB
2026-09-18T10:54:57 systemd[1]: dnf-makecache.service: Failed with result 'signal'.
2026-09-18T10:54:57 systemd[1]: dnf-makecache.service: Consumed 8.235s CPU time.

根因：dnf makecache 会下载各仓库元数据，再完整解析进内存构建 solv 缓存。EPEL 收录 2 万多个包，其 filelists.xml 压缩包就有 20 MB，解压后数百 MB。在正常服务器上这无所谓，在 1.6 GB 的机器上就是致命一击。

而且这是定时复发的 —— 从历史记录看，该定时器在业务繁忙时每天触发十几次：

2026-07-14T15:57:54 Starting dnf makecache...
2026-07-14T17:49:09 Starting dnf makecache...
2026-07-14T19:28:57 Starting dnf makecache...
2026-07-14T20:31:01 Starting dnf makecache...
2026-07-14T22:11:28 Starting dnf makecache...
2026-07-14T23:23:28 Starting dnf makecache...

⑥ 87% 的日志被一个「僵尸」服务刷屏

排查中发现的第二个问题：/var/log/messages 里 12176 / 13984 行来自 btwaf.service，而该服务的可执行文件根本不存在——

Sep 18 11:12:58 ... systemd[1]: btwaf.service: Scheduled restart job, restart counter is at 1473.
Sep 18 11:12:58 ... systemd[1]: btwaf.service: Failed to locate executable /www/server/panel/plugin/btwaf/btwaf.sh: No such file or directory
Sep 18 11:12:58 ... systemd[1]: btwaf.service: Control process exited, code=exited, status=203/EXEC
Sep 18 11:12:58 ... systemd[1]: btwaf.service: Failed with result 'exit-code'.
Sep 18 11:12:58 ... systemd[1]: Failed to start btwaf.

服务单元的关键配置是问题所在：

[Service]
ExecStart=/www/server/panel/plugin/btwaf/btwaf.sh restart
Restart=always
RestartSec=5
StartLimitInterval=0     ← 关闭了重启频率限制

Restart=always 配合 StartLimitInterval=0（禁用启动限流），systemd 就会每 5 秒重试一次，永不停歇。本次开机 2.5 小时已重启 1473 次。

后果不止是 CPU 空转：海量日志把 journald 的历史冲垮了，导致早期日志无法追溯。

⑦ 日志空洞暴露的 13 天停机

排查中发现系统日志存在大段空白，用 journalctl --list-boots 一眼看出：

-1 5b5041a3... Sat 2026-09-05 15:06:40 CST  Sat 2026-09-05 15:30:41 CST
 0 3bf7268e... Fri 2026-09-18 08:41:19 CST  Fri 2026-09-18 11:12:42 CST

上一个 boot 的日志只覆盖了 24 分钟，而下一次启动已经是 13 天后。交叉验证网站访问日志，得到完全一致的结论：

$ grep -oE "\[[0-9]{2}/[A-Za-z]{3}/2026" /www/wwwlogs/*-access_log | sort -u
[16/Jul/2026
[17/Jul/2026
[20/Jul/2026
[05/Sep/2026
[18/Sep/2026

整台机器只有 5 天在提供服务，中间是大段的关机/停机状态。这也解释了为什么 last 里所有启动记录都显示 still running —— 没有任何一次正常关机记录，都是非正常停机。

处置与优化

P0 止血

# 1. 停掉 OOM 元凶（定时器 + 移除 EPEL 源）
systemctl disable --now dnf-makecache.timer
dnf config-manager --set-disabled epel epel-next epel-cisco-openh264
mv /etc/yum.repos.d/epel*.repo /root/epel-repo-backup/

# 2. 停掉无文件的僵尸服务
systemctl disable --now btwaf

P1 内存参数调优

# 3. 恢复 swap 缓冲（1 GB swap 此前完全闲置）
cat > /etc/sysctl.d/99-tuning.conf <<'EOF'
vm.swappiness = 10
vm.vfs_cache_pressure = 50
EOF
sysctl -p /etc/sysctl.d/99-tuning.conf

# 4. 关闭透明大页（消除 242 MB anon_thp 放大）
echo madvise > /sys/kernel/mm/transparent_hugepage/enabled

P2 参数纠偏

先量后调 —— 实测并发只有个位数，而配置值高得离谱：

$ ss -tn state established '( sport = :80 )' | wc -l
8
$ mysql -e "SHOW STATUS LIKE 'Max_used_connections';"
Max_used_connections    13
参数 原值 调整后 依据
Apache MaxRequestWorkers 800 150 实测并发 6~8
Apache Min/MaxSpareThreads 75 / 250 25 / 75 原 MaxSpare 竟大于 MaxRequestWorkers
MySQL max_connections 500 60 历史峰值仅 13

Apache 用 httpd -k graceful 平滑重载，MySQL 用 SET GLOBAL 动态生效，全程不中断业务。

兜底保护

mkdir -p /etc/systemd/system/dnf-makecache.service.d
cat > .../memory-limit.conf <<'EOF'
[Service]
MemoryHigh=300M
MemoryMax=400M
EOF
systemctl daemon-reload

给 dnf 服务加 cgroup 内存上限 —— 万一再次触发，只杀 dnf 自己，不会拖垮整机。

处置效果

指标 处置前 处置后
日志量 每分钟十几行噪音（占全日志 87%） 30 秒 0 行，完全静默
失败单元 2 个 0 个
load average 峰值 30.11 0.17
Apache 线程数 417 156
swap 使用 0 MB（1 GB 全闲置） 162 MB（缓冲已生效）

经验与预防

1. 小内存机器上，dnf makecache 是一个容易被忽视的定时炸弹。

它在正常服务器上完全无害，但在 1.6 GB 的机器上单进程峰值可达 780 MB。处置方式不是调参数，而是关掉定时器 —— 元数据缓存对这类长期不装包的机器毫无价值。若确需保留，用 cgroup 给它设 MemoryMax 兜底。

2. Restart=always + StartLimitInterval=0 是危险组合。

组件被卸载后，服务单元往往不会自动清理。Restart=always 会把它变成一个永动的日志发生器。正确写法是保留启动限流（如 StartLimitIntervalSec=60 + StartLimitBurst=5），让 systemd 在反复失败后放弃并标记 failed，而不是无限重试。

3. load average 三元组是最好的「故障定时器」。

0.05 / 5.92 / 30.44 这种撕裂形状能立刻告诉你在什么时间窗内找线索。只看单一数值会错过这个信号。

4. OOM 日志要按「触发者 / 受害者 / 旁观者」三层来读。

invoked oom-killer 那行写的是触发者（本例是 httpd，无辜的），Killed process 才是受害者（dnf，也是真正的元凶），而完整任务表里的其他进程是旁观者。只看第一行很容易归错因。

5. 配了 swap 不等于用得上 swap。

vm.swappiness = 0 会让内核在内存耗尽时直接 OOM 而不是换页。OOM 日志里 Free swap == Total swap 就是「swap 形同虚设」的铁证。内存吃紧的机器建议 swappiness 设 10 左右，保留一点换页弹性。

6. 参数配置要「先量后调」。

MaxRequestWorkers 800 / max_connections 500 放在 1.6 GB 机器上是纸面数字。实测并发只有 6~8 个连接，按 10 倍余量给到 150 已足够。拍脑袋的参数比没有参数更危险，因为它给人一种"已经配好了"的错觉。

7. 日志被刷屏会掩盖真正的故障。

本次排查中，87% 的日志是噪音，真正的 OOM 记录差点被淹没。定期检查 journalctl --disk-usage 和日志构成，异常的高频服务要及时处置。