Hello,
Under very heavy load (at random different points in the application and at random time intervals from the start) my application crashes with the exception below.
Unfortunately the Generic error is not very helpful and I'm having major problems debugging it. Tracing the code with a debugger leads to where hibernate start executing the query.
One weird thing is that there is a single transaction active when I query postgresql about it, unfortunately there really is no way of telling what the query for the open transaction was, there certainly are no weird or long running queries in the log. The transaction can also be from the previous running query, but again debugging this is hell as it crashes randomly.
One strategy I'm persuing is to increase the per-thread/job limit (if it exists) of queries within Jboss5/Hibernate. I've played around with <property name="hibernate.connection.pool_size" value="20" /> but that does not solve it too. datasource settings are min/max 0/30. Postgresql reports just 2 connections from hibernate, one of which is always idle.
I'm sorry for the lousy report, but that's all I have atm.
Dennis
Hibernate version:
Hibernate EntityManager 3.2.0.GA
Hibernate Annotations 3.2.0.GA
Hibernate 3.2.1
(All from Jboss 5 embedded beta 2)
Mapping documents:
None, all annotations
Code between sessionFactory.openSession() and session.close():
Varies
Full stack trace of any exception that occurs:
Quote:
ERROR 34,519 (CoreRunner.java:112) Exception while running:javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection
javax.ejb.EJBTransactionRolledbackException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.jboss.ejb3.tx.Ejb3TxPolicy.handleInCallerTx(Ejb3TxPolicy.java:87)
at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:130)
at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:197)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:105)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:214)
at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:184)
at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:81)
at $Proxy82.getLowestSecurityPriceExchangeArchive(Unknown Source)
at com.stocketeer.brokers.testers.CandleTestBroker.getMarketPrice(CandleTestBroker.java:134)
at com.stocketeer.brokers.testers.costmodels.SingleAccountCostModel.logCurrentStatus(SingleAccountCostModel.java:178)
at com.stocketeer.brokers.testers.TestBroker.execute(TestBroker.java:633)
at sun.reflect.GeneratedMethodAccessor225.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:121)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:110)
at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)
at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:193)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:105)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:214)
at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:184)
at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:81)
at $Proxy83.execute(Unknown Source)
at com.dennis.CodeRunner.run(CodeRunner.java:104)
at com.dennis.testThingy(TestMe.java:104)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.testng.internal.MethodHelper.invokeMethod(MethodHelper.java:645)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:479)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:715)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
at org.testng.TestRunner.runWorkers(TestRunner.java:673)
at org.testng.TestRunner.privateRun(TestRunner.java:620)
at org.testng.TestRunner.run(TestRunner.java:480)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:278)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:273)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:253)
at org.testng.SuiteRunner.run(SuiteRunner.java:168)
at org.testng.TestNG.createAndRunSuiteRunners(TestNG.java:987)
at org.testng.TestNG.runSuitesLocally(TestNG.java:951)
at org.testng.TestNG.run(TestNG.java:719)
at org.testng.remote.RemoteTestNG.run(RemoteTestNG.java:73)
at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:122)
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:647)
at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:73)
at com.stocketeer.brokers.beans.ExchangeSelectorBean.getLowestSecurityPriceExchangeArchive(ExchangeSelectorBean.java:100)
at sun.reflect.GeneratedMethodAccessor180.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:121)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:110)
at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
... 73 more
Caused by: org.hibernate.exception.GenericJDBCException: Cannot open connection
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:420)
at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1538)
at org.hibernate.loader.Loader.doQuery(Loader.java:661)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
at org.hibernate.loader.Loader.doList(Loader.java:2211)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2095)
at org.hibernate.loader.Loader.list(Loader.java:2090)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:388)
at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:64)
... 87 more
Caused by: org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdff:cd04:4662b288:db8 status: ActionStatus.ABORT_ONLY >; - nested throwable: (Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdff:cd04:4662b288:db8 status: ActionStatus.ABORT_ONLY >)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
... 101 more
Caused by: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdff:cd04:4662b288:db8 status: ActionStatus.ABORT_ONLY >
at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:340)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:394)
at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:838)
at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
... 103 more
Name and version of the database you are using:Postgresql 8.1, JDBC connector 8.1-408.jdbc3
The generated SQL (show_sql=true):Debug level Hibernate log excerpt:Quote:
<Lots of queries before this, noting that the database cannot handle>
WARN [main] (JDBCExceptionReporter.java:logExceptions:77) SQL Error: 0, SQLState: null
ERROR [main] (JDBCExceptionReporter.java:logExceptions:78) Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdff:cd04:4662b288:db8 status: ActionStatus.ABORT_ONLY >; - nested throwable: (Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57fdff:cd04:4662b288:db8 status: ActionStatus.ABORT_ONLY >)
INFO [main] (SessionFactoryImpl.java:close:767) closing
INFO [main] (SessionFactoryObjectFactory.java:removeInstance:112) Unbinding factory from JNDI name: persistence.units:jar=stocketeer-ejb3.jar,unitName=stocketeer
INFO [main] (NamingHelper.java:getInitialContext:26) JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces}
INFO [main] (SessionFactoryObjectFactory.java:removeInstance:117) Unbound factory from JNDI name: persistence.units:jar=stocketeer-ejb3.jar,unitName=stocketeer