起源
最近一直在跟大佬们做公司项目的性能优化,我这种小卡乐咪基本上负责的就是慢接口优化,但实际上只有以下几种情况需要进行接口代码级别的改造:
- 循环查库、RPC
- 数据库设计不合理
- 业务流程太长,代码耦合性太高等
随着对接口分析的深入,我们越来越发现系统中有很多拖后腿的问题是与业务代码无关的,今天要分享的这个是关于MyBatis大名鼎鼎的第三方分页插件PageHelper
在生成count
语句时,若语句参数数量过大导致的性能问题。
初步发现问题
在对慢接口进行日志分析的时候,我们发现一些count
语句日志的打印较上一行隔了很久,而从代码上来看,到上一行日志打印后,这中间没有做什么耗时操作。
一番排查后,我们发现这种慢的语句具有如下特性:
- 都是来自于分页查询中自动生成的
count
- 都具有大量的参数(示例中是7000+个)
简单排查
虽然我们很怀疑这7000多个参数,这2000ms会不会花在网络IO或数据库查询上了,毕竟这种大量in
的几乎都是全表查询,但冷静下来想一想,根据MyBatis打印SQL的一贯套路,可以推断出这个耗时肯定不是count
语句实际执行产生的IO耗时或网络等待,因为在打印这行语句时SQL应该还没有执行。
插一嘴:由于我们表的数据量并不大,几十万级别,并且有覆盖in查询条件的索引可以利用,这大大减少了要扫描的页面数量,实际
count
语句执行只需要几十ms
在执行到该位置时观察CPU,当时几乎是单核心跑满的,所以当时一定在做一些CPU操作。
至此,已经开始怀疑是语句参数数量过大导致的SQL编译大量耗费CPU,但又考虑到一个现代的CPU不可能被这种简单的任务难住,于是决定jstack抓一下当时CPU究竟在干什么:
从堆栈上看,CPU当时肯定是在编译SQL没跑了,本地运行代码Debug到PageHelper中,也发现最终在getSmartCountSql
中调用jSqlParser.parse
来生成分页SQL时耗费了1到2s:
在count
之后,Mybatis自己也要编译这个具有大量in
参数的SQL,而它只花了6ms,至此已经可以完全断定是PageHelper的性能问题了。
这种纯CPU的性能问题是不可扩展的,若你有一个四核心的CPU,CPU处理的总能力肯定只能在2s钟内执行完4个编译任务,假设有80个并发,这个编译时间只会越来越长。
官方issue中有两个人反馈了这个问题,但官方貌似持摆烂态度2
替换策略
联系大佬移除底层脚手架中的PageHelper,使用MyBatis内部的分页插件,性能回归正常
猜想
由于PageHelper内部使用的JSqlParser
实现是CCJSqlParser
,其是C语言实现的,怀疑是不是在参数量大时需要在native堆栈和JVM堆栈中大量传递数据导致的呢?目前不了解JNI,这个不敢妄下结论了。