凌晨两点四十监控系统推过来一条告警某套内部对账系统的 CPU 使用率从日常的 20% 一路窜到 780%。做运维这么些年CentOS 上 CPU 飙高这种事见得太多了大多数时候无非是死循环、GC 风暴、慢查询堆积登上去看一眼 top 就能找到嫌疑人。但这一次不一样从我收到告警到 SSH 彻底连不上中间只有不到十五分钟再往后机器进入了一种很难用语言描述的状态——ping 得通端口不通控制台敲键盘没反应负载高得离谱但 CPU 使用率又掉了下来。这就是典型的 hang 死。我把这次事故从头到尾复盘了一遍把里面用到的判断依据、命令、参数还有当时做错的地方都记了下来。如果你手上也维护着 CentOS 服务器或者正在被CPU 高、系统卡、重启了事这类问题反复折磨这篇东西应该能帮你少走一些弯路。文中涉及的主机名、业务名、人员一律做了脱敏处理只保留技术事实。1. 把时间线捋直从告警响起到彻底失联1.1 十五分钟里到底发生了什么事后我把监控、sar 历史数据、钉钉告警记录、还有当时同事的聊天记录全部拼在一起还原出了下面这条时间线。这条线是整个排查的骨架没有它后面所有的分析都是瞎猜。时间点系统现象我当时做的事02:38CPU 使用率 22% 跳升到 63%没当回事以为是夜间批处理正常波动02:41CPU 冲到 310%load1 从 2.1 涨到 18开始登录SSH 有明显卡顿02:44CPU 780%load1 62swap 开始有出页登录成功top 里看到大量 java 进程处于 D 状态02:47load1 148CPU 使用率反而回落到 45%意识到不对开始抓现场02:50SSH 新连接超时老会话敲一个字符卡三秒手忙脚乱地收集信息02:53完全无响应ping 通22 端口不通只能上带外控制台03:05带外控制台也刷不出登录提示符决定断电重启这里面最值得注意的一点是 02:47 那个拐点。CPU 使用率从 780% 掉到了 45%如果只看 CPU 这一个指标你会以为故障自己好了但 load 还在继续涨。很多人卡在这一步以为机器没事了实际上真正的雪崩才刚刚开始。提示CPU 使用率下降而 load 持续上升几乎可以断定是大量进程进入了不可中断睡眠D 状态。这时候机器不是闲下来了而是干不动了。1.2 CPU 高和 hang 死是两码事这两件事经常被混为一谈但它们的成因、排查路径、处置方式完全不同必须先掰开。CPU 高指的是 CPU 时间被大量占用系统仍然在正常调度只是跑得慢。这种情况哪怕 CPU 打到 100%你照样能 SSH 登录照样能敲命令只是命令返回慢一点。绝大多数CPU 高的故障属于这一类处置起来相对从容。hang 死指的是系统失去了响应能力进程调度、内存分配、IO 提交这些基础动作都卡住了。它往往不是 CPU 本身的问题而是某个资源被打穿之后引发的连锁反应——内存耗尽导致全局回收回收过程中又要等 IOIO 又因为队列堆积变得更慢最后所有进程都堵在 D 状态上连 sshd 都没机会被调度到 CPU 上。所以我在现场看到 load 飙到 148 而 CPU 只有 45% 的时候脑子里第一个反应就是这不是 CPU 的锅CPU 是被连累的。后面查到的结果也印证了这一点真正的引爆点在内存和磁盘写回那条链路上CPU 只是这条链路上最先叫出声的那个指标。理解这个区别有什么用用处在于如果你的直觉是CPU 高就去 kill 进程在 hang 死场景下大概率会失败。因为 kill 命令本身也要走调度系统调度不动的时候你连发信号都发不出去。1.3 三条判据帮我先定方向在还没完全失去登录能力的那几分钟里我只来得及看三个东西但就是这三个东西把方向定死了。我把它们称为三条判据建议你直接背下来。第一条看 CPU 时间被谁吃掉了。top顶部那一行%Cpu(s)里us是用户态、sy是内核态、wa是 IO 等待、hi和si是硬中断和软中断。这次我看到的是sy高达 38%wa12%us只有 30% 出头。用户态不高但内核态很高说明进程大多时间在跟内核打交道——申请内存、提交 IO、等锁而不是在算东西。第二条看 load 高的时候 CPU 到底累不累。用vmstat 1连看十秒r列运行队列和b列阻塞进程数如果一起涨那就是 CPU 争抢和 IO 阻塞同时存在如果r不动而b猛涨基本就是 IO 或锁的问题。第三条看 swap 有没有动静。vmstat里的si和so两列只要不是持续为 0就说明物理内存已经不够用了内核在往外倒页面。这次so一直在 2000 到 8000 之间跳等于宣判了内存这条路有问题。三条判据凑在一起方向就很清楚了内存压力大导致内核频繁回收回收过程产生大量 IOIO 把磁盘打满进程堵在 D 状态load 被推高最终调度器被拖垮。CPU 高只是这个链条中间的一个表征。2. 登录不上的时候还能抓哪些现场2.1 SSH 卡住不等于系统全死这是很多人第一次遇到 hang 死时最容易犯的错一看 SSH 连不上直接打电话让人去机房按电源。按下去的那一刻现场证据就全没了下次大概率还会再犯一次。实际上系统假死的时候很多东西还是活的。网络协议栈由内核处理所以 ping 通常还通TCP 三次握手在 backlog 队列里可能还能完成只是 sshd 进程抢不到 CPU所以连上了也不回包。我在 02:50 那次新开的 SSH 会话就是这么个状态——ssh -v能看到Connection established然后卡在密钥交换一直不动。这时候值得尝试的还有几个入口。一是老会话如果还留着别关用~加回车看看能不能挂起二是带外管理口IPMI、iDRAC 这类虽然这次也没救回来但它是唯一不依赖操作系统的通道三是如果有串口重定向或者 SOL能看到内核打印的 panic 或 hung task 信息这些信息价值极高。我事后反思最该做但没做的一件事是在 02:44 登录成功的那三分钟里先跑一个信息采集脚本把该存的都存下来而不是急着去看 top。人在紧张的时候容易凭直觉行动结果就是三分钟过去了什么也没留下。2.2 Magic SysRq 的正确用法和风险Linux 内核有一组应急调试接口通常叫 Magic SysRq通过组合键或者/proc/sysrq-trigger触发。在系统还没彻底死透的时候它能帮你把大量关键信息打到内核日志里。先确认开关状态cat /proc/sys/kernel/sysrqCentOS 7 的默认值一般是 16这个数字是位掩码16 只允许执行sync。要开启全部功能得临时改成 1echo 1 /proc/sys/kernel/sysrq注意改成 1 之后任何能写/proc/sysrq-trigger的人都能触发重启甚至崩溃。生产环境用完要立刻改回去改成 16 或者干脆改成 0。下面是几个我在现场用到的、相对安全的触发方式# 打印当前所有任务的状态包括运行队列和阻塞情况 echo t /proc/sysrq-trigger # 单独打印处于 D 状态的进程及其内核调用栈这个最有价值 echo w /proc/sysrq-trigger # 打印内存使用详情包括各 zone 的 free、slab、swap 情况 echo m /proc/sysrq-trigger # 打印所有 CPU 上正在执行的代码栈用于判断是哪个路径在吃 CPU echo l /proc/sysrq-trigger这些输出都会落到dmesg里事后可以用dmesg -T | grep -A 20 blocked for more than捞出来。w那一条尤其重要它能把每个 D 状态进程卡在哪个内核函数上直接告诉你——是卡在io_schedule、wait_on_page_writeback还是卡在某个文件系统的锁上一目了然省掉大量猜测。还有一个echo c /proc/sysrq-trigger作用是主动触发内核崩溃。这个命令只有在配置了 kdump 并且需要抓 vmcore 的时候才用因为它的副作用就是让机器立刻宕机。这次事故我没用因为当时判断现场信息已经够分析了而且 kdump 预留内存只有 512M抓全量 vmcore 大概率不够。2.3 靠 sar 和监控回放事故现场机器活着的每一分钟sysstat都在后台记录数据。默认情况下每 10 分钟采一次保留 7 天落在/var/log/sa/目录下。这份数据在事后复盘时的价值比现场那三分钟手忙脚乱抓的东西还要高因为它有完整的趋势。重启之后我做的第一件事就是回放当天的数据# 查看当天 CPU 使用情况从 02:00 开始看 sar -u -s 02:00:00 -f /var/log/sa/sa15 # 查看队列长度和 load sar -q -s 02:00:00 -f /var/log/sa/sa15 # 查看内存和 swap sar -r -s 02:00:00 -f /var/log/sa/sa15 # 查看块设备 IO sar -d -s 02:00:00 -f /var/log/sa/sa15 # 查看网络 sar -n DEV -s 02:00:00 -f /var/log/sa/sa15把-u、-q、-r、-d四份输出按时间对齐来看因果链就非常清楚了。02:38 内存可用量开始快速下降02:41%vmeff页面回收效率掉到 30% 以下说明回收开始变得吃力02:43 磁盘tps从 800 涨到 12000await从 3ms 涨到 400ms02:45 之后blocked列开始上涨。有一点要提醒sar默认的采样间隔是 10 分钟对于十分钟内就崩掉的故障来说粒度太粗了。我在加固阶段把它调到了 1 分钟代价是磁盘占用从每天几 MB 涨到几十 MB这个代价完全值得。2.4 重启之前的信息保全清单如果你判断机器已经救不回来准备重启那么在按下按钮之前尽量把下面这些捞出来。哪怕系统已经卡得厉害只要还能执行单条命令就一条一条试。dmesg -T /tmp/dmesg.log内核日志里面有 OOM、hung task、IO 错误cat /proc/meminfo内存分布重点看Dirty、Writeback、Slab、SUnreclaimcat /proc/loadavg五个数值最后一个是最近调度的 PIDps -eo pid,ppid,stat,pcpu,pmem,wchan:30,comm --sort-pcpu | head -50wchan列会告诉你进程卡在哪儿cat /proc/diskstats磁盘累计计数可以用来算重启前的瞬时 IOls -l /proc/*/fd 2/dev/null | wc -l文件句柄总数排查泄漏ipcs -a共享内存和信号量Java 应用有时会在这里出问题这些命令都不重即使是卡死的系统单条执行通常也能在十几秒内返回。我把它们写成了一个脚本放在所有机器的/root/emergency.sh用nohup后台跑输出到本地磁盘。这次是事后才补的下次就能用上。3. 把 CPU 高的锅分清楚用户态、内核态、IO 等待3.1 top 的第一眼该看什么top谁都会敲但真正看懂的人不多。我见过太多人上来就看进程列表按 CPU 排序取第一名就开杀。这个做法在简单场景下有效在复杂场景下会把你带沟里。正确的顺序是先看顶部汇总行。CentOS 7 的top把 CPU 时间拆成了us、sy、ni、id、wa、hi、si、st八项。这里面的信息量很大us高说明是应用自己在算可能是死循环、正则回溯、加密运算、GC。sy高说明系统调用密集可能是内存分配、文件读写、网络收发、锁竞争。wa高说明 CPU 在等 IO这时候 CPU 其实是闲的真正忙的是磁盘。si高说明软中断处理占用了大量时间最常见的是网卡收包和定时器。st非零说明这台机器是虚拟机宿主机把 CPU 抢走了。这次故障在 02:44 那一刻我看到的sy是 38%wa12%si5%。sy这么高基本上就把嫌疑范围缩小到了内核路径上。再往下看进程列表排在前面的是kswapd0、kworker、还有几个java。kswapd0出现在 CPU 榜首这件事本身就是内存不足的铁证——这个内核线程只有在需要回收页面的时候才会被唤醒。提示top里如果看到kswapd0长期占据 CPU 前列别犹豫先去看内存。这时候去优化应用代码是南辕北辙。3.2 vmstat 的 r 和 b 两列才是重点top是瞬时快照vmstat才能看出趋势。我习惯用vmstat 1 20连看二十秒重点盯四组数字。第一组是r和b。r是运行队列长度也就是等着上 CPU 的进程数b是不可中断睡眠的进程数。正常情况下r应该接近 CPU 核数b应该在个位数。这次我看到r稳定在 60 以上b从 5 涨到 90 多两个都爆表说明 CPU 和 IO 两条路同时堵死。第二组是si和so。这两个是 swap 的换入换出速率单位是 KB/s。只要持续非零就说明物理内存已经不够用了。这次so峰值到过 8000 多意味着每秒往外倒 8MB 的匿名页而这些页面很快又会被读回来形成恶性循环。第三组是bi和bo。块设备的读写速率。bo突然放大到几十万 KB/s通常意味着有大量脏页在被强制回刷。第四组是cs和in。上下文切换和中断次数。cs高说明锁竞争激烈或者进程频繁阻塞唤醒in高说明有设备在疯狂发中断。这四组数字组合起来看能快速判断出故障属于哪一类。我总结了一张对照表平时排查时对着看就行。现象组合大概率原因下一步动作us 高r 高b 低应用 CPU 密集死循环或计算量大perf top 找热点函数sy 高cs 高r 高锁竞争、系统调用密集pidstat -w 看上下文切换大户sy 高kswapd0 高so 非零内存不足回收压力大看 /proc/meminfo 的 Dirty 和 Slabwa 高bo 高b 高IO 打满脏页回刷跟不上iostat -x 看具体设备si 高in 高软中断风暴多为网卡/proc/softirqs 看分布us 低wa 高r 低b 高存储侧故障可能是硬件或网络存储dmesg 找 IO error3.3 内核态高的几种典型来源sy高不像us高那么直观它的来源比较分散我在实际工作中遇到过的主要有这么几类。第一类是内存回收。当空闲内存低于水位线内核会唤醒kswapd做后台回收回收不动的时候还会触发直接回收direct reclaim这时候申请内存的进程本身会被拖进回收流程在sy里体现得非常明显。这次的故障就属于这一类后面会详细拆解。第二类是文件系统操作。大量小文件的创建删除、目录遍历、日志轮转都会消耗大量内核时间。特别是当目录下文件数量过万的时候一次ls都可能让sy飙起来。第三类是网络收包。高并发短连接场景下si会显著升高。如果网卡没开多队列所有软中断都压在一个核上那个核会 100% 而其他核闲着。用mpstat -P ALL 1能一眼看出来。第四类是锁竞争。内核里的自旋锁、互斥锁一旦争抢激烈CPU 就在原地空转。perf top里如果看到大量_raw_spin_lock、mutex_lock之类就是这个原因。第五类是系统调用本身的开销。比如fork一个进程要复制页表mmap一块大内存要维护 VMA 结构这些操作在量大的时候都会推高sy。当时我甚至怀疑过是不是有进程在疯狂 fork后来用pidstat -w看了下cswch/s和nvcswch/s没有异常才排除了这个可能。3.4 IO 等待会伪装成 CPU 高wa这一项很容易被误读。wa高的时候CPU 实际上是空闲的只是top把它从id里扣出来单独显示了。如果你只看总的CPU 使用率会以为 CPU 很忙其实它在干等。但这中间有个陷阱IO 等待本身不会让 load 上升太多可一旦 IO 队列排长新的 IO 请求进来就得排队进程从 R 状态转为 D 状态load 就上去了。而 D 状态进程在 Linux 里是计入 load average 的。所以你会看到一个奇特的现象CPU 使用率不高wa却很高load 也高。这次故障里02:47 那个拐点就是这么来的。脏页回刷把磁盘队列打满后续所有需要写盘的操作都要排队包括 Java 应用写日志、数据库刷 redo、内核写元数据。进程一个个掉进 D 状态load 从 62 涨到 148而 CPU 因为无事可做使用率反而降下来了。判断这一类问题iostat -x 1是最直接的工具。重点看三个值%util接近 100% 说明设备已经饱和await超过 20ms机械盘或 5msSSD说明响应变慢aqu-sz老版本叫avgqu-sz持续大于 2 说明排队严重。iostat -xd 1 5如果%util到了 99% 以上同时await是平时的几十倍那就别再纠结 CPU 了问题在磁盘上。这时候要查的是谁在拼命写盘、写的是什么、能不能限流。4. 定位到代码我用的三件套4.1 pidstat 找嫌疑进程top只能告诉你哪个进程总体吃 CPUpidstat能把它拆到线程级别还能同时看 CPU、内存、IO、上下文切换四个维度。这个工具属于sysstat包CentOS 上一般都有没有的话yum install sysstat一条命令搞定。我当时的用法是这样的# 每 2 秒采样一次共 5 次按线程拆分看 CPU 和 IO pidstat -u -d -t -p 12345 2 5-t这个参数是关键它会把进程下的每个线程单独列出来。Java 应用动辄几十上百个线程不拆开根本看不出是谁在捣乱。这次拆开之后发现GC task thread和几个业务线程池的线程 CPU 占用都在 30% 上下但真正异常的是一个叫log4j2-appender的线程CPU 不高可它每秒要写 400MB 的日志。顺带说一句pidstat的两个好用参数。-w看上下文切换能发现锁竞争-r看内存能发现内存增长趋势-s看栈使用。另外pidstat -d的kB_wr/s列是排查谁在疯狂写盘的利器比iotop轻量得多服务器上没装iotop的时候可以直接用它顶上。4.2 perf top 看热点函数pidstat告诉你是谁perf告诉你在干什么。在用户态 CPU 高的时候perf top能直接列出热点函数名运气好的话一眼就能看到业务代码里的某个方法。# 实时看全系统热点按 CPU 排序 perf top # 只看某个进程 perf top -p 12345 # 采样 30 秒后保存用于事后分析 perf record -F 99 -g -p 12345 -- sleep 30 perf report -i perf.data-F 99是采样频率99Hz 是个经验值既能采到足够多的样本又不会给系统太大压力。-g是记录调用栈这个参数很重要没有它你只能看到叶子函数不知道是谁调用的。在内核态高的时候perf top里看到的往往是__alloc_pages_slowpath、shrink_page_list、try_to_free_pages、balance_dirty_pages这类内存管理相关的函数。这次我看到的排在前面的正是shrink_page_list和try_to_free_pages直接把方向指向了内存回收。注意CentOS 7 上perf默认可能没有装用yum install perf装。另外如果要看内核符号的完整名字需要装对应内核版本的kernel-debuginfo包比较大几百 MB但排障时确实省事。4.3 jstack 抓线程栈这次故障的最终定位是在 Java 侧确认的用的就是jstack。# 先确认 Java 进程的启动用户必须用同一个用户执行 ps -o user -p 12345 # 抓一次线程栈 jstack -l 12345 /tmp/jstack_$(date %s).log # 如果进程响应很慢用 -F 强制 dump但会暂停进程 jstack -F 12345 /tmp/jstack_force.log-l参数会额外输出锁信息包括Locked ownable synchronizers排查死锁时必不可少。-F要慎用它会用信号强制挂起进程在 hang 死的场景下可能直接把进程搞崩。抓下来的栈要连着抓三次间隔 5 秒然后对比。单次栈只能看到快照三次对比才能看出哪些线程一直在同一个位置——那些就是真正卡住的线程。这次三次抓下来有一批线程稳定卡在FileOutputStream.writeBytes上说明写日志这个动作本身被阻塞了进一步印证了磁盘写不动的判断。4.4 磁盘和内存的交叉验证单看任何一个维度的数据都容易误判交叉验证才能定案。我当时的验证动作是这几步。第一步确认磁盘是不是真的满了。df -h看了一眼/用了 71%不紧张但iostat显示vda的%util是 100%说明不是空间问题是吞吐问题。第二步确认是什么在写。pidstat -d 1 5显示 java 进程kB_wr/s是 380000也就是每秒 380MB。这个数字远超磁盘的实际写能力那块盘顺序写实测 200MB/s 左右。第三步确认脏页积压了多少。grep -E Dirty|Writeback /proc/meminfo显示Dirty: 11403264 kB也就是 10.9GB。这个数字非常吓人说明有 10.9GB 的数据在内存里等着落盘。第四步确认内存回收在干什么。cat /proc/vmstat | grep -E pgscan|pgsteal|allocstall看到allocstall_normal在几分钟内涨了几十万说明直接回收被频繁触发。四步走完因果链彻底闭合应用写日志太快脏页积压回刷跟不上直接回收被频繁触发回收本身又要读写进一步加重 IO 压力最终形成正反馈。5. 这次的真凶一条被忽略的参数链5.1 复盘DEBUG 日志加全表扫描重启之后我回到应用侧查很快就找到了源头。前一天傍晚有个版本上线改了两处一处是把日志级别从 INFO 调成了 DEBUG一处是新增了一个对账明细导出功能导出时会对一张三千万行的表做全表扫描把结果全部加载到内存。DEBUG 日志这一改动的影响远超预期。原本这个应用每小时写 200MB 左右的日志改成 DEBUG 之后每小时写 40GB 以上翻了 200 倍。三台应用服务器同时写平均每秒有 300MB 以上的写盘请求。而全表扫描那个功能是运营在凌晨两点半手动触发的对账业务习惯在夜里跑批。三千万行的结果集加上 MyBatis 默认的fetchSize没设一次性全部拉进 JVM 堆直接把堆打到 24GB 上限触发 Full GC。GC 期间应用的写日志线程被 STW 暂停积压的日志在 GC 结束后瞬间倾泻形成写盘洪峰。这两个因素叠在一起就构成了完整的引爆条件。单独一个 DEBUG 日志磁盘可能扛得住单独一次全表扫描内存也扛得住。两个一起来就成了这次事故。提示日志级别变更和批量任务上线是运维侧最容易忽略的两类变更。很多团队有代码发布流程但没有配置变更流程而配置变更引发的事故一点不比代码少。5.2 脏页回刷的参数算术这里要说清楚一个关键点为什么每秒写 380MB 会把系统拖死而不是简单地写慢一点。Linux 的内存管理里有一组参数控制脏页行为默认值是这样的参数默认值含义vm.dirty_background_ratio10脏页占比达到该值后台回刷线程开始工作vm.dirty_ratio20脏页占比达到该值写进程被强制阻塞并同步回刷vm.dirty_expire_centisecs3000脏页超过 30 秒会被强制回刷vm.dirty_writeback_centisecs500后台回刷线程每 5 秒醒一次这台机器 64GB 内存按默认值算dirty_background_ratio10% 就是 6.4GBdirty_ratio20% 就是 12.8GB。也就是说脏页涨到 6.4GB 时内核开始后台刷涨到 12.8GB 时所有写操作被卡住等着刷完。问题出在时间差上。后台回刷从 6.4GB 开始到 12.8GB 结束中间只有 6.4GB 的缓冲空间。按每秒 380MB 的写入速度这 6.4GB 只够撑 17 秒。而磁盘的实际回刷能力只有 200MB/s净流入是 380 - 200 180MB/s脏页还是会涨。17 秒之后脏页突破 12.8GB所有写进程被强制阻塞进入同步回刷。同步回刷期间应用写日志的线程全部进 D 状态线程池被占满业务请求开始堆积连接数上升内存进一步吃紧。这就是那个正反馈的起点。我在事后调整了这几个参数# 降低后台回刷门槛让脏页早点开始落盘 vm.dirty_background_ratio 5 # 降低强制阻塞门槛缩短单次阻塞的时间 vm.dirty_ratio 10 # 缩短脏页过期时间从 30 秒改成 10 秒 vm.dirty_expire_centisecs 1000 # 提高回刷线程的唤醒频率 vm.dirty_writeback_centisecs 100这样调整之后脏页上限从 12.8GB 降到 6.4GB后台回刷从 3.2GB 就开始缓冲窗口虽然小了但脏页积压的绝对量被控制住了不容易出现长时间的全员阻塞。这里没有绝对最优值要看磁盘能力和业务写入模式我的做法是在压测环境里从 5/10 开始试逐步往下调。5.3 swap 反而加重了问题这台机器开了 16GB 的 swap放在一块机械盘上。开 swap 的初衷是防止 OOM 直接杀进程但在这个场景下它起到的是反作用。当 JVM 堆被打满、物理内存不足时内核开始把匿名页换出到 swap。问题在于 swap 分区在机械盘上随机读写性能极差一次换出可能就要几十毫秒。而内存回收是同步进行的换出慢回收就慢申请内存的进程就卡住。更糟的是被换出的页面很快又会被访问于是又换回来。这种换入换出的抖动对磁盘的压力比单纯写日志还大。vmstat里si和so同时飙高就是这个抖动的典型特征。我的处理是把 swap 关掉swapoff -a同时把vm.swappiness从默认的 30 调到 10。这样做的逻辑是与其让系统在 swap 上痛苦挣扎不如让 OOM killer 快速杀掉那个真正吃内存的进程把系统保住。一个有 OOM 记录的服务器远比一台 hang 死需要断电的服务器要好处理。注意关 swap 之前一定要确认机器的内存水位和应用的实际需求。如果应用本身就需要超配内存才能跑关 swap 会直接导致 OOM 频发。这是权衡不是教条。5.4 修复方案与压测验证定位清楚之后修复分了三层。第一层是应用侧也是根本。日志级别改回 INFO同时对日志做了采样正常请求只记摘要异常请求记全量写入量从 40GB/小时降到 1.2GB/小时。全表扫描的导出功能改成分页查询每批 5000 行fetchSize显式设为 1000结果集不再一次性进内存。第二层是系统侧。调整了脏页参数关掉了 swap把vm.swappiness设为 10同时把kernel.hung_task_timeout_secs从 120 调到 30让内核更早地在日志里报出卡住的进程便于下次快速发现。第三层是监控侧。加了几个之前没有的指标脏页占比、kswapd0的 CPU 占用、磁盘await、D 状态进程数。每个指标都配了阈值告警比只看 CPU 使用率靠谱得多。验证是在压测环境做的。用fio模拟 400MB/s 的持续写入同时用脚本模拟 200 并发请求跑 30 分钟。调整前系统在第 8 分钟进入 D 状态堆积调整后脏页稳定在 3GB 上下await峰值 18ms没有出现阻塞。这个结果说明参数调整是有效的但真正的保障还是应用侧的日志量降下来了。6. 常见问题速查与避坑6.1 排查误区对照表下面这些坑有些是我自己踩过的有些是看别人踩过的。整理成表遇到事的时候对着看一眼能省不少时间。误区实际情况正确做法CPU 高就 kill 排第一的进程可能杀掉的是受害者而非元凶先看 us/sy/wa 的分布再定位load 高就是 CPU 不够load 包含 D 状态进程结合 CPU 使用率一起判断SSH 连不上就是要重启系统可能只是调度不过来试带外、试老会话、试 SysRq内存用了 95% 就是有问题page cache 会主动占满内存看 available 和 swap 活动swap 用了就是内存不足少量使用是正常的看 si/so 速率而不是绝对量重启就完事了现场丢失问题必然复发重启前采集信息事后复盘看 Kubernetes 的 Pod CPU那是 cgroup 限制内的值上宿主机看实际占用6.2 应急命令速查表我把自己常用的命令整理了一张表贴在工位上也同步到了团队的文档里。目的命令看 CPU 时间分布top或mpstat -P ALL 1看运行队列和阻塞vmstat 1 20看内存明细free -m、cat /proc/meminfo看脏页积压grep -E Dirty|Writeback /proc/meminfo看进程 IOpidstat -d 1 5看磁盘饱和iostat -xd 1 5看线程级 CPUpidstat -u -t 1 5看上下文切换pidstat -w 1 5看软中断分布cat /proc/softirqs看卡住的内核栈cat /proc/PID/stack需 root看 D 状态进程ps -eo stat,wchan,pid,comm | grep ^D看 OOM 记录dmesg -T | grep -i out of memory看 hung taskdmesg -T | grep blocked for more than回放历史数据sar -u -q -r -d -f /var/log/sa/saXX6.3 我踩过的三个坑第一个坑是太相信top里的 CPU 使用率。前面说过top显示的 CPU 使用率是100 - id在某些版本里并不包含wa和st所以你看到 40% 可能实际已经被占用了 70%。判断系统忙不忙看id那一项最准。第二个坑是忽略了kswapd0。这个内核线程平时几乎不占 CPU一旦出现在top前十名基本可以断定内存有压力。我早期排查时曾经把它当成普通进程忽略过去结果多花了一个多小时。第三个坑是在系统卡死的时候还在敲复杂命令。比如ps aux | grep java这种带管道的命令在调度不灵的时候可能卡住不返回反而耽误时间。后来我改成直接用ls /proc/PID看目录是否存在用cat /proc/PID/stat读单个文件这些操作不依赖 shell 管道成功率更高。还有一个不算坑但值得记一笔的经验dmesg的输出会被环形缓冲区覆盖默认缓冲区大概 128KB 到 512KB系统忙的时候内核日志刷得飞快几分钟前的信息就没了。所以在故障初期就要用dmesg -T /var/log/dmesg-$(date %s).log落盘动作要快。7. 事后加固把下次定位时间压到几分钟7.1 必须补的监控指标只看 CPU 使用率做监控等于闭着眼睛开车。这次事故之后我把监控指标从原来的 8 个扩到了 20 多个其中最关键的几个是这样的。内存侧看三个可用内存不是使用率、脏页占比、swap 换出速率。其中脏页占比这个指标很多团队都没有但它恰恰是这次事故的直接前兆。IO 侧看三个设备%util、读写await、队列深度。await这个指标特别实用它能比%util更早地反映出存储性能下降。进程侧看两个D 状态进程数、kswapd0的 CPU 占用。前者超过 10 个就该告警后者超过 5% 就该查内存。内核侧看两个hung_task计数、OOM 计数。这两个指标平时都是 0一旦非 0 就是明确的故障信号。采集频率也要调整。原来 10 分钟一次对于十分钟内崩掉的故障来说等于没有数据。我把它改成了 1 分钟同时把sysstat的保留天数从 7 天延长到 14 天磁盘代价大概每天多占 40MB完全可以接受。7.2 内核参数调整除了前面说的脏页参数和 swap这次还调整了几个和排障相关的内核参数都是为了让系统在出问题的时候多留一口气。# 让内核更早报出卡住的进程默认 120 秒太长 kernel.hung_task_timeout_secs 30 # 开启 hung task 检测 kernel.hung_task_check_count 4194304 # 保留 panic 后自动重启的行为 kernel.panic 10 # 控制内核日志输出级别避免刷屏掩盖关键信息 kernel.printk 4 4 1 7 # 允许未授权用户读 dmesg 的开关生产环境建议关掉 kernel.dmesg_restrict 1 # 内存不足时倾向于杀占用最大的进程而不是随机杀 vm.oom_kill_allocating_task 0 vm.panic_on_oom 0 vm.overcommit_memory 0kernel.panic 10这一条值得单独说。它的作用是内核 panic 之后 10 秒自动重启配合 kdump 使用可以在保留 vmcore 的同时让机器自动恢复。对无人值守的服务器来说这比等着人去机房按按钮靠谱得多。vm.overcommit_memory 0是启发式超配默认值就是 0我这里明确写出来是因为有些团队为了防 OOM会设成 2结果导致malloc直接失败反而引发更奇怪的问题。除非你非常清楚自己在做什么否则保持 0。7.3 一个应急采集脚本最后贴一个我写的应急采集脚本放在/root/emergency_collect.sh所有机器都部署了一份。它的设计原则是只用最基础的工具不依赖外部组件每条命令加超时避免自己把系统卡死。#!/bin/bash # 紧急信息采集输出到 /var/log/emergency/ OUT/var/log/emergency/$(date %Y%m%d%H%M%S) mkdir -p $OUT run() { local name$1; shift timeout 15 $ $OUT/$name.log 21 } run dmesg dmesg -T run meminfo cat /proc/meminfo run vmstat vmstat 1 10 run loadavg cat /proc/loadavg run ps_dstate ps -eo pid,ppid,stat,pcpu,pmem,wchan:32,comm --sort-pcpu run diskstats cat /proc/diskstats run netstat ss -s run iostat iostat -xd 1 3 run mpstat mpstat -P ALL 1 3 run fdcount bash -c ls -l /proc/[0-9]*/fd 2/dev/null | wc -l # 抓 D 状态进程的内核栈 for pid in $(ps -eo pid,stat | awk $2 ~ /^D/ {print $1}); do timeout 5 cat /proc/$pid/stack $OUT/stack_$pid.log 21 done tar czf $OUT.tar.gz -C $(dirname $OUT) $(basename $OUT) rm -rf $OUT echo collected to $OUT.tar.gztimeout 15是关键每一条命令最多跑 15 秒超了就放弃。这样即使系统卡得厉害整个脚本也能在几分钟内跑完不至于自己变成新的负担。D 状态进程的内核栈单独抓因为这是诊断 hang 死最有价值的信息。脚本跑完之后会打包成一个压缩包我一般顺手用scp传到另一台机器上避免重启后随本地磁盘一起丢。如果网络也不通那就只能指望本地磁盘那就先别重启。这套东西上线之后同类问题又出现过两次都是因为别的业务上线时改了配置。但这两次从告警到定位到具体进程分别只用了 6 分钟和 11 分钟没有再出现过 hang 死。回头看真正的转折点不是那几个内核参数而是把脏页和D 状态进程这两个平时没人看的指标纳入了监控——它们比 CPU 使用率更早、更准地告诉你系统正在往悬崖边上走。