Atomikos Forum

XATransactionResource already closed

Hi,

  I am having a problem with XATransactionResource getting prematurely closed during application shutdown.

  We have a two node cluster with Informix database running on both the nodes. The application is shutdown by sending a QUIT signal. The application has a database writer thread that writes to the database. The code works fine on a LAN setup.
We are seeing the above error only in a WAN setup (where the RTT delay between the two nodes is 80 msec).

  From the logs, Transaction roll back error. After this, all datbase writes error out with "XATransactionResource already closed" exception. The AtomikosDataSourceBean /application context is actually destroyed later - I am logging the close/destroy code.

  What this error does is it fails to remove the row locks on the affected tables. This blocks the application entirely as the second node cannot write to the locked table/row.

 
  How to find out who/what is causing the XATransactionResource to close?
 
  I am attaching the snippets of the application log and atomikos log below.

  Thanks,
  Mahesh



Log snippet attached below:


Application log:

First error:
355383: Oct 09 18:46:38.799 IST %MIVR-CFG_MGR-7-EXCEPTION:org.springframework.transaction.UnexpectedRollbackException: JTA transaction already completed - probably rolled back
355384: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1012)
355385: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
355386: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
355387: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
355388: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
355389: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
355390: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
355391: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at $Proxy58.txReplace(Unknown Source)
355392: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.dbaccessor.DBAccessor.replace(DBAccessor.java:329)
355393: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.ConfigStubImpl.replace(ConfigStubImpl.java:602)
355394: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.Config.replace(Config.java:2659)
355395: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.ContactsUpdater.processOutboundSaveContactMsg(ContactsUpdater.java:53)
355396: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.SaveContactsMsgProcessor.run(SaveContactsMsgProcessor.java:101)
355397: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.Thread.run(Thread.java:539)
355398: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.runCommand(ExecutorStubImpl.java:690)
355399: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:486)
355400: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:762)
355401: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ThreadStubImpl$RequestImpl.run(ThreadStubImpl.java:570)
355402: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.util.ThreadPoolFactory$ThreadImpl.run(ThreadPoolFactory.java:853)
355403: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-UNK:configStubImpl-replace():: Exception=com.cisco.config.ConfigException: DB_ACCESS_ERROR:Replace; nested exception is:
        org.springframework.transaction.UnexpectedRollbackException: JTA transaction already completed - probably rolled back
355404: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:com.cisco.config.ConfigException: DB_ACCESS_ERROR:Replace; nested exception is:
355405: Oct 09 18:46:38.800 IST %MIVR-CFG_MGR-7-EXCEPTION:      org.springframework.transaction.UnexpectedRollbackException: JTA transaction already completed - probably rolled back
355406: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.dbaccessor.DBAccessor.replace(DBAccessor.java:344)
355407: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.ConfigStubImpl.replace(ConfigStubImpl.java:602)
355408: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.Config.replace(Config.java:2659)
355409: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.ContactsUpdater.processOutboundSaveContactMsg(ContactsUpdater.java:53)
355410: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.SaveContactsMsgProcessor.run(SaveContactsMsgProcessor.java:101)
355411: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.Thread.run(Thread.java:539)
355412: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.runCommand(ExecutorStubImpl.java:690)
355413: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:486)
355414: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:762)
355415: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ThreadStubImpl$RequestImpl.run(ThreadStubImpl.java:570)
355416: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.util.ThreadPoolFactory$ThreadImpl.run(ThreadPoolFactory.java:853)
355417: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      nested stack trace is:
355418: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      org.springframework.transaction.UnexpectedRollbackException: JTA transaction already completed - probably rolled back
355419: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1012)
355420: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
355421: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
355422: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
355423: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
355424: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
355425: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
355426: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at $Proxy58.txReplace(Unknown Source)
355427: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.dbaccessor.DBAccessor.replace(DBAccessor.java:329)
355428: Oct 09 18:46:38.801 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.ConfigStubImpl.replace(ConfigStubImpl.java:602)
355429: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.Config.replace(Config.java:2659)
355430: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.ContactsUpdater.processOutboundSaveContactMsg(ContactsUpdater.java:53)
355431: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.SaveContactsMsgProcessor.run(SaveContactsMsgProcessor.java:101)
355432: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.Thread.run(Thread.java:539)
355433: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.runCommand(ExecutorStubImpl.java:690)
355434: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:486)
355435: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:762)
355436: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ThreadStubImpl$RequestImpl.run(ThreadStubImpl.java:570)
355437: Oct 09 18:46:38.802 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.util.ThreadPoolFactory$ThreadImpl.run(ThreadPoolFactory.java:853)


