一次被“隐形错误”折磨了三个通宵的血泪史
先看今日请求日志里这个接口的访问量
凌晨两点，服务器负载突然飙到95%，CPU温度直逼85度，我瘫在椅子上，盯着屏幕上疯狂滚动的错误日志，眼睛都快瞎了，这已经是我连续第三晚干到这时候了，旁边的烟灰缸里堆满了烟头，手边的红牛罐子排成一排,像极了我的绝望。
说出来不怕你笑话，让一个做了5年运维的老手栽跟头的，不是什么惊天动地的大故障，而是一个躲在日志海洋里的“隐形错误”。
踩坑实录：日志多到“看不到”问题
那天下午，我给客户部署了一个新的PHP商城系统，部署完测试一切正常，我还悠闲地泡了杯茶，可到了晚上11点，客户就开始疯狂打电话：“网站打不开了！后台卡成狗！” 我赶紧SSH登录服务器,一眼就看到宝塔面板的负载曲线像坐火箭一样冲上去。
按照老习惯，我直接点开“日志”->“网站日志”查看，好家伙！几万行请求日志刷刷地往外冒，全是正常用户的访问记录，我只扫了一眼，“嗯，流量不小。”然后马上切到“错误日志”选项卡，想找系统报错，结果发现，错误日志只有零星几条PHP Notice级别的警告，什么“Undefined index: xxx”之类的,都是些不影响运行的小毛病。
我一看，心想难道是流量太大，服务器扛不住了？于是开始加带宽、调PHP进程数、开Opcache缓存，折腾了两个多小时，CPU负载暂时降下来一点，结果第二天白天，负载又上去了，客户抱怨更狠了：“你们到底行不行？”
报错截图描述：藏在“正常”里的异常
那天晚上，我终于注意到一个细节：日志滚动速度真的太快了，按理说一个日IP不到5000的小商城，不应该有这么高的日志量，我截了一张图（描述一下）：宝塔面板的实时日志监控窗口里，一行行日志像瀑布一样往下刷，每一行都长得差不多,大概长这样：
[2025-01-15 02:33:17] 203.0.113.45 - "POST /api/order/query HTTP/1.1" 200 342 "Mozilla/5.0" 0.142s
[2025-01-15 02:33:17] 203.0.113.46 - "POST /api/order/query HTTP/1.1" 200 341 "Mozilla/5.0" 0.143s看起来正常啊！全返回200状态码，响应时间都在0.14秒左右，IP虽然不同，但很多个IP长得像兄弟一样——同一个C段的地址，访问的都是同一个API路由，诡异的是，我手动curl测这个接口，返回结果正常,也没报错。
这时候，我总算意识到问题可能出在别的地方，排查思路彻底转变：不是所有200状态码都代表一切正常，日志量大本身就是异常信号。
我开始用宝塔面板自带的“日志分析”功能，筛选出访问频次最高的IP段和URL，结果发现：有将近200个IP，在过去24小时内疯狂轮询那一个订单查询接口，平均每个IP请求了3000多次，更坑爹的是，这些IP有80%都是来自同一家CDN节点，但因为CDN回源用了不同的出口IP,在日志里看起来就像是不同用户。
解决方案：一条grep命令帮我省下3天青春
找到问题根源后，我打开了SSH终端,直接跳到服务器日志目录：
cd /www/wwwlogs/cat www.xxx.com.log | grep "/api/order/query" | wc -l # 输出：386742 —— 38万次！难怪服务器懵了。
然后我大概看了一下客户端信息，发现所有请求的User-Agent都一样：“MallApp/3.2.1”，这就确定了：是客户那边的前端App写了个死循环轮询,而且没做防抖。
但日志还在暴涨啊！在客户修复App之前，我总不能干等着,我赶紧在宝塔面板里做两件事：
- 关闭日志记录到文件（临时）：在网站设置 -> 日志 -> 关闭“开启访问日志”，这能让日志写磁盘的压力立刻消失,把CPU从日志输出中解放出来。
- 设置日志过滤规则：宝塔Nginx防火墙里，添加一条“UA过滤规则”，拦截User-Agent包含“MallApp/3.2.1”的所有请求，直接返回444状态码（断开连接，不返回任何内容）,这样Nginx连日志都不写了。
操作完毕后，我执行了一下实时监控：CPU负载从95%直接掉到15%，仅仅用了三分钟！我盯着屏幕，差点哭出来，想想之前加带宽、调参数折腾的几个通宵,真的全是冤枉路。
预防建议：日常运维的“三板斧”
经过这次教训，我给自己服务器搞了一套“日志防坑三板斧”，现在分享给你,少走弯路：
第一板斧：日志量预警一定要开。 宝塔面板的监控设置里，有一个“日志告警”功能，设置一个规则：每分钟日志行数超过500行就通知你，发现日志量暴涨，不要去想“是不是业务变好了”，第一反应先检查是不是被攻击了,或者出Bug了。
第二板斧：日志不要一股脑全存。 不是所有日志都需要保留，在“网站设置”->“日志配置”里，可以设置哪些状态码记录、哪些不记录，我一般只记录4xx和5xx错误，以及关键业务的日志，正常200请求，除非在做安全审计，否则直接关闭日志记录到文件，真的需要排查问题时，用宝塔的“实时日志”功能临时打开即可。
第三板斧：日志分析要养成习惯。 每天抽5分钟，看一眼“日志分析”里的TOP 10访问IP和URL，你会发现很多隐患：某个API被高频轮询、某个IP段在暴力破解、某个URL返回了大量错误，这些小信号，往往是重大故障的“天气预报”。
尾声与忠告
那次之后，我把客户那边的App开发狠狠批了一顿，他们也不敢吭声，因为确实是他们的死循环代码作妖，但我也反思：如果早一点注意到日志量激增这个信号，如果能早点用日志过滤来做排查，而不是凭经验瞎猜,那三个通宵根本不用熬。
最后送你一句话：在运维的世界里，日志不是用来翻看的，是用来过滤的。 你的眼睛和时间都有限，真正有价值的问题信号，往往被淹没在大量正常日志里，学会过滤,比学会看日志更重要。
真到了服务器崩溃的那一刻，你没有时间去翻几天前的日志，你能依靠的只有你设置好的日志过滤规则和告警机制，别像我一样，等被日志淹了才想起救生圈，早点配置好,晚上睡安稳觉。
（写完这篇文章，我把我的宝塔面板全部重配了一遍，现在每天只花5分钟看日志，省下来的时间全在摸鱼。）
发表评论