[jbossts-issues] [JBoss JIRA] (JBTM-2995) RTS InboundBridgeRecoveryTestCase hanging

Ondra Chaloupka (JIRA) issues at jboss.org
Tue Feb 27 05:26:00 EST 2018


    [ https://issues.jboss.org/browse/JBTM-2995?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13538672#comment-13538672 ] 

Ondra Chaloupka commented on JBTM-2995:
---------------------------------------

I was able to reproduce this on my local machine thus I was trying to check the existence of the JTS log and I think there isn't. I think the reason is in wrong implementation of {{TransactionImporterImple}}. When the failure happens the jts version is in serve ({{com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple}}). That's because of race condition of transaction manager instance being used. The {{SubordinationManager}} decides based on the transaction manager implementation is setup in {{JTAEnvironmentBean}} (https://github.com/jbosstm/narayana/blob/master/ArjunaJTA/jta/classes/com/arjuna/ats/internal/jta/transaction/arjunacore/jca/SubordinationManager.java#L144). At time the {{JTAEnvironmentBeanService}} is started (https://github.com/wildfly/wildfly/blob/master/transactions/src/main/java/org/jboss/as/txn/service/JTAEnvironmentBeanService.java#L60) the content of the {{transactionManagerClassName}}  is setup (https://github.com/jbosstm/narayana/blob/master/ArjunaJTA/jta/classes/com/arjuna/ats/jta/common/JTAEnvironmentBean.java#L54) based on the {{jbossts-properties.xml}} from https://github.com/jbosstm/narayana/blob/master/ArjunaJTS/narayana-jts-idlj/src/main/resources/jbossts-properties.xml#L149 where jts transaction manager is configured. Then recovery manager service is started and before the setup to the JTA transaction manager, by definition taken from {{standalone.xml}} in WFLY, is done (https://github.com/wildfly/wildfly/blob/master/transactions/src/main/java/org/jboss/as/txn/service/ArjunaTransactionManagerService.java#L102) the recovery already starts (https://github.com/wildfly/wildfly/blob/master/transactions/src/main/java/org/jboss/as/txn/subsystem/TransactionSubsystemAdd.java#L243) and uses jts importer which fails of not having ORB configured.

My debugging output
{code}
2018-02-26 23:46:49,050 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0003: Undertow 2.0.0.Final starting
2018-02-26 23:46:49,111 INFO  [stdout] (MSC service thread 1-8) >>> ochaloup >>> : setting the txn manager: com.arjuna.ats.internal.jta.transaction.jts.TransactionManagerImple -> 
2018-02-26 23:46:49,112 ERROR [stderr] (MSC service thread 1-8) java.lang.Exception: Stack trace
2018-02-26 23:46:49,113 ERROR [stderr] (MSC service thread 1-8) 	at java.lang.Thread.dumpStack(Thread.java:1336)
2018-02-26 23:46:49,113 ERROR [stderr] (MSC service thread 1-8) 	at com.arjuna.ats.jta.common.JTAEnvironmentBean.setTransactionManagerClassName(JTAEnvironmentBean.java:167)
2018-02-26 23:46:49,113 ERROR [stderr] (MSC service thread 1-8) 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2018-02-26 23:46:49,113 ERROR [stderr] (MSC service thread 1-8) 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2018-02-26 23:46:49,114 ERROR [stderr] (MSC service thread 1-8) 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2018-02-26 23:46:49,114 ERROR [stderr] (MSC service thread 1-8) 	at java.lang.reflect.Method.invoke(Method.java:498)
2018-02-26 23:46:49,114 ERROR [stderr] (MSC service thread 1-8) 	at com.arjuna.common.internal.util.propertyservice.BeanPopulator.handleSimpleProperty(BeanPopulator.java:298)
2018-02-26 23:46:49,114 ERROR [stderr] (MSC service thread 1-8) 	at com.arjuna.common.internal.util.propertyservice.BeanPopulator.configureFromProperties(BeanPopulator.java:172)
2018-02-26 23:46:49,114 ERROR [stderr] (MSC service thread 1-8) 	at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getNamedInstance(BeanPopulator.java:87)
2018-02-26 23:46:49,115 ERROR [stderr] (MSC service thread 1-8) 	at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getDefaultInstance(BeanPopulator.java:53)
2018-02-26 23:46:49,115 ERROR [stderr] (MSC service thread 1-8) 	at com.arjuna.ats.jta.common.jtaPropertyManager.getJTAEnvironmentBean(jtaPropertyManager.java:42)
2018-02-26 23:46:49,115 ERROR [stderr] (MSC service thread 1-8) 	at org.jboss.as.txn.service.JTAEnvironmentBeanService.start(JTAEnvironmentBeanService.java:60)
2018-02-26 23:46:49,116 ERROR [stderr] (MSC service thread 1-8) 	at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1714)
2018-02-26 23:46:49,116 ERROR [stderr] (MSC service thread 1-8) 	at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1693)
2018-02-26 23:46:49,116 ERROR [stderr] (MSC service thread 1-8) 	at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1540)
2018-02-26 23:46:49,116 ERROR [stderr] (MSC service thread 1-8) 	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
2018-02-26 23:46:49,117 ERROR [stderr] (MSC service thread 1-8) 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
2018-02-26 23:46:49,118 ERROR [stderr] (MSC service thread 1-8) 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
2018-02-26 23:46:49,119 ERROR [stderr] (MSC service thread 1-8) 	at java.lang.Thread.run(Thread.java:748)
2018-02-26 23:46:49,125 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 66) WFLYUT0014: Creating file handler for path '/home/ochaloup/jboss/wildfly/dist/target/wildfly-12.0.0.Beta2-SNAPSHOT/welcome-content' with options [directory-listing: 'false', follow-symlink: 'false', case-sensitive: 'true', safe-symlink-paths: '[]']
2018-02-26 23:46:49,130 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-2) WFLYUT0012: Started server default-server.
2018-02-26 23:46:49,132 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-2) WFLYUT0018: Host default-host starting
2018-02-26 23:46:49,352 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-6) WFLYUT0006: Undertow HTTP listener default listening on 127.0.0.1:8080
2018-02-26 23:46:49,359 INFO  [stdout] (MSC service thread 1-6) >>> ochaloup >>> : setting the txn manager: com.arjuna.ats.jbossatx.jta.TransactionManagerDelegate -> 
2018-02-26 23:46:49,360 ERROR [stderr] (MSC service thread 1-6) java.lang.Exception: Stack trace
2018-02-26 23:46:49,360 ERROR [stderr] (MSC service thread 1-6) 	at java.lang.Thread.dumpStack(Thread.java:1336)
2018-02-26 23:46:49,360 ERROR [stderr] (MSC service thread 1-6) 	at com.arjuna.ats.jta.common.JTAEnvironmentBean.setTransactionManagerClassName(JTAEnvironmentBean.java:167)
2018-02-26 23:46:49,360 INFO  [stdout] (Periodic Recovery) >>> ochaloup >>> txType init: null
2018-02-26 23:46:49,360 ERROR [stderr] (MSC service thread 1-6) 	at org.jboss.as.txn.service.ArjunaTransactionManagerService.start(ArjunaTransactionManagerService.java:102)
2018-02-26 23:46:49,361 ERROR [stderr] (MSC service thread 1-6) 	at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1714)
2018-02-26 23:46:49,361 ERROR [stderr] (MSC service thread 1-6) 	at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1693)
2018-02-26 23:46:49,361 ERROR [stderr] (MSC service thread 1-6) 	at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1540)
2018-02-26 23:46:49,361 ERROR [stderr] (MSC service thread 1-6) 	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
2018-02-26 23:46:49,362 ERROR [stderr] (MSC service thread 1-6) 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
2018-02-26 23:46:49,362 ERROR [stderr] (MSC service thread 1-6) 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
2018-02-26 23:46:49,362 ERROR [stderr] (MSC service thread 1-6) 	at java.lang.Thread.run(Thread.java:748)
2018-02-26 23:46:49,368 INFO  [stdout] (Periodic Recovery) >>> ochaloup >>> txType init2: JTS
2018-02-26 23:46:49,369 ERROR [stderr] (Periodic Recovery) java.lang.Exception: Stack trace
2018-02-26 23:46:49,369 ERROR [stderr] (Periodic Recovery) 	at java.lang.Thread.dumpStack(Thread.java:1336)
2018-02-26 23:46:49,369 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jta.transaction.arjunacore.jca.SubordinationManager.initTransactionImporter(SubordinationManager.java:96)
2018-02-26 23:46:49,369 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jta.transaction.arjunacore.jca.SubordinationManager.getTransactionImporter(SubordinationManager.java:46)
2018-02-26 23:46:49,370 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jta.recovery.arjunacore.SubordinateAtomicActionRecoveryModule.periodicWorkFirstPass(SubordinateAtomicActionRecoveryModule.java:74)
2018-02-26 23:46:49,370 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:765)
2018-02-26 23:46:49,370 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:377)
2018-02-26 23:46:49,404 WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012087: Activate of atomic action with id 0:ffff0a000009:-5269a529:5a948e53:14 and type /StateManager/BasicAction/TwoPhaseCoordinator/ArjunaTransactionImple/ServerTransaction/JCA unexpectedly failed, could not load state.
2018-02-26 23:46:49,409 FATAL [com.arjuna.ats.jts] (Periodic Recovery) ARJUNA022006: The ORB has not been initialized yet
2018-02-26 23:46:49,409 ERROR [stderr] (Periodic Recovery) Exception in thread "Periodic Recovery" com.arjuna.ats.arjuna.exceptions.FatalError
2018-02-26 23:46:49,410 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jts.ORBManager.getPOA(ORBManager.java:97)
2018-02-26 23:46:49,410 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jts.orbspecific.ControlImple.createTransactionHandle(ControlImple.java:524)
2018-02-26 23:46:49,410 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jts.orbspecific.interposition.ServerControl.<init>(ServerControl.java:223)
2018-02-26 23:46:49,410 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.SubordinateAtomicTransaction.<init>(SubordinateAtomicTransaction.java:71)
2018-02-26 23:46:49,411 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.TransactionImple.<init>(TransactionImple.java:77)
2018-02-26 23:46:49,411 ERROR [stderr] (Periodic Recovery) 	at com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple.recoverTransaction(TransactionImporterImple.java:98)
2018-02-26 23:46:49,411 WARN  [com.arjuna.ats.arjuna] (MSC service thread 1-6) ARJUNA012087: Activate of atomic action with id 0:ffff0a000009:-5269a529:5a948e53:14 and type /StateManager/BasicAction/TwoPhaseCoordinator/ArjunaTransactionImple/ServerTransaction/JCA unexpectedly failed, could not load state.
2018-02-26 23:46:49,411 FATAL [com.arjuna.ats.jts] (MSC service thread 1-6) ARJUNA022006: The ORB has not been initialized yet
2018-02-26 23:46:49,412 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-6) MSC000001: Failed to start service jboss.txn.context.local: org.jboss.msc.service.StartException in service jboss.txn.context.local: Failed to start service
	at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1706)
	at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1540)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
	at java.lang.Thread.run(Thread.java:748)
