之前写了很多资料,不过都是自己整理没有公开,如果大家感兴趣可以看下我在码云整理的资料
不过上面的资料都是随手记得,没有很好地归类梳理,有空会慢慢整理放到博客中。只有不断梳理和整理才能不断地加深记忆和提高
最近在使用@Async注解进行异步处理的时候发现一个奇怪的问题,在项目正常使用的时候没有问题,而在使用junit测试的时候异常
问题描述
代码如下:
启用异步注解
@Configuration
@EnableAsync
public class TaskPoolConfig {
@Bean("taskExecutor")
public Executor taskExecutor(){
ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
executor.setCorePoolSize(10);
executor.setMaxPoolSize(20);
executor.setQueueCapacity(200);
executor.setKeepAliveSeconds(60);
executor.setThreadNamePrefix("taskExecutor-");
executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
return executor;
}
}
使用@Async做异步操作
@Autowired
StringRedisTemplate stringRedisTemplate;
@Async("taskExecutor")
public void doTaskOne() {
log.info("开始做任务一");
long start = System.currentTimeMillis();
long end = System.currentTimeMillis();
stringRedisTemplate.opsForValue().set("kipeng","hello world");
String value = stringRedisTemplate.opsForValue().get("kipeng");
log.info("完成任务一,耗时:" + (end - start) + "毫秒");
}
junit测试代码
@Test
public void testTask() {
task.doTaskOne();
}
执行结果如下:
:: Spring Boot :: (v2.0.1.RELEASE)
2018-04-14 14:12:29.825 INFO 15736 --- [ main] c.chengjue.springboot.ApplicationTests : Starting ApplicationTests on DESKTOP-2AMB1L3 with PID 15736 (started by kipeng in G:\project\springcache\spring-boot)
2018-04-14 14:12:29.828 INFO 15736 --- [ main] c.chengjue.springboot.ApplicationTests : No active profile set, falling back to default profiles: default
2018-04-14 14:12:29.857 INFO 15736 --- [ main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@126253fd: startup date [Sat Apr 14 14:12:29 CST 2018]; root of context hierarchy
2018-04-14 14:12:30.139 INFO 15736 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2018-04-14 14:12:30.870 INFO 15736 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'taskExecutor'
2018-04-14 14:12:31.133 INFO 15736 --- [ main] c.chengjue.springboot.ApplicationTests : Started ApplicationTests in 1.592 seconds (JVM running for 2.509)
2018-04-14 14:12:31.222 INFO 15736 --- [ Thread-2] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@126253fd: startup date [Sat Apr 14 14:12:29 CST 2018]; root of context hierarchy
2018-04-14 14:12:31.224 INFO 15736 --- [ Thread-2] o.s.s.concurrent.ThreadPoolTaskExecutor : Shutting down ExecutorService 'taskExecutor'
2018-04-14 14:12:31.226 INFO 15736 --- [ taskExecutor-1] com.chengjue.springboot.task.Task : 开始做任务一
Process finished with exit code 0
通过结果输出可以发现
log.info("完成任务一,耗时:" + (end - start) + "毫秒");
并没有执行
问题分析
- 通过debug分析执行步骤
stringRedisTemplate.opsForValue().set("kipeng","hello world");
String value = stringRedisTemplate.opsForValue().get("kipeng");
在debug的过程中是在上面代码执行的时候抛出异常结束的,提示redis connection is closed。当时的第一反应就是redis的连接已经断开,但是不知道是什么原因,怀疑是不是stringRedisTemplate不能在子线程中使用。为了验证是不是不能在子线程使用,为了验证是否是@Async的问题,下面使用手动创建线程测试下
- 使用手动创建线程异步执行测试验证
//@Async("taskExecutor")
public void doTaskOne(){
Executors.newSingleThreadExecutor().execute(new Runnable() {
@Override
public void run() {
log.info("开始做任务一");
long start = System.currentTimeMillis();
long end = System.currentTimeMillis();
stringRedisTemplate.opsForValue().set("kipeng","hello world");
String value = stringRedisTemplate.opsForValue().get("kipeng");
log.info("完成任务一,耗时:" + (end - start) + "毫秒");
}
});
}
修改代码后,发现在项目中正常使用,可是junit中一样报错
报错如下:
Exception in thread "pool-1-thread-1" org.springframework.data.redis.RedisSystemException: Redis exception; nested exception is io.lettuce.core.RedisException: Connection is closed
at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:74)
at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:41)
at org.springframework.data.redis.PassThroughExceptionTranslationStrategy.translate(PassThroughExceptionTranslationStrategy.java:44)
at org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:42)
at org.springframework.data.redis.connection.lettuce.LettuceConnection.convertLettuceAccessException(LettuceConnection.java:257)
at org.springframework.data.redis.connection.lettuce.LettuceStringCommands.convertLettuceAccessException(LettuceStringCommands.java:718)
at org.springframework.data.redis.connection.lettuce.LettuceStringCommands.set(LettuceStringCommands.java:143)
at org.springframework.data.redis.connection.DefaultedRedisConnection.set(DefaultedRedisConnection.java:231)
at org.springframework.data.redis.connection.DefaultStringRedisConnection.set(DefaultStringRedisConnection.java:917)
at org.springframework.data.redis.core.DefaultValueOperations$3.inRedis(DefaultValueOperations.java:202)
at org.springframework.data.redis.core.AbstractOperations$ValueDeserializingRedisCallback.doInRedis(AbstractOperations.java:59)
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:224)
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:184)
at org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:95)
at org.springframework.data.redis.core.DefaultValueOperations.set(DefaultValueOperations.java:198)
at com.chengjue.springboot.task.Task$1.run(Task.java:34)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: io.lettuce.core.RedisException: Connection is closed
at io.lettuce.core.protocol.DefaultEndpoint.validateWrite(DefaultEndpoint.java:171)
at io.lettuce.core.protocol.DefaultEndpoint.write(DefaultEndpoint.java:113)
at io.lettuce.core.RedisChannelHandler.dispatch(RedisChannelHandler.java:123)
at io.lettuce.core.StatefulRedisConnectionImpl.dispatch(StatefulRedisConnectionImpl.java:152)
at io.lettuce.core.AbstractRedisAsyncCommands.dispatch(AbstractRedisAsyncCommands.java:461)
at io.lettuce.core.AbstractRedisAsyncCommands.set(AbstractRedisAsyncCommands.java:1194)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at io.lettuce.core.FutureSyncInvocationHandler.handleInvocation(FutureSyncInvocationHandler.java:52)
at io.lettuce.core.internal.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:80)
at com.sun.proxy.$Proxy66.set(Unknown Source)
at org.springframework.data.redis.connection.lettuce.LettuceStringCommands.set(LettuceStringCommands.java:141)
... 12 more
- 结果反思
通过上面的验证和测试,发现者这不是@Async的问题。那么只能去思考使用junit测试和项目正常启动的不同点是什么。
使用Spring容器项目启动的时候,容器一直在运行中,他的stringRedisTemplate实例一直存在,不管异步还是同步执行,stringRedisTemplate bean的资源都不会被回收
而使用@SpringBootTest在跑test的时候,虽然同样也是使用Spring管理bean,但是执行下面这段测试会发现,Spring容器的执行时间是不一样的。主线程跑完后测试结束,Spring容器中的bean被回收,但是子线程还没有结束,这样在执行到stringRedisTemplate操作后拿不到相关的连接
@Test
public void testTask() {
task.doTaskOne();
}
为了验证上面的猜想是否正确,下面做下从测试
猜想验证
既然是主线程已经结束,子线程还没执行完毕,那么就在主线程阻塞等待一段时间或者使用join等子线程执行完毕
- 主线程 sleep
@Test
public void testTask() throws InterruptedException {
task.doTaskOne();
Thread.sleep(2000L);
}
- 等待子线程执行完毕 使用join
@Test
public void testTask() throws InterruptedException {
task.doTaskOne();
Thread.currentThread().join();
}
发现通过以上两种方式都是可行的,执行结果
:: Spring Boot :: (v2.0.1.RELEASE)
2018-04-14 14:32:15.805 INFO 10172 --- [ main] c.chengjue.springboot.ApplicationTests : Starting ApplicationTests on DESKTOP-2AMB1L3 with PID 10172 (started by kipeng in G:\project\springcache\spring-boot)
2018-04-14 14:32:15.808 INFO 10172 --- [ main] c.chengjue.springboot.ApplicationTests : No active profile set, falling back to default profiles: default
2018-04-14 14:32:15.832 INFO 10172 --- [ main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@126253fd: startup date [Sat Apr 14 14:32:15 CST 2018]; root of context hierarchy
2018-04-14 14:32:16.170 INFO 10172 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2018-04-14 14:32:17.023 INFO 10172 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'taskExecutor'
2018-04-14 14:32:17.327 INFO 10172 --- [ main] c.chengjue.springboot.ApplicationTests : Started ApplicationTests in 1.846 seconds (JVM running for 2.951)
2018-04-14 14:32:17.415 INFO 10172 --- [ taskExecutor-1] com.chengjue.springboot.task.Task : 开始做任务一
2018-04-14 14:32:17.508 INFO 10172 --- [ taskExecutor-1] io.lettuce.core.EpollProvider : Starting without optional epoll library
2018-04-14 14:32:17.510 INFO 10172 --- [ taskExecutor-1] io.lettuce.core.KqueueProvider : Starting without optional kqueue library
2018-04-14 14:32:17.682 INFO 10172 --- [ taskExecutor-1] com.chengjue.springboot.task.Task : 完成任务一,耗时:0毫秒
2018-04-14 14:32:19.411 INFO 10172 --- [ Thread-2] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@126253fd: startup date [Sat Apr 14 14:32:15 CST 2018]; root of context hierarchy
2018-04-14 14:32:19.412 INFO 10172 --- [ Thread-2] o.s.s.concurrent.ThreadPoolTaskExecutor : Shutting down ExecutorService 'taskExecutor'
问题解决
通过上面的分析和验证已经找到了问题的原因,但是我们在正式的项目中总不能使用sleep和join来解决吧,这样就失去了异步处理的意义了,变成了同步执行。
虽然上面的情况只有在使用junit测试的时候会出现问题,那么在项目正常使用会不会有问题呢?
当然是有问题的,如果我们的项目并发比较高,在项目关闭的时候恰好有子线程还没有执行完毕,子线程中部分功能无法正常执行或者关闭,会给我们的系统或者数据带来问题。
这时我们需要考虑怎样优雅的避免此问题的发生。
因为我们项目中使用的是ThreadPoolTaskExecutor(关于的使用和理解可以看我的另一篇博客)来做线程池管理,那我们第一件事去看相关的源码和文档,有没有相关内容的提示
/**
* JavaBean that allows for configuring a {@link java.util.concurrent.ThreadPoolExecutor}
* in bean style (through its "corePoolSize", "maxPoolSize", "keepAliveSeconds", "queueCapacity"
* properties) and exposing it as a Spring {@link org.springframework.core.task.TaskExecutor}.
* This class is also well suited for management and monitoring (e.g. through JMX),
* providing several useful attributes: "corePoolSize", "maxPoolSize", "keepAliveSeconds"
* (all supporting updates at runtime); "poolSize", "activeCount" (for introspection only).
*
* <p>For an alternative, you may set up a ThreadPoolExecutor instance directly using
* constructor injection, or use a factory method definition that points to the
* {@link java.util.concurrent.Executors} class. To expose such a raw Executor as a
* Spring {@link org.springframework.core.task.TaskExecutor}, simply wrap it with a
* {@link org.springframework.scheduling.concurrent.ConcurrentTaskExecutor} adapter.
*
* <p><b>NOTE:</b> This class implements Spring's
* {@link org.springframework.core.task.TaskExecutor} interface as well as the
* {@link java.util.concurrent.Executor} interface, with the former being the primary
* interface, the other just serving as secondary convenience. For this reason, the
* exception handling follows the TaskExecutor contract rather than the Executor contract,
* in particular regarding the {@link org.springframework.core.task.TaskRejectedException}.
*
* <p><b>If you prefer native {@link java.util.concurrent.ExecutorService} exposure instead,
* consider {@link ThreadPoolExecutorFactoryBean} as an alternative to this class.</b>
*
* @author Juergen Hoeller
* @since 2.0
* @see org.springframework.core.task.TaskExecutor
* @see java.util.concurrent.ThreadPoolExecutor
* @see ConcurrentTaskExecutor
*/
通过注释没有看到相关的内容,那么只能通过代码来去看了,发现他有一个shutdown方法
public void shutdown() {
if (logger.isInfoEnabled()) {
logger.info("Shutting down ExecutorService" + (this.beanName != null ? " '" + this.beanName + "'" : ""));
}
if (this.executor != null) {
if (this.waitForTasksToCompleteOnShutdown) {
this.executor.shutdown();
}
else {
for (Runnable remainingTask : this.executor.shutdownNow()) {
cancelRemainingTask(remainingTask);
}
}
awaitTerminationIfNecessary(this.executor);
}
}
/**
* Wait for the executor to terminate, according to the value of the
* {@link #setAwaitTerminationSeconds "awaitTerminationSeconds"} property.
*/
private void awaitTerminationIfNecessary(ExecutorService executor) {
if (this.awaitTerminationSeconds > 0) {
try {
if (!executor.awaitTermination(this.awaitTerminationSeconds, TimeUnit.SECONDS)) {
if (logger.isWarnEnabled()) {
logger.warn("Timed out while waiting for executor" +
(this.beanName != null ? " '" + this.beanName + "'" : "") + " to terminate");
}
}
}
catch (InterruptedException ex) {
if (logger.isWarnEnabled()) {
logger.warn("Interrupted while waiting for executor" +
(this.beanName != null ? " '" + this.beanName + "'" : "") + " to terminate");
}
Thread.currentThread().interrupt();
}
}
}
通过代码发现有个waitForTasksToCompleteOnShutdown参数。
如果没有设置waitForTasksToCompleteOnShutdown,则直接使用executor.shutdownNow(),如果为true则executor.shutdown()优雅关闭处理。
同时如果设置了awaitTerminationSeconds,executor会设置awaitTermination,下面是ExecutorService中awaitTermination方法的注释,如果设置了这个参数,如果调用了shutdown请求会一直阻塞直到执行完成
/**
* Blocks until all tasks have completed execution after a shutdown
* request, or the timeout occurs, or the current thread is
* interrupted, whichever happens first.
*
* @param timeout the maximum time to wait
* @param unit the time unit of the timeout argument
* @return {@code true} if this executor terminated and
* {@code false} if the timeout elapsed before termination
* @throws InterruptedException if interrupted while waiting
*/
boolean awaitTermination(long timeout, TimeUnit unit)
throws InterruptedException;
既然有上面的提示,我们就试下设置下这个参数是否有效
@Bean("taskExecutor")
public Executor taskExecutor(){
ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
executor.setCorePoolSize(10);
executor.setMaxPoolSize(20);
executor.setQueueCapacity(200);
executor.setKeepAliveSeconds(60);
executor.setThreadNamePrefix("taskExecutor-");
executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
executor.setWaitForTasksToCompleteOnShutdown(true);
executor.setAwaitTerminationSeconds(60);
return executor;
}
通过验证此方法有效,这样就可以避免在Spring容器结束的时候异常和子线程执行结果问题了,可以实现优雅关闭线程
建议
如果你的项目中有高并发和数据很重要的时候,一定要考虑系统关闭,子线程执行是否会受到影响,确保子线程正确退出和执行