Timeout problem with JDBC LrcXAConnection

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

Timeout problem with JDBC LrcXAConnection

PhilipMeier
Hi,
we are happily using btm and had no problems running our software. But when pushing a lot of data into the db, we are getting an error in connection with a timeout. I think it has something to do with the state ACCESSIBLE and STARTED, but am not shure what to do about it since it is working for smaller data.

org.hibernate.exception.GenericJDBCException: error enlisting a JdbcConnectionHandle of a JdbcPooledConnection from datasource jdbc/ressDS in state ACCESSIBLE with usage count 1 wrapping a JDBC LrcXAConnection on org.hsqldb.jdbc.JDBCConnection@61193052 on a JDBC LrcConnectionHandle on a JDBC LrcXAResource in state STARTED

      at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)
        at org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.continueInvocation(ConnectionProxyHandler.java:146)
        at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81)
        at $Proxy134.prepareStatement(Unknown Source)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:147)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:166)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:145)
        at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1720)
        at org.hibernate.loader.Loader.doQuery(Loader.java:828)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:289)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
        at org.hibernate.loader.Loader.loadCollection(Loader.java:2159)
        at org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:61)
        at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:622)
        at org.hibernate.event.internal.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:82)
        at org.hibernate.internal.SessionImpl.initializeCollection(SessionImpl.java:1772)
        at org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:379)
        at org.hibernate.collection.internal.AbstractPersistentCollection.read(AbstractPersistentCollection.java:112)
        at org.hibernate.collection.internal.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:137)
        at org.hibernate.collection.internal.PersistentSet.size(PersistentSet.java:156)
        at java.util.Collections$UnmodifiableCollection.size(Collections.java:1055)


We are using the following configuration file (changing timeout doesn't work :-( ):
bitronix.tm.serverId=tomcat-btm-node0
bitronix.tm.journal.disk.logPart1Filename=${catalina.base}/work/btm1.tlog
bitronix.tm.journal.disk.logPart2Filename=${catalina.base}/work/btm2.tlog
bitronix.tm.resource.configuration=${catalina.base}/conf/resources.properties
bitronix.tm.disableJmx=true
bitronix.tm.timer.defaultTransactionTimeout=900

Any help on what the problem might be would be great.

Thanks in advance
Philip
Reply | Threaded
Open this post in threaded view
|

Re: Timeout problem with JDBC LrcXAConnection

Ludovic Orban-2
Sorry for the delay answering your question.

From what I can see from you config snippet, you've configured the default timeout to be at 900s which is about 15 minutes. If you run transactions that last more than this, it is very normal that BTM prevents it from running longer as soon as it has the opportunity which usually is when you try to run another query when using the LRC wrapper.

If you do have very long running transactions, I would advise you to set the transaction timeout by calling TransactionManager.setTransactionTimeout(int seconds) before calling TransactionManager.begin().

If you're quite sure your transactions don't last that long, could you please provide more information like what DB and JDBC driver you are using? The complete stack trace could be useful too.

--
Ludovic


On Thu, Oct 25, 2012 at 4:46 PM, PhilipMeier <[hidden email]> wrote:

Hi,
we are happily using btm and had no problems running our software. But when
pushing a lot of data into the db, we are getting an error in connection
with a timeout. I think it has something to do with the state ACCESSIBLE and
STARTED, but am not shure what to do about it since it is working for
smaller data.

org.hibernate.exception.GenericJDBCException: error enlisting a
JdbcConnectionHandle of a JdbcPooledConnection from datasource jdbc/ressDS
in state ACCESSIBLE with usage count 1 wrapping a JDBC LrcXAConnection on
org.hsqldb.jdbc.JDBCConnection@61193052 on a JDBC LrcConnectionHandle on a
JDBC LrcXAResource in state STARTED

      at
org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
        at
org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
        at
org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)
        at
org.hibernate.engine.jdbc.internal.proxy.ConnectionProxyHandler.continueInvocation(ConnectionProxyHandler.java:146)
        at
org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81)
        at $Proxy134.prepareStatement(Unknown Source)
        at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:147)
        at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:166)
        at
org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:145)
        at
org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1720)
        at org.hibernate.loader.Loader.doQuery(Loader.java:828)
        at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:289)
        at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
        at org.hibernate.loader.Loader.loadCollection(Loader.java:2159)
        at
org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:61)
        at
