mybatis批量更新导致cpu100%

1.1 线上问题的表现:cpu间歇性的100%

mybatis批量更新导致cpu100%

1.2问题定位:线程dump

mybatis批量更新导致cpu100%

当时准备用top -p pid -H,来查看哪个jvm进程中那个线程占用的cpu最高的时候,发现cpu已经降下去了,所以没办法定位是哪个线程占用cpu最高.在线程dump文件中全文搜索业务包名称,意外的发现只有如下这个代码是业务系统开发人员自己写的代码:
*.*ExtService.publish(java.lang.String, java.lang.Long) @bci=201, line=384 (Interpreted frame)
怀疑是这个地方导致的问题,这个方法里面有一个foreach+update的操作
mybatis批量更新导致cpu100%

1.3.梳理代码逻辑,发现这个list的数据是从 某个表的info字段获取的.找到这个表的最近的100条数据,按照order by length(info)排序.发现第一条数据的info字段存储的是一个json数组,元素个数是2770.

1.4本地环境复现问题.
测试环境拷贝线上的info到测试环境数据库中,然后本地调试代码.发现本地的cpu占用超过100%,复现了问题.

1.5 top -p pid -H
发现占用cpu最多的是14364=0x381c,占用99%

mybatis批量更新导致cpu100%

1.6 本地线程dump
14364=0x381c
mybatis批量更新导致cpu100%

在16:24:42,16:26:37,16:27:30这三个时间做的线程dump,0x381c这个线程都是在执行
*.*ExtService.publish->*MybatisInterceptor.intercept->MybatisInterceptor.showSql这个方法调用栈.所以应该是MybatisInterceptor这个拦截器耗用cpu资源很多.

mybatis批量更新导致cpu100%

1.7 优化

1.7.1去掉拦截器MybatisInterceptor
mybatis.xml去掉引入
MybatisInterceptor拦截器的代码

mybatis批量更新导致cpu100%

1.7.2将2700一次性提交,改为分批次提交

有拦截器 一次性提交 500提交一次 100 10
总耗时 5.9min 1min 38s 2.5min
线程占用cpu最大值 99% 90% 40% 10%
去掉拦截器 一次性提交 500提交一次 100 10
总耗时 40s 16s 25s 2.5min
线程占用cpu最大值 60% 41% 17% 8%

结论:
相同条件下,发现去掉拦截器后,cpu占用和时间显著降低.
去掉拦截器,500提交一次,有最快的响应时间16s.

1.8总结
1.8.1
本次线上问题cpu100%的问题很大一部分是由于*MybatisInterceptor这个拦截器的showSql方法,for循环替换问号,这个方法有性能问题.当update,insert,delete类型的sql的长度很长并且sql里问号比较多的时候(本例中最多2700个问号),会导致频繁计算,cpu飙升.对于这个问题,需要去掉拦截器.

mybatis批量更新导致cpu100%

1.8.2
除此之外,如果一次性更新的数据超过500的时候,mybatis做sql解析和问号替换的时候效率也很慢,所以建议分批次更新数据,500条数据更新一次.

mybatis批量更新导致cpu100%

1.8.3
*ExtService.publish方法里面涉及到10次数据库读写,而且好几个select和update没有走索引,导致效率低下.所以目前最快的16s还有优化空间.