[jbossts-issues] [JBoss JIRA] (JBTM-1751) TransactionRolledBackException thrown during the test case of a participant initiated ReadOnly message occurring prior to the prepare phase

TransactionRolledBackException thrown during the test case of a participant initiated ReadOnly message occurring prior to the prepare phase ------------------------------------------------------------------------------------------------------------------------------------------- Key: JBTM-1751 URL: https://issues.jboss.org/browse/JBTM-1751 Project: JBoss Transaction Manager Issue Type: Bug Security Level: Public(Everyone can see) Components: XTS Reporter: Gytis Trikleris Assignee: Amos Feng Fix For: 4.17.8, 5.0.0.M4 Original Estimate: 2 hours Time Spent: 2 hours Remaining Estimate: 1 day http://172.17.131.2/view/Narayana+BlackTie/job/jbossts-EAP61/1791/console... {code} [0m22:25:44,948 ERROR [org.jboss.arquillian.protocol.jmx.JMXTestRunner] (pool-1-thread-1) Failed: com.jboss.transaction.txinterop.interop.ATTest.testAT4_1: com.arjuna.wst.TransactionRolledBackException at com.arjuna.wst11.stub.CompletionStub.commit(CompletionStub.java:65) [jbossxts-4.17.5.Final-SNAPSHOT.jar:4.17.5.Final-SNAPSHOT] at com.jboss.transaction.txinterop.interop.ATTestCase.testAT4_1(ATTestCase.java:281) [classes:] at com.jboss.transaction.txinterop.interop.ATTest.testAT4_1(ATTest.java:104) [classes:] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_37] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_37] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_37] at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_37] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45) [arquillian-service:] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) [arquillian-service:] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian$6$1.invoke(Arquillian.java:270) [arquillian-service:] at org.jboss.arquillian.container.test.impl.execution.LocalTestExecuter.execute(LocalTestExecuter.java:60) [arquillian-service:] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_37] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_37] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_37] at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_37] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) [arquillian-service:] at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) [arquillian-service:] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) [arquillian-service:] at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135) [arquillian-service:] at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115) [arquillian-service:] at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67) [arquillian-service:] at org.jboss.arquillian.container.test.impl.execution.ContainerTestExecuter.execute(ContainerTestExecuter.java:38) [arquillian-service:] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_37] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_37] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_37] at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_37] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) [arquillian-service:] at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) [arquillian-service:] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) [arquillian-service:] at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:89) [arquillian-service:] at sun.reflect.GeneratedMethodAccessor91.invoke(Unknown Source) [:1.6.0_37] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_37] at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_37] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) [arquillian-service:] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:] at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:75) [arquillian-service:] at sun.reflect.GeneratedMethodAccessor90.invoke(Unknown Source) [:1.6.0_37] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_37] at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_37] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) [arquillian-service:] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:] at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:60) [arquillian-service:] at sun.reflect.GeneratedMethodAccessor87.invoke(Unknown Source) [:1.6.0_37] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_37] at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_37] at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:90) [arquillian-service:] at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:] at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135) [arquillian-service:] at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.test(EventTestRunnerAdaptor.java:111) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian$6.evaluate(Arquillian.java:263) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:226) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:240) [arquillian-service:] at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263) [arquillian-service:] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68) [arquillian-service:] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) [arquillian-service:] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) [arquillian-service:] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) [arquillian-service:] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) [arquillian-service:] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) [arquillian-service:] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:185) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:199) [arquillian-service:] at org.junit.runners.ParentRunner.run(ParentRunner.java:300) [arquillian-service:] at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:147) [arquillian-service:] at org.junit.runner.JUnitCore.run(JUnitCore.java:157) [arquillian-service:] at org.junit.runner.JUnitCore.run(JUnitCore.java:136) [arquillian-service:] at org.jboss.arquillian.junit.container.JUnitTestRunner.execute(JUnitTestRunner.java:65) [arquillian-service:] at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethodInternal(JMXTestRunner.java:128) [arquillian-service:] at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethod(JMXTestRunner.java:107) [arquillian-service:] at org.jboss.as.arquillian.service.ArquillianService$ExtendedJMXTestRunner.runTestMethod(ArquillianService.java:214) [arquillian-service:] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_37] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_37] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_37] at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_37] at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:93) [rt.jar:1.6.0_37] at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:27) [rt.jar:1.6.0_37] at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:208) [rt.jar:1.6.0_37] at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:120) [rt.jar:1.6.0_37] at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:262) [rt.jar:1.6.0_37] at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:836) [rt.jar:1.6.0_37] at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:761) [rt.jar:1.6.0_37] at org.jboss.as.jmx.PluggableMBeanServerImpl$TcclMBeanServer.invoke(PluggableMBeanServerImpl.java:527) at org.jboss.as.jmx.PluggableMBeanServerImpl.invoke(PluggableMBeanServerImpl.java:263) at org.jboss.remotingjmx.protocol.v2.ServerProxy$InvokeHandler.handle(ServerProxy.java:915) at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1.run(ServerCommon.java:152) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_37] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_37] at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_37] {code} Another errors in the log: {code} 22:26:26,763 WARN [com.arjuna.mw.wstx] (TaskWorker-2) ARJUNA045035: comms timeout attempting to prepare WS-AT participant D0:ffffac118324:4acfdb55:51afacb7:87 22:26:26,763 ERROR [stderr] (TaskWorker-2) com.arjuna.mw.wsas.exceptions.SystemCommunicationException: com.arjuna.wst.stub.SystemCommunicationException 22:26:26,763 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.prepare(DurableTwoPhaseCommitParticipant.java:124) 22:26:26,764 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.confirmOnePhase(DurableTwoPhaseCommitParticipant.java:233) 22:26:26,764 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf.model.twophase.arjunacore.ParticipantRecord.topLevelOnePhaseCommit(ParticipantRecord.java:429) 22:26:26,764 ERROR [stderr] (TaskWorker-2) at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2263) 22:26:26,764 ERROR [stderr] (TaskWorker-2) at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475) 22:26:26,764 ERROR [stderr] (TaskWorker-2) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) 22:26:26,765 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorControl.complete(CoordinatorControl.java:137) 22:26:26,765 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf11.model.twophase.arjunacore.TwoPhaseHLSImple.complete(TwoPhaseHLSImple.java:130) 22:26:26,765 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wsas.activity.ActivityImple.end(ActivityImple.java:293) 22:26:26,765 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wsas.UserActivityImple.end(UserActivityImple.java:261) 22:26:26,765 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorServiceImple.confirm(CoordinatorServiceImple.java:156) 22:26:26,766 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wst11.at.participants.CompletionCoordinatorImple.commit(CompletionCoordinatorImple.java:41) 22:26:26,766 ERROR [stderr] (TaskWorker-2) at com.arjuna.wst11.messaging.CompletionCoordinatorProcessorImpl.commit(CompletionCoordinatorProcessorImpl.java:84) 22:26:26,766 ERROR [stderr] (TaskWorker-2) at com.arjuna.webservices11.wsat.sei.CompletionCoordinatorPortTypeImpl$1.executeTask(CompletionCoordinatorPortTypeImpl.java:58) 22:26:26,766 ERROR [stderr] (TaskWorker-2) at com.arjuna.services.framework.task.TaskWorker.run(TaskWorker.java:63) 22:26:26,766 ERROR [stderr] (TaskWorker-2) at java.lang.Thread.run(Thread.java:662) {code} and: {code} 22:27:03,729 WARN [com.arjuna.mw.wstx] (TaskWorker-2) ARJUNA045035: comms timeout attempting to prepare WS-AT participant D0:ffffac118324:4acfdb55:51afacb7:9c 22:27:03,730 ERROR [stderr] (TaskWorker-2) com.arjuna.mw.wsas.exceptions.SystemCommunicationException: com.arjuna.wst.stub.SystemCommunicationException 22:27:03,730 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.prepare(DurableTwoPhaseCommitParticipant.java:124) 22:27:03,731 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.confirmOnePhase(DurableTwoPhaseCommitParticipant.java:233) 22:27:03,731 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf.model.twophase.arjunacore.ParticipantRecord.topLevelOnePhaseCommit(ParticipantRecord.java:429) 22:27:03,731 ERROR [stderr] (TaskWorker-2) at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2263) 22:27:03,731 ERROR [stderr] (TaskWorker-2) at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475) 22:27:03,732 ERROR [stderr] (TaskWorker-2) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) 22:27:03,732 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorControl.complete(CoordinatorControl.java:137) 22:27:03,732 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf11.model.twophase.arjunacore.TwoPhaseHLSImple.complete(TwoPhaseHLSImple.java:130) 22:27:03,732 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wsas.activity.ActivityImple.end(ActivityImple.java:293) 22:27:03,733 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wsas.UserActivityImple.end(UserActivityImple.java:261) 22:27:03,733 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorServiceImple.confirm(CoordinatorServiceImple.java:156) 22:27:03,733 ERROR [stderr] (TaskWorker-2) at com.arjuna.mwlabs.wst11.at.participants.CompletionCoordinatorImple.commit(CompletionCoordinatorImple.java:41) 22:27:03,733 ERROR [stderr] (TaskWorker-2) at com.arjuna.wst11.messaging.CompletionCoordinatorProcessorImpl.commit(CompletionCoordinatorProcessorImpl.java:84) 22:27:03,733 ERROR [stderr] (TaskWorker-2) at com.arjuna.webservices11.wsat.sei.CompletionCoordinatorPortTypeImpl$1.executeTask(CompletionCoordinatorPortTypeImpl.java:58) 22:27:03,734 ERROR [stderr] (TaskWorker-2) at com.arjuna.services.framework.task.TaskWorker.run(TaskWorker.java:63) 22:27:03,734 ERROR [stderr] (TaskWorker-2) at java.lang.Thread.run(Thread.java:662) {code}