Details
-
Bug
-
Resolution: Done
-
Major
-
16.0.0.Final
-
None
Description
Transaction default timeout could be wrongly set up because of race condition in configuration of the CoordinatorEnvironmentBean and the TxControl class which is used on transaction begin and loads data from the coordinator bean to static variable.
The default transaction timeout defined by Narayana is 60 seconds. It's coded in source at https://github.com/jbosstm/narayana/blob/master/ArjunaCore/arjuna/classes/com/arjuna/ats/arjuna/common/CoordinatorEnvironmentBean.java#L74
The CoordinatorEnvironmentBean is instantiated with the default value or with value taken from system property or xml descriptor (https://jbossts.blogspot.com/2018/01/narayana-periodic-recovery-of-xa.html#configuration).
When new transaction is started it does not use directly the CoordinatorEnvironmentBean#getDefaultTimeout() but the TxControl#getDefaultTimeout() (https://github.com/jbosstm/narayana/blob/5.9.3.Final/ArjunaCore/arjuna/classes/com/arjuna/ats/arjuna/coordinator/TxControl.java#L75).
From the rhn-support-sfikes testing with Byteman[1] when there is used the environment property -Dcom.arjuna.ats.arjuna.coordinator.defaultTimeout=301 (should not be used for WFLY) and WFLY model configuration <coordinator-environment default-timeout="302"/> we can see the CoordinatorEnvironmentBean.setDefaultTimeout is called twice. First time it's time of the bean initialization and the value of 301 is taken (BeanPopulator instantiates the bean and reset the default value of 60 to 301. Next the ArjunaTransactionManagerService is started and set the value to 302 as model defines https://github.com/wildfly/wildfly/blob/16.0.0.Final/transactions/src/main/java/org/jboss/as/txn/service/ArjunaTransactionManagerService.java#L87.
Unfortunately, there is no changes for the TxControl class which is used during transaction startup. If the TxControl would be initialized before the ArjunaTransactionService is started then the value defined in the WFLY model would not be considered until a change in the CLI (/subsystem=transactions:write-attribute(name=default-timeout, value=100)) is done. The cli command causes the TxControl is reset - https://github.com/wildfly/wildfly/blob/master/transactions/src/main/java/org/jboss/as/txn/subsystem/TransactionSubsystemRootResourceDefinition.java#L524
We should ensure the TxControl._defaultTimeout value is configured during ArjunaTransactionManagerService start up as well.
[1]
INFO [stdout] (MSC service thread 1-2) [BMAN] CoordinatorEnvironmentBean.setDefaultTimeout(301) com.arjuna.ats.arjuna.common.CoordinatorEnvironmentBean.setDefaultTimeout(CoordinatorEnvironmentBean.java:-1) sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2) sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) java.lang.reflect.Method.invoke(Method.java:498) com.arjuna.common.internal.util.propertyservice.BeanPopulator.handleSimpleProperty(BeanPopulator.java:312) com.arjuna.common.internal.util.propertyservice.BeanPopulator.configureFromProperties(BeanPopulator.java:172) com.arjuna.common.internal.util.propertyservice.BeanPopulator.getNamedInstance(BeanPopulator.java:87) com.arjuna.common.internal.util.propertyservice.BeanPopulator.getDefaultInstance(BeanPopulator.java:53) com.arjuna.ats.arjuna.common.arjPropertyManager.getCoordinatorEnvironmentBean(arjPropertyManager.java:51) com.arjuna.ats.arjuna.coordinator.BasicAction.<clinit>(BasicAction.java:3754) com.arjuna.ats.internal.jta.recovery.arjunacore.CommitMarkableResourceRecordRecoveryModule.<clinit>(CommitMarkableResourceRecordRecoveryModule.java:79) java.lang.Class.forName0(Class.java:-2) java.lang.Class.forName(Class.java:264) com.arjuna.common.internal.util.ClassloadingUtility.loadClass(ClassloadingUtility.java:57) com.arjuna.common.internal.util.ClassloadingUtility.loadClass(ClassloadingUtility.java:85) com.arjuna.common.internal.util.ClassloadingUtility.loadAndInstantiateClass(ClassloadingUtility.java:117) com.arjuna.common.internal.util.ClassloadingUtility.loadAndInstantiateClassesWithInit(ClassloadingUtility.java:192) com.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.getRecoveryModules(RecoveryEnvironmentBean.java:465) com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.loadModules(PeriodicRecovery.java:883) com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.<init>(PeriodicRecovery.java:121) com.arjuna.ats.internal.arjuna.recovery.RecoveryManagerImple.<init>(RecoveryManagerImple.java:107) com.arjuna.ats.arjuna.recovery.RecoveryManager.<init>(RecoveryManager.java:477) com.arjuna.ats.arjuna.recovery.RecoveryManager.manager(RecoveryManager.java:132) com.arjuna.ats.arjuna.recovery.RecoveryManager.manager(RecoveryManager.java:112) com.arjuna.ats.jbossatx.jta.RecoveryManagerService.create(RecoveryManagerService.java:54) org.jboss.as.txn.service.ArjunaRecoveryManagerService.start(ArjunaRecoveryManagerService.java:126) org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:2032) org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1955) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) INFO [stdout] (MSC service thread 1-2) [BMAN] CoordinatorEnvironmentBean.setDefaultTimeout(302) com.arjuna.ats.arjuna.common.CoordinatorEnvironmentBean.setDefaultTimeout(CoordinatorEnvironmentBean.java:-1) org.jboss.as.txn.service.ArjunaTransactionManagerService.start(ArjunaTransactionManagerService.java:88) org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:2032) org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1955) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748)
