背景
在某个项目中开放了一批接口供其他项目调用,需要统计每个人每个接口每一条的调用次数。目前采用的做法是用@Async异步记录日志,@Async对应的线程池配置如下:1个线程,队列1000,超出队列后的处理策略ThreadPoolExecutor.CallerRunsPolicy。之后压测发现同一天有可能出现两条记录。
分析
由于线程池中只有一个线程,相当于将所有请求串行化之后处理,正常是会每天只产生一条记录的。伪代码如下:
@Async(TRACK_TASK)
public synchronized void callTrack(AuthInfo authInfo,String principle) {
LocalDate current=LocalDate.now();
Long authId=authInfo.getOpenApiAuth().getId();
Long apiId=authInfo.getOpenApiInfo().getId();
OpenApiTrack openApiTrack=openApiTrackService.getOne(Wrappers.lambdaQuery(OpenApiTrack.class)
.eq(OpenApiTrack::getDeleteFlag, DataStateConstant.NORMAL)
.eq(OpenApiTrack::getAuthId,authId)
.eq(OpenApiTrack::getPrinciple,principle)
.eq(OpenApiTrack::getApiId,apiId)
.eq(OpenApiTrack::getDate,current));
if(openApiTrack==null){
openApiTrack=new OpenApiTrack();
openApiTrack.setApiId(apiId);
openApiTrack.setAuthId(authId);
openApiTrack.setPrinciple(principle);
openApiTrack.setDate(current);
openApiTrack.setCallNum(1);
openApiTrack.setCreateTime(LocalDateTime.now());
openApiTrack.setDeleteFlag(DataStateConstant.NORMAL);
openApiTrack.setLastUpdateTime(LocalDateTime.now());
openApiTrackService.save(openApiTrack);
}else {
openApiTrack.setCallNum(openApiTrack.getCallNum()+1);
openApiTrack.setLastUpdateTime(LocalDateTime.now());
openApiTrackService.updateById(openApiTrack);
}
}
最后经过压测发现有可能出现同一天多条记录的情况
查看线程情况也确实只有一个Async-track-线程
经过分析发现当前@Async线程池队列超过1000后,新增的任务就会回到调用线程也就是tomcat 工作线程处理,于是tomcat工作线程和@Async中的那个唯一的线程就出现了竞争,于是出现了并发问题。 更深层次的分析是tomcat最大工作线程本来默认是200,但是出于某些原因在项目中调大了工作线程到2200。所以在请求到达@Async注解的方法时就会出现超过线程池队列长度的情况从而引发并发问题。
server:
port: 9083
tomcat:
threads:
max: 2200
处理
-
修改拒绝策略直接拒绝就行 (相对好一些)
-
调大队列(但是当任务达到一定程度还是会有问题,不可行)
-
获取在方法上面增加synchronized (可以看到,就算超出队列长度,最后主调线程执行callTrack还是会因为synchronized串行,正常业务中就会在tomcat工作线程堵塞,影响系统的并发)
结论
在打算使用单个线程的线程池进行任务串行化的时候一定要考虑队列长度和超时队列时的处理策略,否则很容易发生并发问题。而且对于tomcat的配置也要理解其原理,不然有些情况可能不会有问题,一旦修改了配置就会暴露出来。