实习踩坑之路：一个诡异的SQL？PageHelper莫名多了一个Limit子句，导致SQL执行错误？

Posted 2022-01-03 会写代码的花城

问题复现

昨天晚上上线，业务上回归测试都很正常，但是就在那时，突然爆了一个SQL执行异常，告警群中看到这个SQL是这样的

这怎么有两个Limit拼在一起了？是我SQL写错了么？
然后我第一反应就是这个SQL写错了，但是我定位了这个Mapper文件，发现并没有这一条SQL是拼了两个limit语句的，然后在师兄提醒的情况下，认为是上个线程的（分页插件拼接的）ThreadLocal变量没有被清除，也就是说，有可能是分页插件要拼这个limit，但是还没执行到mysql查询，报错了，这个现场的limit 1000就被别的业务抢到了这个线程，恰好新业务需要走SQL，就直接拼接到了新的SQL中。

知道了问题所在，就要排查那个线程出了问题，通过日志，我拿到了这个线程的名字pool-21-thread-40，很明显这是线程池中的一个线程，也就是说他可以被重复利用，这点我更加确信是线程之间搞串了。
通过阿里云的日志服务，我搜索了这个线程号，得到了下面的信息
报错的时候




我连续找了附近这个线程干了什么事，大概就是在推WS，发送MQ、还有就是同步ES数据(双写)/（查询）
也没有什么太有用的信息，所以我跟另一小伙伴把目标转移到了代码上，既然这个1000是以参数传递的，那我们就在全局搜索了1000发现有几个分页插件，参数设置的是1000，我们就开始一个一个排查，但最终都没有发现问题，那些分页插件内部并不会报错，导致limit 1000走不到Mysql。

为什么PageHelper多了一个Limit子句

例如有一段业务代码如下, 在第二行转换Date时因为requestNo字段为null报错, 导致执行了startPage却没有执行SQL, 从而影响了后续SQL的执行, 为什么会影响到后续SQL的执行呢?

PageHelper.startPage(pageNo, pageSize);
Date createdAt = DateTimeKit.parseFromCompactDateTime(request.getRequestNo().subString(0, 14));
List<XxxDO> list = xxxxMapper.selectByCreatedAt(createdAt);

我们使用的是Dubbo体系, 每一个请求从Dubbo线程池中获取一个线程执行业务, 执行结束后, 线程不会被销毁, 而是归还回Dubbo线程池.

而PageHelper通过使用ThreadLocal保存某个线程下的分页信息, 正常情况下, 第一行保存, 第三行使用并清除. 第二行异常时, 第一行保存, 没有执行第三行, 所以就没有从ThreadLocal中清理掉该线程的信息. 该线程就被归还回了Dubbo线程池

当另一个请求重新使用该Dubbo线程的时候, 执行第一条SQL时, PageHelper检查到ThreadLocal中有该线程的分页信息, 这时就会改写该线程, 添加了一些不可预料的内容, 导致最终报错

破局

但是我们没放弃，继续在全局搜索1000的情况下，终于发现了一点端倪，我们第二次把目标转移到了定义了1000的局部变量的地方，突然发现有个代码后面的修改日期是今天(IDEA插件可以看到)，然后我们就开始分析他的上下文，发现这个是自旋查询ES数据的方法，但是他想走分页查询，诶，问题找到了
上代码：

问题就在listByConversationQuery(xxxx).getDate()这个地方，因为我们是多分支并行开发项目，可能当时并没有特别在意，以为走了实体，肯定是走Mysql查询了，但是其实并不是，这个方法里面只是走了ES的查询，这样就导致上面开启了分页，但是limit 1000并没有被消除，导致这个线程就有个limit 1000一直在。
等到这个查完了，线程被复用，恰好就走到了刚才报错的地方，直接给这条SQL拼了一个limit 1000，然后修改思路就是不走分页插件，因为查询的是ES，直接走ES查询就行了，至此问题解决

如何规范使用分页插件

推荐的解决办法是遵守PageHelper的使用规范, 在分页和执行SQL之间不要有其他的内容, 防止万一, 从根本上避免异常发生

也可以手动从PageHelper的ThreadLocal中移除当前线程的信息, 通过Aop或者抓异常啥的, 但是这个就比较low了