ScheduledExecutorService出现异常挂掉的问题

1,481 阅读2分钟

导语:

最近遇到一个问题,有个周期给业务方推送信息的功能,突然就没推送了。日志里面也没有查询到报错的信息, 然后检查代码发现原来写这个推送功能用的是ScheduledExecutorService,再设定好执行时间,就会周期性去用 ScheduledExecutorService的子线程来执行任务。

问题排查:

问题的原因最后发现是某些配置修改了,导致运行推送任务的子线程在执行的时候回抛出异常,但是这个线程池是不打印子线程的异常信息的, 所以日志里面根本看不到报错的信息。

测试例子:

写一个简单方法,直接子线程就抛出异常,看看会不会打印堆栈信息:

@Slf4j
public class ScheduledExecutorServiceTest {

    public static Integer count = 0;

    public static void main(String[] args) {
        ScheduledExecutorService executorService = Executors.newScheduledThreadPool(1);
        executorService.scheduleAtFixedRate(() -> {
            if (count % 2 == 1) {
                throw new RuntimeException();
            } else {
                log.info("子线程执行了");
            }
            count++;
        }, 0, 1, TimeUnit.SECONDS);
    }
}

执行结果

Connected to the target VM, address: '127.0.0.1:49300', transport: 'socket'
20:10:42.180 [pool-1-thread-1] INFO com.scott.java.task.thread.scheduled.executor.service.ScheduledExecutorServiceTest - 子线程执行了

可以看到只有在第一次执行成功了,当count表位1的时候走到throw new RuntimeException()并没有打印出抛出的异常信息,之后也在没有打印后续的日志。 所以当count等于1的时候线程报错,这个线程就不会在执行任务后续的任务了。只要程序出错,这个线程池就会挂掉,如果有多个子线程的话,一个个子线程慢慢的都会抛出异常,会慢慢的 挂掉。

解决方式:

方式一:给子线程用try-catch给包起来

因为是子线程报错,抛了异常才导致线程池挂掉,如果我们把异常捕获了打印出日志,那么子线程下个周期还是可以正常运行的。 例子:

public static void main(String[] args) {
        ScheduledExecutorService executorService = Executors.newScheduledThreadPool(1);
        executorService.scheduleAtFixedRate(() -> {
            try {
                if (count % 2 == 1) {
                    throw new RuntimeException();
                } else {
                    log.info("子线程执行了");
                }
                count++;
            } catch (Exception e) {
                log.error("线程执行异常", e);
            }
        }, 0, 1, TimeUnit.SECONDS);
    }

输出结果:

20:25:54.648 [pool-1-thread-1] ERROR com.scott.java.task.thread.scheduled.executor.service.ScheduledExecutorServiceTest - 线程执行异常
java.lang.RuntimeException: null
	at com.scott.java.task.thread.scheduled.executor.service.ScheduledExecutorServiceTest.lambda$main$0(ScheduledExecutorServiceTest.java:24)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308)
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
20:25:55.642 [pool-1-thread-1] ERROR com.scott.java.task.thread.scheduled.executor.service.ScheduledExecutorServiceTest - 线程执行异常
java.lang.RuntimeException: null
	at com.scott.java.task.thread.scheduled.executor.service.ScheduledExecutorServiceTest.lambda$main$0(ScheduledExecutorServiceTest.java:24)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308)
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

可以看到这次抛出的异常都可以打印出来了,而且线程池继续在执行着。

方式二:使用@Scheduled注解来实现周期性任务

例子:

@Slf4j
@SpringBootApplication
@EnableScheduling
public class ScheduledTest {

    public static Integer count = 0;

    public static void main(String[] args) {
        SpringApplication.run(ScheduledTest.class);
    }

    @Scheduled(fixedRate = 1000)
    public void test() {
        if (count % 2 == 1) {
            throw new RuntimeException();
        } else {
            log.info("子线程执行了");
        }
        count++;
    }
}

输出结果:

2020-12-20 20:36:55.431 ERROR 2164 --- [pool-1-thread-1] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task.

java.lang.RuntimeException: null
	at com.scott.java.task.thread.scheduled.executor.service.ScheduledTest.test(ScheduledTest.java:27) ~[classes/:na]
	at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_162]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_162]
	at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65) ~[spring-context-5.0.5.RELEASE.jar:5.0.5.RELEASE]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.0.5.RELEASE.jar:5.0.5.RELEASE]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_162]
	at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) [na:1.8.0_162]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [na:1.8.0_162]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_162]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_162]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_162]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_162]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_162]

2020-12-20 20:36:56.431 ERROR 2164 --- [pool-1-thread-1] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task.

java.lang.RuntimeException: null
	at com.scott.java.task.thread.scheduled.executor.service.ScheduledTest.test(ScheduledTest.java:27) ~[classes/:na]
	at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_162]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_162]
	at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65) ~[spring-context-5.0.5.RELEASE.jar:5.0.5.RELEASE]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.0.5.RELEASE.jar:5.0.5.RELEASE]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_162]
	at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) [na:1.8.0_162]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [na:1.8.0_162]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_162]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_162]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_162]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_162]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_162]

可以看到周期性的抛出了异常,但是线程还是在继续执行着。

总结:

1.ScheduledExecutorService和普通的线程池都会把异常信息给吃掉,会导致线程池也挂掉 2.使用线程池的时候要注意catch住异常或者使用线程池的submit来打印异常信息
3.可以使用@Scheduled注解来替代ScheduledExecutorService。