[JBoss JIRA] (JBTM-1107) Recovery Support in Compensation API
by Gytis Trikleris (JIRA)
[ https://issues.jboss.org/browse/JBTM-1107?page=com.atlassian.jira.plugin.... ]
Issue was automatically transitioned when Gytis Trikleris created pull request #1077 in GitHub
----------------------------------------------------------------------------------------------
Status: Pull Request Sent (was: Coding In Progress)
> Recovery Support in Compensation API
> ------------------------------------
>
> Key: JBTM-1107
> URL: https://issues.jboss.org/browse/JBTM-1107
> Project: JBoss Transaction Manager
> Issue Type: Enhancement
> Components: Compensations
> Reporter: Tom Jenkinson
> Assignee: Gytis Trikleris
> Fix For: 5.next
>
>
> *Background*
> Currently Compensations API cannot handle system failures. Transaction state is not persisted in any stage. Thus no handlers will be invoked in case of the system crash.
> *Requirements*
> # Make handlers persistable (CompensationHandler, ConfirmationHandler, TransactionLoggedHandler).
> ## Require Serializable interface.
> ## Create PersistableHandler interface (similar to PersistableParticipant in RTS integration).
> # Make participant persistable (ParticipantImpl, LocalParticipant, RemoteParticipant).
> ## Make transaction identifier persistable (converting it to String should work).
> ## Implement PersistableParticipant in ParticipantImpl.
> ## Investigate if PARTICIPANT_COUNTERS in ParticipatnImpl have to be updated.
> # Make compensation scoped beans persistable.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
9 years, 2 months
[JBoss JIRA] (JBTM-2772) Introduce an authorization SPI
by Amos Feng (JIRA)
[ https://issues.jboss.org/browse/JBTM-2772?page=com.atlassian.jira.plugin.... ]
Amos Feng updated JBTM-2772:
----------------------------
Component/s: SPI
> Introduce an authorization SPI
> ------------------------------
>
> Key: JBTM-2772
> URL: https://issues.jboss.org/browse/JBTM-2772
> Project: JBoss Transaction Manager
> Issue Type: Enhancement
> Components: Application Server Integration, SPI
> Reporter: David Lloyd
> Assignee: Amos Feng
>
> We need an SPI that can be invoked to authorize state changes in a transaction. The method(s) should make it clear in some way which operation is being authorized, and it must run from the same thread as the thread which instigates the state change.
> It must be possible to register an implementation of the SPI when the container starts up or acquires the transaction manager.
> The operations that should provide authorization checks include, but are not limited to:
> * begin
> * rollback
> * prepare
> * forget
> * commit (one or two phase)
> * recover
> Thanks!
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2772) Introduce an authorization SPI
by David Lloyd (JIRA)
David Lloyd created JBTM-2772:
---------------------------------
Summary: Introduce an authorization SPI
Key: JBTM-2772
URL: https://issues.jboss.org/browse/JBTM-2772
Project: JBoss Transaction Manager
Issue Type: Enhancement
Components: Application Server Integration
Reporter: David Lloyd
Assignee: Amos Feng
We need an SPI that can be invoked to authorize state changes in a transaction. The method(s) should make it clear in some way which operation is being authorized, and it must run from the same thread as the thread which instigates the state change.
It must be possible to register an implementation of the SPI when the container starts up or acquires the transaction manager.
The operations that should provide authorization checks include, but are not limited to:
* begin
* rollback
* prepare
* forget
* commit (one or two phase)
* recover
Thanks!
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2771) JTS works incorrectly for JMS connection being interrupted at commit phase
by Ondra Chaloupka (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Ondra Chaloupka updated JBTM-2771:
----------------------------------
Component/s: JTS
> 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
> 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
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2771) JTS works incorrectly for JMS connection being interrupted at commit phase
by Ondra Chaloupka (JIRA)
Ondra Chaloupka created JBTM-2771:
-------------------------------------
Summary: 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
Reporter: Ondra Chaloupka
Priority: Blocker
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
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2771) JTS works incorrectly for JMS connection being interrupted at commit phase
by Ondra Chaloupka (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Ondra Chaloupka reassigned JBTM-2771:
-------------------------------------
Assignee: Tom Jenkinson (was: Ondra Chaloupka)
> 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
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2771) JTS works incorrectly for JMS connection being interrupted at commit phase
by Ondra Chaloupka (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Ondra Chaloupka updated JBTM-2771:
----------------------------------
Attachment: JMSProxyMessagingServerCrashRecoveryTestCase_prepareHalt_jts_server.log
> 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
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2771) JTS works incorrectly for JMS connection being interrupted at commit phase
by Ondra Chaloupka (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Ondra Chaloupka reassigned JBTM-2771:
-------------------------------------
Assignee: Ondra Chaloupka
> 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: Ondra Chaloupka
> 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
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2771) JTS works incorrectly for JMS connection being interrupted at commit phase
by Ondra Chaloupka (JIRA)
[ https://issues.jboss.org/browse/JBTM-2771?page=com.atlassian.jira.plugin.... ]
Ondra Chaloupka updated JBTM-2771:
----------------------------------
Affects Version/s: 5.3.5.Final
> 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
> Affects Versions: 5.3.5.Final
> Reporter: Ondra Chaloupka
> 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
(v6.4.11#64026)
9 years, 3 months
[JBoss JIRA] (JBTM-2770) Inconsistent behavior of CMR resource: XARecoveryModule#getNewXAResource
by Ondra Chaloupka (JIRA)
[ https://issues.jboss.org/browse/JBTM-2770?page=com.atlassian.jira.plugin.... ]
Ondra Chaloupka updated JBTM-2770:
----------------------------------
Affects Version/s: 5.3.5.Final
> Inconsistent behavior of CMR resource: XARecoveryModule#getNewXAResource
> ------------------------------------------------------------------------
>
> 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
> Attachments: JPAProxyCMRCrashRecoveryTestCase_commitHaltRecoveryProxyHalted_jta_server.log
>
>
> 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}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
9 years, 3 months