Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve exception message when Scheduled tasks that are using Virtual Threads fail on shutdown #32381

Closed
snicoll opened this issue Mar 6, 2024 · 1 comment
Assignees
Labels
in: core Issues in core modules (aop, beans, core, context, expression) type: enhancement A general enhancement
Milestone

Comments

@snicoll
Copy link
Member

snicoll commented Mar 6, 2024

A @Scheduled task that is using other components (such as the database) should terminate processing of any pending tasks on shutdown with a vanilla setup.

When using Virtual Threads however, scheduled threads are managed differently and the underlying scheduler is considered as shut down when the main scheduler thread completed. Any individual task executions may still be running on the side. This leads to an expected failure to complete the task, but the current exception message makes it sound way worse that it really is.

Here is an example:

Exception in thread "scheduling-11" org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:313)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:531)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:405)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:610)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:379)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:220)
	at jdk.proxy2/jdk.proxy2.$Proxy99.saveAll(Unknown Source)
	at io.spring.sample.opsstatus.AvailabilityChecker.checkComponents(AvailabilityChecker.java:33)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at org.springframework.scheduling.support.ScheduledMethodRunnable.runInternal(ScheduledMethodRunnable.java:130)
	at org.springframework.scheduling.support.ScheduledMethodRunnable.lambda$run$2(ScheduledMethodRunnable.java:124)
	at io.micrometer.observation.Observation.observe(Observation.java:499)
	at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:124)
	at java.base/java.lang.VirtualThread.run(VirtualThread.java:309)
Caused by: java.sql.SQLException: HikariDataSource HikariDataSource (opsstatus) has been closed.
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:96)
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:269)
	... 20 more

Given this kind of case is expected, we should probably log something more explicit that relates to an issue on shutdown and lower the log level.

@snicoll snicoll added in: core Issues in core modules (aop, beans, core, context, expression) type: enhancement A general enhancement labels Mar 6, 2024
@snicoll snicoll added this to the 6.1.x milestone Mar 6, 2024
@jhoeller jhoeller modified the milestones: 6.1.x, 6.1.5 Mar 6, 2024
@jhoeller
Copy link
Contributor

jhoeller commented Mar 6, 2024

This relates to #32298 for which we should better use LOG_AND_SUPPRESS_ERROR_HANDLER instead - otherwise, there will always be a log entry and thread stderror output on the console, duplicating the stacktrace.

Additionally, we should try to lower the log level for shutdown scenarios where such exceptions are expected.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: core Issues in core modules (aop, beans, core, context, expression) type: enhancement A general enhancement
Projects
None yet
Development

No branches or pull requests

2 participants