On Dec 12, 2016, at 12:10 PM, Kabir Khan <kabir.khan(a)jboss.com&gt; wrote: Where are you trying to use the system property from? They should only be attempted resolved during the RUNTIME stage, not MODEL. > On 12 Dec 2016, at 18:00, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: > > Hi, > > I have a subsystem that configures itself from system properties. > > For example: > <system-properties> > <property name="RecoveryEnvironmentBean.expiryScannerClassNames" value="com.arjuna.ats.internal.arjuna.recovery.ExpiredTransactionStatusManagerScanner com.arjuna.ats.internal.arjuna.recovery.AtomicActionExpiryScanner"/> > </system-properties> > > In earlier revisions of WFLY this worked fine. However I am now seeing that the system property is not set until after my subsystem has started. I can tell this as I have breakpoints on where I process the property. I can see "MSC service thread 1-4" attempting to process the property (which is not set). I do later see messages that suggest the system property is set but at that the later point: > > 2016-12-12 17:57:48,042 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@784c8c5f handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > 2016-12-12 17:57:48,093 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@87b4493 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > > Does my subsystem need to depend on something to get the old behaviour of being started after system properties are processed? > > My subsystem is the transaction one and the service is the recovery manager. > > Thanks! > Tom > _______________________________________________ > wildfly-dev mailing list > wildfly-dev(a)lists.jboss.org > https://lists.jboss.org/mailman/listinfo/wildfly-dev _______________________________________________ wildfly-dev mailing list wildfly-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/wildfly-dev

This works fine for me. Adding that xml snippet to standalone.xml after the <extensions> element I see the property being set during boot before any processing of subsystem operations begins. > On Dec 12, 2016, at 1:55 PM, Brian Stansberry < brian.stansberry(a)redhat.com&gt; wrote: > > I don’t see anything in the organization of boot ops that would have changed the ordering, and the add op for that system property should be executing prior to the subsystem ops. I’ll see if I can reproduce. > >> On Dec 12, 2016, at 12:10 PM, Kabir Khan <kabir.khan(a)jboss.com&gt; wrote: >> >> Where are you trying to use the system property from? They should only be attempted resolved during the RUNTIME stage, not MODEL. >>> On 12 Dec 2016, at 18:00, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: >>> >>> Hi, >>> >>> I have a subsystem that configures itself from system properties. >>> >>> For example: >>> <system-properties> >>> <property name="RecoveryEnvironmentBean.expiryScannerClassNames" value="com.arjuna.ats.internal.arjuna.recovery. ExpiredTransactionStatusManagerScanner com.arjuna.ats.internal. arjuna.recovery.AtomicActionExpiryScanner"/> >>> </system-properties> >>> >>> In earlier revisions of WFLY this worked fine. However I am now seeing that the system property is not set until after my subsystem has started. I can tell this as I have breakpoints on where I process the property. I can see "MSC service thread 1-4" attempting to process the property (which is not set). I do later see messages that suggest the system property is set but at that the later point: >>> >>> 2016-12-12 17:57:48,042 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@784c8c5f handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} >>> 2016-12-12 17:57:48,093 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@87b4493 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} >>> >>> Does my subsystem need to depend on something to get the old behaviour of being started after system properties are processed? >>> >>> My subsystem is the transaction one and the service is the recovery manager. >>> >>> Thanks! >>> Tom >>> _______________________________________________ >>> wildfly-dev mailing list >>> wildfly-dev(a)lists.jboss.org >>> https://lists.jboss.org/mailman/listinfo/wildfly-dev >> >> >> _______________________________________________ >> wildfly-dev mailing list >> wildfly-dev(a)lists.jboss.org >> https://lists.jboss.org/mailman/listinfo/wildfly-dev > > -- > Brian Stansberry > Manager, Senior Principal Software Engineer > JBoss by Red Hat > > > > > _______________________________________________ > wildfly-dev mailing list > wildfly-dev(a)lists.jboss.org > https://lists.jboss.org/mailman/listinfo/wildfly-dev -- Brian Stansberry Manager, Senior Principal Software Engineer JBoss by Red Hat _______________________________________________ wildfly-dev mailing list wildfly-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/wildfly-dev

On Dec 12, 2016, at 3:03 PM, Tomaž Cerar <tomaz.cerar(a)gmail.com&gt; wrote: You are adding and starting this service in performBoottime which is causing you this issues. As you service can get started before stage MODEL can complete

