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

问题复现

昨天晚上上线,业务上回归测试都很正常,但是就在那时,突然爆了一个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了

本图文内容来源于网友网络收集整理提供,作为学习参考使用,版权属于原作者。
THE END
分享
二维码
< <上一篇
下一篇>>