Caused by: com.arjuna.ats.arjuna.exceptions.FatalError
	at com.arjuna.ats.internal.jts.ORBManager.getPOA(ORBManager.java:97)
	at com.arjuna.ats.internal.jts.orbspecific.ControlImple.createTransactionHandle(ControlImple.java:524)
	at com.arjuna.ats.internal.jts.orbspecific.interposition.ServerControl.<init>(ServerControl.java:223)
	at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.SubordinateAtomicTransaction.<init>(SubordinateAtomicTransaction.java:71)
	at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.TransactionImple.<init>(TransactionImple.java:77)
	at com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple.recoverTransaction(TransactionImporterImple.java:98)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.jca.XATerminatorImple.doRecover(XATerminatorImple.java:434)
	at org.wildfly.transaction.client.provider.jboss.JBossLocalTransactionProvider.<init>(JBossLocalTransactionProvider.java:85)
	at org.wildfly.transaction.client.provider.jboss.JBossJTALocalTransactionProvider.<init>(JBossJTALocalTransactionProvider.java:52)
	at org.wildfly.transaction.client.provider.jboss.JBossLocalTransactionProvider$Builder.build(JBossLocalTransactionProvider.java:746)
	at org.jboss.as.txn.service.LocalTransactionContextService.start(LocalTransactionContextService.java:57)
	at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1714)
	at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1693)
	... 5 more
{code}