I would change initial state of the service to ON_DEMAND instead of active. https://github.com/wildfly/wildfly/blob/master/transactions/src/main/java... which should solve your problem. I would do the same also for JTAEnvironmentBeanService. so they get started only when needed not up front without any requirement. -- tomaz On Mon, Dec 12, 2016 at 9:50 PM, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: Thanks for the input/ This is the point I do not think the property has been set by: "MSC service thread 1-3@2595" prio=5 tid=0x14 nid=NA runnable java.lang.Thread.State: RUNNABLE at com.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.getExpiryScannerClassNames(RecoveryEnvironmentBean.java:336) - locked <0x1bb6> (a com.arjuna.ats.arjuna.common.RecoveryEnvironmentBean) at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.arjuna.common.internal.util.propertyservice.BeanPopulator.handleGroupProperty(BeanPopulator.java:263) at com.arjuna.common.internal.util.propertyservice.BeanPopulator.configureFromProperties(BeanPopulator.java:170) at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getNamedInstance(BeanPopulator.java:87) at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getDefaultInstance(BeanPopulator.java:53) at com.arjuna.ats.arjuna.common.recoveryPropertyManager.getRecoveryEnvironmentBean(recoveryPropertyManager.java:34) at org.jboss.as.txn.service.ArjunaRecoveryManagerService.start(ArjunaRecoveryManagerService.java:96) - locked <0x1bd2> (a org.jboss.as.txn.service.ArjunaRecoveryManagerService) at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1963) at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1896) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) (that is output from the debugger) Once releasing that thread and letting the container continue startup I see this execute: 2016-12-12 20:46:49,731 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@5c7e7735 handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} 2016-12-12 20:46:49,787 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@f15c8f7 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} I believe this is different to previous behaviour as I have had a defect raised against TX: https://issues.jboss.org/browse/JBEAP-7820. It's possible that there is a regression in Narayana (somehow) if nothing changed in this area in the core itself. Thanks for your input, Tom On 12 December 2016 at 20:15, Brian Stansberry <brian.stansberry(a)redhat.com&gt; wrote: This works fine for me. Adding that xml snippet to standalone.xml after the <extensions> element I see the property being set during boot before any processing of subsystem operations begins. > On Dec 12, 2016, at 1:55 PM, Brian Stansberry <brian.stansberry(a)redhat.com&gt; wrote: > > I don’t see anything in the organization of boot ops that would have changed the ordering, and the add op for that system property should be executing prior to the subsystem ops. I’ll see if I can reproduce. > >> On Dec 12, 2016, at 12:10 PM, Kabir Khan <kabir.khan(a)jboss.com&gt; wrote: >> >> Where are you trying to use the system property from? They should only be attempted resolved during the RUNTIME stage, not MODEL. >>> On 12 Dec 2016, at 18:00, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: >>> >>> Hi, >>> >>> I have a subsystem that configures itself from system properties. >>> >>> For example: >>> <system-properties> >>> <property name="RecoveryEnvironmentBean.expiryScannerClassNames" value="com.arjuna.ats.internal.arjuna.recovery.ExpiredTransactionStatusManagerScanner com.arjuna.ats.internal.arjuna.recovery.AtomicActionExpiryScanner"/> >>> </system-properties> >>> >>> In earlier revisions of WFLY this worked fine. However I am now seeing that the system property is not set until after my subsystem has started. I can tell this as I have breakpoints on where I process the property. I can see "MSC service thread 1-4" attempting to process the property (which is not set). I do later see messages that suggest the system property is set but at that the later point: >>> >>> 2016-12-12 17:57:48,042 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@784c8c5f handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} >>> 2016-12-12 17:57:48,093 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@87b4493 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} >>> >>> Does my subsystem need to depend on something to get the old behaviour of being started after system properties are processed? >>> >>> My subsystem is the transaction one and the service is the recovery manager. >>> >>> Thanks! >>> Tom >>> _______________________________________________ >>> wildfly-dev mailing list >>> wildfly-dev(a)lists.jboss.org >>> https://lists.jboss.org/mailman/listinfo/wildfly-dev >> >> >> _______________________________________________ >> wildfly-dev mailing list >> wildfly-dev(a)lists.jboss.org >> https://lists.jboss.org/mailman/listinfo/wildfly-dev > > -- > Brian Stansberry > Manager, Senior Principal Software Engineer > JBoss by Red Hat > > > > > _______________________________________________ > wildfly-dev mailing list > wildfly-dev(a)lists.jboss.org > https://lists.jboss.org/mailman/listinfo/wildfly-dev -- Brian Stansberry Manager, Senior Principal Software Engineer JBoss by Red Hat _______________________________________________ wildfly-dev mailing list wildfly-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/wildfly-dev _______________________________________________ wildfly-dev mailing list wildfly-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/wildfly-dev

On Dec 12, 2016, at 3:21 PM, Brian Stansberry <brian.stansberry(a)redhat.com&gt; wrote: This is the problem: the TransactionExtension initialize method of touching classes that result in doing static initialization stuff that reads the system props at that point, which is too early:

