Hello.
After updated to Spring Boot 3.0.1, the following propertie does not work anymore:
spring.jpa.properties.jakarta.persistence.query.timeout=20000
Before updating the propertie spring.jpa.properties.javax.persistence.query.timeout=20000 was working successfully.
Have tried to reach Spring Boot 3.0 migration guide but this information could not be found.
Any thoughts?
Thank you.
Comment From: wilkinsona
This appears to work for me. Setting spring.jpa.properties.jakarta.persistence.query.timeout=20000 in application.properties results in a timeout of 20 (seconds) being set on QueryOptionsImpl which is then applied to the PreparedStatement as expected. If you would like us to spend some more time investigating, please spend some time providing a complete yet minimal sample that reproduces the problem. You can share it with us by pushing it to a separate repository on GitHub or by zipping it up and attaching it to this issue.
Comment From: trcoelho
Hi @wilkinsona , thanks for reply.
This is pretty weird, I have debugged QueryOptionsImpl and in fact timeout variable is set by AbstractCommonQueryContract as per defined in application.properties, however once a database call is performed by a repository, method getTimeout() of QueryOptionsImpl always returns null.
application.properties
spring.jpa.properties.jakarta.persistence.query.timeout=2000
AbstractCommonQueryContract.applyHint :
QueryOptionsImpl.setTimeout(int):
QueryOptionsImpl.getTimeout():
In Spring Boot 2.7.7 the propertie spring.jpa.properties.javax.persistence.query.timeout works charming.
Is there any additional propertie missing as a result to have this query timeout work?
Thank you.
Comment From: philwebb
@trcoelho Are you able to provide a sample application that we can run and debug? Preferably one that works in 2.7 and not in 3.0.
Comment From: trcoelho
Hi @philwebb.
Please find attached a zip file (examples.zip) which contains 2 projects:
- example-3.0.1 (which has Spring Boot version 3.0.1)
- example-2.7.7 (which has Spring Boot version 2.7.7)
Inside each project I've created a folder which contains a file named \db\script.sql that has a sample database info as a result to test either projects.
For example-3.0.1 you will see that has propertie spring.jpa.properties.jakarta.persistence.query.timeout=5000 and on example-2.7.7 we have propertie spring.jpa.properties.javax.persistence.query.timeout=5000.
As a result to test timeout you will find on \db\script.sql two commands:
LOCK TABLES test_table READ;
LOCK TABLES test_table WRITE;
To lock tables when a request is performed and to unlock tables:
UNLOCK TABLES;
For example-2.7.7 application will respond (which is expected):
{
"timestamp":"2023-01-18T22:54:10.811+00:00",
"status":500,
"error":"Internal Server Error",
"trace":"org.springframework.dao.QueryTimeoutException: could not extract ResultSet; SQL [n/a]; nested exception is org.hibernate.QueryTimeoutException: could not extract ResultSet\r\n\tat org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:263)\r\n\tat org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:233)\r\n\tat org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:551)\r\n\tat org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61)\r\n\tat org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:242)\r\n\tat org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:152)\r\n\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)\r\n\tat org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:145)\r\n\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)\r\n\tat org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)\r\n\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)\r\n\tat org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)\r\n\tat jdk.proxy4/jdk.proxy4.$Proxy106.findByDescription(Unknown Source)\r\n\tat com.example.controller.impl.ExampleControllerImpl.findByName(ExampleControllerImpl.java:35)\r\n\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\r\n\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)\r\n\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\r\n\tat java.base/java.lang.reflect.Method.invoke(Method.java:568)\r\n\tat org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)\r\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150)\r\n\tat org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)\r\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895)\r\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)\r\n\tat org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)\r\n\tat org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1071)\r\n\tat org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:964)\r\n\tat org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)\r\n\tat org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)\r\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:670)\r\n\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)\r\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:779)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)\r\n\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)\r\n\tat org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)\r\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)\r\n\tat org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)\r\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)\r\n\tat org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)\r\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)\r\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)\r\n\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:177)\r\n\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)\r\n\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)\r\n\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)\r\n\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)\r\n\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)\r\n\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)\r\n\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)\r\n\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)\r\n\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:891)\r\n\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1784)\r\n\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)\r\n\tat org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)\r\n\tat org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)\r\n\tat org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)\r\n\tat java.base/java.lang.Thread.run(Thread.java:833)\r\nCaused by: org.hibernate.QueryTimeoutException: could not extract ResultSet\r\n\tat org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66)\r\n\tat org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:37)\r\n\tat org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)\r\n\tat org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)\r\n\tat org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:67)\r\n\tat org.hibernate.loader.Loader.getResultSet(Loader.java:2322)\r\n\tat org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2075)\r\n\tat org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2037)\r\n\tat org.hibernate.loader.Loader.doQuery(Loader.java:956)\r\n\tat org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:357)\r\n\tat org.hibernate.loader.Loader.doList(Loader.java:2868)\r\n\tat org.hibernate.loader.Loader.doList(Loader.java:2850)\r\n\tat org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2682)\r\n\tat org.hibernate.loader.Loader.list(Loader.java:2677)\r\n\tat org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:540)\r\n\tat org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:400)\r\n\tat org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:219)\r\n\tat org.hibernate.internal.SessionImpl.list(SessionImpl.java:1459)\r\n\tat org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1649)\r\n\tat org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1617)\r\n\tat org.hibernate.query.internal.AbstractProducedQuery.getSingleResult(AbstractProducedQuery.java:1665)\r\n\tat org.hibernate.query.criteria.internal.compile.CriteriaQueryTypeQueryAdapter.getSingleResult(CriteriaQueryTypeQueryAdapter.java:111)\r\n\tat org.springframework.data.jpa.repository.query.JpaQueryExecution$SingleEntityExecution.doExecute(JpaQueryExecution.java:198)\r\n\tat org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:90)\r\n\tat org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:156)\r\n\tat org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:144)\r\n\tat org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:137)\r\n\tat org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:121)\r\n\tat org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:160)\r\n\tat org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:139)\r\n\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)\r\n\tat org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:81)\r\n\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)\r\n\tat org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)\r\n\tat org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)\r\n\tat org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)\r\n\tat org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)\r\n\tat org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137)\r\n\t... 58 more\r\nCaused by: com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request\r\n\tat com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:113)\r\n\tat com.mysql.cj.jdbc.StatementImpl.checkCancelTimeout(StatementImpl.java:2167)\r\n\tat com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:1133)\r\n\tat com.mysql.cj.NativeSession.execSQL(NativeSession.java:665)\r\n\tat com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:893)\r\n\tat com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:972)\r\n\tat com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)\r\n\tat com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)\r\n\tat org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:57)\r\n\t... 91 more\r\n",
"message":"could not extract ResultSet; SQL [n/a]; nested exception is org.hibernate.QueryTimeoutException: could not extract ResultSet",
"path":"/examples/description/test_1"
}
And for example-3.0.1 will be running forever.
Additionally find curl command that I used to perform request:
curl -X 'GET' 'http://localhost:2008/examples/description/test_1' -H 'accept: application/json'
Database that I used to test is MySQL.
Let me know if you have any question.
Thanks in advance.
Comment From: philwebb
@trcoelho Thanks for the sample. I can replicate the issue, but I'm having a hard time working out what Spring is doing wrong. As far as I can tell we're correctly setting the jakarta.persistence.query.timeout property.
I have a feeling this might be a Hibernate issue. I think we'll need to try and recreate it without Spring being involved. We're doing a call to EntityManager.createQuery(CriteriaQuery<T> criteriaQuery). That creates a org.hibernate.query.sqm.internal.QuerySqmImpl instance which has its own queryOptions. It seems like setTimeout is never called on that instance.
Comment From: trcoelho
Hi @philwebb .
Exactly. Do we have a workaround for it , since this configuration is a must on project that I am working on, or should I downgrade to Spring Boot 2.7.7?
Do we have an idea of when (Spring Boot version) it will be fixed?
Thank you.
Comment From: wilkinsona
No idea, I'm afraid. If it's a Hibernate issue as we suspect, the timing of the fix is out of our control.
Comment From: trcoelho
Thank you @wilkinsona ,
Let me know if any action is needed from my side. Hopefully it should be fixed soon.
Thank you.
Comment From: trcoelho
Hello everyone!
After several testing I could solve it setting property:
spring.transaction.default-timeout=20s
on application.properties using Spring Boot 3.0.1 version.
QueryOptionsImpl.getTimeout() now retrieves correct value that is set on property above.
Not sure if is the best/correct approach but solved the problem.
I still think that this investigation should be opened as a result to make sure if this is a Spring or Hibernate bug.
Have opened a bug on Hibernate as well (https://hibernate.atlassian.net/browse/HHH-16062).
Thank you.
Comment From: philwebb
I've created a simple Hibernate only app and not been able to replicate it so it might still be a Spring issue.
Comment From: philwebb
Replicated it. Repro is at https://github.com/philwebb/HHH-16062. Will comment on the Hibernate issue.
Comment From: mpfaehler
If someone ends up here after trying to set jakarta.persistence.query.timeout to a value < 1000ms (like I did for testing purposes) you could try setting it to a value >= 1000ms since Hibernate converts values less than 1s to 0 (=no timeout), cp.
https://hibernate.atlassian.net/browse/HHH-18269?focusedCommentId=115790