Second error:
355509: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:java.lang.IllegalStateException: XATransactionResource already closed
355510: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.atomikos.datasource.xa.XATransactionalResource.getResourceTransaction(XATransactionalResource.java:604)
355511: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.atomikos.datasource.xa.session.BranchEnlistedStateHandler.<init>(BranchEnlistedStateHandler.java:29)
355512: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.atomikos.datasource.xa.session.NotInBranchStateHandler.checkEnlistBeforeUse(NotInBranchStateHandler.java:41)
355513: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.atomikos.datasource.xa.session.TransactionContext.checkEnlistBeforeUse(TransactionContext.java:60)
355514: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.atomikos.datasource.xa.session.SessionHandleState.notifyBeforeUse(SessionHandleState.java:151)
355515: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.atomikos.jdbc.AtomikosConnectionProxy.enlist(AtomikosConnectionProxy.java:172)
355516: Oct 09 18:46:38.842 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.atomikos.jdbc.AtomikosConnectionProxy.invoke(AtomikosConnectionProxy.java:106)
355517: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at $Proxy5910.prepareStatement(Unknown Source)
355518: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at sun.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
355519: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
355520: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at java.lang.reflect.Method.invoke(Method.java:597)
355521: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:225)
355522: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at $Proxy16.prepareStatement(Unknown Source)
355523: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:534)
355524: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:116)
355525: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:109)
355526: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:244)
355527: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2382)
355528: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
355529: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
355530: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.impl.StatelessSessionImpl.update(StatelessSessionImpl.java:161)
355531: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.hibernate.impl.StatelessSessionImpl.update(StatelessSessionImpl.java:143)
355532: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.persistence.dao.impl.DialingListDAOImpl.txReplace(DialingListDAOImpl.java:112)
355533: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at sun.reflect.GeneratedMethodAccessor147.invoke(Unknown Source)
355534: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
355535: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at java.lang.reflect.Method.invoke(Method.java:597)
355536: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
355537: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
355538: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
355539: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
355540: Oct 09 18:46:38.843 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
355541: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
355542: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at $Proxy58.txReplace(Unknown Source)
355543: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.dbaccessor.DBAccessor.replace(DBAccessor.java:329)
355544: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.impl.ConfigStubImpl.replace(ConfigStubImpl.java:602)
355545: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.config.Config.replace(Config.java:2659)
355546: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.ContactsUpdater.processOutboundSaveContactMsg(ContactsUpdater.java:53)
355547: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.wf.subsystems.outbound.SaveContactsMsgProcessor.run(SaveContactsMsgProcessor.java:101)
355548: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.Thread.run(Thread.java:539)
355549: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.runCommand(ExecutorStubImpl.java:690)
355550: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:486)
355551: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:762)
355552: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.executor.impl.ThreadStubImpl$RequestImpl.run(ThreadStubImpl.java:570)
355553: Oct 09 18:46:38.844 IST %MIVR-CFG_MGR-7-EXCEPTION:      at com.cisco.util.ThreadPoolFactory$ThreadImpl.run(ThreadPoolFactory.java:853)

Beans getting closed/destroyed:
356591: Oct 09 18:46:39.096 IST %MIVR-DB_MGR-7-UNK:EntityDataSource.destroy
356592: Oct 09 18:46:39.096 IST %MIVR-DB_MGR-7-UNK:EntityDataSource.closeLocalDS

===============

