I know that spring-retry doesn't grab database connections.
We've wrapped a REST endpoint with @Retryable in an attempt to enact retry functionality but its not quite working as expected. I had anticipated that when a SQLException is thrown due to a com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure that the next attempt would grab a new connection from the pool. I'm facing an issue whereby if we take down the MySQL database part way through processing, spring-retry retries the method call, but does not get a new database connection. As a result all retries fail but new requests to the REST endpoint work successfully. Is there a way I can force a new connection from the datasource.?
I know that Spring-retry knows nothing about the code being run, but I'm bewildered why the connection, having just thrown an exception, isn't ditched and a new one pulled from the pool given the datasource configuration. (Its a simple Spring datasource)
I appreciate that Spring-retry and HikariCP are separate things but I had envisioned that if the database failed for some reason, the Spring-retry would allow us to re-attempt the same processing?
Versions
Mysql connector version: 8.0.18
HikariCP version: 3.4.5
SpringBoot version: 2.1.9.RELEASE
application.yml
spring:
main:
allow-bean-definition-overriding: true
jpa:
database-platform: org.hibernate.dialect.MySQL5Dialect
hibernate:
use-new-id-generator-mappings: false
boot:
admin:
url: http://127.0.0.1:8022
username: admin
password: *****
client:
name: ${spring.application.name}
application:
name: Usage Aggregation
datasource:
type: com.zaxxer.hikari.HikariDataSource
url: jdbc:mysql://localhost:3308/db?createDatabaseIfNotExist=false&autoReconnect=true&autoReconnectForPools=true&socketTimeout=5000&connectTimeout=1000&useSSL=false
hikari:
jdbcUrl: jdbc:mysql://localhost:3308/db?createDatabaseIfNotExist=false&autoReconnect=true&autoReconnectForPools=true&socketTimeout=5000&connectTimeout=1000&useSSL=false
username: root
password: ****
register-mbeans: true
connectionInitSql: SELECT 1 FROM DUAL
connectionTestQuery: SELECT 1 FROM DUAL
socketTimeout: 3000
validationTimeout: 500
maximumPoolSize: 5
idleTimeout: 3000
poolName: SpringBootJPAHikariCP
maxLifetime: 60000
connectionTimeout: 1000
Controller
@Retryable(exclude = {IllegalStateException.class},
maxAttemptsExpression = 3,
backoff = @Backoff(
delayExpression = 30000,
maxDelayExpression = 2,
multiplierExpression = 500000
))
@RequestMapping("usageData/load/")
public void usageDataFromSource() {
log.info("Running usage data live service end point for: usageData");
//Sets status of aggregation disabled to false.
aggregationService.updateAggregationDisabledFlag("usageData", false);
usageService.copyUsageDataFromSourceToDestination();
}
Logs:
[2020-12-11 16:03:00,933] [http-nio-8095-exec-1] INFO u.b.c.RestController [] - Running usage data live service end point for: usageData
[2020-12-11 16:03:09,099] [http-nio-8095-exec-1] DEBUG o.s.retry.support.RetryTemplate [] - Retry: count=0
[2020-12-11 16:03:09,099] [http-nio-8095-exec-1] INFO u.b.config.RetryableDataSource [] - ***************************** Getting a new Database connection *****************************
[2020-12-11 16:03:09,811] [http-nio-8095-exec-1] INFO u.b.service.UsageDataServiceImpl [] - aggregation switch is false
[2020-12-11 16:03:19,906] [http-nio-8095-exec-1] ERROR u.b.service.UsageDataServiceImpl [] - No usage data file available to process. Setting aggregationDisabled flag to true.
The database has already queried for the state of a flag at this point, showing the database connection is working. The database is stopped at this point in order to simulate a database failure in order to test the fail/retry/recover scenario.
[2020-12-11 16:03:19,929] [http-nio-8095-exec-1] WARN c.zaxxer.hikari.pool.ProxyConnection [] - SpringBootJPAHikariCP - Connection com.mysql.cj.jdbc.ConnectionImpl@184c1740 marked as broken because of SQLSTATE(08S01), ErrorCode(0)
com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
The last packet successfully received from the server was 10,738 milliseconds ago. The last packet sent successfully to the server was 10,738 milliseconds ago.
at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2056)
at com.zaxxer.hikari.pool.ProxyConnection.setAutoCommit(ProxyConnection.java:414)
at com.zaxxer.hikari.pool.HikariProxyConnection.setAutoCommit(HikariProxyConnection.java)
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:67)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:263)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:236)
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:86)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:184)
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:402)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:378)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:475)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:289)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:144)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$ExposeRepositoryInvocationInterceptor.invoke(CrudMethodMetadataPostProcessor.java:364)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:61)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy133.updateAggregationDisabledFlag(Unknown Source)
at uk.bobbins.service.AggregationServiceImpl.updateAggregationDisabledFlag(AggregationServiceImpl.java:457)
at uk.bobbins.service.UsageDataServiceImpl.copyUsageDataFromSourceToDestination(UsageDataServiceImpl.java:94)
at uk.bobbins.UsageServiceImpl.copyUsageDataFromSourceToDestination(UsageServiceImpl.java:94)
at uk.bobbins.controller.RestController.UsageDataFromSource(RestController.java:152)
at uk.bobbins.controller.RestController$$FastClassBySpringCGLIB$$ae255ac.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
...
...
at java.lang.Thread.run(Thread.java:748)
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure
The last packet successfully received from the server was 10,738 milliseconds ago. The last packet sent successfully to the server was 10,738 milliseconds ago.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
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.readMessage(NativeProtocol.java:539)
at com.mysql.cj.protocol.a.NativeProtocol.checkErrorMessage(NativeProtocol.java:703)
at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:642)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:941)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryString(NativeProtocol.java:887)
at com.mysql.cj.NativeSession.execSQL(NativeSession.java:1073)
at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2046)
... 104 common frames omitted
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:67)
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63)
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45)
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:52)
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:41)
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:54)
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:44)
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:533)
... 110 common frames omitted
[2020-12-11 16:03:19,947] [http-nio-8095-exec-1] DEBUG o.s.r.b.ExponentialBackOffPolicy [] - Sleeping for 30000
The database is restarted at this point. We were hoping that the Spring-retry would grab a new connection and carry on. This is not the case. Instead the same dead connection is used for subsequent retries and the process fails accordingly.
[2020-12-11 16:03:49,948] [http-nio-8095-exec-1] DEBUG o.s.retry.support.RetryTemplate [] - Checking for rethrow: count=1
[2020-12-11 16:03:49,948] [http-nio-8095-exec-1] DEBUG o.s.retry.support.RetryTemplate [] - Retry: count=1
[2020-12-11 16:03:49,948] [http-nio-8095-exec-1] INFO u.b.c.RestController [] - Running usage data live service end point for: usageData
[2020-12-11 16:03:53,752] [http-nio-8095-exec-1] DEBUG o.s.r.b.ExponentialBackOffPolicy [] - Sleeping for 60000
[2020-12-11 16:04:53,753] [http-nio-8095-exec-1] DEBUG o.s.retry.support.RetryTemplate [] - Checking for rethrow: count=2
[2020-12-11 16:04:53,753] [http-nio-8095-exec-1] DEBUG o.s.retry.support.RetryTemplate [] - Retry: count=2
[2020-12-11 16:04:53,753] [http-nio-8095-exec-1] INFO u.b.c.RestController [] - Running usage data live service end point for: usageData
[2020-12-11 16:06:53,609] [SpringBootJPAHikariCP housekeeper] WARN com.zaxxer.hikari.pool.HikariPool [] - SpringBootJPAHikariCP - Thread starvation or clock leap detected (housekeeper delta=2m3s700ms974µs274ns).
[2020-12-11 16:06:53,608] [http-nio-8095-exec-1] DEBUG o.s.retry.support.RetryTemplate [] - Checking for rethrow: count=3
[2020-12-11 16:06:53,612] [http-nio-8095-exec-1] DEBUG o.s.retry.support.RetryTemplate [] - Retry failed last attempt: count=3
[2020-12-11 16:06:53,640] [http-nio-8095-exec-1] ERROR o.a.c.c.C.[.[.[.[dispatcherServlet] [] - Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.TransactionException: JDBC begin transaction failed: ] with root cause
java.sql.SQLException: Connection is closed
at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:515)
at com.sun.proxy.$Proxy98.setAutoCommit(Unknown Source)
at com.zaxxer.hikari.pool.ProxyConnection.setAutoCommit(ProxyConnection.java:414)
at com.zaxxer.hikari.pool.HikariProxyConnection.setAutoCommit(HikariProxyConnection.java)
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:67)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:263)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:236)
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:86)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:184)
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:402)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:378)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:475)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:289)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:144)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$ExposeRepositoryInvocationInterceptor.invoke(CrudMethodMetadataPostProcessor.java:364)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:61)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy133.updateAggregationDisabledFlag(Unknown Source)
at uk.bobbins.service.AggregationServiceImpl.updateAggregationDisabledFlag(AggregationServiceImpl.java:457)
at uk.bobbins.controller.RestController.usageDataFromSource(RestController.java:149)
at uk.bobbins.controller.RestController$$FastClassBySpringCGLIB$$ae255ac.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.retry.interceptor.RetryOperationsInterceptor$1.doWithRetry(RetryOperationsInterceptor.java:91)
at org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:287)
at org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:164)
at org.springframework.retry.interceptor.RetryOperationsInterceptor.invoke(RetryOperationsInterceptor.java:118)
at org.springframework.retry.annotation.AnnotationAwareRetryOperationsInterceptor.invoke(AnnotationAwareRetryOperationsInterceptor.java:153)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
at uk.bobbins.controller.RestController$$EnhancerBySpringCGLIB$$574fc03d.usageDataFromSource(<generated>)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:893)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:798)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:88)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:94)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:114)
at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:104)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
If anyone could shine a light on how I can make the spring-retry functionality acquire a new database connection (even from the pool) I would appreciate the knowledge.
Edited for a little more clarity.
Reading the solution that uses a separate thread by Andrew Harrison is fantastic. It provided different perspective to the problem and made me dig up more on the issue.
Apparently the issue is because of spring.jpa.open-in-view by default is enabled. The transaction actually is created much earlier, at the interceptor layer, than what is annotated at the controller or service level method.
You will notice this debugging line
o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
As such when the annotated method either controller or service is retried, the transaction did not cease despite the database connection has been interrupted.
This debugging line was never printed
o.s.orm.jpa.JpaTransactionManager : Closing JPA EntityManager [SessionImpl(1649520370<open>)] after transaction
Hence the spring-retry just keep repeating the method attempt to revive the transaction.
Disabling spring.jpa.open-in-view ensure no transaction has started before the spring-retry point-cut, thus ending of the spring-retry point-cut would result in the transaction ending along with the annotated method and each new iteration of the method would be also a new transaction open hence getting a new connection from the entity manager.
If spring.jpa.open-in-view is enabled, spring-retry will keep iterating the annotated method and end with the debugging line
o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
If it spring.jpa.open-in-view is disabled, each iteration while spring-retry is retrying the method would shows
o.s.orm.jpa.JpaTransactionManager : Closing JPA EntityManager [SessionImpl(1633589911<open>)] after transaction
and on start of each iteration would shows
o.s.orm.jpa.JpaTransactionManager : Creating new transaction with name [....]: PROPAGATION....
I hope this helps to shed light into why it may not be necessary to use Andrew Harrison method. Spring-retry works.
Andrew Harrison method may have created another problem should your View still requires access to the database. His method created new database connections in the new thread via the thread local EntityManager, but once the original request thread is resumed, the EntityManager in it will still be holding on to a defunct database connection. While I may not have tested, I highly suspect attempting to access the database in the View would result in JDBC errors too.