压测到 800 QPS 就上不去,P99 是 600ms,CPU 只有 30%。把日志级别从 info 调到 warn,P99 立刻回到 45ms。日志里能对上时间点,这种反而好排。
每条日志都走同步 write,调用线程要等磁盘写完才返回,磁盘 IO 一抖就整段阻塞。事件循环被这些写入切成碎片,请求排队时间跟着涨。这一点先确认清楚,后面就不用反复试。
const winston = require('winston');
const logger = winston.createLogger({
transports: [new winston.transports.File({ filename: 'app.log' })],
});
围绕「同步日志阻塞」排查时,命令行跑一遍比在面板里点十次有用,面板会替你做掉不少隐式操作。偶发问题先统计频率,一小时几次和一天一次,查法完全不同。
改完顺手把文档补一句,省得下次自己重新推一遍。监控和日志的时间要对上,时区不一致会多绕很大一圈。
临时改动用注释写上日期和原因,过两周自己都记不清为什么这么写。
处理上按这个顺序:换成异步 transport 或者先写内存队列再批量落盘;生产环境给 debug 和 info 采样 不要全量;日志目录别和数据库数据盘共用;压测前后对比 P99 和磁盘 await。
结果对不对很好判断,同样 800 QPS 下 P99 回到 50ms 左右 磁盘 await 不再出现尖峰。
