Atomikos Forum |
|
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
Hi,
Did you try this? http://www.atomikos.com/Documentation/SpringIntegration#Optimizing_the_Init_and_Close_Or HTH |