SimpleAsyncTaskScheduler should ignore scheduled exceptions after shutdown (not termination)

[genuss]

Basically my issue is described in #32381. The implemented solution works in almost all cases, but I still experience TaskRejectedException logged as errors in the following case:

• application context is stopping;
• ContextClosedEvent is already published;
• SimpleAsyncTaskScheduler#scheduledExecutor is shut down, but didn't yet terminated;
  I couldn't create a minimal reproducible example, but I'd like to show an excerpt from logs.

2024-08-07T09:59:05.977+02:00 DEBUG 65937 --- [cheduling-19424] c.c.MyTaskBean          : Task working
2024-08-07T09:59:05.977+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.b.a.ApplicationAvailabilityBean      : Application availability state ReadinessState changed from ACCEPTING_TRAFFIC to REFUSING_TRAFFIC
2024-08-07T09:59:05.977+02:00 DEBUG 65937 --- [ionShutdownHook] ConfigServletWebServerApplicationContext : Closing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@28a2a3e7, started on Wed Aug 07 09:59:00 CEST 2024
2024-08-07T09:59:05.977+02:00 DEBUG 65937 --- [cheduling-19425] c.c.MyTaskBean          : Task working
2024-08-07T09:59:05.977+02:00 DEBUG 65937 --- [cheduling-19426] c.c.MyTaskBean          : Task working
2024-08-07T09:59:05.977+02:00 DEBUG 65937 --- [cheduling-19427] c.c.MyTaskBean          : Task working
2024-08-07T09:59:05.977+02:00 DEBUG 65937 --- [cheduling-19428] c.c.MyTaskBean          : Task working
2024-08-07T09:59:05.977+02:00 ERROR 65937 --- [cheduling-19428] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task

org.springframework.core.task.TaskRejectedException: ExecutorService in shutdown state did not accept task: com.company.MyTaskBean$$Lambda/0x000003ff01a10ed0@3c00151f
	at org.springframework.scheduling.concurrent.SimpleAsyncTaskScheduler.schedule(SimpleAsyncTaskScheduler.java:234)
	at com.company.MyTaskBean.task(MyTaskBean.kt:87)
	at com.company.MyTaskBean.task$lambda$1(MyTaskBean.kt:87)
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
	at java.base/java.lang.VirtualThread.run(VirtualThread.java:329)
Caused by: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@93d3468[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@74f27d38[Wrapped task = org.springframework.scheduling.concurrent.SimpleAsyncTaskScheduler$$Lambda/0x000003ff019a8f70@53630565]] rejected from org.springframework.scheduling.concurrent.SimpleAsyncTaskScheduler$1@1d884a19[Shutting down, pool size = 1, active threads = 0, queued tasks = 2, completed tasks = 19427]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2081)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:841)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562)
	at org.springframework.scheduling.concurrent.SimpleAsyncTaskScheduler.schedule(SimpleAsyncTaskScheduler.java:231)
	... 4 common frames omitted

2024-08-07T09:59:05.978+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Stopping beans in phase 2147483647
2024-08-07T09:59:05.978+02:00 TRACE 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Asking bean 'taskScheduler' of type [org.springframework.scheduling.concurrent.SimpleAsyncTaskScheduler] to stop
2024-08-07T09:59:05.978+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Bean 'taskScheduler' completed its stop procedure
2024-08-07T09:59:05.978+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Stopping beans in phase 2147482623
2024-08-07T09:59:05.978+02:00 TRACE 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Asking bean 'webServerGracefulShutdown' of type [org.springframework.boot.web.context.WebServerGracefulShutdownLifecycle] to stop
2024-08-07T09:59:05.979+02:00  INFO 65937 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2024-08-07T09:59:05.980+02:00  INFO 65937 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete
2024-08-07T09:59:05.980+02:00 DEBUG 65937 --- [tomcat-shutdown] o.s.c.support.DefaultLifecycleProcessor  : Bean 'webServerGracefulShutdown' completed its stop procedure
2024-08-07T09:59:05.981+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Stopping beans in phase 2147481599
2024-08-07T09:59:05.981+02:00 TRACE 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Asking bean 'webServerStartStop' of type [org.springframework.boot.web.servlet.context.WebServerStartStopLifecycle] to stop
2024-08-07T09:59:05.981+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Bean 'webServerStartStop' completed its stop procedure
2024-08-07T09:59:05.981+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Stopping beans in phase -2147483647
2024-08-07T09:59:05.981+02:00 TRACE 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Asking bean 'springBootLoggingLifecycle' of type [org.springframework.boot.context.logging.LoggingApplicationListener$Lifecycle] to stop
2024-08-07T09:59:05.981+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Bean 'springBootLoggingLifecycle' completed its stop procedure
2024-08-07T09:59:05.982+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.s.c.ThreadPoolTaskScheduler          : Shutting down ExecutorService
2024-08-07T09:59:05.985+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown
2024-08-07T09:59:05.985+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans
2024-08-07T09:59:05.986+02:00  INFO 65937 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource       : read-only - Shutdown initiated...
2024-08-07T09:59:05.988+02:00  INFO 65937 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource       : read-only - Shutdown completed.
2024-08-07T09:59:05.988+02:00  INFO 65937 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource       : read-write - Shutdown initiated...
2024-08-07T09:59:05.989+02:00  INFO 65937 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource       : read-write - Shutdown completed.
2024-08-07T09:59:05.989+02:00 DEBUG 65937 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Custom destroy method 'close' on bean with name 'simpleclientPrometheusMeterRegistry' completed

I suppose, the reason can be explained as follows.

• SimpleAsyncTaskScheduler#onApplicationEvent calls ExecutorService#shutdown thus switching its running state to SHUTDOWN.
• SimpleAsyncTaskScheduler#shutdownAwareErrorHandler checks for ExecutorService#isTerminated which only returns true if an executor is in TERMINATED running state.

The proposed solution: use ExecutorService#isShutdown instead.

I hesitated to create a PR as I also found a call to isTerminated to ExecutorLifecycleDelegate and not sure if it should be changed too.

[simonbasle]

Thanks for the detailed analysis @genuss. I think what you propose for SimpleAsyncTaskScheduler#shutdownAwareErrorHandler makes sense. The ExecutorLifecycleDelegate should be reviewed separately though.

[genuss]

Should I create a PR for the change?

[simonbasle]

@genuss if you have something ready, please go ahead :)

[jhoeller]

Sounds sensible to use isShutdown() there, suppressing the log entry even before full termination there.

As for ExecutorLifecycleDelegate, the use of isTerminated() seems correct there since isRunning() is expected to return true up until actual termination.

[jhoeller]

Superseded by PR #33336.