1. 从一次“用户说慢”到实际定位,我走过的弯路
先说当时的具体场景。那是一个再普通不过的工作日早上,运营突然在群里反馈:后台管理页面的数据刷新很慢,一个列表接口平时 300ms 左右,现在经常要 2、3 秒,部分操作甚至直接超时。第一反应是看网络,ping 了一下网关和外网,延迟正常,没有丢包。接着远程登录服务器,uptime一看,负载均值已经到了 7.8,而在正常情况下,这台 8C16G 的机器负载基本稳定在 1.5 以内。到这里基本可以确认:问题不在网络侧,而是服务器本身负载不正常。
但我最初犯了一个很多运维人都会犯的错误——凭直觉去查 CPU 和内存。top进去按 CPU 排序,看到的是一堆 Java 进程(这台机器上跑着 Spring Boot 服务),CPU 占用率虽然在波动,但并没有哪个进程高到离谱,整体 us 占比也只有 30% 左右。内存更是充足,16G 的内存只用了 9G。那负载 7.8 是从哪来的?我盯着这个数字发了一会儿呆,然后做了一个后来回头看纯属浪费时间的动作:重启了应用服务。结果你们也猜得到,服务起来之后负载短暂降到 2 左右,但不到 20 分钟又慢慢爬了上去。
重启没用,那就说明问题不是某个服务进程临时卡死,而是有持续的资源消耗源在周期性起作用。这时我才冷静下来,重新用系统化的方式走了一遍排障流程。回头看,前 40 分钟基本都耗在了“想当然”上面:先入为主地认为是应用本身出了问题,却没有从系统的角度去观察“负载到底消耗在了哪里”。
如果当初第一时间就去关注vmstat里的 r 和 wa 两列,或者直接看pidstat的线程级数据,定位时间至少可以缩短一半。这也是最想先分享的一点:服务器变慢,第一步不是盯着某个进程猛看,而是先搞清楚慢的“类型”——是 CPU 密集、IO 密集、内存不足导致换页,还是线程阻塞。不同类型的慢,对应的排查工具和方向完全不同。
2. 负载高但 CPU 不高的典型形态:把等待时间算进去
回到当时的数据。当我重新用vmstat 1 5采集时,输出大概是这样的:
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 8 1 0 512340 120450 4023340 0 0 512 340 2100 4300 30 25 45 0 0 10 0 0 510220 120480 4023400 0 0 480 320 2350 4820 32 28 40 0 0注意看cs(context switch,上下文切换)这一列,每秒 4000 多次,配合r列(运行队列)长期在 8-10,这明显不是空闲状态。但 CPU 的 us 和 sy 加起来也只有 55% 上下,还有 40% 的空闲。这就形成了一个看起来矛盾的画面:CPU 明明有空闲,系统却觉得“忙不过来”。
为什么?因为负载均值统计的是处于可运行状态和不可中断睡眠状态的进程数。当一个进程频繁地在可运行和睡眠之间切换,或者大量线程同时去争抢某个资源(锁、IO、CPU 时间片)时,虽然每个线程单次占用的 CPU 时间很少,但整体上会让运行队列变长,负载自然被拉高。
当时我用pidstat -w 1看了进程级的上下文切换数据,发现一个名为check_data_sync.sh的进程,cswch/s(自愿上下文切换)特别高,每秒 700 多次,远高于其他进程。这是个非常关键的信息:自愿上下文切换高,说明这个线程或进程经常在等待某些条件满足——很可能是等待 IO、等待锁、等待网络响应。非自愿上下文切换高,则说明它被系统强制剥夺 CPU,通常意味着 CPU 资源竞争激烈。
这个脚本的名字一看就知道是个定时任务。顺着ps -ef看到的 PID,我去/proc/<PID>/cmdline里确认了完整的执行路径和参数,然后ls -l /proc/<PID>/cwd找到了它的工作目录,再配合cat /proc/<PID>/status里的内存、线程数信息,基本拼出了这个任务的轮廓。到这一步,距离元凶只差最后一步——找到定义它的 crontab 条目。
3. 定位到“元凶”之后:这个定时任务为什么能拖垮整台机器
先说说最终发现的问题本身。在/var/spool/cron/root和/etc/crontab里,我找到了这样一个条目:
*/5 * * * * /opt/apps/scripts/check_data_sync.sh >> /opt/apps/logs/data_sync.log 2>&1每 5 分钟跑一次脚本。表面上看没什么大不了的,但拆开脚本内容就发现问题了。脚本里做的事情大概是:遍历一个数据目录下的大量小文件,逐个做 md5 校验,然后通过 HTTP 请求把校验结果同步给另一个服务,每个文件一次请求。
问题出在三个叠加因素上:
- 脚本没有加锁,也没有防重入机制。上一次执行还没跑完,下一次执行又被 cron 触发,于是同一时间可能有五六个脚本实例在同时扫描文件、发 HTTP 请求。
- HTTP 请求是同步阻塞的,而且没有设置超时时间。目标服务某次处理变慢后,请求全部堆积,脚本实例像滚雪球一样越积越多。
- 脚本里用了大量的
find和md5sum,每个文件都要独立 fork 一次子进程。大量短生命周期进程反复 fork,直接拉高了系统上下文切换。
我记得当时pstree看到的结果非常直观:连续几层的check_data_sync.sh子进程,同一时刻有 6 个实例在跑。也就是说,这个任务从半小时前就开始出现积压,之后每 5 分钟追加一个新实例,越积越多,最后把整个系统的任务队列塞满了。
更隐蔽的一点是,它的 IO 消耗其实并不大,因为文件都很小,bi/bo都不高。它真正消耗的是进程调度资源——每个文件的 md5sum 运算都要占用一点点 CPU,短暂到可能只反映在 0.1% 的利用率上,但几十万个文件叠加起来,再加上 HTTP 请求的同步等待,进程的等待、唤醒、切换就成了压倒系统的最后一根稻草。
这种“单个任务不显眼、叠加后拖垮系统”的特性,正是定时任务类问题最难排查的地方。top里看到的 CPU 大头永远是 Java 应用,因为它的瞬时占比最高;但真正让系统过载的,可能是一个 CPU 占 3%、状态却是 R 的脚本。
另外一个值得说的小细节:当时dmesg里没有 OOM 记录,磁盘也没有报错,内存、IO、CPU 三个维度表面看起来都正常,只有上下文切换和运行队列异常。如果只看“资源四大件”,很容易得出“系统没毛病,是应用的问题”这种错误结论。
4. 定时任务这个“隐形坑”:cron 本身不背锅,但设计者很容易写错
很多人听到定时任务导致服务器变慢,第一反应是“cron 真坑”。但实际上 cron 只是个到点触发器的角色,它不会去判断上一个任务是否执行完毕,也不会替你考虑并发问题。真正容易被写错的,是任务本身的设计。结合这次的教训,我总结了定时任务最常见的四个隐性坑。
并行堆积是最常见的一种。脚本执行时长超过触发间隔,cron 到点照样拉新实例。解决办法有两个方向:一是脚本内部做单实例控制,二是把触发间隔拉长,确保上一次执行能完成。单实例控制最标准的做法是用flock:
*/5 * * * * /usr/bin/flock -xn /var/lock/check_data_sync.lock -c /opt/apps/scripts/check_data_sync.sh-x表示排他锁,-n表示拿不到锁就直接退出,不等待。这样即使上一个实例还在跑,下一个时钟周期也不会再起新进程,而是跳过本次执行。实测下来,这是防重入成本最低、效果最稳定的方案。
不设置超时是第二个大坑。脚本内部的 HTTP 请求、数据库连接、网络读写,如果没设置超时时间,一旦下游服务异常,任务就会永久卡在等待状态。日积月累,僵尸进程和堆积线程会让系统越来越慢。
第三个坑是任务时间扎堆。很多定时任务都爱配置成整点执行,比如每天的 00:00、每小时的第 30 分钟,或者像这次一样每 5 分钟。一旦某个时点上有多个重任务同时启动,瞬间的系统负载会非常高。合理的做法是给不同任务设置不同的偏移量,比如 A 任务在第 3 分钟跑,B 任务在第 8 分钟跑,错开峰值。
第四个坑最容易忽略:脚本产生的日志没有做切割和清理。这次排查时我顺手看了一眼data_sync.log,发现已经涨到 4.7GB 了。日志文件过大不仅占用磁盘,还会让日志写入变慢,进而拖慢脚本本身的执行速度,间接加剧任务堆积。定期用logrotate做切割,是每个跑着定时任务的机器都应该有的基础配置。
平时写脚本的时候多花十分钟考虑这四点,能省下后面排查时至少两小时的痛苦。
5. 这次排查里真正起作用的命令组合,以及它们各自的定位
工具不在多,在于用得准。这里复盘一下我真正用到、并且从结果上证明有效的那几条命令链路。不是因为其他命令没用,而是这次问题的数据特征刚好和这几个工具的定位匹配。
全局视角用的uptime+vmstat。uptime看负载均值趋势,vmstat看运行队列、上下文切换、IO 等待、CPU 各态占比。这两条是排障起点,它们决定了下一步应该往哪个方向走。特别是vmstat的cs列,如果长期高于两三千,就要警惕上下文切换过载。
进程视角用的top+pidstat。top适合快速浏览,但要真正定位到具体线程、具体进程的上下文切换情况,还得靠pidstat:
pidstat -w 1 5 pidstat -wt 1 5-w看进程,-wt看线程。输出里cswch/s和nvcswch/s两列直接告诉你这个进程每秒发生多少次自愿/非自愿切换。这次能快速锁定脚本,就是因为它的 cswch/s 一骑绝尘。
文件与进程的映射用的是lsof和/proc文件系统。拿到 PID 后,我通过ls -l /proc/PID/fd看到了脚本打开的日志文件路径,通过/proc/PID/cmdline看到了完整命令行。这些信息帮助我在没有任何监控平台的情况下,也能还原出任务的完整面貌。
定时任务排查用的是crontab+ 日志。排查的顺序是:先crontab -l看当前用户的 crontab,再看/etc/crontab和/etc/cron.d/目录下的分文件,最后排查/var/spool/cron/。cron 执行记录默认会写入/var/log/cron(CentOS/RHEL 系),可以通过它核对任务的实际执行时间和频率:
grep check_data_sync /var/log/cron | tail -30比如我看到日志里:
Jul 25 10:30:01 appserver CROND[24555]: (root) CMD (/usr/bin/flock -xn /var/lock/check_data_sync.lock -c /opt/apps/scripts/check_data_sync.sh)和脚本内单独记录的开始/结束时间戳对照,就能算出来每次执行到底用了多久,是不是已经超过了触发间隔。
这里顺便提一句,dmesg在排查时也别跳过。它记录的是内核环形缓冲区里的消息,像 OOM、IO 错误、CPU 过热降频这类硬件和内核级问题,在常规命令里看不出来,但dmesg里会留下痕迹。这次虽然没用到它的告警信息,但确认“没有硬件层面的异常”也是排障闭环的一部分。
6. 从这场事故里沉淀出的排查顺序框架,和几条通用的判断规则
排障经验永远是从具体场景里长出来的。把这次的完整链路捋一遍,其实可以抽象成一个可复用的顺序框架:先定性,再定位,最后止血和优化。
定性的意思是先回答“系统慢在哪个维度”。用vmstat看 CPU/内存/IO/上下文切换的画像,用uptime看负载趋势,用free看内存是否吃紧,用iostat看磁盘是否到了瓶颈。四个维度里,哪个异常明显,就往哪个方向深挖。如果都正常,那就直接怀疑进程层——很可能是某个进程单方面消耗了某种资源,但还没有达到系统告警阈值。
定位的意思是找到“问题进程和它的来源”。这里除了top、pidstat,还有一个很常用但我这次没来得及用的命令是perf top,它能直接从内核层面告诉你 CPU 到底在跑哪些函数。如果遇到的是 CPU 100% 的问题,perf top往往比top更精准。而在没有perf的机器上,strace -p PID可以实时跟踪进程的系统调用,看看它到底卡在read、write还是socket上,也是一个非常有效的补充手段。
止血和优化的意思也分两步:先把影响消除,再把根因修掉。这次的实际操作顺序是先用pkill把堆积的脚本实例全部杀掉,让系统负载立刻降下来,应用服务恢复正常响应。然后才是改脚本加锁、加超时、调整执行策略。
再分享一个通用的判断规则:一个进程的 CPU 占用率不高,但系统负载很高,优先怀疑三类情况。第一,不可中断睡眠的进程偏多,通常是 IO 卡住,sysstat里的wa或iostat的%util会告诉你答案。第二,上下文切换过高,大量短命线程在频繁切换,pidstat -w可以验证。第三,僵尸进程在系统进程表里堆积,ps aux | grep defunct一眼可查。
这套规则几乎可以覆盖所有“负载高但 CPU 正常”的奇怪场景。以后再遇到类似问题,不用再从零开始猜,可以直接按这四个方向逐一排查。
7. 二十多分钟的收尾加固:从修复根因到防止复发
定位到元凶只是排障的第一步,真正考验功力的是怎么让它不再复发。当时我按优先级做了几件事,每件事都有明确的理由。
第一件是给脚本加单实例锁。用flock -xn包住整个脚本主体,确保同一时间只有一个实例在跑。这样即使脚本执行超过 5 分钟,也不会再有新的实例堆积。这是最根本的止血方式,从进程数量上杜绝了问题再次出现。
第二件是给脚本内部的 HTTP 请求加超时。我用的是curl --connect-timeout 5 --max-time 15,保证每个请求最多等待 15 秒。这样即使目标服务挂掉,脚本也能快速失败退出,而不是永久阻塞在那里。设置超时时间时注意平衡:太短容易误判正常慢请求,太长又起不到保护作用。对内部服务,5 秒连接、15 秒总时长是比较合理的初始值。
第三件是拆分执行逻辑。原先脚本把文件遍历和 HTTP 同步耦合在一起,导致单次执行时间很长。我把文件扫描和发送请求拆成了两步,分别放到不同的时段执行:扫描步骤只负责生成待同步清单,发送步骤从清单里分批读取,每批 100 个文件,处理完后记录断点。这样不管数据量多大,单次任务都能在一个周期内完成,不会像之前那样越积越多。
第四件是配置日志轮转。用logrotate给data_sync.log设置按天切割、保留 7 天,并在切割后自动压缩:
/opt/apps/logs/data_sync.log { daily rotate 7 compress delaycompress missingok notifempty copytruncate }copytruncate这个参数值得特别提一下:它会先复制日志内容到一个新文件,再清空原文件,这样脚本持有文件句柄也不会因为日志被移动而写丢内容。
第五件是加监控告警。虽然机器没有部署额外的监控平台,但我直接用系统自带的方式补了一层基础告警逻辑:写了一个简单的 shell 脚本,每 5 分钟检查一次/proc/loadavg,如果 1 分钟负载超过 6,就往群机器人里推一条通知。这种方式比较轻量,适合没有集中监控体系的小规模服务器场景。
8. 关于这次事故的复盘总结:排障的顺序感比“知道命令”更重要
很多教程会把top、vmstat、iostat这些命令单独拎出来讲,讲完就完事了。但实际排障的时候,真正的难度不在于不认识这些命令,而在于不知道在什么场景下该用哪一条、排到什么阶段该切什么视角。这次 2 小时的排障经历,有 40 分钟花在误判上,有 30 分钟花在翻日志确认信息上,真正定位和修复只用了不到二十分钟。如果我能更早意识到“负载高不等于 CPU 忙”,也许整个过程可以在 30 分钟内结束。
还有一个特别想强调的点:排障的时候,永远要对进程的“来源”保持敏感。看到一个叫check_data_sync.sh的进程时,不要只关心它当前占了多少 CPU,还要追问它是谁拉起来的、从哪个 crontab 来的、它的完整执行链是什么、有没有潜在的重入风险。这条追问链,恰恰是定位定时任务问题的核心方法。很多人卡在中间,是因为只看“进程本身”而忽略了“进程从哪里来”。
经过这次事故,我现在对新配置的定时任务有一条硬性校验标准:每加一个定时任务到线上机器之前,必须确认脚本内部有单实例保护;必须有超时控制;必须清楚它的最长执行耗时,确保不和其他任务重叠;日志必须有轮转。四点缺一不可。宁可多花十几分钟在设计阶段把问题想清楚,也绝不在事后花几个小时去盯着负载曲线猜原因。系统排障靠的不是灵感,而是一套稳定的排查动作和一次次的复盘沉淀。