Uploaded image for project: 'JBoss Transaction Manager'
  1. JBoss Transaction Manager
  2. JBTM-1115

com.arjuna.wst.SystemException on BA XTS Crash Recovery tests

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • 4.16.4, 4.17.0
    • 4.16.3
    • Testing, XTS
    • None

      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

            [JBTM-1115] com.arjuna.wst.SystemException on BA XTS Crash Recovery tests

            Tom Jenkinson added a comment - Is this http://172.17.131.2/view/Narayana+BlackTie/job/jbossts-narayana-java6-ipv6-dualstack/39/console

            Paul Robinson added a comment - No it's JBTM-1216 . grep for "EndpointPublishService.java:95" on: http://172.17.131.2/view/Narayana+BlackTie/job/jbossts-branch417-EAP61-java7/456/artifact/XTS/localjunit/crash-recovery-tests/target/surefire-reports/com.arjuna.qa.junit.TestBACrashDuringCommit-output.txt

            Tom Jenkinson added a comment - Is it possible this has re-appeared? http://172.17.131.2/view/Narayana+BlackTie/job/jbossts-branch417-EAP61-java7/456/console

            This issue was pretty prevalent before we had a fix for it. It was occurring at least one run in 5. I am confident that the fix resolves this bug and we have now done 10+ runs without seeing this error. Therefore I am confident it is now resolved.

            Paul Robinson added a comment - This issue was pretty prevalent before we had a fix for it. It was occurring at least one run in 5. I am confident that the fix resolves this bug and we have now done 10+ runs without seeing this error. Therefore I am confident it is now resolved.

            Great, I really hope so!

            Can you comment on JBTM-1118 and explain why you think it is a duplicate of JBTM-1115.

            Paul Robinson added a comment - Great, I really hope so! Can you comment on JBTM-1118 and explain why you think it is a duplicate of JBTM-1115 .

            Zheng Feng added a comment -

            It looks like causing JBTM-1118 also.

            Zheng Feng added a comment - It looks like causing JBTM-1118 also.

            Paul Robinson added a comment - - edited

            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. occasionaly, one of these completed messages is delayed. 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 coordinator starts to abort the protocol. In the mean time the final 'completed' message comes in and the participant state machine moves to state competed. It then attempts to update the Basic Action, but is blocked as the coordinator is still in the process of aborting it. When the coordinator gets round to aborting this participant, a failure is raised as the state machine has moved to completing. A heuristic hazard is then raised, due to the mixed outcome.

            This is a bug. What should happen is that the participant is compensated if an abort is attempted when it is in state completed. This results in atomic outcome, where the transaction is aborted.

            This won't make the test pass, as the test expects a successful outcome. Therefore we need to use Byteman rules to ensure that this timing issue does not occur.

            Paul Robinson added a comment - - edited 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. occasionaly, one of these completed messages is delayed. 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 coordinator starts to abort the protocol. In the mean time the final 'completed' message comes in and the participant state machine moves to state competed. It then attempts to update the Basic Action, but is blocked as the coordinator is still in the process of aborting it. When the coordinator gets round to aborting this participant, a failure is raised as the state machine has moved to completing. A heuristic hazard is then raised, due to the mixed outcome. This is a bug. What should happen is that the participant is compensated if an abort is attempted when it is in state completed. This results in atomic outcome, where the transaction is aborted. This won't make the test pass, as the test expects a successful outcome. Therefore we need to use Byteman rules to ensure that this timing issue does not occur.

            This problem is usually happening in TestBACrashDuringCommit, but the actual test method that fails, varies. The failure also doesn't seem to be dependent on the order that the tests run. For example, it's not always the later tests that fail (indicating a resource issue).

            Distribution:

            TestBACrashDuringCommit:

            MultiParticipantParticipantCompletionParticipantCloseTest x 3
            MultiServiceParticipantCompletionParticipantCloseTest x 2
            MultiServiceParticipantCompletionParticipantCloseAndExitTest x 2
            MultiParticipantParticipantCompletionParticipantCloseAndExitTest x 1

            TestBACrashDuringOnePhaseCommit:

            SingleCoordinatorCompletionParticipantCloseTest x 1

            Paul Robinson added a comment - This problem is usually happening in TestBACrashDuringCommit, but the actual test method that fails, varies. The failure also doesn't seem to be dependent on the order that the tests run. For example, it's not always the later tests that fail (indicating a resource issue). Distribution: TestBACrashDuringCommit: MultiParticipantParticipantCompletionParticipantCloseTest x 3 MultiServiceParticipantCompletionParticipantCloseTest x 2 MultiServiceParticipantCompletionParticipantCloseAndExitTest x 2 MultiParticipantParticipantCompletionParticipantCloseAndExitTest x 1 TestBACrashDuringOnePhaseCommit: SingleCoordinatorCompletionParticipantCloseTest x 1

            I think this might be the significant part of the log:

            18:42:59,398 WARN  [com.arjuna.ats.arjuna] (TaskWorker-1) ARJUNA012073: BasicAction.End() - prepare phase of action-id 0:ffffac118303:693ecf52:4f8b089a:10 failed.
            18:42:59,399 WARN  [com.arjuna.ats.arjuna] (TaskWorker-1) ARJUNA012075: Action Aborting
            18:42:59,413 INFO  [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-1) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionParticipantService from WSDL: jar:file:/home/hudson/workspace/narayana-xts-recovery-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-5.0.0.M2-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-participant-binding.wsdl
            18:42:59,715 INFO  [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-2) Creating Service {http://docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionCoordinatorService from WSDL: jar:file:/home/hudson/workspace/narayana-xts-recovery-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-5.0.0.M2-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-coordinator-binding.wsdl
            18:42:59,837 WARN  [com.arjuna.ats.arjuna] (TaskWorker-1) ARJUNA012089: Top-level abort of action 0:ffffac118303:693ecf52:4f8b089a:10 received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
            18:42:59,926 INFO  [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-1) Creating Service {http://schemas.arjuna.com/ws/2005/10/wsarjtx}TerminationParticipantService from WSDL: jar:file:/home/hudson/workspace/narayana-xts-recovery-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-5.0.0.M2-SNAPSHOT.jar!/com/arjuna/schemas/ws/_2005/_10/wsarjtx/wsdl/wsarjtx-termination-participant-binding.wsdl
            18:42:59,979 ERROR [stderr] (Thread-79) org.jboss.jbossts.xts.servicetests.test.ba.MultiParticipantParticipantCompletionParticipantCloseAndExitTest : commit failure com.arjuna.wst.SystemException
            

            Note the failure to prepare and the HEURISTIC_HAZARD.

            Paul Robinson added a comment - I think this might be the significant part of the log: 18:42:59,398 WARN [com.arjuna.ats.arjuna] (TaskWorker-1) ARJUNA012073: BasicAction.End() - prepare phase of action-id 0:ffffac118303:693ecf52:4f8b089a:10 failed. 18:42:59,399 WARN [com.arjuna.ats.arjuna] (TaskWorker-1) ARJUNA012075: Action Aborting 18:42:59,413 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-1) Creating Service {http: //docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionParticipantService from WSDL: jar:file:/home/hudson/workspace/narayana-xts-recovery-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-5.0.0.M2-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-participant-binding.wsdl 18:42:59,715 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-2) Creating Service {http: //docs.oasis-open.org/ws-tx/wsba/2006/06}BusinessAgreementWithParticipantCompletionCoordinatorService from WSDL: jar:file:/home/hudson/workspace/narayana-xts-recovery-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-5.0.0.M2-SNAPSHOT.jar!/org/oasis_open/docs/ws_tx/wsba/_2006/_06/wsdl/wsba-participant-completion-coordinator-binding.wsdl 18:42:59,837 WARN [com.arjuna.ats.arjuna] (TaskWorker-1) ARJUNA012089: Top-level abort of action 0:ffffac118303:693ecf52:4f8b089a:10 received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD 18:42:59,926 INFO [org.apache.cxf.service.factory.ReflectionServiceFactoryBean] (TaskWorker-1) Creating Service {http: //schemas.arjuna.com/ws/2005/10/wsarjtx}TerminationParticipantService from WSDL: jar:file:/home/hudson/workspace/narayana-xts-recovery-java6/jboss-as/build/target/jboss-as-7.1.2.Final-SNAPSHOT/modules/org/jboss/xts/main/jbossxts-5.0.0.M2-SNAPSHOT.jar!/com/arjuna/schemas/ws/_2005/_10/wsarjtx/wsdl/wsarjtx-termination-participant-binding.wsdl 18:42:59,979 ERROR [stderr] ( Thread -79) org.jboss.jbossts.xts.servicetests.test.ba.MultiParticipantParticipantCompletionParticipantCloseAndExitTest : commit failure com.arjuna.wst.SystemException Note the failure to prepare and the HEURISTIC_HAZARD.

            Paul Robinson added a comment - - edited Currently on Hudson we have these jobs failing with, what looks like the same issue: http://albany/job/narayana-xts-recovery-java6/1 http://albany/job/narayana-xts-recovery-java6/3 http://albany/job/narayana-xts-recovery-java6/11 http://albany/job/narayana-xts-recovery-java6/13 http://albany/job/narayana-xts-recovery-java6/22 http://albany/view/Narayana+BlackTie/job/narayana-java6/1161 http://albany/view/Narayana+BlackTie/job/narayana-java6/1163 http://albany/view/Narayana+BlackTie/job/narayana-java6/1156 http://albany/view/Narayana+BlackTie/job/narayana-java7/321 http://172.17.131.2/view/Narayana+BlackTie/job/jbossts-branch416-java6/179 http://172.17.131.2/view/Narayana+BlackTie/job/jbossts-branch416-java6/177 http://172.17.131.2/view/Narayana+BlackTie/job/jbossts-branch416-java6/175

            This is what's happening:

            The Test is calling UserBusinessActivityImple.close() to complete the transaction
            UserBusinessActivityImple.close() seems to be sending the close message to the coordinator and then waits for a response.
            It doesn't look like a "closed" message is coming back from the server.

            I suspect something is going wrong on the server, preventing the closed() being returned. Unfortunately we would need the AS server logs to see this, which we don't have for this run. I'll add them to the list of artefacts saved so that if it happens again we get more info.

            Paul Robinson added a comment - This is what's happening: The Test is calling UserBusinessActivityImple.close() to complete the transaction UserBusinessActivityImple.close() seems to be sending the close message to the coordinator and then waits for a response. It doesn't look like a "closed" message is coming back from the server. I suspect something is going wrong on the server, preventing the closed() being returned. Unfortunately we would need the AS server logs to see this, which we don't have for this run. I'll add them to the list of artefacts saved so that if it happens again we get more info.

            Zheng Feng added a comment -

            Pual,

            I tried building on my machine in the same way like narayana.sh. but can not reproducing this error. all xts crash recovery tests work fine. my machine info is :

            OS: fc16.x86_64
            JAVA: java version "1.6.0_24"
            OpenJDK Runtime Environment (IcedTea6 1.11.1) (fedora-65.1.11.1.fc16-x86_64)
            OpenJDK 64-Bit Server VM (build 20.0-b12, mixed mode)

            any idea?

            Zheng Feng added a comment - Pual, I tried building on my machine in the same way like narayana.sh. but can not reproducing this error. all xts crash recovery tests work fine. my machine info is : OS: fc16.x86_64 JAVA: java version "1.6.0_24" OpenJDK Runtime Environment (IcedTea6 1.11.1) (fedora-65.1.11.1.fc16-x86_64) OpenJDK 64-Bit Server VM (build 20.0-b12, mixed mode) any idea?

            Added fixVer of 5M2

            Tom Jenkinson added a comment - Added fixVer of 5M2

            Amos,

            Can you try reproducing this on your own machine? You will need to build Narayana and AS7 from source in the same way that the CI script does. Can you then run the crash recovery tests with just 'org.jboss.jbossts.xts.servicetests.test.ba.MultiServiceParticipantCompletionParticipantCloseTest' and see if you get this same error. Can you run it a few times to make sure it isn't intermittent.

            Paul Robinson added a comment - Amos, Can you try reproducing this on your own machine? You will need to build Narayana and AS7 from source in the same way that the CI script does. Can you then run the crash recovery tests with just 'org.jboss.jbossts.xts.servicetests.test.ba.MultiServiceParticipantCompletionParticipantCloseTest' and see if you get this same error. Can you run it a few times to make sure it isn't intermittent.

              paul.robinson@redhat.com Paul Robinson
              zfeng@redhat.com Zheng Feng
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: