[jbossts-issues] [JBoss JIRA] (JBTM-1115) com.arjuna.wst.SystemException on BA XTS Crash Recovery tests
Paul Robinson (JIRA)
jira-events at lists.jboss.org
Tue Apr 17 05:22:17 EDT 2012
[ https://issues.jboss.org/browse/JBTM-1115?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12684829#comment-12684829 ]
Paul Robinson commented on JBTM-1115:
-------------------------------------
I've been talking to Andrew, and we think we now know what is causing this...
What happens is that all the services send a completed message to the coordinator **asynchronously** and then the services return control to the client. The client then calls uba.close() which tells the coordinator to close. The coordinator then checks that all ParticipantCompletionParticipants have completed, but finds that one or more have not (due to the completed message not arriving yet). The close fails and the the participants that have already completed, are compensated.
This is valid behaviour for XTS, but it breaks the test as the test is playing out a different scenario.
I'm going to put in some Byteman rules to provide us with enough logging to check this. If this is the cause, then we will need to add some synchronisation Byteman code to make sure this timing issue does not occur.
> com.arjuna.wst.SystemException on BA XTS Crash Recovery tests
> -------------------------------------------------------------
>
> Key: JBTM-1115
> URL: https://issues.jboss.org/browse/JBTM-1115
> Project: JBoss Transaction Manager
> Issue Type: Bug
> Security Level: Public(Everyone can see)
> Components: XTS
> Affects Versions: 4.16.3
> Reporter: Amos Feng
> Assignee: Amos Feng
> Fix For: 4.16.4, 5.0.0.M2
>
>
> when running org.jboss.jbossts.xts.servicetests.test.ba.MultiServiceParticipantCompletionParticipantCloseTest with BACrashDuringCommit, it fails with commands caused by throwing com.arjuna.wst.SystemException:
> 13:40:13,819 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (Thread-79) Creating Service {http://docs.oasis-open.org/ws-tx/wscoor/2006/06}ActivationService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wscoor/_2006/_06/wsdl/wscoor-activation-binding.wsdl
> 13:40:13,846 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (Thread-79) Creating Service {http://docs.oasis-open.org/ws-tx/wscoor/2006/06}ActivationService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wscoor/_2006/_06/wsdl/wscoor-activation-binding.wsdl
> 13:40:14,276 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (Thread-79) Creating Service {http://jbossts.jboss.org/xts/servicetests/generated}XTSServiceTestService from WSDL: vfs:/content/xtstest.war/WEB-INF/classes/org/jboss/jbossts/xts/servicetests/generated/wsdl/xtsservicetests.wsdl
> 13:40:14,444 INFO [stdout] (http--127.0.0.1-8080-2) service /xtsservicetest1
> 13:40:14,446 INFO [stdout] (http--127.0.0.1-8080-2) command enlistParticipantCompletion
> 13:40:14,448 INFO [stdout] (http--127.0.0.1-8080-2) command close
> 13:40:14,491 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (http--127.0.0.1-8080-2) Creating Service {http://docs.oasis-open.org/ws-tx/wscoor/2006/06}RegistrationService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wscoor/_2006/_06/wsdl/wscoor-registration-binding.wsdl
> 13:40:14,690 INFO [stdout] (http--127.0.0.1-8080-3) exits unaccounted for in block B9
> 13:40:14,711 INFO [stdout] (http--127.0.0.1-8080-3) exits unaccounted for in block B9
> 13:40:14,789 INFO [stdout] (http--127.0.0.1-8080-2) service /xtsservicetest2
> 13:40:14,790 INFO [stdout] (http--127.0.0.1-8080-2) command enlistParticipantCompletion
> 13:40:14,791 INFO [stdout] (http--127.0.0.1-8080-2) command close
> 13:40:14,806 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (http--127.0.0.1-8080-2) Creating Service {http://docs.oasis-open.org/ws-tx/wscoor/2006/06}RegistrationService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wscoor/_2006/_06/wsdl/wscoor-registration-binding.wsdl
> 13:40:14,869 INFO [stdout] (http--127.0.0.1-8080-2) service /xtsservicetest3
> 13:40:14,870 INFO [stdout] (http--127.0.0.1-8080-2) command enlistParticipantCompletion
> 13:40:14,872 INFO [stdout] (http--127.0.0.1-8080-2) command close
> 13:40:14,885 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (http--127.0.0.1-8080-2) Creating Service {http://docs.oasis-open.org/ws-tx/wscoor/2006/06}RegistrationService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wscoor/_2006/_06/wsdl/wscoor-registration-binding.wsdl
> 13:40:14,948 INFO [stdout] (http--127.0.0.1-8080-2) service /xtsservicetest1
> 13:40:14,950 INFO [stdout] (http--127.0.0.1-8080-2) command completed
> 13:40:14,950 INFO [stdout] (http--127.0.0.1-8080-2) command org.jboss.jbossts.xts.servicetests.ParticipantCompletionParticipant.0
> 13:40:15,049 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (http--127.0.0.1-8080-2) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionCoordinatorService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-coordinator-binding.wsdl
> 13:40:15,135 INFO [stdout] (http--127.0.0.1-8080-2) service /xtsservicetest2
> 13:40:15,136 INFO [stdout] (http--127.0.0.1-8080-2) command completed
> 13:40:15,137 INFO [stdout] (http--127.0.0.1-8080-2) command org.jboss.jbossts.xts.servicetests.ParticipantCompletionParticipant.1
> 13:40:15,155 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (http--127.0.0.1-8080-2) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionCoordinatorService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-coordinator-binding.wsdl
> 13:40:15,249 INFO [stdout] (http--127.0.0.1-8080-2) service /xtsservicetest3
> 13:40:15,250 INFO [stdout] (http--127.0.0.1-8080-2) command completed
> 13:40:15,251 INFO [stdout] (http--127.0.0.1-8080-2) command org.jboss.jbossts.xts.servicetests.ParticipantCompletionParticipant.2
> 13:40:15,289 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (http--127.0.0.1-8080-2) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionCoordinatorService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-coordinator-binding.wsdl
> 13:40:15,601 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (Thread-79) Creating Service {http://docs.oasis-open.org/ws-tx/wscoor/2006/06}RegistrationService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wscoor/_2006/_06/wsdl/wscoor-registration-binding.wsdl
> 13:40:15,656 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (Thread-79) Creating Service {http://schemas.arjuna.com/ws/2005/10/wsarjtx}TerminationCoordinatorService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/com/arjuna/schemas/ws/_2005/_10/wsarjtx/wsdl/wsarjtx-termination-coordinator-binding.wsdl
> 13:40:15,695 WARN [com.arjuna.ats.arjuna] (TaskWorker-2) ARJUNA012073: BasicAction.End() - prepare phase of action-id 0:ffffac118308:323f7d83:4f857ba3:10 failed.
> 13:40:15,697 WARN [com.arjuna.ats.arjuna] (TaskWorker-2) ARJUNA012075: Action Aborting
> 13:40:15,744 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-2) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionParticipantService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-participant-binding.wsdl
> 13:40:15,857 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-3) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionCoordinatorService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-coordinator-binding.wsdl
> 13:40:15,906 WARN [com.arjuna.ats.arjuna] (TaskWorker-2) ARJUNA012089: Top-level abort of action 0:ffffac118308:323f7d83:4f857ba3:10 received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
> 13:40:15,925 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-2) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionParticipantService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-participant-binding.wsdl
> 13:40:16,122 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-3) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionCoordinatorService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-coordinator-binding.wsdl
> 13:40:16,212 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-2) Creating Service {http://schemas.arjuna.com/ws/2005/10/wsarjtx}TerminationParticipantService from WSDL: jar:file:/home/hudson/workspace/jbossts-branch416-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-4.16.4.Final-SNAPSHOT.jar!/com/arjuna/schemas/ws/_2005/_10/wsarjtx/wsdl/wsarjtx-termination-participant-binding.wsdl
> 13:40:16,272 ERROR [stderr] (Thread-79) com.arjuna.wst.SystemException
> 13:40:16,273 ERROR [stderr] (Thread-79) at com.arjuna.wst11.stub.BusinessActivityTerminatorStub.close(BusinessActivityTerminatorStub.java:103)
> 13:40:16,276 ERROR [stderr] (Thread-79) at com.arjuna.mwlabs.wst11.ba.remote.UserBusinessActivityImple.close(UserBusinessActivityImple.java:157)
> 13:40:16,278 ERROR [stderr] (Thread-79) at org.jboss.jbossts.xts.servicetests.test.ba.MultiServiceParticipantCompletionParticipantCloseTest.run(MultiServiceParticipantCompletionParticipantCloseTest.java:163)
> 13:40:16,281 ERROR [stderr] (Thread-79) at org.jboss.jbossts.xts.servicetests.bean.XTSServiceTestRunnerBean$1.run(XTSServiceTestRunnerBean.java:115)
> 13:40:16,283 ERROR [stderr] (Thread-79) org.jboss.jbossts.xts.servicetests.test.ba.MultiServiceParticipantCompletionParticipantCloseTest : commit failure com.arjuna.wst.SystemException
> 13:40:16,286 INFO [stdout] (Thread-79) org.jboss.jbossts.xts.servicetests.test.ba.MultiServiceParticipantCompletionParticipantCloseTest : completed
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the jbossts-issues
mailing list