Hi,
I'm encountering, seemingly random, transaction timeouts with my ODE
process under heavy load (10 requests/second). I say 'seemingly random',
because sometimes the test run completes without problems and the next
time it will crash early in the run. Not sure if this is an ODE problem
or related to Bitronix TM, but you'll probably be able to help with
that.
Attached you'll find some of the exceptions that were thrown.
I'm running Apache ODE 1.3.6 with Hibernate 3.2.0 GA on Tomcat 7 with
Bitronix 2.1.4.
My Bitronix config is:
resource.ds1.className=oracle.jdbc.xa.client.OracleXADataSource
resource.ds1.uniqueName=jdbc/ode
resource.ds1.minPoolSize=0
resource.ds1.maxPoolSize=50
resource.ds1.driverProperties.URL=jdbc:oracle:thin:@<omitted>
resource.ds1.driverProperties.user=ode
resource.ds1.driverProperties.password=ode
resource.ds1.allowLocalTransactions=true
resource.ds1.shareTransactionConnections=true
resource.ds1.acquisitionTimeout=120
I'm able to provide more info if needed.
Regards,
Michael
-------------------------Disclaimer-------------------------------
De informatie verzonden met dit e-mailbericht (en bijlagen) is uitsluitend
bestemd voor de geadresseerde(n) en zij die van de geadresseerde(n) toestemming
kregen dit bericht te lezen. Gebruik door anderen dan geadresseerde(n) is
verboden. De informatie in dit e-mailbericht (en bijlagen) kan vertrouwelijk
van aard zijn en kan binnen het bereik vallen van een geheimhoudingsplicht en
een verschoningsrecht.
-------------------------------------------------------------------
14:31:52,962 ERROR [JacobVPU] Method "run" in class
"org.apache.ode.bpel.runtime.PICK" threw an unexpected exception.
org.hibernate.exception.GenericJDBCException: could not insert:
[org.apache.ode.daohib.bpel.hobj.HCorrelationProperty]
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.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2202)
at
org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2595)
at
org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:51)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:139)
at
org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at
org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:41)
at
org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:969)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1114)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
at
org.apache.ode.daohib.bpel.ScopeDaoImpl.getCorrelationSet(ScopeDaoImpl.java:84)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl.isCorrelationInitialized(BpelRuntimeContextImpl.java:202)
at org.apache.ode.bpel.runtime.PICK.resolveCorrelationKey(PICK.java:154)
at org.apache.ode.bpel.runtime.PICK.run(PICK.java:93)
at sun.reflect.GeneratedMethodAccessor108.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.run(JacobVPU.java:451)
at org.apache.ode.jacob.vpu.JacobVPU.execute(JacobVPU.java:139)
at
org.apache.ode.bpel.engine.BpelRuntimeContextImpl.execute(BpelRuntimeContextImpl.java:978)
at
org.apache.ode.bpel.engine.PartnerLinkMyRoleImpl.invokeNewInstance(PartnerLinkMyRoleImpl.java:209)
at org.apache.ode.bpel.engine.BpelProcess$1.invoke(BpelProcess.java:283)
at
org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:238)
at
org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:279)
at
org.apache.ode.bpel.engine.BpelProcess.handleJobDetails(BpelProcess.java:426)
at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:460)
at
org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.java:450)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:523)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:517)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:289)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:244)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:517)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:501)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.sql.SQLException: error enlisting a JdbcConnectionHandle of a
JdbcPooledConnection from datasource jdbc/ode in state ACCESSIBLE with usage
count 1 wrapping oracle.jdbc.driver.T4CXAConnection@1dd3d5f on
oracle.jdbc.driver.LogicalConnection@1e85e45
at
bitronix.tm.resource.jdbc.JdbcConnectionHandle.enlistResource(JdbcConnectionHandle.java:87)
at
bitronix.tm.resource.jdbc.JdbcConnectionHandle.prepareStatement(JdbcConnectionHandle.java:242)
at sun.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64)
at $Proxy5.prepareStatement(Unknown Source)
at
org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:497)
at
org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:94)
at
org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:87)
at
org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:218)
at
org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2159)
... 38 more
Caused by: bitronix.tm.internal.BitronixSystemException: transaction timed out
at
bitronix.tm.resource.common.TransactionContextHelper.enlistInCurrentTransaction(TransactionContextHelper.java:63)
at
bitronix.tm.resource.jdbc.JdbcConnectionHandle.enlistResource(JdbcConnectionHandle.java:85)
... 49 more
==================
14:36:30,141 ERROR [BpelEngineImpl] Scheduled job failed; jobDetail=JobDetails(
instanceId: null mexId: 665012 processId:
{http://www.example.com/docloket/}docloket-4 type: INVOKE_INTERNAL channel:
null correlatorId: null correlationKeySet: null retryCount: null inMem: false
detailsExt: {})
org.hibernate.exception.SQLGrammarException: could not execute query
at
org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:67)
at
org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.loader.Loader.doList(Loader.java:2147)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
at org.hibernate.loader.Loader.list(Loader.java:2023)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)
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.apache.ode.daohib.bpel.CorrelatorDaoImpl.findRoute(CorrelatorDaoImpl.java:143)
at
org.apache.ode.bpel.engine.PartnerLinkMyRoleImpl.findRoute(PartnerLinkMyRoleImpl.java:140)
at
org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:233)
at
org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:279)
at
org.apache.ode.bpel.engine.BpelProcess.handleJobDetails(BpelProcess.java:426)
at
org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.java:460)
at
org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.java:450)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:523)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob$1.call(SimpleScheduler.java:517)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:289)
at
org.apache.ode.scheduler.simple.SimpleScheduler.execTransaction(SimpleScheduler.java:244)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:517)
at
org.apache.ode.scheduler.simple.SimpleScheduler$RunJob.call(SimpleScheduler.java:501)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed
transaction waiting for lock
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:447)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:396)
at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:879)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:505)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:223)
at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:531)
at
oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:207)
at
oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:884)
at
oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1167)
at
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1288)
at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3593)
at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3637)
at
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1495)
at
bitronix.tm.resource.jdbc.JdbcUncachedPreparedStatementHandle.executeQuery(JdbcUncachedPreparedStatementHandle.java:81)
at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64)
at $Proxy8.executeQuery(Unknown Source)
at
org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186)
at org.hibernate.loader.Loader.getResultSet(Loader.java:1668)
at org.hibernate.loader.Loader.doQuery(Loader.java:662)
at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
at org.hibernate.loader.Loader.doList(Loader.java:2144)
... 25 more
===================
14:41:00,804 ERROR [JDBCExceptionReporter] unable to get a connection from pool
of a PoolingDataSource containing an XAPool of resource jdbc/ode with 5
connection(s) (0 still available)
14:41:00,804 ERROR [ODEService] Exception occured while invoking ODE
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.prepareSelectStatement(AbstractBatcher.java:123)
at
org.hibernate.id.SequenceGenerator.generate(SequenceGenerator.java:73)
at
org.hibernate.id.SequenceHiLoGenerator.generate(SequenceHiLoGenerator.java:58)
at
org.apache.ode.daohib.NativeHiLoGenerator.generate(NativeHiLoGenerator.java:48)
at
org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:98)
at
org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:186)
at
org.hibernate.event.def.DefaultSaveEventListener.saveWithGeneratedOrRequestedId(DefaultSaveEventListener.java:33)
at
org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:175)
at
org.hibernate.event.def.DefaultSaveEventListener.performSaveOrUpdate(DefaultSaveEventListener.java:27)
at
org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70)
at org.hibernate.impl.SessionImpl.fireSave(SessionImpl.java:535)
at org.hibernate.impl.SessionImpl.save(SessionImpl.java:523)
at org.hibernate.impl.SessionImpl.save(SessionImpl.java:519)
at
org.apache.ode.daohib.bpel.BpelDAOConnectionImpl.createMessageExchange(BpelDAOConnectionImpl.java:96)
at
org.apache.ode.bpel.engine.BpelEngineImpl.createNewMyRoleMex(BpelEngineImpl.java:175)
at
org.apache.ode.bpel.engine.BpelEngineImpl.createMessageExchange(BpelEngineImpl.java:157)
at
org.apache.ode.bpel.engine.BpelEngineImpl.createMessageExchange(BpelEngineImpl.java:210)
at
org.apache.ode.axis2.ODEService.onAxisMessageExchange(ODEService.java:111)
at
org.apache.ode.axis2.hooks.ODEMessageReceiver.invokeBusinessLogic(ODEMessageReceiver.java:69)
at
org.apache.ode.axis2.hooks.ODEMessageReceiver.invokeBusinessLogic(ODEMessageReceiver.java:63)
at
org.apache.axis2.receivers.AbstractMessageReceiver.receive(AbstractMessageReceiver.java:114)
at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:173)
at
org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:173)
at
org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:144)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1041)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:603)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:312)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.sql.SQLException: unable to get a connection from pool of a
PoolingDataSource containing an XAPool of resource jdbc/ode with 5
connection(s) (0 still available)
at
bitronix.tm.resource.jdbc.PoolingDataSource.getConnection(PoolingDataSource.java:262)
at
org.apache.ode.daohib.SessionManager.getConnection(SessionManager.java:152)
at
org.apache.ode.daohib.DataSourceConnectionProvider.getConnection(DataSourceConnectionProvider.java:44)
at
org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
... 43 more
Caused by: bitronix.tm.internal.BitronixRuntimeException: XA pool of resource
jdbc/ode still empty after 30s wait time
at
bitronix.tm.resource.common.XAPool.waitForConnectionInPool(XAPool.java:423)
at bitronix.tm.resource.common.XAPool.getInPool(XAPool.java:374)
at
bitronix.tm.resource.common.XAPool.getConnectionHandle(XAPool.java:123)
at
bitronix.tm.resource.common.XAPool.getConnectionHandle(XAPool.java:91)
at
bitronix.tm.resource.jdbc.PoolingDataSource.getConnection(PoolingDataSource.java:258)
... 46 more
