问题现象
9点多,运营同学反馈系统某模块业务响应很慢,登录系统查看,后端接口响应耗时很久,需要好几秒;
查看对应的服务器资源情况,cpu使用率80%左右(10点多之后cpu使用率90%+),内存使用率70%左右,系统负载不低(服务器4核),波动比较厉害,10点多之后1min负载达到40左右;
初步排查+调整
问题现象1:查看stackTrace+pinpoint,获取数据库连接在等待;
问题现象2:大量的fullGC;下图是相关服务运行一段时间后的gc采集信息,FullGC的次数超过了YoungGC的一半;猜测是新生代太小,导致触发了大量的full gc;
针对上面两个问题点进行调整,适当增加了应用的jvm新生代内存大小(由1G调整为1.5G),增加了数据库连接池的大小;更新服务后发现系统响应仍然很慢;
gc的情况有明显改善,但数据库连接仍有大量的等待;观察mysql的连接使用是充足的;
保存了一个dump的文件,留待后面分析;
临时解决措施
扩容了一个节点,均分流量,系统响应正常,cpu、负载显著下降;cpu使用率降到40%左右,系统1min负载降到5以下;
问题二次定位+原因分析
-
分析异常时段,其他的业务服务响应正常,确认只有某一个服务有异常;
-
基于前面保存的dump分解分析,发现应用druid的mysql连接池大小调整未生效,查看对应的配置,应用程序配置了多个数据源,业务调整,新增了数据源配置,新增的数据源被定义为@Primary(两个数据源使用的是同一个物理db),调整的是原来业务定义的数据源连接池大小,故不生效;
-
正确调整连接池大小后,流量切换到原来的节点上,问题仍存在;可疑点:jstack中分析发现大量http线程池在等待锁(mysql获取连接或者释放连接时的锁)。查看dump文件,连接池中仍有缓存的连接,连接和释放连接时正常的;说明本次不是连接池大小不够,翻源码没有找到头绪;
-
查看MySQL的thread cache,发现过低,不到70%
-
将thread_cache_size由32调整为64后,变动时段的thread缓存命中率提升为83.2%左右,后调整为96,命中率超过90%,符合预期;然后将流量全部切换到原来的节点上,运行一天,系统响应耗时正常,和最开始一个节点运行时对比,业务高峰期的cpu、内存、系统负载情况,内存使用率略有增长(jvm调大了512M),CPU偶尔80%+,基本稳定在75%以下,系统负载比之前有明显下降。
-
在上一步的基础上,业务高峰期增加系统的负载(压缩大文件),CPU使用率90%以上,系统负载上升,系统接口响应耗时很长,和最开始的问题现象类似;文件压缩结束后,响应恢复正常;后发现MySQL还有一些其他的需要优化点,另服务器本身的负荷比较高,需要扩容;
为什么会出现异常
- 基于请求分析,系统响应慢的前一天服务升级,有一个核心的业务行为进行了调整,导致系统的qps上升了一倍