小记:本地服务耗时和上游调用显示耗时相差过大问题排查及优化
问题
在最近一次压测时发现了一个现象:监控显示服务端p995耗时只有15ms左右,调用方的耗时却高达2000ms,二者相差巨大。
定位过程
查看cpu
查看了压测期间的cpu数据,发现cpu使用率只有20~30%,说明并不是cpu阻塞引起的调用方耗时高
查看jvm
查看了压测期间的jvm数据,发现压测期间并没有出现full gc和年老代垃圾回收,young gc的次数和耗时也并没有过多的上涨
问题缩小
排除了cpu和jvm后,猜测可能是处理网络链接的rpc框架的线程池出现了积压所致。
因为服务启动时并没有显式的设置线程池数量,使用的默认配置。查询了rpc框架的文档,发现其默认线程池数量是30,队列深度是30000。
根据这个数据推测是过少的线程池数量和过大的队列深度,导致了上游调用出现了积压,导致上游的耗时过长
改进
当前的容器是8核,一次请求平均耗时是15ms,那么一秒可以处理的线程数是 8*1000/15=533。考虑到cpu调度会占用一些时间,最终设置了450个线程数,900个队列深度。
结果
调整了线程池配置后,在同样的qps的情况下,上游调用方的耗时和本地服务端耗时相差就很小,当然cpu使用率也上升了。
小结
用餐厅来类比:厨师相当于cpu、餐桌数量相当于rpc框架线程池、 服务端耗时相当于客人到餐桌后吃饭所需时间、客人从来到离开时间是服务端调用时间。
如果厨师不忙,客人到餐桌后吃饭所需时间不长,但客人从来到离开时间确很长,就说明是餐桌过少,增加餐桌就可以了。