Atomikos log:
11-10-09 18:46:37,525 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] XAResource.start ( 6D697672746D30303239363030303132:6D697672746D313537 , XAResource.TMNOFLAGS ) on resource XADS-smahesh-n1 represented by XAResource instance com.informix.jdbcx.IfxXAResource@be0382
11-10-09 18:46:37,526 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@3aec42: calling prepareStatement...
11-10-09 18:46:37,532 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n2': getConnection ( null )...
11-10-09 18:46:37,532 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n2': init...
11-10-09 18:46:37,806 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@eab6b4: calling toString...
11-10-09 18:46:37,806 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@eab6b4: calling toString...
11-10-09 18:46:37,806 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] addParticipant ( XAResourceTransaction: 6D697672746D30303239363030303132:6D697672746D313538 ) for transaction mivrtm0029600012
11-10-09 18:46:37,806 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] XAResource.start ( 6D697672746D30303239363030303132:6D697672746D313538 , XAResource.TMNOFLAGS ) on resource XADS-smahesh-n2 represented by XAResource instance com.informix.jdbcx.IfxXAResource@10ba17d
11-10-09 18:46:37,891 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@eab6b4: calling prepareStatement...
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING core version: 3.6.2
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.console_file_name = tm.out
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.console_file_count = 500
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.automatic_resource_registration = true
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.client_demarcation = false
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.threaded_2pc = true
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.serial_jta_transactions = true
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.log_base_dir = /var/log/active/uccx/log/MIVR/
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.console_log_level = INFO
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.max_actives = 50
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.checkpoint_interval = 500
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.enable_logging = false
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.output_dir = /var/log/active/uccx/log/MIVR/
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.log_base_name = tmlog
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.console_file_limit = 5491520
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.max_timeout = 300000
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.tm_unique_name = mivrtm
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING java.naming.factory.initial = com.sun.jndi.rmi.registry.RegistryContextFactory
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING          =
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING java.naming.provider.url = rmi://localhost:1099
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.service = com.atomikos.icatch.standalone.UserTransactionServiceFactory
11-10-09 18:46:38,606 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.force_shutdown_on_vm_exit = true
11-10-09 18:46:38,607 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] USING com.atomikos.icatch.default_jta_timeout = 10000
11-10-09 18:46:38,624 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@3aec42: close()...
11-10-09 18:46:38,625 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] XAResource.end ( 6D697672746D30303239363030303132:6D697672746D313537 , XAResource.TMSUCCESS ) on resource XADS-smahesh-n1 represented by XAResource instance com.informix.jdbcx.IfxXAResource@be0382
11-10-09 18:46:38,626 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@eab6b4: close()...
11-10-09 18:46:38,711 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] XAResource.end ( 6D697672746D30303239363030303132:6D697672746D313538 , XAResource.TMSUCCESS ) on resource XADS-smahesh-n2 represented by XAResource instance com.informix.jdbcx.IfxXAResource@10ba17d
11-10-09 18:46:38,804 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n1': getConnection ( null )...
11-10-09 18:46:38,804 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n1': init...
11-10-09 18:46:38,819 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: calling toString...
11-10-09 18:46:38,819 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: calling toString...
11-10-09 18:46:38,820 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: calling prepareStatement...
11-10-09 18:46:38,821 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: isClosed()...
11-10-09 18:46:38,821 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: calling getWarnings...
11-10-09 18:46:38,821 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: calling clearWarnings...
11-10-09 18:46:38,822 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: close()...
11-10-09 18:46:38,822 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] THREADS: using JDK thread pooling...
11-10-09 18:46:38,824 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] createCompositeTransaction ( 300000 ): created new ROOT transaction with id mivrtm0000100013
11-10-09 18:46:38,824 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n1': getConnection ( null )...
11-10-09 18:46:38,824 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n1': init...
11-10-09 18:46:38,840 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: calling toString...
11-10-09 18:46:38,840 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: calling toString...
11-10-09 18:46:38,841 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] Error enlisting in transaction - connection might be broken? Please check the logs for more information...
11-10-09 18:46:38,841 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] Error enlisting in transaction - connection might be broken? Please check the logs for more information...
java.lang.IllegalStateException: XATransactionResource already closed
        at com.atomikos.datasource.xa.XATransactionalResource.getResourceTransaction(XATransactionalResource.java:604)
        at com.atomikos.datasource.xa.session.BranchEnlistedStateHandler.<init>(BranchEnlistedStateHandler.java:29)
        at com.atomikos.datasource.xa.session.NotInBranchStateHandler.checkEnlistBeforeUse(NotInBranchStateHandler.java:41)
        at com.atomikos.datasource.xa.session.TransactionContext.checkEnlistBeforeUse(TransactionContext.java:60)
        at com.atomikos.datasource.xa.session.SessionHandleState.notifyBeforeUse(SessionHandleState.java:151)
        at com.atomikos.jdbc.AtomikosConnectionProxy.enlist(AtomikosConnectionProxy.java:172)
        at com.atomikos.jdbc.AtomikosConnectionProxy.invoke(AtomikosConnectionProxy.java:106)
        at $Proxy5910.prepareStatement(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:225)
        at $Proxy16.prepareStatement(Unknown Source)
        at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:534)
        at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:116)
        at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:109)
        at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:244)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2382)
        at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
        at org.hibernate.impl.StatelessSessionImpl.update(StatelessSessionImpl.java:161)
        at org.hibernate.impl.StatelessSessionImpl.update(StatelessSessionImpl.java:143)
        at com.cisco.persistence.dao.impl.DialingListDAOImpl.txReplace(DialingListDAOImpl.java:112)
        at sun.reflect.GeneratedMethodAccessor147.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy58.txReplace(Unknown Source)
        at com.cisco.config.impl.dbaccessor.DBAccessor.replace(DBAccessor.java:329)
        at com.cisco.config.impl.ConfigStubImpl.replace(ConfigStubImpl.java:602)
        at com.cisco.config.Config.replace(Config.java:2659)
        at com.cisco.wf.subsystems.outbound.ContactsUpdater.processOutboundSaveContactMsg(ContactsUpdater.java:53)
        at com.cisco.wf.subsystems.outbound.SaveContactsMsgProcessor.run(SaveContactsMsgProcessor.java:101)
        at com.cisco.executor.Thread.run(Thread.java:539)
        at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.runCommand(ExecutorStubImpl.java:690)
        at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:486)
        at com.cisco.executor.impl.ExecutorStubImpl$RequestImpl.run(ExecutorStubImpl.java:762)
        at com.cisco.executor.impl.ThreadStubImpl$RequestImpl.run(ThreadStubImpl.java:570)
        at com.cisco.util.ThreadPoolFactory$ThreadImpl.run(ThreadPoolFactory.java:853)