"ServerService Thread Pool -- 21@3635" prio=5 tid=0x30 nid=NA runnable java.lang.Thread.State: RUNNABLE at com.arjuna.common.util.propertyservice.PropertiesFactory.initPropertiesFactory(PropertiesFactory.java:53) - locked <0x1389> (a java.lang.Class) at com.arjuna.common.util.propertyservice.PropertiesFactory.getDefaultProperties(PropertiesFactory.java:36) at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getNamedInstance(BeanPopulator.java:86) at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getDefaultInstance(BeanPopulator.java:53) at com.arjuna.ats.arjuna.common.arjPropertyManager.getCoordinatorEnvironmentBean(arjPropertyManager.java:51) at org.jboss.as.txn.subsystem.TransactionSubsystemRootResourceDefinition$StatisticsEnabledHandler.<init>(TransactionSubsystemRootResourceDefinition.java:518) at org.jboss.as.txn.subsystem.TransactionSubsystemRootResourceDefinition.registerAttributes(TransactionSubsystemRootResourceDefinition.java:314) at org.jboss.as.controller.registry.NodeSubregistry.registerChild(NodeSubregistry.java:104) at org.jboss.as.controller.registry.ConcreteResourceRegistration.registerSubModel(ConcreteResourceRegistration.java:225) at org.jboss.as.controller.extension.ExtensionRegistry$SubsystemRegistrationImpl.registerSubsystemModel(ExtensionRegistry.java:706) at org.jboss.as.txn.subsystem.TransactionExtension.initialize(TransactionExtension.java:104) at org.jboss.as.controller.extension.ExtensionAddHandler.initializeExtension(ExtensionAddHandler.java:131) at org.jboss.as.controller.extension.ExtensionAddHandler.initializeExtension(ExtensionAddHandler.java:104) at org.jboss.as.controller.extension.ParallelExtensionAddHandler$ExtensionInitializeTask.call(ParallelExtensionAddHandler.java:144) at org.jboss.as.controller.extension.ParallelExtensionAddHandler$ExtensionInitializeTask.call(ParallelExtensionAddHandler.java:127) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) at org.jboss.threads.JBossThread.run(JBossThread.java:320) > On Dec 12, 2016, at 2:50 PM, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: > > Thanks for the input/ > > This is the point I do not think the property has been set by: > > "MSC service thread 1-3@2595" prio=5 tid=0x14 nid=NA runnable > java.lang.Thread.State: RUNNABLE > at com.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.getExpiryScannerClassNames(RecoveryEnvironmentBean.java:336) > - locked <0x1bb6> (a com.arjuna.ats.arjuna.common.RecoveryEnvironmentBean) > at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1) > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:498) > at com.arjuna.common.internal.util.propertyservice.BeanPopulator.handleGroupProperty(BeanPopulator.java:263) > at com.arjuna.common.internal.util.propertyservice.BeanPopulator.configureFromProperties(BeanPopulator.java:170) > at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getNamedInstance(BeanPopulator.java:87) > at com.arjuna.common.internal.util.propertyservice.BeanPopulator.getDefaultInstance(BeanPopulator.java:53) > at com.arjuna.ats.arjuna.common.recoveryPropertyManager.getRecoveryEnvironmentBean(recoveryPropertyManager.java:34) > at org.jboss.as.txn.service.ArjunaRecoveryManagerService.start(ArjunaRecoveryManagerService.java:96) > - locked <0x1bd2> (a org.jboss.as.txn.service.ArjunaRecoveryManagerService) > at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1963) > at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1896) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) > at java.lang.Thread.run(Thread.java:745) > > (that is output from the debugger) > > Once releasing that thread and letting the container continue startup I see this execute: > 2016-12-12 20:46:49,731 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@5c7e7735 handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > 2016-12-12 20:46:49,787 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@f15c8f7 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > > I believe this is different to previous behaviour as I have had a defect raised against TX: https://issues.jboss.org/browse/JBEAP-7820. It's possible that there is a regression in Narayana (somehow) if nothing changed in this area in the core itself. > > Thanks for your input, > Tom > > > > > On 12 December 2016 at 20:15, Brian Stansberry <brian.stansberry(a)redhat.com&gt; wrote: > This works fine for me. Adding that xml snippet to standalone.xml after the <extensions> element I see the property being set during boot before any processing of subsystem operations begins. > >> On Dec 12, 2016, at 1:55 PM, Brian Stansberry <brian.stansberry(a)redhat.com&gt; wrote: >> >> I don’t see anything in the organization of boot ops that would have changed the ordering, and the add op for that system property should be executing prior to the subsystem ops. I’ll see if I can reproduce. >> >>> On Dec 12, 2016, at 12:10 PM, Kabir Khan <kabir.khan(a)jboss.com&gt; wrote: >>> >>> Where are you trying to use the system property from? They should only be attempted resolved during the RUNTIME stage, not MODEL. >>>> On 12 Dec 2016, at 18:00, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: >>>> >>>> Hi, >>>> >>>> I have a subsystem that configures itself from system properties. >>>> >>>> For example: >>>> <system-properties> >>>> <property name="RecoveryEnvironmentBean.expiryScannerClassNames" value="com.arjuna.ats.internal.arjuna.recovery.ExpiredTransactionStatusManagerScanner com.arjuna.ats.internal.arjuna.recovery.AtomicActionExpiryScanner"/> >>>> </system-properties> >>>> >>>> In earlier revisions of WFLY this worked fine. However I am now seeing that the system property is not set until after my subsystem has started. I can tell this as I have breakpoints on where I process the property. I can see "MSC service thread 1-4" attempting to process the property (which is not set). I do later see messages that suggest the system property is set but at that the later point: >>>> >>>> 2016-12-12 17:57:48,042 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@784c8c5f handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} >>>> 2016-12-12 17:57:48,093 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@87b4493 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} >>>> >>>> Does my subsystem need to depend on something to get the old behaviour of being started after system properties are processed? >>>> >>>> My subsystem is the transaction one and the service is the recovery manager. >>>> >>>> Thanks! >>>> Tom >>>> _______________________________________________ >>>> wildfly-dev mailing list >>>> wildfly-dev(a)lists.jboss.org >>>> https://lists.jboss.org/mailman/listinfo/wildfly-dev >>> >>> >>> _______________________________________________ >>> wildfly-dev mailing list >>> wildfly-dev(a)lists.jboss.org >>> https://lists.jboss.org/mailman/listinfo/wildfly-dev >> >> -- >> Brian Stansberry >> Manager, Senior Principal Software Engineer >> JBoss by Red Hat >> >> >> >> >> _______________________________________________ >> wildfly-dev mailing list >> wildfly-dev(a)lists.jboss.org >> https://lists.jboss.org/mailman/listinfo/wildfly-dev > > -- > Brian Stansberry > Manager, Senior Principal Software Engineer > JBoss by Red Hat > > > > > _______________________________________________ > wildfly-dev mailing list > wildfly-dev(a)lists.jboss.org > https://lists.jboss.org/mailman/listinfo/wildfly-dev > -- Brian Stansberry Manager, Senior Principal Software Engineer JBoss by Red Hat _______________________________________________ wildfly-dev mailing list wildfly-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/wildfly-dev

