现场是这样的。发布新版本后接口 P99 从八十毫秒涨到两百六十毫秒,数据库监控一切正常,CPU 使用率反而降了一点,JVM 是 11,堆四 G。
中间走过弯路,把「新引入的序列化库走反射,单次开销变大」当成主因,改完现象没变。
把日志和配置对完,能解释这个现象的基本就这几处。新版本产生大量临时对象,Young GC 频率翻倍;日志级别被改成了 DEBUG,每条请求都拼字符串;线程池队列从无界改成有界,排队时间变长。
动手时先对比发布前后的 GC 次数与停顿
jstat -gcutil $(pgrep -f order-service) 1000 30
然后抓一份火焰图看热点在哪
perf record -F 99 -p $(pgrep -f order-service) -g -- sleep 30
接着确认日志级别是否被改动
curl -s http://10.0.0.11:8080/actuator/loggers/root | head -c 200
末了核对当前发布版本号
curl -s http://10.0.0.11:8080/actuator/info | head -c 200
怎么算真的好了,看的是同一批现象。关掉 DEBUG 并减少临时对象后,Young GC 次数回到发布前水平,P99 降到九十毫秒以内。
发布后延迟回退先看 GC 和日志级别,这两项最容易被忽略;手上有版本对比基线,定位能快一半。这类问题最好一次改到位,反复小改反而容易把原因搅混。