org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:622)
        at
org.hibernate.event.internal.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:82)
        at
org.hibernate.internal.SessionImpl.initializeCollection(SessionImpl.java:1772)
        at
org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:379)
        at
org.hibernate.collection.internal.AbstractPersistentCollection.read(AbstractPersistentCollection.java:112)
        at
org.hibernate.collection.internal.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:137)
        at
org.hibernate.collection.internal.PersistentSet.size(PersistentSet.java:156)
        at
java.util.Collections$UnmodifiableCollection.size(Collections.java:1055)


We are using the following configuration file (changing timeout doesn't work
:-( ):
bitronix.tm.serverId=tomcat-btm-node0
bitronix.tm.journal.disk.logPart1Filename=${catalina.base}/work/btm1.tlog
bitronix.tm.journal.disk.logPart2Filename=${catalina.base}/work/btm2.tlog
bitronix.tm.resource.configuration=${catalina.base}/conf/resources.properties
bitronix.tm.disableJmx=true
bitronix.tm.timer.defaultTransactionTimeout=900

Any help on what the problem might be would be great.

Thanks in advance
Philip
--
View this message in context: http://old.nabble.com/Timeout-problem-with-JDBC-LrcXAConnection-tp34601428p34601428.html
Sent from the Bitronix Transaction Manager mailing list archive at Nabble.com.


---------------------------------------------------------------------
To unsubscribe from this list, please visit:

    http://xircles.codehaus.org/manage_email



Reply | Threaded
Open this post in threaded view
|

Re: Timeout problem with JDBC LrcXAConnection

PhilipMeier
HI Ludovic,
thanks for your reply, I will try changing the code.

While inspecting my folders I found that I had a second config file with these options:

resource.ds1.className=bitronix.tm.resource.jdbc.lrc.LrcXADataSource
resource.ds1.uniqueName=jdbc/waveDS
resource.ds1.minPoolSize=10
resource.ds1.maxPoolSize=20
resource.ds1.allowLocalTransactions=true
resource.ds1.acquisitionTimeout=60
resource.ds1.acquisitionInterval=1
resource.ds1.shareTransactionConnections=true

Changing the acquisitionTimeout from 60 to 20 seconds did the trick. I still don't know why, but it worked. I have since changed the code itself and had no further problems.

Keep up the great work on Bitronix
Philip
Reply | Threaded
Open this post in threaded view
|

Re: Timeout problem with JDBC LrcXAConnection

rramchandhar
This post has NOT been accepted by the mailing list yet.
Hi,

We have this problem in 2 situations.

1) increase the batch size of database rows retrieved when queried.
2) when the commiting the database with huge number of data.

we have hierarchy of tables where we link more than 6 nearly 10 tables.

and we persit the top/root table, so that it persists all the data modified in the related tables.

Regarsd
Ram

