问题反馈
接到实施同事反馈线上某医院的服务导出数据比较久,大数据导出导致服务暂时卡死,影响其他服务正常运行,需要帮忙排查解决,数据量在百万级别。
分析调试工具
IDEA(需要插件arthas idea)
Postman
Windows PowerShell
分析过程
- 分析环境准备
- idea启动服务并安装插件”arthas ide”,方便快捷使用arthas 命令
- 官网下载解压arthas,进入目录,右键”此处打开PowerShell”,执行如下启动命令
java -jar .\arthas-boot.jar
- 选择需要分析的服务序号,比如现在要分析的server服务序号是2
- 确定需要分析的方法,获取trace指令
需要分析的数据导出接口方法如下
具体方法为getPatientExportData:
右键选择trans指令,如下图:
可获取如下可执行指令,复制到刚才的power shell中执行
trace com.xxxx.server.business.PatientDataBusiness getPatientExportData -n 5 --skipJDKMethod false
结果如下:
- 分析初次耗时数据
此时使用postman发起数据导出请求,powershell可获得方法执行耗时数据,如下:
可直观看见该接口耗时21324.2375ms,[90.45% 19288.7202ms ] java.util.List:forEach() #1543,该循环为主要耗时,查看1543行代码是什么情况,如下图:
发现数据拆分集合为5000,可能过大,调整拆分集合大小为1000,验证修改结果
- 分析调整数据拆分处理集合大小为1000
接口耗时17287.8971ms,[90.54% 15652.7592ms ] java.util.List:forEach() #1543,有效但是区别不大
考虑多线程处理,使用list的并发流处理
- 循环处理改为并发流处理
接口耗时15445.9318ms,[90.62% 13996.4388ms ] java.util.stream.Stream:forEach() #1543 优化效果不加,继续分析耗时点,循环体代码太长,将该部分代码优化成一个方法,方便分析代码耗时。如下图:
- 分析循环体方法代码耗时
trace com.xxxx.server.business.PatientDataBusiness extractedData -n 5 --skipJDKMethod false
发现耗时代码主要是:buildCheckReportData() #1747行代码,是一个方法体耗时,继续跟踪该方法
- 分析buildCheckReportData()方法耗时
trace com.xxxx.server.business.PatientDataBusiness buildCheckReportData -n 5 --skipJDKMethod false
发现是一个数据库配置查询耗时严重[96.47% 3.6172ms ] com.xxxx.biz.util.VteDetectUtil:getConfigurationByKey() #2475
跟踪该方法,发现该数据直接查数据库,查询次数过多导致耗时严重
优化该方法走缓存,降低数据库查询性能损耗。
优化之后,耗时大大降低。结果从3ms优化至0.02毫秒。分析主要问题是由于多次循环嵌套,该位置频繁查询数据库导致耗时。验证修改,整体耗时再次查看如下:
修改有效,验证成功,该循环体时间从[90.45% 19288.7202ms ] java.util.List:forEach() #1543降低到[27.58% 443.4449ms ] java.util.stream.Stream:forEach() #1543,性能提高了43倍。
优化结果
数据导出性能提高43倍