MelonBlog

排查SpringTask无报错停止问题

描述

最近遇到了一个很奇怪的问题,SpringTask的任务会无缘无故停止运行

排查

查了一下资料,初步断定是线程阻塞导致的,那如何排查线程是否真的阻塞呢?

两个操作:

给线程命名
通过jstack命令查看线程状态

线程命名

@Configuration
@EnableScheduling
@Profile({"prod", "prod-ai"})
public class SpringTaskConfiguration {
    @Bean
    public ThreadPoolTaskScheduler threadPoolTaskScheduler() {
        ThreadPoolTaskScheduler threadPoolTaskScheduler = new ThreadPoolTaskScheduler();
        threadPoolTaskScheduler.setPoolSize(5);
        threadPoolTaskScheduler.setThreadNamePrefix("SpringTask");
        return threadPoolTaskScheduler;
    }
}

jstack中的关键内容

"SpringTask1" #92 prio=5 os_prio=0 cpu=7902.05ms elapsed=250384.31s tid=0x00007f6758fbcff0 nid=0x1f9db6 waiting on condition  [0x00007f67019f0000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@17.0.7/Native Method)
        - parking to wait for  <0x00000000e4915b30> (a java.util.concurrent.CompletableFuture$Signaller)
        at java.util.concurrent.locks.LockSupport.park(java.base@17.0.7/LockSupport.java:211)
        at java.util.concurrent.CompletableFuture$Signaller.block(java.base@17.0.7/CompletableFuture.java:1864)
        at java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@17.0.7/ForkJoinPool.java:3463)
        at java.util.concurrent.ForkJoinPool.managedBlock(java.base@17.0.7/ForkJoinPool.java:3434)
        at java.util.concurrent.CompletableFuture.waitingGet(java.base@17.0.7/CompletableFuture.java:1898)
        at java.util.concurrent.CompletableFuture.join(java.base@17.0.7/CompletableFuture.java:2117)
        at com.airss.task.RssReadTask.doExec(RssReadTask.java:60)
        at com.airss.task.AbstractTask.exec(AbstractTask.java:42)
        at com.airss.task.RssReadTask.exec(RssReadTask.java:29)
        at jdk.internal.reflect.GeneratedMethodAccessor316.invoke(Unknown Source)
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@17.0.7/DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(java.base@17.0.7/Method.java:568)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
        at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115)
        at org.springframework.aop.interceptor.AsyncExecutionInterceptor$$Lambda$1062/0x00000008012dbc70.call(Unknown Source)
        at java.util.concurrent.FutureTask.run(java.base@17.0.7/FutureTask.java:264)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@17.0.7/ScheduledThreadPoolExecutor.java:304)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@17.0.7/ThreadPoolExecutor.java:1136)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@17.0.7/ThreadPoolExecutor.java:635)
        at java.lang.Thread.run(java.base@17.0.7/Thread.java:833)
"SpringTask2" #93 prio=5 os_prio=0 cpu=62041.99ms elapsed=250384.31s tid=0x00007f6759494810 nid=0x1f9db7 waiting on condition  [0x00007f67018ef000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@17.0.7/Native Method)
        - parking to wait for  <0x00000000e4915d18> (a java.util.concurrent.CompletableFuture$Signaller)
        at java.util.concurrent.locks.LockSupport.park(java.base@17.0.7/LockSupport.java:211)
        at java.util.concurrent.CompletableFuture$Signaller.block(java.base@17.0.7/CompletableFuture.java:1864)
        at java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@17.0.7/ForkJoinPool.java:3463)
        at java.util.concurrent.ForkJoinPool.managedBlock(java.base@17.0.7/ForkJoinPool.java:3434)
        at java.util.concurrent.CompletableFuture.waitingGet(java.base@17.0.7/CompletableFuture.java:1898)
        at java.util.concurrent.CompletableFuture.join(java.base@17.0.7/CompletableFuture.java:2117)
        at com.airss.task.RssReadTask.doExec(RssReadTask.java:60)
        at com.airss.task.AbstractTask.exec(AbstractTask.java:42)
        at com.airss.task.RssReadTask.exec(RssReadTask.java:29)
        at jdk.internal.reflect.GeneratedMethodAccessor316.invoke(Unknown Source)
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@17.0.7/DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(java.base@17.0.7/Method.java:568)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
        at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115)
        at org.springframework.aop.interceptor.AsyncExecutionInterceptor$$Lambda$1062/0x00000008012dbc70.call(Unknown Source)
        at java.util.concurrent.FutureTask.run(java.base@17.0.7/FutureTask.java:264)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@17.0.7/ScheduledThreadPoolExecutor.java:304)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@17.0.7/ThreadPoolExecutor.java:1136)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@17.0.7/ThreadPoolExecutor.java:635)
        at java.lang.Thread.run(java.base@17.0.7/Thread.java:833)
"SpringTask3" #94 prio=5 os_prio=0 cpu=286.72ms elapsed=250384.31s tid=0x00007f6758eb5110 nid=0x1f9db8 waiting on condition  [0x00007f67017ed000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@17.0.7/Native Method)
        - parking to wait for  <0x00000000e49160c0> (a java.util.concurrent.CompletableFuture$Signaller)
        at java.util.concurrent.locks.LockSupport.park(java.base@17.0.7/LockSupport.java:211)
        at java.util.concurrent.CompletableFuture$Signaller.block(java.base@17.0.7/CompletableFuture.java:1864)
        at java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@17.0.7/ForkJoinPool.java:3463)
        at java.util.concurrent.ForkJoinPool.managedBlock(java.base@17.0.7/ForkJoinPool.java:3434)
        at java.util.concurrent.CompletableFuture.waitingGet(java.base@17.0.7/CompletableFuture.java:1898)
        at java.util.concurrent.CompletableFuture.join(java.base@17.0.7/CompletableFuture.java:2117)
        at com.airss.task.RssReadTask.doExec(RssReadTask.java:60)
        at com.airss.task.AbstractTask.exec(AbstractTask.java:42)
        at com.airss.task.RssReadTask.exec(RssReadTask.java:29)
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@17.0.7/Native Method)
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@17.0.7/NativeMethodAccessorImpl.java:77)
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@17.0.7/DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(java.base@17.0.7/Method.java:568)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
        at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115)
        at org.springframework.aop.interceptor.AsyncExecutionInterceptor$$Lambda$1062/0x00000008012dbc70.call(Unknown Source)
        at java.util.concurrent.FutureTask.run(java.base@17.0.7/FutureTask.java:264)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@17.0.7/ScheduledThreadPoolExecutor.java:304)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@17.0.7/ThreadPoolExecutor.java:1136)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@17.0.7/ThreadPoolExecutor.java:635)
        at java.lang.Thread.run(java.base@17.0.7/Thread.java:833)
"DestroyJavaVM" #95 prio=5 os_prio=0 cpu=7989.75ms elapsed=250384.30s tid=0x00007f6758023980 nid=0x1f9d51 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
...

可以发现5个task线程都被阻塞在CompletableFuture的join方法上

解决方案

为CompletableFuture添加超时时间

future.orTimeout(60, java.util.concurrent.TimeUnit.SECONDS);