> RTS InboundBridgeRecoveryTestCase hanging
> -----------------------------------------
>
>                 Key: JBTM-2995
>                 URL: https://issues.jboss.org/browse/JBTM-2995
>             Project: JBoss Transaction Manager
>          Issue Type: Bug
>          Components: REST
>    Affects Versions: 5.7.2.Final
>            Reporter: Michael Musgrove
>            Assignee: Ondra Chaloupka
>             Fix For: 5.next
>
>         Attachments: surefire.jstack.23019.txt, wfly.jstack.txt
>
>
> The following test is hanging:
> org.jboss.narayana.rest.bridge.inbound.test.integration.InboundBridgeRecoveryTestCase
> and the WildFly server log for the run is reporting that TM recovery is starting before the ORB has initialised and therefore the deploy of the test fails: 
> 2018-02-20 01:56:03,233 WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012087: Activate of atomic action with id 0:ffffac110014:-3aed03e2:5a8b802e:14 and type /StateManager/BasicAction/TwoPhaseCoordinat
> or/ArjunaTransactionImple/ServerTransaction/JCA unexpectedly failed, could not load state.               
> 2018-02-20 01:56:03,236 FATAL [com.arjuna.ats.jts] (MSC service thread 1-7) ARJUNA022006: The ORB has not been initialized yet                                                                                     
> 2018-02-20 01:56:03,236 FATAL [com.arjuna.ats.jts] (Periodic Recovery) ARJUNA022006: The ORB has not been initialized yet                                                                                          
> 2018-02-20 01:56:03,236 ERROR [stderr] (Periodic Recovery) Exception in thread "Periodic Recovery" com.arjuna.ats.arjuna.exceptions.FatalError                                                                     
> 2018-02-20 01:56:03,237 ERROR [stderr] (Periodic Recovery)      at com.arjuna.ats.internal.jts.ORBManager.getPOA(ORBManager.java:97)                                                                               
> 2018-02-20 01:56:03,237 ERROR [stderr] (Periodic Recovery)      at com.arjuna.ats.internal.jts.orbspecific.ControlImple.createTransactionHandle(ControlImple.java:524)                                             
> 2018-02-20 01:56:03,236 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-7) MSC000001: Failed to start service jboss.txn.context.local: org.jboss.msc.service.StartException in service jboss.txn.context.l
> ocal: Failed to start service                       
>         at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1693)
>         at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1527)                                                                                                         
>         at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)              
>         at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481) 
>         at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)       
>         at java.lang.Thread.run(Thread.java:748)    
> Caused by: com.arjuna.ats.arjuna.exceptions.FatalError                                                   
>         at com.arjuna.ats.internal.jts.ORBManager.getPOA(ORBManager.java:97)                             
>         at com.arjuna.ats.internal.jts.orbspecific.ControlImple.createTransactionHandle(ControlImple.java:524)                                                                                                     
>         at com.arjuna.ats.internal.jts.orbspecific.interposition.ServerControl.<init>(ServerControl.java:223)                                                                                                      
>         at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.SubordinateAtomicTransaction.<init>(SubordinateAtomicTransaction.java:71)                                                                   
>         at com.arjuna.ats.internal.jta.transaction.jts.subordinate.jca.TransactionImple.<init>(TransactionImple.java:77)                                                                                           
>         at com.arjuna.ats.internal.jta.transaction.jts.jca.TransactionImporterImple.recoverTransaction(TransactionImporterImple.java:98)                                                                           
>         at com.arjuna.ats.internal.jta.transaction.arjunacore.jca.XATerminatorImple.doRecover(XATerminatorImple.java:434)                                                                                          
>         at org.wildfly.transaction.client.provider.jboss.JBossLocalTransactionProvider.<init>(JBossLocalTransactionProvider.java:85)                                                                               
>         at org.wildfly.transaction.client.provider.jboss.JBossJTALocalTransactionProvider.<init>(JBossJTALocalTransactionProvider.java:52)                                                                         
>         at org.wildfly.transaction.client.provider.jboss.JBossLocalTransactionProvider$Builder.build(JBossLocalTransactionProvider.java:746)                                                                       
>         at org.jboss.as.txn.service.LocalTransactionContextService.start(LocalTransactionContextService.java:57)                                                                                                   
>         at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1701)                                                                                                     
> 2018-02-20 01:56:03,237 ERROR [stderr] (Periodic Recovery)      at com.arjuna.ats.internal.jts.ORBManager
> .getPOA(ORBManager.java:97)                         
>         at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
>         at java.lang.Thread.run(Thread.java:748)
> Caused by: com.arjuna.ats.arjuna.exceptions.FatalError
>         at com.arjuna.ats.internal.jts.ORBManager.getPOA(ORBManager.java:97)



--
This message was sent by Atlassian JIRA
(v7.5.0#75005)



More information about the jbossts-issues mailing list