记一次MybatisPlus分页查询引起的CPU占用率过高问题排查

最新推荐文章于 2024-06-04 16:21:03 发布

FKJGFK

最新推荐文章于 2024-06-04 16:21:03 发布

阅读量1.5k

点赞数 1

分类专栏：疑难杂症文章标签： mybatis

本文链接：https://blog.csdn.net/FKJGFK/article/details/106617157

版权

疑难杂症专栏收录该内容

2 篇文章 0 订阅

订阅专栏

前段时间一个业务系统上线试运行阶段，总是过一段时间CPU占用率超过100%、200%、300%、400%......900%、GameOver。一般CPU占用异常都是由于代码死循环引起的，但是在开发环境和测试环境却总是无法复现，一头雾水。

既然无法复现，那就在线上环境排查问题吧。

(1)远程连上Linux服务器，重启服务后，用 top命令查看到 cpu占用率的情况。

(2)服务启动后等到系统定时任务出发后，系统CPU持续升高。找到占用率较高的进程PID。然后通过 "ps -mp 进程ID -o THREAD,tid,time"命令查找到占用CPU较高的线程ID。

(3)随后把线程ID通过 printf "%x\n" 线程ID 转换为16进制。

(4)再用 jstack命令查看线程代码信息 jstack 进程ID|grep 线程ID -A 300。

这时就可以定位到出问题的代码相关信息，如下图所示:

定位到业务代码，确实是一个定时任务+循环业务逻辑。既然发现了问题代码，那就好好排查吧。代码如下图所示：

    @Override
	@Transactional(rollbackFor = ServiceException.class)
	public void crewReportTask() {
		try {
			//只查询 0待开始
			int pageNo = 1;
			int pageSize = 500;
			while (true) {
				Page page = new Page(pageNo, pageSize);

				List<DutyTrainBean> entityList = dutyTrainMapper.selectRegularList(page);
				if (!CollectionUtils.isEmpty(entityList)) {
					List<DutyTrain> dataList = new ArrayList<>();
					entityList.forEach(entity -> {
						Long time = System.currentTimeMillis();
						if (entity.getArrivalTimestamp() < time) {
							DutyTrain data = new DutyTrain();
							BeanUtils.copyProperties(entity, data);
							//未出勤
							data.setState(3);
							dataList.add(data);
						}
					});
					//更新状态
					if (!CollectionUtils.isEmpty(dataList)) {
						dutyTrainService.updateBatchById(dataList);
					}
					//终止条件
					if (entityList.size() < 500) {
						break;
					} else {
						pageNo++;
					}
				} else {
					break;
				}
			}
		} catch (Exception e) {
			log.error("执行值乘报告定时任务异常:", e);
			throw new ServiceException(e.getMessage());
		}
	}

这个业务逻辑也不复杂，就是简单地分页查询，然后判断数据、更新数据。

大致一看确实没毛病，仔细一看还是没有陷入死循环的逻辑。本地开发环境数据验证了一下还是没有复现。查询了生产环境表中的数据，因为刚上线数据也才2000+条，符合条件的数据才7条，但为什么就陷入死循环了呢? 结合后台的logback debug日志和druid连接池的sql监控。发现定时任务触发后，一直持续的向数据库更新数据，现象如下图:

这样问题就基本上可以确定了，这个定时任务导致数据库持续插入数据。但数据库中的数据也不多，需要更新的才7条，怎么就陷入一直更新的业务了呢?随便选中一条数据查询执行结果，这么多的Update语句执行后，表中状态还是没有改变。

实在无法找到原因后，就把现场数据库中这个表的数据导出来，单元测试后，问题果然复现了........ 代码陷入了死循环查询，打了断点，发现每次查询的500条数据一模一样，但是分页参数确实在改变。但为什么 1页500条.....2页500条.....数据都是一样的呢? 查看控制台的SQL语句才发现，首次查询时，mybatis 每次执行的sql语句没有改变。即 sql语句中的? ? 只有第一次会赋值，后续的循环中虽然page参数已经改变了，但是执行的sql语句却是没有改变。

查找资料后发现：mybatisPlus 默认开启一级缓存，对查询的语句会存在一级缓存中，如果在一个事务中，mybatis对同一个session多次查询同一个sql语句就会去找缓存而不是再去查一次数据库。

猜测：这里的page参数比较特殊，它的改变并不会在mybatis查询时处理，仍然会从一级缓存中查找结果。

这样除非服务down掉，否者这个循环会一直执行，事务也不提交。

解决办法:

(1) 这个sql查询时不使用一级缓存

mapper.xml 中 select 标签中加上 flushCache="true"属性

(2)更改代码逻辑，不要轻易仅使用page一个参数。

@Override
@Transactional(rollbackFor = ServiceException.class)
public void crewReportTask() {
   try {
      //只查询 0待开始
      List<DutyTrain> entityList = dutyTrainMapper.selectRegularList(System.currentTimeMillis());
      if (!CollectionUtils.isEmpty(entityList)) {
         InBatch.execute2(entityList, 100, (temp, batchIndex) -> {
            //更新未出勤状态
            temp.forEach(entity -> {
               entity.setState(3);
            });
            dutyTrainService.updateBatchById(temp);
            return true;
         });
      }
   } catch (Exception e) {
      log.error("执行值乘报告定时任务异常:", e);
      throw new ServiceException(e.getMessage());
   }
}

把查询出的数据用批量方法截取处理(仅适用于数据量不多的业务)。