[
https://issues.jboss.org/browse/JBTM-2287?page=com.atlassian.jira.plugin....
]
Christian von Kutzleben commented on JBTM-2287:
-----------------------------------------------
@Michael: here is the entire log file output (it's not that long), from the bean
invocation which (artificially) kills the database, after prepare, before returning
the result; up to a successful bean invocation after the database has been restarted
automatically after the crash and after that the recovery attempts.
Let me know, if you need more information. Note, that Xids logged by us in this output use
a different toString() because of JBTM-2284
09:59:45,005 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 4) start
flags=TMNOFLAGS
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
09:59:45,006 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 4) start created
Versant TxnId 5641.0.4109 for Xid
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
09:59:45,012 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 4) start
flags=TMNOFLAGS
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.76.0.0.0.0.0.0.0.0
09:59:45,012 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 4) start created
Versant TxnId 5642.0.4106 for Xid
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.76.0.0.0.0.0.0.0.0
09:59:45,044 INFO [stdout] (EJB default - 4) About to terminate db server 0
09:59:45,047 INFO [stdout] (EJB default - 4) Crashhook set.
09:59:45,054 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) end
flags=TMSUCCESS
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
09:59:45,055 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) prepare
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
09:59:46,890 WARN [com.arjuna.ats.jtax] (RequestProcessor-5) ARJUNA024015: XAResource
prepare failed on resource com.versant.odbms.XAResourceImpl@2eed27ad for transaction <
131072, 29, 36, 0000000000-1-1101065041-50-615010084100114-110007049,
292929292929292929292828391357970-21-327912911312914318292929997829292929292929 > with:
XAException.XAER_RMFAIL: com.versant.odbms.VersantXAException: Prepare error: Network
error on database [jpadb1@localhost].
at com.versant.odbms.XAResourceImpl.getResult(XAResourceImpl.java:650)
at com.versant.odbms.XAResourceImpl.prepare(XAResourceImpl.java:409)
at
com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.prepare(XAResourceRecord.java:234)
[jbossjts-jacorb-4.17.15.Final-redhat-5.jar:4.17.15.Final-redhat-5]
at com.arjuna.ArjunaOTS.OTSAbstractRecordPOA._invoke(OTSAbstractRecordPOA.java:81)
[jbossjts-jacorb-4.17.15.Final-redhat-5.jar:4.17.15.Final-redhat-5]
at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:306)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:626)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:769)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
Caused by: com.versant.odbms.DatastoreException: Network error on database
[jpadb1@localhost].
at com.versant.odbms.Connection$30.getOrThrow(Connection.java:597)
at com.versant.odbms.XAResourceImpl.getResult(XAResourceImpl.java:623)
... 6 more
Caused by: java.io.IOException: An existing connection was forcibly closed by the remote
host
at sun.nio.ch.SocketDispatcher.read0(Native Method) [rt.jar:1.7.0_25]
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:43) [rt.jar:1.7.0_25]
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:225) [rt.jar:1.7.0_25]
at sun.nio.ch.IOUtil.read(IOUtil.java:193) [rt.jar:1.7.0_25]
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:375) [rt.jar:1.7.0_25]
at com.versant.odbms.net.RPC.readAll(RPC.java:759)
at com.versant.odbms.net.StreamedRPC.read(StreamedRPC.java:125)
at com.versant.odbms.net.StreamedRPC.receive(StreamedRPC.java:114)
at com.versant.odbms.SimpleConnection.doReceive(SimpleConnection.java:704)
at com.versant.odbms.Connection$30.getOrThrow(Connection.java:593)
... 7 more
09:59:46,900 WARN [com.arjuna.ats.arjuna] (EJB default - 4) ARJUNA012073:
BasicAction.End() - prepare phase of action-id 0:ffff0a6a3229:-313ccd9c:546472f5:46
failed.
09:59:46,900 WARN [com.arjuna.ats.arjuna] (EJB default - 4) ARJUNA012075: Action
Aborting
09:59:46,901 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) end
flags=TMFAIL
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
09:59:46,904 WARN [com.arjuna.ats.jts] (EJB default - 4) ARJUNA022223:
ExtendedResourceRecord.topLevelAbort caught exception: org.omg.CORBA.UNKNOWN: Server-side
Exception: null
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[rt.jar:1.7.0_25]
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
[rt.jar:1.7.0_25]
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[rt.jar:1.7.0_25]
at java.lang.reflect.Constructor.newInstance(Constructor.java:526) [rt.jar:1.7.0_25]
at org.jacorb.orb.SystemExceptionHelper.read(SystemExceptionHelper.java:223)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.orb.ReplyReceiver.getReply(ReplyReceiver.java:319)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.orb.Delegate.invoke_internal(Delegate.java:1090)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.orb.Delegate.invoke(Delegate.java:957)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:80)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at
com.arjuna.ArjunaOTS._ArjunaSubtranAwareResourceStub.rollback(_ArjunaSubtranAwareResourceStub.java:75)
at
com.arjuna.ats.internal.jts.resources.ExtendedResourceRecord.topLevelAbort(ExtendedResourceRecord.java:445)
at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2875)
at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2854)
at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Abort(BasicAction.java:1924)
at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1494)
at
com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.commit(ArjunaTransactionImple.java:375)
at com.arjuna.ats.internal.jts.ControlWrapper.commit(ControlWrapper.java:243)
at com.arjuna.ats.internal.jts.orbspecific.CurrentImple.commit(CurrentImple.java:247)
at com.arjuna.ats.jts.extensions.AtomicTransaction.commit(AtomicTransaction.java:276)
at
com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1296)
at
com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:130)
at
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:276)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:339)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
[jboss-as-ee-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45)
[jboss-as-ee-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165)
[jboss-as-ee-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:329)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:70)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:203)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[rt.jar:1.7.0_25]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_25]
at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_25]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[rt.jar:1.7.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[rt.jar:1.7.0_25]
at java.lang.Thread.run(Thread.java:724) [rt.jar:1.7.0_25]
at org.jboss.threads.JBossThread.run(JBossThread.java:122)
09:59:46,910 WARN [jacorb.poa.controller] (RequestController-1) rid: 200 opname:
_get_type_id cannot process request, because object doesn't exist
09:59:46,911 WARN [jacorb.poa.controller] (RequestController-1) rid: 200 opname:
_get_type_id request rejected with exception: null
09:59:46,911 WARN [com.arjuna.ats.jts] (EJB default - 4) ARJUNA022228:
ExtendedResourceRecord.typeIs failed. Returning default value: 151
09:59:46,912 WARN [com.arjuna.ats.arjuna] (EJB default - 4) ARJUNA012091: Top-level abort
of action 0:ffff0a6a3229:-313ccd9c:546472f5:46 received TwoPhaseOutcome.FINISH_ERROR from
com.arjuna.ats.internal.jts.resources.ExtendedResourceRecord
09:59:46,914 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) end
flags=TMFAIL
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.76.0.0.0.0.0.0.0.0
09:59:46,914 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) rollback
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.76.0.0.0.0.0.0.0.0
09:59:46,962 ERROR [stderr] (EJB default - 4) org.omg.CORBA.TRANSACTION_ROLLEDBACK
09:59:46,962 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.commit(ArjunaTransactionImple.java:414)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jts.ControlWrapper.commit(ControlWrapper.java:243)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jts.orbspecific.CurrentImple.commit(CurrentImple.java:247)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.jts.extensions.AtomicTransaction.commit(AtomicTransaction.java:276)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1296)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:130)
09:59:46,964 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
09:59:46,964 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92)
09:59:46,964 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:276)
09:59:46,964 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:339)
09:59:46,964 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
09:59:46,965 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,965 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79)
09:59:46,965 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,965 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
09:59:46,966 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,966 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
09:59:46,966 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,966 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59)
09:59:46,967 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,967 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
09:59:46,967 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,968 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55)
09:59:46,968 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,968 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45)
09:59:46,968 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
09:59:46,969 ERROR [stderr] (EJB default - 4) at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
09:59:46,969 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165)
09:59:46,969 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:329)
09:59:46,969 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:70)
09:59:46,969 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:203)
09:59:46,970 ERROR [stderr] (EJB default - 4) at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
09:59:46,970 ERROR [stderr] (EJB default - 4) at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
09:59:46,970 ERROR [stderr] (EJB default - 4) at
java.util.concurrent.FutureTask.run(FutureTask.java:166)
09:59:46,970 ERROR [stderr] (EJB default - 4) at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
09:59:46,970 ERROR [stderr] (EJB default - 4) at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
09:59:46,970 ERROR [stderr] (EJB default - 4) at java.lang.Thread.run(Thread.java:724)
09:59:46,971 ERROR [stderr] (EJB default - 4) at
org.jboss.threads.JBossThread.run(JBossThread.java:122)
09:59:46,971 ERROR [org.jboss.as.ejb3.invocation] (EJB default - 4) JBAS014134: EJB
Invocation failed on component ReconnectTestBean for method public abstract long[]
com.versant.jpa.j2ee.jboss.beans.ReconnectTestBeanRemote.modifyAndStopDbBeforeCommit(com.versant.jpa.j2ee.jboss.entities.J2EEBook[],com.versant.jpa.foundation.Option,int):
javax.ejb.EJBTransactionRolledbackException: Transaction rolled back
at
org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:138)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:118)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:276)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:339)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
[jboss-as-ee-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at
org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45)
[jboss-as-ee-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
[jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165)
[jboss-as-ee-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:329)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:70)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:203)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[rt.jar:1.7.0_25]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_25]
at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_25]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[rt.jar:1.7.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[rt.jar:1.7.0_25]
at java.lang.Thread.run(Thread.java:724) [rt.jar:1.7.0_25]
at org.jboss.threads.JBossThread.run(JBossThread.java:122)
Caused by: javax.transaction.RollbackException: org.omg.CORBA.TRANSACTION_ROLLEDBACK
at
com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1324)
at
com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:130)
at
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
... 30 more
09:59:48,516 INFO [stdout] (EJB default - 5) * ADD: begin J2EEBook[0 / Programming In
Scala]
09:59:48,593 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 5) start
flags=TMNOFLAGS
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.84.0.0.0.0.0.0.0.0
09:59:48,593 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 5) start created
Versant TxnId 5641.0.19463 for Xid
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.84.0.0.0.0.0.0.0.0
09:59:48,601 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 5) start
flags=TMNOFLAGS
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.88.0.0.0.0.0.0.0.0
09:59:48,601 FINER [com.versant.odbms.XAResourceImpl] (EJB default - 5) start created
Versant TxnId 5642.0.4108 for Xid
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.88.0.0.0.0.0.0.0.0
09:59:48,619 INFO [stdout] (EJB default - 5) * ADD: finish J2EEBook[1587800343624829960 /
Programming In Scala]
09:59:48,624 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) end
flags=TMSUCCESS
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.84.0.0.0.0.0.0.0.0
09:59:48,625 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) prepare
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.84.0.0.0.0.0.0.0.0
09:59:48,744 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) end
flags=TMSUCCESS
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.88.0.0.0.0.0.0.0.0
09:59:48,745 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) prepare
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.88.0.0.0.0.0.0.0.0
09:59:48,998 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) commit
onePhase=false
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.84.0.0.0.0.0.0.0.0
09:59:49,097 FINER [com.versant.odbms.XAResourceImpl] (RequestProcessor-5) commit
onePhase=false
xid=131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.82.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.88.0.0.0.0.0.0.0.0
09:59:49,664 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
09:59:49,665 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
09:59:58,022 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
09:59:58,022 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:06,067 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
10:00:06,067 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:14,184 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
10:00:14,184 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:22,275 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
10:00:22,275 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:30,329 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
10:00:30,329 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:38,377 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
10:00:38,377 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:46,493 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
10:00:46,493 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:54,545 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Found 1 XA transactions to recover.
10:00:54,545 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant JPA:
Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
JTS recovery module forgets about transaction -> transaction never
recovered
----------------------------------------------------------------------------
Key: JBTM-2287
URL:
https://issues.jboss.org/browse/JBTM-2287
Project: JBoss Transaction Manager
Issue Type: Bug
Affects Versions: 4.17.15
Environment: EAP 6.2.4 with JBoss Transactions 4.17.15
Reporter: Christian von Kutzleben
Assignee: Tom Jenkinson
The scenario is as follows (and works fine with JTA, see below):
Two XAResources in the same transaction, with xid1 and xid2, respectively.
(For better readability, log file excerpts are referenced and provided at the end of the
description.)
start xid1
start xid2
end xid1, tmsuccess
prepare xid1 -> XAException.XAER_RMFAIL; provoked, txn is indeed prepared in our test
case
end xid1, tmfail -> against XA protocol, however silently ignored by us
[error1 printed in log file]
end xid2, tmfail
rollback xid2
[error2 printed in log file]
[JTS: periodic, but fruitless recovery attempts]
as an effect, the transaction branch is never recovered and the dead transaction hangs
around forever in the database; it looks like, as if the JTS recovery component forgot to
early about that transaction, so does not do any rollback/commit decision for the reported
to-be-recovered transaction
with JTA the call sequence is as follows:
start xid1
start xid2
end xid1, tmsuccess
prepare xid1 -> XAException.XAER_RMFAIL; provoked, txn is indeed prepared in our test
case
rollback xid1 //this races with recovery module, but in any case, will be rolled back
end xid2, tmfail
rollback xid2
[JTA: periodic, successfull recovery]
With JTA, rollback might even be triggered twice (second invocation ignored by us)
here the log file excerpts, Xids printed with own toString() impl, because of JBTM-2284)
[JTA: periodic, successfull recovery]
10:48:20,646 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:48:20,646 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131077-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.113.21.-21.110.84.100.126.76.0.0.0.41.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.113.21.-21.110.84.100.126.76.0.0.0.42.0.0.0.0.0.0.0.0
10:48:23,689 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Rolled back
xid < formatId=131077, gtrid_length=29, bqual_length=36,
tx_uid=0:ffff0a6a3229:7115eb6e:54647e4c:29, node_name=1,
branch_uid=0:ffff0a6a3229:7115eb6e:54647e4c:2a, subordinatenodename=null, eis_name=unknown
eis name >
[JTS: periodic, but fruitless recovery attempts]
09:59:49,664 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
09:59:49,665 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
09:59:58,022 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
09:59:58,022 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:06,067 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:00:06,067 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:14,184 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:00:14,184 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:22,275 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:00:22,275 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:30,329 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:00:30,329 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:38,377 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:00:38,377 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:46,493 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:00:46,493 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
10:00:54,545 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Found 1 XA transactions to recover.
10:00:54,545 INFO [com.versant.odbms.XARecoveryResource] (Periodic Recovery) Versant
JPA: Xid to recover:
131072-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.70.49-0.0.0.0.0.0.0.0.0.0.-1.-1.10.106.50.41.-50.-61.50.100.84.100.114.-11.0.0.0.72.0.0.0.0.0.0.0.0
[error1]
09:59:46,904 WARN [com.arjuna.ats.jts] (EJB default - 4) ARJUNA022223:
ExtendedResourceRecord.topLevelAbort caught exception: org.omg.CORBA.UNKNOWN: Server-side
Exception: null
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[rt.jar:1.7.0_25]
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
[rt.jar:1.7.0_25]
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[rt.jar:1.7.0_25]
at java.lang.reflect.Constructor.newInstance(Constructor.java:526) [rt.jar:1.7.0_25]
at org.jacorb.orb.SystemExceptionHelper.read(SystemExceptionHelper.java:223)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.orb.ReplyReceiver.getReply(ReplyReceiver.java:319)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.orb.Delegate.invoke_internal(Delegate.java:1090)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.jacorb.orb.Delegate.invoke(Delegate.java:957)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:80)
[jacorb-2.3.2.redhat-6.jar:2.3.2.redhat-6]
at
com.arjuna.ArjunaOTS._ArjunaSubtranAwareResourceStub.rollback(_ArjunaSubtranAwareResourceStub.java:75)
at
com.arjuna.ats.internal.jts.resources.ExtendedResourceRecord.topLevelAbort(ExtendedResourceRecord.java:445)
at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2875)
at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2854)
at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Abort(BasicAction.java:1924)
at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1494)
at
com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.commit(ArjunaTransactionImple.java:375)
at com.arjuna.ats.internal.jts.ControlWrapper.commit(ControlWrapper.java:243)
at com.arjuna.ats.internal.jts.orbspecific.CurrentImple.commit(CurrentImple.java:247)
at com.arjuna.ats.jts.extensions.AtomicTransaction.commit(AtomicTransaction.java:276)
at
com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1296)
at
com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:130)
at
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92)
[jboss-as-ejb3-7.3.4.Final-redhat-1.jar:7.3.4.Final-redhat-1]
[error2]
09:59:46,962 ERROR [stderr] (EJB default - 4) org.omg.CORBA.TRANSACTION_ROLLEDBACK
09:59:46,962 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.commit(ArjunaTransactionImple.java:414)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jts.ControlWrapper.commit(ControlWrapper.java:243)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jts.orbspecific.CurrentImple.commit(CurrentImple.java:247)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.jts.extensions.AtomicTransaction.commit(AtomicTransaction.java:276)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1296)
09:59:46,963 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:130)
09:59:46,964 ERROR [stderr] (EJB default - 4) at
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
09:59:46,964 ERROR [stderr] (EJB default - 4) at
org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92)
--
This message was sent by Atlassian JIRA
(v6.3.8#6338)