-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 
Author Message
 Post subject: Hibernate calls with .setQueryTimeout(0) with Postgresql.
PostPosted: Fri Jul 06, 2012 7:46 am 
Contributor
Contributor

Joined: Fri Apr 03, 2009 11:07 am
Posts: 11
Hi,
I am using PostgreSQL 9.2 Beta and the postgres JDBC driver code in CVS. In 9.2 the java.sql.Statement.setQueryTimeout(int) method is implemented for the first time. The value is in seconds.

Using the postgres JDBC driver that I built from source I find my JEE application is failing to execute PreparedStatements.
My application has named queries. These work fine because I have defined timeouts (120) in the deployment descriptor.

But the PreparedStatements causing the issue are generated by Hibernate to load entities with the timeout set to 0. That causes the driver to timeout the call immediately. This is one example of the error.

Code:
06:10:42,637 ERROR [org.jboss.as.ejb3.invocation] (EJB default - 13) JBAS014134: EJB Invocation failed on component OrderAuditSession for method public abstract void org.spec.jent.ejb.orders.session.OrderAuditService.validateInitialValues(int) throws org.spec.jent.common.AuditValidationException: javax.ejb.EJBException: java.lang.RuntimeException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: ERROR: canceling statement due to user request
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInOurTx(CMTTxInterceptor.java:165) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:229) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:303) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:189) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:80) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:42) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:43) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:299) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:67) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:199) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.6.0_22]
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.6.0_22]
        at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.6.0_22]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.6.0_22]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.6.0_22]
        at java.lang.Thread.run(Thread.java:679) [rt.jar:1.6.0_22]
        at org.jboss.threads.JBossThread.run(JBossThread.java:122)
Caused by: java.lang.RuntimeException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: ERROR: canceling statement due to user request
        at org.spec.jent.common.util.Utils.count(Utils.java:273) [specj.jar:1.0]
        at org.spec.jent.ejb.orders.session.OrderAuditSession.validateInitialValues(OrderAuditSession.java:72) [specj.jar:1.0]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_22]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.6.0_22]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.6.0_22]
        at java.lang.reflect.Method.invoke(Method.java:616) [rt.jar:1.6.0_22]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:36) [jboss-as-ee-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47) [jboss-as-jpa-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final-redhat-1.jar:1.1.1.Final-redhat-1]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:227) [jboss-as-ejb3-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1]
        ... 29 more
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: ERROR: canceling statement due to user request
        at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1372) [hibernate-entitymanager-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1295) [hibernate-entitymanager-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:317) [hibernate-entitymanager-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.spec.jent.common.util.Utils.count(Utils.java:271) [specj.jar:1.0]
        ... 51 more
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: ERROR: canceling statement due to user request
        at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1372) [hibernate-entitymanager-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1295) [hibernate-entitymanager-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:317) [hibernate-entitymanager-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.spec.jent.common.util.Utils.count(Utils.java:271) [specj.jar:1.0]
        ... 51 more
Caused by: org.hibernate.exception.GenericJDBCException: ERROR: canceling statement due to user request
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:129) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at $Proxy97.executeQuery(Unknown Source)        at org.hibernate.loader.Loader.getResultSet(Loader.java:1953) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.loader.Loader.doQuery(Loader.java:829) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:289) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.loader.Loader.doList(Loader.java:2438) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.loader.Loader.doList(Loader.java:2424) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2254) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.loader.Loader.list(Loader.java:2249) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:470) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:355) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:195) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1248) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.internal.QueryImpl.list(QueryImpl.java:101) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:284) [hibernate-entitymanager-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        ... 52 more
Caused by: org.postgresql.util.PSQLException: ERROR: canceling statement due to user request
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2159)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1888)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:417)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:302)
        at sun.reflect.GeneratedMethodAccessor39.invoke(Unknown Source) [:1.6.0_22]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.6.0_22]
        at java.lang.reflect.Method.invoke(Method.java:616) [rt.jar:1.6.0_22]
        at org.postgresql.ds.jdbc23.AbstractJdbc23PooledConnection$StatementHandler.invoke(AbstractJdbc23PooledConnection.java:455)
        at $Proxy96.executeQuery(Unknown Source)        at org.jboss.jca.adapters.jdbc.CachedPreparedStatement.executeQuery(CachedPreparedStatement.java:107)
        at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:462)
        at sun.reflect.GeneratedMethodAccessor39.invoke(Unknown Source) [:1.6.0_22]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.6.0_22]
        at java.lang.reflect.Method.invoke(Method.java:616) [rt.jar:1.6.0_22]
        at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:122) [hibernate-core-4.1.3.Final-redhat-1.jar:4.1.3.Final-redhat-1]
        ... 67 more


Is there a property I can set in persistence.xml to change the default timeout from 0 to a higher value for PreparedStatements ?

Regards,
Jeremy


Top
 Profile  
 
 Post subject: Re: Hibernate calls with .setQueryTimeout(0) with Postgresql.
PostPosted: Fri Jul 06, 2012 9:35 am 
Contributor
Contributor

Joined: Fri Apr 03, 2009 11:07 am
Posts: 11
Hi,
My fault. The code repo for postgresql has migrated from CVS to Git.

Using the latest code in Git now has a fix for passing a value of 0 to the driver. Which is to operate with no timeout limit. As specificied in the javadocs for java.sql.Statement.setQueryTimeout(int).

Regards,
Jeremy


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.