[JBoss JIRA] (JBTM-1751) TransactionRolledBackException thrown during commit in com.jboss.transaction.txinterop.interop.ATTest
5:28 a.m.
[
https://issues.jboss.org/browse/JBTM-1751?page=com.atlassian.jira.plugin....
]
Amos Feng commented on JBTM-1751:
---------------------------------
[~paul.robinson] I add the 3s delay in the method readOnlyOperation()
XTS/WS-T/dev/src/com/arjuna/webservices11/wsat/sei/CoordinatorPortTypeImpl.java
{code}
@WebMethod(operationName = "ReadOnlyOperation", action =
"http://docs.oasis-open.org/ws-tx/wsat/2006/06/ReadOnly")
@Oneway
@Action(input="http://docs.oasis-open.org/ws-tx/wsat/2006/06/ReadOnly")
public void readOnlyOperation(
@WebParam(name = "ReadOnly", targetNamespace =
"http://docs.oasis-open.org/ws-tx/wsat/2006/06", partName =
"parameters")
Notification parameters)
{
MessageContext ctx = webServiceCtx.getMessageContext();
final Notification readOnly = parameters;
final MAP inboundMap = AddressingHelper.inboundMap(ctx);
final ArjunaContext arjunaContext = ArjunaContext.getCurrentContext(ctx);
TaskManager.getManager().queueTask(new Task() {
public void executeTask() {
System.out.println("starting readOnly");
try {
Thread.sleep(3*1000);
} catch(Exception e) {};
CoordinatorProcessor.getProcessor().readOnly(readOnly, inboundMap,
arjunaContext) ;
System.out.println("ended readOnly");
}
}) ;
}
{code}
It can re-produce these two issues. So I think it's maybe a race condition that the
prepare happens before the readOnly operation because the task execute delays.
TransactionRolledBackException thrown during commit in
com.jboss.transaction.txinterop.interop.ATTest
-----------------------------------------------------------------------------------------------------
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}
[0m[31m22: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}
[0m[33m22:26:26,763 WARN [com.arjuna.mw.wstx] (TaskWorker-2) ARJUNA045035: comms
timeout attempting to prepare WS-AT participant D0:ffffac118324:4acfdb55:51afacb7:87
[0m[31m22:26:26,763 ERROR [stderr] (TaskWorker-2)
com.arjuna.mw.wsas.exceptions.SystemCommunicationException:
com.arjuna.wst.stub.SystemCommunicationException
[0m[31m22:26:26,763 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.prepare(DurableTwoPhaseCommitParticipant.java:124)
[0m[31m22:26:26,764 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.confirmOnePhase(DurableTwoPhaseCommitParticipant.java:233)
[0m[31m22:26:26,764 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf.model.twophase.arjunacore.ParticipantRecord.topLevelOnePhaseCommit(ParticipantRecord.java:429)
[0m[31m22:26:26,764 ERROR [stderr] (TaskWorker-2) at
com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2263)
[0m[31m22:26:26,764 ERROR [stderr] (TaskWorker-2) at
com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475)
[0m[31m22:26:26,764 ERROR [stderr] (TaskWorker-2) at
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98)
[0m[31m22:26:26,765 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorControl.complete(CoordinatorControl.java:137)
[0m[31m22:26:26,765 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf11.model.twophase.arjunacore.TwoPhaseHLSImple.complete(TwoPhaseHLSImple.java:130)
[0m[31m22:26:26,765 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wsas.activity.ActivityImple.end(ActivityImple.java:293)
[0m[31m22:26:26,765 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wsas.UserActivityImple.end(UserActivityImple.java:261)
[0m[31m22:26:26,765 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorServiceImple.confirm(CoordinatorServiceImple.java:156)
[0m[31m22:26:26,766 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wst11.at.participants.CompletionCoordinatorImple.commit(CompletionCoordinatorImple.java:41)
[0m[31m22:26:26,766 ERROR [stderr] (TaskWorker-2) at
com.arjuna.wst11.messaging.CompletionCoordinatorProcessorImpl.commit(CompletionCoordinatorProcessorImpl.java:84)
[0m[31m22:26:26,766 ERROR [stderr] (TaskWorker-2) at
com.arjuna.webservices11.wsat.sei.CompletionCoordinatorPortTypeImpl$1.executeTask(CompletionCoordinatorPortTypeImpl.java:58)
[0m[31m22:26:26,766 ERROR [stderr] (TaskWorker-2) at
com.arjuna.services.framework.task.TaskWorker.run(TaskWorker.java:63)
[0m[31m22:26:26,766 ERROR [stderr] (TaskWorker-2) at
java.lang.Thread.run(Thread.java:662)
{code}
and:
{code}
[0m[33m22:27:03,729 WARN [com.arjuna.mw.wstx] (TaskWorker-2) ARJUNA045035: comms
timeout attempting to prepare WS-AT participant D0:ffffac118324:4acfdb55:51afacb7:9c
[0m[31m22:27:03,730 ERROR [stderr] (TaskWorker-2)
com.arjuna.mw.wsas.exceptions.SystemCommunicationException:
com.arjuna.wst.stub.SystemCommunicationException
[0m[31m22:27:03,730 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.prepare(DurableTwoPhaseCommitParticipant.java:124)
[0m[31m22:27:03,731 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wst.at.participants.DurableTwoPhaseCommitParticipant.confirmOnePhase(DurableTwoPhaseCommitParticipant.java:233)
[0m[31m22:27:03,731 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf.model.twophase.arjunacore.ParticipantRecord.topLevelOnePhaseCommit(ParticipantRecord.java:429)
[0m[31m22:27:03,731 ERROR [stderr] (TaskWorker-2) at
com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2263)
[0m[31m22:27:03,731 ERROR [stderr] (TaskWorker-2) at
com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475)
[0m[31m22:27:03,732 ERROR [stderr] (TaskWorker-2) at
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98)
[0m[31m22:27:03,732 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorControl.complete(CoordinatorControl.java:137)
[0m[31m22:27:03,732 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf11.model.twophase.arjunacore.TwoPhaseHLSImple.complete(TwoPhaseHLSImple.java:130)
[0m[31m22:27:03,732 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wsas.activity.ActivityImple.end(ActivityImple.java:293)
[0m[31m22:27:03,733 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wsas.UserActivityImple.end(UserActivityImple.java:261)
[0m[31m22:27:03,733 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wscf.model.twophase.arjunacore.CoordinatorServiceImple.confirm(CoordinatorServiceImple.java:156)
[0m[31m22:27:03,733 ERROR [stderr] (TaskWorker-2) at
com.arjuna.mwlabs.wst11.at.participants.CompletionCoordinatorImple.commit(CompletionCoordinatorImple.java:41)
[0m[31m22:27:03,733 ERROR [stderr] (TaskWorker-2) at
com.arjuna.wst11.messaging.CompletionCoordinatorProcessorImpl.commit(CompletionCoordinatorProcessorImpl.java:84)
[0m[31m22:27:03,733 ERROR [stderr] (TaskWorker-2) at
com.arjuna.webservices11.wsat.sei.CompletionCoordinatorPortTypeImpl$1.executeTask(CompletionCoordinatorPortTypeImpl.java:58)
[0m[31m22:27:03,734 ERROR [stderr] (TaskWorker-2) at
com.arjuna.services.framework.task.TaskWorker.run(TaskWorker.java:63)
[0m[31m22:27:03,734 ERROR [stderr] (TaskWorker-2) at
java.lang.Thread.run(Thread.java:662)
{code}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
3954
days inactive
3954
days old
jbossts-issues@lists.jboss.org
0 comments
1 participants
participants (1)
-
Amos Feng (JIRA)