================================================================
2013-09-09 14:17:32,283 ERROR [Camel (ewmp-camel-context) thread #7 - JmsConsumer[BT.PR.ORWMG1P1.WMG.EAS_ALCT_JOBS_TRIG.01]] - SqlExceptionHelper error enlisting a JdbcConnectionHandle of a JdbcPooledConnection from datasource oracle.ewmp in state ACCESSIBLE with usage count 1 wrapping a JDBC LrcXAConnection on oracle.jdbc.driver.T4CConnection@3af7dab3 on a JDBC LrcConnectionHandle on a JDBC LrcXAResource in state STARTED
2013-09-09 14:17:32,374 WARN [Camel (ewmp-camel-context) thread #7 - JmsConsumer[BT.PR.ORWMG1P1.WMG.EAS_ALCT_JOBS_TRIG.01]] - CapabilityBase$CapabilityLog Capability [EasAllocate/LogicalAddress(EAS_ALLOCATE_JOBS_TRIGGER)] error detected during execution
org.hibernate.exception.GenericJDBCException: could not prepare statement
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:188)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:159)
        at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1858)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1835)
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1815)
        at org.hibernate.loader.Loader.doQuery(Loader.java:899)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:341)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:311)
        at org.hibernate.loader.Loader.loadCollection(Loader.java:2234)
        at org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:65)
        at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:674)
        at org.hibernate.event.internal.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:83)
        at org.hibernate.internal.SessionImpl.initializeCollection(SessionImpl.java:1849)
        at org.hibernate.collection.internal.AbstractPersistentCollection$4.doWork(AbstractPersistentCollection.java:549)
        at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:234)
        at org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:545)
        at org.hibernate.collection.internal.AbstractPersistentCollection.read(AbstractPersistentCollection.java:124)
        at org.hibernate.collection.internal.AbstractPersistentCollection$1.doWork(AbstractPersistentCollection.java:153)
        at org.hibernate.collection.internal.AbstractPersistentCollection$1.doWork(AbstractPersistentCollection.java:138)
        at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:234)
        at org.hibernate.collection.internal.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:137)
        at org.hibernate.collection.internal.PersistentBag.size(PersistentBag.java:242)
        at java.util.Collections$UnmodifiableCollection.size(Collections.java:1055)
        at com.bt.ewmp.workFlow.thirdPartyTasking.processors.eas.AllocateJobsProcessor.processResults(AllocateJobsProcessor.java:183)
        at com.bt.ewmp.workFlow.thirdPartyTasking.processors.eas.AllocateJobsProcessor.runAllocationRequests(AllocateJobsProcessor.java:156)
        at com.bt.ewmp.workFlow.thirdPartyTasking.processors.eas.AllocateJobsProcessor.process(AllocateJobsProcessor.java:89)
        at com.bt.ewmp.workFlow.thirdPartyTasking.capability.CapabilityBase.processMessage(CapabilityBase.java:58)
        at com.bt.ewmp.workFlow.thirdPartyTasking.capability.CamelCapabilityProcessor$1.doInTransactionWithoutResult(CamelCapabilityProcessor.java:100)
        at org.springframework.transaction.support.TransactionCallbackWithoutResult.doInTransaction(TransactionCallbackWithoutResult.java:33)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130)
        at com.bt.ewmp.workFlow.thirdPartyTasking.capability.CamelCapabilityProcessor.executeCapabilityInANewTransaction(CamelCapabilityProcessor.java:92)
        at com.bt.ewmp.workFlow.thirdPartyTasking.capability.CamelCapabilityProcessor.process(CamelCapabilityProcessor.java:60)
        at org.apache.camel.util.AsyncProcessorConverterHelper$ProcessorToAsyncProcessorBridge.process(AsyncProcessorConverterHelper.java:61)
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73)
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73)
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:72)
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73)
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.processor.interceptor.BacklogTracerInterceptor.process(BacklogTracerInterceptor.java:84)
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73)
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:91)
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73)
        at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:390)
        at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:273)
        at org.apache.camel.processor.RouteContextProcessor.processNext(RouteContextProcessor.java:46)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.processor.interceptor.DefaultChannel.process(DefaultChannel.java:335)
        at org.apache.camel.processor.RouteContextProcessor.processNext(RouteContextProcessor.java:46)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.processor.UnitOfWorkProcessor.processAsync(UnitOfWorkProcessor.java:150)
        at org.apache.camel.processor.UnitOfWorkProcessor.process(UnitOfWorkProcessor.java:117)
        at org.apache.camel.processor.RouteInflightRepositoryProcessor.processNext(RouteInflightRepositoryProcessor.java:48)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73)
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90)
        at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:72)
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:99)
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:86)
        at org.apache.camel.component.jms.EndpointMessageListener.onMessage(EndpointMessageListener.java:104)
        at org.springframework.jms.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:562)
        at org.springframework.jms.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:500)
        at org.springframework.jms.listener.AbstractMessageListenerContainer.doExecuteListener(AbstractMessageListenerContainer.java:468)
        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:326)
        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:244)
        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1069)
        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1061)
        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:958)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
Caused by: java.sql.SQLException: error enlisting a JdbcConnectionHandle of a JdbcPooledConnection from datasource oracle.ewmp in state ACCESSIBLE with usage count 1 wrapping a JDBC LrcXAConnection on oracle.jdbc.driver.T4CConnection@3af7dab3 on a JDBC LrcConnectionHandle on a JDBC LrcXAResource in state STARTED
        at bitronix.tm.resource.jdbc.JdbcConnectionHandle.enlistResource(JdbcConnectionHandle.java:87)
        at bitronix.tm.resource.jdbc.JdbcConnectionHandle.prepareStatement(JdbcConnectionHandle.java:242)
        at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64)
        at com.sun.proxy.$Proxy24.prepareStatement(Unknown Source)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:161)
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:182)
        ... 77 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)
        ... 85 more