11-10-09 18:46:38,842 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] afterCompletion ( STATUS_ROLLEDBACK ) called  on Synchronization: org.hibernate.transaction.CacheSynchronization
11-10-09 18:46:38,842 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] afterCompletion ( STATUS_ROLLEDBACK ) called  on Synchronization: org.hibernate.transaction.CacheSynchronization
11-10-09 18:46:38,842 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] rollback() done of transaction mivrtm0000100013
11-10-09 18:46:38,842 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection proxy for com.informix.jdbcx.IfxXAReusableConnection@2cb5c6: close()...
11-10-09 18:46:38,850 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n1': getConnection ( null )...
11-10-09 18:46:38,850 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] AtomikosDataSoureBean 'XADS-smahesh-n1': init...
11-10-09 18:46:38,851 [MIVR_SS_OB_SaveContactsMsgProcessor-58-0-SaveContactsMsgProcessor] atomikos connection pool 'XADS-smahesh-n1': error creating proxy of connection an AtomikosXAPooledConnection with a SessionHandleState with 0 context(s)
com.atomikos.datasource.pool.CreateConnectionException: an AtomikosXAPooledConnection with a SessionHandleState with 0 context(s): connection is erroneous
smahesh Send private email
Monday, October 10, 2011
 
 
Guy Pardon Send private email
Saturday, October 29, 2011
 
 

This topic is archived. No further replies will be accepted.

Other recent topics Other recent topics