I'm working with Spring Boot 2.4.3 and I'm having troubles with a task scheduled every night at midnight UTC.
So, to begin, I have an external file with this configuration:
news.task.latest.cron=0 0 0 * * *
and the task is this one:
@Scheduled(cron = "${news.task.latest.cron:0 0 0 * * *}")
public void getLatestNews() {
LOG.info("BEGIN");
// Calculate publish date (at the beginning of the next hour)
Calendar calendar = Calendar.getInstance();
calendar.setTime(new Date());
calendar.set(Calendar.MILLISECOND, 0);
calendar.set(Calendar.SECOND, 0);
calendar.set(Calendar.MINUTE, 0);
calendar.add(Calendar.HOUR, 1);
Date publishDate = calendar.getTime();
try {
// Retrieve all news categories
final List<NewsCategory> newsCategories = newsCategoryService.listCriteria();
for (NewsCategory newsCategory : newsCategories) {
// Retrieve max external date of category
final Date maxExternalDate = newsService.getMaxExternalDateByCategory(newsCategory.getId());
// Retrieve news from internet
final List<NewsItem> latestNews = newsProviderService.getLatestNews(newsCategory.getSearchQuery(), NEWS_COUNT);
final List<News> newsList = new ArrayList<>();
for (NewsItem newsItem : latestNews) {
// Avoidance of duplicates (not extremely good but it's something)
final Date externalDate = MicrosoftAzureUtils.toDate(newsItem.getDatePublished());
if (maxExternalDate != null && !DateUtils.after(externalDate, maxExternalDate)) break;
// Convert the news
News news = new News(
newsItem.getName(),
newsItem.getUrl(),
publishDate,
newsCategory
);
news.setExternalDate(externalDate);
news.setDescription(newsItem.getDescription());
if (newsItem.getImage() != null) {
news.setImageUrl(newsItem.getImage().getContentUrl());
if (newsItem.getImage().getThumbnail() != null)
news.setThumbnailUrl(newsItem.getImage().getThumbnail().getContentUrl());
}
if (newsItem.getProvider() != null && newsItem.getProvider().size() > 0)
news.setSourceName(newsItem.getProvider().get(0).getName());
// Push to list
newsList.add(news);
}
// Persist news
if (newsList.size() > 0)
newsService.saveAll(newsList);
// Throttle requests
Thread.sleep(1000);
}
} catch (Exception e) {
LOG.error("Exception: ", e);
}
LOG.info("END");
}
The task run always regularly as expected but when I put it on the server online I am starting to have problems. When the task run I get this exception:
28-mag-2021 02:00:00.074 ERROR [scheduling-1] it.xeos.youfund.util.AppLogger - it.xeos.youfund.scheduled.NewsTasks : getLatestNews - Exception:
org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.TransactionException: JDBC begin transaction failed:
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:467)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:595)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:382)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
at it.xeos.youfund.service.core.NewsCategoryServiceImpl$$EnhancerBySpringCGLIB$$1bb15911.listCriteria(<generated>)
at it.xeos.youfund.scheduled.NewsTasks.getLatestNews(NewsTasks.java:55)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84)
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:95)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: org.hibernate.TransactionException: JDBC begin transaction failed:
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:78)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:283)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:246)
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:164)
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:421)
... 24 common frames omitted
Caused by: java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed.
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:110)
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89)
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63)
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:73)
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73)
at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2061)
at org.apache.commons.dbcp.DelegatingConnection.setAutoCommit(DelegatingConnection.java:331)
at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.setAutoCommit(PoolingDataSource.java:317)
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:72)
... 29 common frames omitted
Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.lang.reflect.Constructor.newInstance(Unknown Source)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151)
at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:1171)
at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:573)
at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2011)
... 32 common frames omitted
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: The last packet successfully received from the server was 35.614.085 milliseconds ago. The last packet sent successfully to the server was 35.614.085 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.lang.reflect.Constructor.newInstance(Unknown Source)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151)
at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:167)
at com.mysql.cj.protocol.a.NativeProtocol.send(NativeProtocol.java:577)
at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:632)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:948)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryString(NativeProtocol.java:894)
at com.mysql.cj.NativeSession.execSQL(NativeSession.java:1073)
at com.mysql.cj.jdbc.ConnectionImpl.setReadOnlyInternal(ConnectionImpl.java:2159)
at com.mysql.cj.jdbc.ConnectionImpl.setReadOnly(ConnectionImpl.java:2150)
at org.apache.commons.dbcp.DelegatingConnection.setReadOnly(DelegatingConnection.java:337)
at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.setReadOnly(PoolingDataSource.java:327)
at org.springframework.jdbc.datasource.DataSourceUtils.prepareConnectionForTransaction(DataSourceUtils.java:188)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:153)
... 25 common frames omitted
Caused by: java.net.SocketException: Software caused connection abort: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(Unknown Source)
at java.net.SocketOutputStream.write(Unknown Source)
at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.io.BufferedOutputStream.flush(Unknown Source)
at com.mysql.cj.protocol.a.SimplePacketSender.send(SimplePacketSender.java:55)
at com.mysql.cj.protocol.a.TimeTrackingPacketSender.send(TimeTrackingPacketSender.java:50)
at com.mysql.cj.protocol.a.NativeProtocol.send(NativeProtocol.java:568)
... 35 common frames omitted
and on the first fail I get before the above exception this one too:
28-mag-2021 02:00:00.074 ERROR [scheduling-1] o.s.o.jpa.EntityManagerFactoryUtils - Failed to release JPA EntityManager
org.hibernate.exception.GenericJDBCException: Unable to release JDBC Connection
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.releaseConnection(LogicalConnectionManagedImpl.java:221)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.close(LogicalConnectionManagedImpl.java:259)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:175)
at org.hibernate.internal.AbstractSharedSessionContract.close(AbstractSharedSessionContract.java:351)
at org.hibernate.internal.SessionImpl.closeWithoutOpenChecks(SessionImpl.java:376)
at org.hibernate.internal.SessionImpl.close(SessionImpl.java:361)
at org.springframework.orm.jpa.EntityManagerFactoryUtils.closeEntityManager(EntityManagerFactoryUtils.java:427)
at org.springframework.orm.jpa.JpaTransactionManager.closeEntityManagerAfterFailedBegin(JpaTransactionManager.java:514)
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:466)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:595)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:382)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
at it.xeos.youfund.service.core.NewsCategoryServiceImpl$$EnhancerBySpringCGLIB$$1bb15911.listCriteria(<generated>)
at it.xeos.youfund.scheduled.NewsTasks.getLatestNews(NewsTasks.java:55)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84)
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:95)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: java.sql.SQLException: Already closed.
at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:84)
at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:181)
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.closeConnection(DatasourceConnectionProviderImpl.java:127)
at org.hibernate.internal.NonContextualJdbcConnectionAccess.releaseConnection(NonContextualJdbcConnectionAccess.java:49)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.releaseConnection(LogicalConnectionManagedImpl.java:217)
... 32 common frames omitted
I said "on the first fail" because, without restarting the server (nor phisically, the jvm or the application itself), not always the task is failing launching the above exceptions, sometimes the task simply go smootly and do his job as expected.
As mentioned in the stacktrace I've added autoReconnect=true to the DB connection, but it changed nothing.
The method that is provoking all the exceptions (newsCategoryService.listCriteria()) come from an abstract superclass and is this one:
@Transactional(readOnly = true)
public List<Entity> listCriteria() throws NoSuchFieldException, IllegalAccessException {
//getting all entities
return repository.findAll();
}
The fact that the task is not giving always the exception is really making me wandering.
Seems that the jdbc connection from the task (so, as I understand, from another thread) is having difficulties to remain stable but I don't understand how can I improve that or what I've done or not done to weaken it so much.
Edit 1:
Our database is configured by external file and the content is this:
#db service
spring.datasource.service.url=jdbc:mysql://localhost:3306/database_name?useSSL=false&useUnicode=true&useJDBCCompliantTimezoneShift=true&useLegacyDatetimeCode=false&serverTimezone=UTC&autoReconnect=true
spring.datasource.service.username=username
spring.datasource.service.password=password
spring.datasource.service.driverClassName=com.mysql.cj.jdbc.Driver
## Hibernate Properties
# The SQL dialect makes Hibernate generate better SQL for the chosen database
spring.jpa.properties.hibernate.dialect = org.hibernate.dialect.MySQL5InnoDBDialect
# Hibernate ddl auto (create, create-drop, validate, update)
spring.jpa.hibernate.ddl-auto = update
spring.jpa.generate-ddl=true
spring.jpa.show-sql=false
spring.jpa.database=mysql