[JBoss JIRA] (JBTM-2771) JTS XAResources that throw XA_RETRY or XAER_RMFAIL cannot be retried
by Tom Jenkinson (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Tom Jenkinson updated JBTM-2771:
--------------------------------
Description: There is a flag that is persisted _committed which defines if a commit was attempted on an XAResource. In the case where the XAR returned XARETRY for example, we would have consulted that flag and not reattempted the commit. (was: I do experience regression against DR5 (Narayana 5.3.3.Final) with current DR6 (Narayana 5.3.5.Final) release.
The following scenario fails when JTS is used
{quote}
* prepare jms XA
* stop connection to jms broker
* prepare test XA
* call commit on jms XA
as connection is down we can experience {{XAException.XA_RETRY}}
* commit test XA
(the test XA is committed as XA_RETRY commands to finish the commit later which is made by recovery)
* recovery: commit jms XA
{quote}
in 7.1.0.DR6 version the recovery does not {{commit}} but {{rollback}} which can cause data integrity failure.
{code}
2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( getStatus ) nodeId=1 requestId=135
2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( getStatus ) nodeId=1 requestId=135
2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( getStatus ) nodeId=1 requestId=132
2016-10-11 17:03:32,194 DEBUG [com.arjuna.ats.jts] (Periodic Recovery) StatusChecker.getStatus(0:ffff7f000001:-687fd072:57fcfee8:4f) - stored status = CosTransactions::StatusNoTransaction
2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( replay_completion ) nodeId=1 requestId=133
2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( replay_completion ) nodeId=1 requestId=133
2016-10-11 17:03:32,195 DEBUG [com.arjuna.ats.jts] (Thread-276) ResourceCompletor.rollback()
2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( replay_completion ) nodeId=1 requestId=130
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionClientRequestInterceptorImpl::send_request ( rollback ) nodeId=1 requestId=133
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.recover got status: CosTransactions::StatusRolledBack
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) ContextManager::current ()
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.doRecovery ( false )
2016-10-11 17:03:32,196 INFO [com.arjuna.ats.jtax] (Periodic Recovery) ARJUNA024002: XA recovery rolling back < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request_service_contexts ( rollback ) nodeId=1 requestId=136
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request ( rollback ) nodeId=1 requestId=136
2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Periodic Recovery) Calling rollback:: xid=XidImpl (948004762 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Thread-276) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Thread-276) Calling rollback:: xid=XidImpl (1942398309 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,197 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Periodic Recovery) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
2016-10-11 17:03:32,240 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl] (Thread-3 (ActiveMQ-client-netty-threads-2140185711)) handling packet PACKET(SessionXAResponseMessage)[type=55, channelID=10, packetObject=SessionXAResponseMessage]
2016-10-11 17:03:32,241 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) HornetqObjectStore.remove_committed(0:ffff7f000001:-687fd072:57fcfee8:55, /CosTransactions/XAResourceRecord)
2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.journal.impl.JournalImpl] (Periodic Recovery) appendDeleteRecord::id=1, usedFile = JournalFileImpl: (jbossts-1.txlog id = 1, recordID = 1)
2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-276) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
2016-10-11 17:03:32,247 TRACE [com.arjuna.orbportability] (Periodic Recovery) RootOA::shutdownObject (Servant)
2016-10-11 17:03:32,248 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@4b366010, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@5db75d15}, transactionOriginNodeIdentifier='1'} 1476198202113 1476198212248 false
2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check TestXAResourceRecovered(TestXAResourceCommon(id:473, xid:null, timeout:0, prepareReturn:0)) 1476198162076 1476198212248 true
2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@16b79fd1 1476198161776 1476198212251 true
2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@130c1cb1 1476198202161 1476198212251 false
2016-10-11 17:03:32,251 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) JTS XARecoveryModule.resourceInitiatedRecovery completed
{code})
> JTS XAResources that throw XA_RETRY or XAER_RMFAIL cannot be retried
> --------------------------------------------------------------------
>
> Key: JBTM-2771
> URL: https://issues.jboss.org/browse/JBTM-2771
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Components: JTS
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> Assignee: Tom Jenkinson
> Priority: Blocker
> Attachments: JMSProxyMessagingServerCrashRecoveryTestCase_prepareHalt_jts_server.log
>
>
> There is a flag that is persisted _committed which defines if a commit was attempted on an XAResource. In the case where the XAR returned XARETRY for example, we would have consulted that flag and not reattempted the commit.
--
This message was sent by Atlassian JIRA
(v7.2.2#72004)
8 years, 1 month
[JBoss JIRA] (JBTM-2771) JTS XAResources that throw XA_RETRY or XAER_RMFAIL cannot be retried
by Tom Jenkinson (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Tom Jenkinson updated JBTM-2771:
--------------------------------
Summary: JTS XAResources that throw XA_RETRY or XAER_RMFAIL cannot be retried (was: JTS works incorrectly for JMS connection being interrupted at commit phase)
> JTS XAResources that throw XA_RETRY or XAER_RMFAIL cannot be retried
> --------------------------------------------------------------------
>
> Key: JBTM-2771
> URL: https://issues.jboss.org/browse/JBTM-2771
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Components: JTS
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> Assignee: Tom Jenkinson
> Priority: Blocker
> Attachments: JMSProxyMessagingServerCrashRecoveryTestCase_prepareHalt_jts_server.log
>
>
> I do experience regression against DR5 (Narayana 5.3.3.Final) with current DR6 (Narayana 5.3.5.Final) release.
> The following scenario fails when JTS is used
> {quote}
> * prepare jms XA
> * stop connection to jms broker
> * prepare test XA
> * call commit on jms XA
> as connection is down we can experience {{XAException.XA_RETRY}}
> * commit test XA
> (the test XA is committed as XA_RETRY commands to finish the commit later which is made by recovery)
> * recovery: commit jms XA
> {quote}
> in 7.1.0.DR6 version the recovery does not {{commit}} but {{rollback}} which can cause data integrity failure.
> {code}
> 2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( getStatus ) nodeId=1 requestId=135
> 2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( getStatus ) nodeId=1 requestId=135
> 2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( getStatus ) nodeId=1 requestId=132
> 2016-10-11 17:03:32,194 DEBUG [com.arjuna.ats.jts] (Periodic Recovery) StatusChecker.getStatus(0:ffff7f000001:-687fd072:57fcfee8:4f) - stored status = CosTransactions::StatusNoTransaction
> 2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( replay_completion ) nodeId=1 requestId=133
> 2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( replay_completion ) nodeId=1 requestId=133
> 2016-10-11 17:03:32,195 DEBUG [com.arjuna.ats.jts] (Thread-276) ResourceCompletor.rollback()
> 2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( replay_completion ) nodeId=1 requestId=130
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionClientRequestInterceptorImpl::send_request ( rollback ) nodeId=1 requestId=133
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.recover got status: CosTransactions::StatusRolledBack
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) ContextManager::current ()
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.doRecovery ( false )
> 2016-10-11 17:03:32,196 INFO [com.arjuna.ats.jtax] (Periodic Recovery) ARJUNA024002: XA recovery rolling back < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request_service_contexts ( rollback ) nodeId=1 requestId=136
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request ( rollback ) nodeId=1 requestId=136
> 2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Periodic Recovery) Calling rollback:: xid=XidImpl (948004762 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Thread-276) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Thread-276) Calling rollback:: xid=XidImpl (1942398309 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,197 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Periodic Recovery) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
> 2016-10-11 17:03:32,240 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl] (Thread-3 (ActiveMQ-client-netty-threads-2140185711)) handling packet PACKET(SessionXAResponseMessage)[type=55, channelID=10, packetObject=SessionXAResponseMessage]
> 2016-10-11 17:03:32,241 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) HornetqObjectStore.remove_committed(0:ffff7f000001:-687fd072:57fcfee8:55, /CosTransactions/XAResourceRecord)
> 2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.journal.impl.JournalImpl] (Periodic Recovery) appendDeleteRecord::id=1, usedFile = JournalFileImpl: (jbossts-1.txlog id = 1, recordID = 1)
> 2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-276) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
> 2016-10-11 17:03:32,247 TRACE [com.arjuna.orbportability] (Periodic Recovery) RootOA::shutdownObject (Servant)
> 2016-10-11 17:03:32,248 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@4b366010, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@5db75d15}, transactionOriginNodeIdentifier='1'} 1476198202113 1476198212248 false
> 2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check TestXAResourceRecovered(TestXAResourceCommon(id:473, xid:null, timeout:0, prepareReturn:0)) 1476198162076 1476198212248 true
> 2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@16b79fd1 1476198161776 1476198212251 true
> 2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@130c1cb1 1476198202161 1476198212251 false
> 2016-10-11 17:03:32,251 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) JTS XARecoveryModule.resourceInitiatedRecovery completed
> {code}
--
This message was sent by Atlassian JIRA
(v7.2.2#72004)
8 years, 1 month
[JBoss JIRA] (JBTM-2767) JCA inflowed JTS transactions can throw NPE
by Tom Jenkinson (JIRA)
[ https://issues.jboss.org/browse/JBTM-2767?page=com.atlassian.jira.plugin.... ]
Tom Jenkinson updated JBTM-2767:
--------------------------------
Status: Pull Request Sent (was: Open)
Git Pull Request: https://github.com/jbosstm/narayana/pull/1085/commits
> JCA inflowed JTS transactions can throw NPE
> -------------------------------------------
>
> Key: JBTM-2767
> URL: https://issues.jboss.org/browse/JBTM-2767
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Components: JTS
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> Assignee: Tom Jenkinson
> Priority: Minor
> Fix For: 5.next
>
>
> If an XAResource throws a heuristic we can't forget it but we do clean up some transactional state meaning it will need reloading from disk (after the heuristic is cleared) before it can be meaningfully used again. In the state where it can't be meaningfully used we need to provide something to the caller.
> [1]
> {code}
> 2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1) java.lang.NullPointerException2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.SubordinateAtomicTransaction.getXid(SubordinateAtomicTransaction.java:80)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.TransactionImple.baseXid(TransactionImple.java:126)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1) at com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple.getImportedTransaction(TransactionImporterImple.java:135)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at com.arjuna.ats.internal.jta.transaction.jts.jca.XATerminatorImple.commit(XATerminatorImple.java:83)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.as.test.jbossts.crashrec.jca.rar.TestResourceTxnWorkUnit.run(Unknown Source)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.jca.core.workmanager.WorkWrapper.run(WorkWrapper.java:223)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.SimpleDirectExecutor.execute(SimpleDirectExecutor.java:33)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.QueueExecutor.runTask(QueueExecutor.java:808)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.QueueExecutor.access$100(QueueExecutor.java:45)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.QueueExecutor$Worker.run(QueueExecutor.java:828)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at java.lang.Thread.run(Thread.java:745)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.JBossThread.run(JBossThread.java:320)
> 2016-10-05 16:19:23,538 ERROR [org.jboss.as.test.jbossts.crashrec.jca.rar.TestResourceTxnWorkUnit] (default-threads - 1) Unspecified sever exception: java.lang.NullPointerException at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.TransactionImple.recover(TransactionImple.java:135)
> at com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple.getImportedTransaction(TransactionImporterImple.java:141)
> at com.arjuna.ats.internal.jta.transaction.jts.jca.XATerminatorImple.commit(XATerminatorImple.java:83) at org.jboss.as.test.jbossts.crashrec.jca.rar.TestResourceTxnWorkUnit.run(Unknown Source) at org.jboss.jca.core.workmanager.WorkWrapper.run(WorkWrapper.java:223)
> at org.jboss.threads.SimpleDirectExecutor.execute(SimpleDirectExecutor.java:33) at org.jboss.threads.QueueExecutor.runTask(QueueExecutor.java:808)
> at org.jboss.threads.QueueExecutor.access$100(QueueExecutor.java:45)
> at org.jboss.threads.QueueExecutor$Worker.run(QueueExecutor.java:828)
> at java.lang.Thread.run(Thread.java:745)
> at org.jboss.threads.JBossThread.run(JBossThread.java:320)
> {code}
--
This message was sent by Atlassian JIRA
(v7.2.2#72004)
8 years, 1 month
[JBoss JIRA] (JBTM-2771) JTS works incorrectly for JMS connection being interrupted at commit phase
by Tom Jenkinson (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Tom Jenkinson updated JBTM-2771:
--------------------------------
Status: Pull Request Sent (was: Open)
Git Pull Request: https://github.com/jbosstm/narayana/pull/1085/
> JTS works incorrectly for JMS connection being interrupted at commit phase
> --------------------------------------------------------------------------
>
> Key: JBTM-2771
> URL: https://issues.jboss.org/browse/JBTM-2771
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Components: JTS
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> Assignee: Tom Jenkinson
> Priority: Blocker
> Attachments: JMSProxyMessagingServerCrashRecoveryTestCase_prepareHalt_jts_server.log
>
>
> I do experience regression against DR5 (Narayana 5.3.3.Final) with current DR6 (Narayana 5.3.5.Final) release.
> The following scenario fails when JTS is used
> {quote}
> * prepare jms XA
> * stop connection to jms broker
> * prepare test XA
> * call commit on jms XA
> as connection is down we can experience {{XAException.XA_RETRY}}
> * commit test XA
> (the test XA is committed as XA_RETRY commands to finish the commit later which is made by recovery)
> * recovery: commit jms XA
> {quote}
> in 7.1.0.DR6 version the recovery does not {{commit}} but {{rollback}} which can cause data integrity failure.
> {code}
> 2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( getStatus ) nodeId=1 requestId=135
> 2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( getStatus ) nodeId=1 requestId=135
> 2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( getStatus ) nodeId=1 requestId=132
> 2016-10-11 17:03:32,194 DEBUG [com.arjuna.ats.jts] (Periodic Recovery) StatusChecker.getStatus(0:ffff7f000001:-687fd072:57fcfee8:4f) - stored status = CosTransactions::StatusNoTransaction
> 2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( replay_completion ) nodeId=1 requestId=133
> 2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( replay_completion ) nodeId=1 requestId=133
> 2016-10-11 17:03:32,195 DEBUG [com.arjuna.ats.jts] (Thread-276) ResourceCompletor.rollback()
> 2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( replay_completion ) nodeId=1 requestId=130
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionClientRequestInterceptorImpl::send_request ( rollback ) nodeId=1 requestId=133
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.recover got status: CosTransactions::StatusRolledBack
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) ContextManager::current ()
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.doRecovery ( false )
> 2016-10-11 17:03:32,196 INFO [com.arjuna.ats.jtax] (Periodic Recovery) ARJUNA024002: XA recovery rolling back < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request_service_contexts ( rollback ) nodeId=1 requestId=136
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request ( rollback ) nodeId=1 requestId=136
> 2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Periodic Recovery) Calling rollback:: xid=XidImpl (948004762 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Thread-276) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Thread-276) Calling rollback:: xid=XidImpl (1942398309 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
> 2016-10-11 17:03:32,197 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Periodic Recovery) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
> 2016-10-11 17:03:32,240 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl] (Thread-3 (ActiveMQ-client-netty-threads-2140185711)) handling packet PACKET(SessionXAResponseMessage)[type=55, channelID=10, packetObject=SessionXAResponseMessage]
> 2016-10-11 17:03:32,241 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) HornetqObjectStore.remove_committed(0:ffff7f000001:-687fd072:57fcfee8:55, /CosTransactions/XAResourceRecord)
> 2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.journal.impl.JournalImpl] (Periodic Recovery) appendDeleteRecord::id=1, usedFile = JournalFileImpl: (jbossts-1.txlog id = 1, recordID = 1)
> 2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-276) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
> 2016-10-11 17:03:32,247 TRACE [com.arjuna.orbportability] (Periodic Recovery) RootOA::shutdownObject (Servant)
> 2016-10-11 17:03:32,248 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@4b366010, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@5db75d15}, transactionOriginNodeIdentifier='1'} 1476198202113 1476198212248 false
> 2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check TestXAResourceRecovered(TestXAResourceCommon(id:473, xid:null, timeout:0, prepareReturn:0)) 1476198162076 1476198212248 true
> 2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@16b79fd1 1476198161776 1476198212251 true
> 2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@130c1cb1 1476198202161 1476198212251 false
> 2016-10-11 17:03:32,251 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) JTS XARecoveryModule.resourceInitiatedRecovery completed
> {code}
--
This message was sent by Atlassian JIRA
(v7.2.2#72004)
8 years, 1 month
[JBoss JIRA] (JBTM-2770) Xids that relate to an CMR that has been recovered are rolledback even if the CMR committed
by Tom Jenkinson (JIRA)
[ https://issues.jboss.org/browse/JBTM-2770?page=com.atlassian.jira.plugin.... ]
Tom Jenkinson updated JBTM-2770:
--------------------------------
Description: During recovery the CMR orphan detection checks to make sure that there is not an indoubt transaction that pertains to the CMR before deciding if an Xid is an orphan. Actually the check should also see if the transaction committed. (was: I found another regression (besides JBEAP-6326) for behavior of CMR datasource which came with DR6 (Narayana 5.3.5.Final) and is regression against DR5 (5.3.3.Final)
The scenario which I run is following
{quote}
* enlist test xa resource
* enlist cmr db resource
* prepare cmr db resource
* prepare test xa resource
* commit cmr db resource
* crash app server
* start server and halt connection to DB
* do recovery of test xa resource which is expected being committed
{quote}
What happens is that the second resource (test XA resource) is not committed but is rolled-back. By my investigation I think that the regression came from changes under {{com.arjuna.ats.internal.jta.recovery.arjunacore#getNewXAResource(Xid xid)}} (but it's only observation and it could be wrong interpretation).
In log the rollback could be seen being caused by {{JTANodeNameXAResourceOrphanFilter}} which votes for rollback.
{code}
2016-10-06 17:59:19,552 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) node name of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:4302bcff:57f67425:2a, node_name=1, branch_uid=0:ffff7f000001:4302bcff:57f67425:2f, subordinatenodename=null, eis_name=java:/TestXAResource > is 12016-10-06 17:59:19,552 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) XAResourceOrphanFilter com.arjuna.ats.internal.jta.recovery.arjunacore.JTANodeNameXAResourceOrphanFilter voted ROLLBACK
{code})
> Xids that relate to an CMR that has been recovered are rolledback even if the CMR committed
> -------------------------------------------------------------------------------------------
>
> Key: JBTM-2770
> URL: https://issues.jboss.org/browse/JBTM-2770
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> Assignee: Tom Jenkinson
> Priority: Blocker
> Fix For: 5.next
>
>
> During recovery the CMR orphan detection checks to make sure that there is not an indoubt transaction that pertains to the CMR before deciding if an Xid is an orphan. Actually the check should also see if the transaction committed.
--
This message was sent by Atlassian JIRA
(v7.2.2#72004)
8 years, 1 month
[JBoss JIRA] (JBTM-2767) JCA inflowed JTS transactions can throw NPE
by Tom Jenkinson (JIRA)
[ https://issues.jboss.org/browse/JBTM-2767?page=com.atlassian.jira.plugin.... ]
Tom Jenkinson updated JBTM-2767:
--------------------------------
Fix Version/s: 5.next
> JCA inflowed JTS transactions can throw NPE
> -------------------------------------------
>
> Key: JBTM-2767
> URL: https://issues.jboss.org/browse/JBTM-2767
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Components: JTS
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> Assignee: Tom Jenkinson
> Priority: Minor
> Fix For: 5.next
>
>
> If an XAResource throws a heuristic we can't forget it but we do clean up some transactional state meaning it will need reloading from disk (after the heuristic is cleared) before it can be meaningfully used again. In the state where it can't be meaningfully used we need to provide something to the caller.
> [1]
> {code}
> 2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1) java.lang.NullPointerException2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.SubordinateAtomicTransaction.getXid(SubordinateAtomicTransaction.java:80)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.TransactionImple.baseXid(TransactionImple.java:126)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1) at com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple.getImportedTransaction(TransactionImporterImple.java:135)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at com.arjuna.ats.internal.jta.transaction.jts.jca.XATerminatorImple.commit(XATerminatorImple.java:83)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.as.test.jbossts.crashrec.jca.rar.TestResourceTxnWorkUnit.run(Unknown Source)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.jca.core.workmanager.WorkWrapper.run(WorkWrapper.java:223)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.SimpleDirectExecutor.execute(SimpleDirectExecutor.java:33)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.QueueExecutor.runTask(QueueExecutor.java:808)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.QueueExecutor.access$100(QueueExecutor.java:45)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.QueueExecutor$Worker.run(QueueExecutor.java:828)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at java.lang.Thread.run(Thread.java:745)2016-10-05 16:19:23,537 ERROR [stderr] (default-threads - 1)
> at org.jboss.threads.JBossThread.run(JBossThread.java:320)
> 2016-10-05 16:19:23,538 ERROR [org.jboss.as.test.jbossts.crashrec.jca.rar.TestResourceTxnWorkUnit] (default-threads - 1) Unspecified sever exception: java.lang.NullPointerException at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.TransactionImple.recover(TransactionImple.java:135)
> at com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple.getImportedTransaction(TransactionImporterImple.java:141)
> at com.arjuna.ats.internal.jta.transaction.jts.jca.XATerminatorImple.commit(XATerminatorImple.java:83) at org.jboss.as.test.jbossts.crashrec.jca.rar.TestResourceTxnWorkUnit.run(Unknown Source) at org.jboss.jca.core.workmanager.WorkWrapper.run(WorkWrapper.java:223)
> at org.jboss.threads.SimpleDirectExecutor.execute(SimpleDirectExecutor.java:33) at org.jboss.threads.QueueExecutor.runTask(QueueExecutor.java:808)
> at org.jboss.threads.QueueExecutor.access$100(QueueExecutor.java:45)
> at org.jboss.threads.QueueExecutor$Worker.run(QueueExecutor.java:828)
> at java.lang.Thread.run(Thread.java:745)
> at org.jboss.threads.JBossThread.run(JBossThread.java:320)
> {code}
--
This message was sent by Atlassian JIRA
(v7.2.2#72004)
8 years, 1 month
[JBoss JIRA] (JBTM-2769) CMR resource calls xa_forget on local resources
by Tom Jenkinson (JIRA)
[ https://issues.jboss.org/browse/JBTM-2769?page=com.atlassian.jira.plugin.... ]
Tom Jenkinson updated JBTM-2769:
--------------------------------
Fix Version/s: 5.next
> CMR resource calls xa_forget on local resources
> -----------------------------------------------
>
> Key: JBTM-2769
> URL: https://issues.jboss.org/browse/JBTM-2769
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> Assignee: Michael Musgrove
> Priority: Blocker
> Fix For: 5.next
>
>
> {code}
> 2016-10-06 17:50:17,105 WARN [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012290: failed to recover Transaction 0:ffff7f000001:6351fff9:57f67185:2a: java.lang.NullPointerException
> at com.arjuna.ats.internal.jta.resources.arjunacore.CommitMarkableResourceRecord.forgetHeuristic(CommitMarkableResourceRecord.java:544)
> at com.arjuna.ats.arjuna.coordinator.BasicAction.doForget(BasicAction.java:3603)
> at com.arjuna.ats.arjuna.coordinator.BasicAction.forgetHeuristics(BasicAction.java:1347)
> at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Abort(BasicAction.java:1991)
> at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2852)
> at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1871)
> at com.arjuna.ats.arjuna.recovery.RecoverAtomicAction.replayPhase2(RecoverAtomicAction.java:71)
> at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.doRecoverTransaction(AtomicActionRecoveryModule.java:152)
> at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.processTransactionsStatus(AtomicActionRecoveryModule.java:253)
> at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.periodicWorkSecondPass(AtomicActionRecoveryModule.java:109)
> at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:811)
> at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:377)
> {code}
> A local resource will have no concept of the forget and indeed the app server has an implementation that throws an exception if you call it.
--
This message was sent by Atlassian JIRA
(v7.2.2#72004)
8 years, 1 month