Thanks, I will take a look. Did this change recently? If not I am at a loss why it is starting to fail an existing test. On 12 December 2016 at 21:33, Brian Stansberry < brian.stansberry(a)redhat.com&gt; wrote: > > > On Dec 12, 2016, at 3:21 PM, Brian Stansberry < > brian.stansberry(a)redhat.com&gt; wrote: > > > > This is the problem: the TransactionExtension initialize method of > touching classes that result in doing static initialization stuff that > reads the system props at that point, which is too early: > > > > s/of touching/is touching/g > > A likely fix is to just not store a ref to coordinatorEnvironmentBean in > TransactionSubsystemRootResourceDefinition$StatisticsEnabledHandler. > Just find it and use it in applyUpdateToRuntime/revertUpdateToRuntime > neither of which will get called before system properties are set. They > don’t get called at all if the user doesn’t do a write-attribute op to > change that attribute. > > > "ServerService Thread Pool -- 21@3635" prio=5 tid=0x30 nid=NA runnable > > java.lang.Thread.State: RUNNABLE > > at com.arjuna.common.util.propertyservice.PropertiesFactory.ini > tPropertiesFactory(PropertiesFactory.java:53) > > - locked <0x1389> (a java.lang.Class) > > at com.arjuna.common.util.propertyservice.PropertiesFactory.get > DefaultProperties(PropertiesFactory.java:36) > > at com.arjuna.common.internal.util.propertyservice.BeanPopulato > r.getNamedInstance(BeanPopulator.java:86) > > at com.arjuna.common.internal.util.propertyservice.BeanPopulato > r.getDefaultInstance(BeanPopulator.java:53) > > at com.arjuna.ats.arjuna.common.arjPropertyManager.getCoordinat > orEnvironmentBean(arjPropertyManager.java:51) > > at org.jboss.as.txn.subsystem.TransactionSubsystemRootResourceD > efinition$StatisticsEnabledHandler.<init>(TransactionSubsyst > emRootResourceDefinition.java:518) > > at org.jboss.as.txn.subsystem.TransactionSubsystemRootResourceD > efinition.registerAttributes(TransactionSubsystemRootResourc > eDefinition.java:314) > > at org.jboss.as.controller.registry.NodeSubregistry.registerChi > ld(NodeSubregistry.java:104) > > at org.jboss.as.controller.registry.ConcreteResourceRegistratio > n.registerSubModel(ConcreteResourceRegistration.java:225) > > at org.jboss.as.controller.extension.ExtensionRegistry$Subsyste > mRegistrationImpl.registerSubsystemModel(ExtensionRegistry.java:706) > > at org.jboss.as.txn.subsystem.TransactionExtension.initialize(T > ransactionExtension.java:104) > > at org.jboss.as.controller.extension.ExtensionAddHandler.initia > lizeExtension(ExtensionAddHandler.java:131) > > at org.jboss.as.controller.extension.ExtensionAddHandler.initia > lizeExtension(ExtensionAddHandler.java:104) > > at org.jboss.as.controller.extension.ParallelExtensionAddHandle > r$ExtensionInitializeTask.call(ParallelExtensionAddHandler.java:144) > > at org.jboss.as.controller.extension.ParallelExtensionAddHandle > r$ExtensionInitializeTask.call(ParallelExtensionAddHandler.java:127) > > at java.util.concurrent.FutureTask.run(FutureTask.java:266) > > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool > Executor.java:1142) > > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo > lExecutor.java:617) > > at java.lang.Thread.run(Thread.java:745) > > at org.jboss.threads.JBossThread.run(JBossThread.java:320) > > > > > >> On Dec 12, 2016, at 2:50 PM, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; > wrote: > >> > >> Thanks for the input/ > >> > >> This is the point I do not think the property has been set by: > >> > >> "MSC service thread 1-3@2595" prio=5 tid=0x14 nid=NA runnable > >> java.lang.Thread.State: RUNNABLE > >> at com.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.getExpi > ryScannerClassNames(RecoveryEnvironmentBean.java:336) > >> - locked <0x1bb6> (a com.arjuna.ats.arjuna.common.R > ecoveryEnvironmentBean) > >> at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAcc > essorImpl.java:-1) > >> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAcce > ssorImpl.java:62) > >> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe > thodAccessorImpl.java:43) > >> at java.lang.reflect.Method.invoke(Method.java:498) > >> at com.arjuna.common.internal.util.propertyservice.BeanPopulato > r.handleGroupProperty(BeanPopulator.java:263) > >> at com.arjuna.common.internal.util.propertyservice.BeanPopulato > r.configureFromProperties(BeanPopulator.java:170) > >> at com.arjuna.common.internal.util.propertyservice.BeanPopulato > r.getNamedInstance(BeanPopulator.java:87) > >> at com.arjuna.common.internal.util.propertyservice.BeanPopulato > r.getDefaultInstance(BeanPopulator.java:53) > >> at com.arjuna.ats.arjuna.common.recoveryPropertyManager.getReco > veryEnvironmentBean(recoveryPropertyManager.java:34) > >> at org.jboss.as.txn.service.ArjunaRecoveryManagerService.start( > ArjunaRecoveryManagerService.java:96) > >> - locked <0x1bd2> (a org.jboss.as.txn.service.Arjun > aRecoveryManagerService) > >> at org.jboss.msc.service.ServiceControllerImpl$StartTask. > startService(ServiceControllerImpl.java:1963) > >> at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(Se > rviceControllerImpl.java:1896) > >> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool > Executor.java:1142) > >> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo > lExecutor.java:617) > >> at java.lang.Thread.run(Thread.java:745) > >> > >> (that is output from the debugger) > >> > >> Once releasing that thread and letting the container continue startup > I see this execute: > >> 2016-12-12 20:46:49,731 TRACE [org.jboss.as.controller.management-operation] > (Controller Boot Thread) Final response for step handler > org.jboss.as.server.operations.SystemPropertyAddHandler@5c7e7735 > handling add in address [("system-property" => > "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => > "success"} > >> 2016-12-12 20:46:49,787 TRACE [org.jboss.as.controller.management-operation] > (Controller Boot Thread) Final response for step handler > org.jboss.as.controller.ValidateModelStepHandler@f15c8f7 handling > internal-model-validation in address [("system-property" => > "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => > "success"} > >> > >> I believe this is different to previous behaviour as I have had a > defect raised against TX: https://issues.jboss.org/browse/JBEAP-7820. > It's possible that there is a regression in Narayana (somehow) if nothing > changed in this area in the core itself. > >> > >> Thanks for your input, > >> Tom > >> > >> > >> > >> > >> On 12 December 2016 at 20:15, Brian Stansberry < > brian.stansberry(a)redhat.com&gt; wrote: > >> This works fine for me. Adding that xml snippet to standalone.xml > after the <extensions> element I see the property being set during boot > before any processing of subsystem operations begins. > >> > >>> On Dec 12, 2016, at 1:55 PM, Brian Stansberry < > brian.stansberry(a)redhat.com&gt; wrote: > >>> > >>> I don’t see anything in the organization of boot ops that would have > changed the ordering, and the add op for that system property should be > executing prior to the subsystem ops. I’ll see if I can reproduce. > >>> > >>>> On Dec 12, 2016, at 12:10 PM, Kabir Khan <kabir.khan(a)jboss.com&gt; > wrote: > >>>> > >>>> Where are you trying to use the system property from? They should > only be attempted resolved during the RUNTIME stage, not MODEL. > >>>>> On 12 Dec 2016, at 18:00, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; > wrote: > >>>>> > >>>>> Hi, > >>>>> > >>>>> I have a subsystem that configures itself from system properties. > >>>>> > >>>>> For example: > >>>>> <system-properties> > >>>>> <property name="RecoveryEnvironmentBean.expiryScannerClassNames" > value="com.arjuna.ats.internal.arjuna.recovery.ExpiredTransactionStatusManagerScanner > com.arjuna.ats.internal.arjuna.recovery.AtomicActionExpiryScanner"/> > >>>>> </system-properties> > >>>>> > >>>>> In earlier revisions of WFLY this worked fine. However I am now > seeing that the system property is not set until after my subsystem has > started. I can tell this as I have breakpoints on where I process the > property. I can see "MSC service thread 1-4" attempting to process the > property (which is not set). I do later see messages that suggest the > system property is set but at that the later point: > >>>>> > >>>>> 2016-12-12 17:57:48,042 TRACE [org.jboss.as.controller.management-operation] > (Controller Boot Thread) Final response for step handler > org.jboss.as.server.operations.SystemPropertyAddHandler@784c8c5f > handling add in address [("system-property" => > "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => > "success"} > >>>>> 2016-12-12 17:57:48,093 TRACE [org.jboss.as.controller.management-operation] > (Controller Boot Thread) Final response for step handler > org.jboss.as.controller.ValidateModelStepHandler@87b4493 handling > internal-model-validation in address [("system-property" => > "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => > "success"} > >>>>> > >>>>> Does my subsystem need to depend on something to get the old > behaviour of being started after system properties are processed? > >>>>> > >>>>> My subsystem is the transaction one and the service is the recovery > manager. > >>>>> > >>>>> Thanks! > >>>>> Tom > >>>>> _______________________________________________ > >>>>> wildfly-dev mailing list > >>>>> wildfly-dev(a)lists.jboss.org > >>>>> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >>>> > >>>> > >>>> _______________________________________________ > >>>> wildfly-dev mailing list > >>>> wildfly-dev(a)lists.jboss.org > >>>> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >>> > >>> -- > >>> Brian Stansberry > >>> Manager, Senior Principal Software Engineer > >>> JBoss by Red Hat > >>> > >>> > >>> > >>> > >>> _______________________________________________ > >>> wildfly-dev mailing list > >>> wildfly-dev(a)lists.jboss.org > >>> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >> > >> -- > >> Brian Stansberry > >> Manager, Senior Principal Software Engineer > >> JBoss by Red Hat > >> > >> > >> > >> > >> _______________________________________________ > >> wildfly-dev mailing list > >> wildfly-dev(a)lists.jboss.org > >> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >> > > > > -- > > Brian Stansberry > > Manager, Senior Principal Software Engineer > > JBoss by Red Hat > > > > > > > > > > _______________________________________________ > > wildfly-dev mailing list > > wildfly-dev(a)lists.jboss.org > > https://lists.jboss.org/mailman/listinfo/wildfly-dev > > -- > Brian Stansberry > Manager, Senior Principal Software Engineer > JBoss by Red Hat > > > >

Great. :) It looks like the TransactionSubsystemRootResourceDefinition$StatisticsEnabledHandler logic came in about a month ago. The issue may have surfaced more recently than that if the test that revealed it was not part of CI, but was something extended that Red Hat QE runs against periodic internal builds. Those happen every few weeks. > On Dec 13, 2016, at 5:55 AM, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: > > Yeah, moving the lookup to the area you mentioned worked - thanks again! > > On 13 December 2016 at 10:54, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: > Thanks, I will take a look. Did this change recently? If not I am at a loss why it is starting to fail an existing test. > > On 12 December 2016 at 21:33, Brian Stansberry < brian.stansberry(a)redhat.com&gt; wrote: > > > On Dec 12, 2016, at 3:21 PM, Brian Stansberry < brian.stansberry(a)redhat.com&gt; wrote: > > > > This is the problem: the TransactionExtension initialize method of touching classes that result in doing static initialization stuff that reads the system props at that point, which is too early: > > > > s/of touching/is touching/g > > A likely fix is to just not store a ref to coordinatorEnvironmentBean in TransactionSubsystemRootResourceDefinition$StatisticsEnabledHandler. Just find it and use it in applyUpdateToRuntime/revertUpdateToRuntime neither of which will get called before system properties are set. They don’t get called at all if the user doesn’t do a write-attribute op to change that attribute. > > > "ServerService Thread Pool -- 21@3635" prio=5 tid=0x30 nid=NA runnable > > java.lang.Thread.State: RUNNABLE > > at com.arjuna.common.util.propertyservice.PropertiesFactory. initPropertiesFactory(PropertiesFactory.java:53) > > - locked <0x1389> (a java.lang.Class) > > at com.arjuna.common.util.propertyservice.PropertiesFactory. getDefaultProperties(PropertiesFactory.java:36) > > at com.arjuna.common.internal.util.propertyservice. BeanPopulator.getNamedInstance(BeanPopulator.java:86) > > at com.arjuna.common.internal.util.propertyservice. BeanPopulator.getDefaultInstance(BeanPopulator.java:53) > > at com.arjuna.ats.arjuna.common.arjPropertyManager. getCoordinatorEnvironmentBean(arjPropertyManager.java:51) > > at org.jboss.as.txn.subsystem.TransactionSubsystemRootResour ceDefinition$StatisticsEnabledHandler.<init>( TransactionSubsystemRootResourceDefinition.java:518) > > at org.jboss.as.txn.subsystem.TransactionSubsystemRootResour ceDefinition.registerAttributes(TransactionSubsystemRootResour ceDefinition.java:314) > > at org.jboss.as.controller.registry.NodeSubregistry. registerChild(NodeSubregistry.java:104) > > at org.jboss.as.controller.registry. ConcreteResourceRegistration.registerSubModel( ConcreteResourceRegistration.java:225) > > at org.jboss.as.controller.extension.ExtensionRegistry$ SubsystemRegistrationImpl.registerSubsystemModel( ExtensionRegistry.java:706) > > at org.jboss.as.txn.subsystem.TransactionExtension.initialize( TransactionExtension.java:104) > > at org.jboss.as.controller.extension.ExtensionAddHandler. initializeExtension(ExtensionAddHandler.java:131) > > at org.jboss.as.controller.extension.ExtensionAddHandler. initializeExtension(ExtensionAddHandler.java:104) > > at org.jboss.as.controller.extension. ParallelExtensionAddHandler$ExtensionInitializeTask.call( ParallelExtensionAddHandler.java:144) > > at org.jboss.as.controller.extension. ParallelExtensionAddHandler$ExtensionInitializeTask.call( ParallelExtensionAddHandler.java:127) > > at java.util.concurrent.FutureTask.run(FutureTask.java:266) > > at java.util.concurrent.ThreadPoolExecutor.runWorker( ThreadPoolExecutor.java:1142) > > at java.util.concurrent.ThreadPoolExecutor$Worker.run( ThreadPoolExecutor.java:617) > > at java.lang.Thread.run(Thread.java:745) > > at org.jboss.threads.JBossThread.run(JBossThread.java:320) > > > > > >> On Dec 12, 2016, at 2:50 PM, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: > >> > >> Thanks for the input/ > >> > >> This is the point I do not think the property has been set by: > >> > >> "MSC service thread 1-3@2595" prio=5 tid=0x14 nid=NA runnable > >> java.lang.Thread.State: RUNNABLE > >> at com.arjuna.ats.arjuna.common.RecoveryEnvironmentBean. getExpiryScannerClassNames(RecoveryEnvironmentBean.java:336) > >> - locked <0x1bb6> (a com.arjuna.ats.arjuna.common. RecoveryEnvironmentBean) > >> at sun.reflect.NativeMethodAccessorImpl.invoke0( NativeMethodAccessorImpl.java:-1) > >> at sun.reflect.NativeMethodAccessorImpl.invoke( NativeMethodAccessorImpl.java:62) > >> at sun.reflect.DelegatingMethodAccessorImpl.invoke( DelegatingMethodAccessorImpl.java:43) > >> at java.lang.reflect.Method.invoke(Method.java:498) > >> at com.arjuna.common.internal.util.propertyservice. BeanPopulator.handleGroupProperty(BeanPopulator.java:263) > >> at com.arjuna.common.internal.util.propertyservice. BeanPopulator.configureFromProperties(BeanPopulator.java:170) > >> at com.arjuna.common.internal.util.propertyservice. BeanPopulator.getNamedInstance(BeanPopulator.java:87) > >> at com.arjuna.common.internal.util.propertyservice. BeanPopulator.getDefaultInstance(BeanPopulator.java:53) > >> at com.arjuna.ats.arjuna.common.recoveryPropertyManager. getRecoveryEnvironmentBean(recoveryPropertyManager.java:34) > >> at org.jboss.as.txn.service.ArjunaRecoveryManagerService. start(ArjunaRecoveryManagerService.java:96) > >> - locked <0x1bd2> (a org.jboss.as.txn.service. ArjunaRecoveryManagerService) > >> at org.jboss.msc.service.ServiceControllerImpl$ StartTask.startService(ServiceControllerImpl.java:1963) > >> at org.jboss.msc.service.ServiceControllerImpl$StartTask.run( ServiceControllerImpl.java:1896) > >> at java.util.concurrent.ThreadPoolExecutor.runWorker( ThreadPoolExecutor.java:1142) > >> at java.util.concurrent.ThreadPoolExecutor$Worker.run( ThreadPoolExecutor.java:617) > >> at java.lang.Thread.run(Thread.java:745) > >> > >> (that is output from the debugger) > >> > >> Once releasing that thread and letting the container continue startup I see this execute: > >> 2016-12-12 20:46:49,731 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@5c7e7735 handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > >> 2016-12-12 20:46:49,787 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@f15c8f7 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > >> > >> I believe this is different to previous behaviour as I have had a defect raised against TX: https://issues.jboss.org/browse/JBEAP-7820. It's possible that there is a regression in Narayana (somehow) if nothing changed in this area in the core itself. > >> > >> Thanks for your input, > >> Tom > >> > >> > >> > >> > >> On 12 December 2016 at 20:15, Brian Stansberry < brian.stansberry(a)redhat.com&gt; wrote: > >> This works fine for me. Adding that xml snippet to standalone.xml after the <extensions> element I see the property being set during boot before any processing of subsystem operations begins. > >> > >>> On Dec 12, 2016, at 1:55 PM, Brian Stansberry < brian.stansberry(a)redhat.com&gt; wrote: > >>> > >>> I don’t see anything in the organization of boot ops that would have changed the ordering, and the add op for that system property should be executing prior to the subsystem ops. I’ll see if I can reproduce. > >>> > >>>> On Dec 12, 2016, at 12:10 PM, Kabir Khan <kabir.khan(a)jboss.com&gt; wrote: > >>>> > >>>> Where are you trying to use the system property from? They should only be attempted resolved during the RUNTIME stage, not MODEL. > >>>>> On 12 Dec 2016, at 18:00, Tom Jenkinson <tom.jenkinson(a)redhat.com&gt; wrote: > >>>>> > >>>>> Hi, > >>>>> > >>>>> I have a subsystem that configures itself from system properties. > >>>>> > >>>>> For example: > >>>>> <system-properties> > >>>>> <property name="RecoveryEnvironmentBean.expiryScannerClassNames" value="com.arjuna.ats.internal.arjuna.recovery. ExpiredTransactionStatusManagerScanner com.arjuna.ats.internal. arjuna.recovery.AtomicActionExpiryScanner"/> > >>>>> </system-properties> > >>>>> > >>>>> In earlier revisions of WFLY this worked fine. However I am now seeing that the system property is not set until after my subsystem has started. I can tell this as I have breakpoints on where I process the property. I can see "MSC service thread 1-4" attempting to process the property (which is not set). I do later see messages that suggest the system property is set but at that the later point: > >>>>> > >>>>> 2016-12-12 17:57:48,042 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.server.operations.SystemPropertyAddHandler@784c8c5f handling add in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > >>>>> 2016-12-12 17:57:48,093 TRACE [org.jboss.as.controller.management-operation] (Controller Boot Thread) Final response for step handler org.jboss.as.controller.ValidateModelStepHandler@87b4493 handling internal-model-validation in address [("system-property" => "RecoveryEnvironmentBean.expiryScannerClassNames")] is {"outcome" => "success"} > >>>>> > >>>>> Does my subsystem need to depend on something to get the old behaviour of being started after system properties are processed? > >>>>> > >>>>> My subsystem is the transaction one and the service is the recovery manager. > >>>>> > >>>>> Thanks! > >>>>> Tom > >>>>> _______________________________________________ > >>>>> wildfly-dev mailing list > >>>>> wildfly-dev(a)lists.jboss.org > >>>>> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >>>> > >>>> > >>>> _______________________________________________ > >>>> wildfly-dev mailing list > >>>> wildfly-dev(a)lists.jboss.org > >>>> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >>> > >>> -- > >>> Brian Stansberry > >>> Manager, Senior Principal Software Engineer > >>> JBoss by Red Hat > >>> > >>> > >>> > >>> > >>> _______________________________________________ > >>> wildfly-dev mailing list > >>> wildfly-dev(a)lists.jboss.org > >>> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >> > >> -- > >> Brian Stansberry > >> Manager, Senior Principal Software Engineer > >> JBoss by Red Hat > >> > >> > >> > >> > >> _______________________________________________ > >> wildfly-dev mailing list > >> wildfly-dev(a)lists.jboss.org > >> https://lists.jboss.org/mailman/listinfo/wildfly-dev > >> > > > > -- > > Brian Stansberry > > Manager, Senior Principal Software Engineer > > JBoss by Red Hat > > > > > > > > > > _______________________________________________ > > wildfly-dev mailing list > > wildfly-dev(a)lists.jboss.org > > https://lists.jboss.org/mailman/listinfo/wildfly-dev > > -- > Brian Stansberry > Manager, Senior Principal Software Engineer > JBoss by Red Hat > > > > > -- Brian Stansberry Manager, Senior Principal Software Engineer JBoss by Red Hat