Node diagnostic of xxxx components is displayed in the logs

Problem

"platform.availabilityMonitor - Node diagnostic of xxxx components" is displayed in the node logs during startup.

Explanation

It is important to understand that Node diagnostic is not an ERROR but an INFO message. Decision Insight is composed of hundreds of individual components that must all be initialized before the node can be started. These log messages are there to inform you that a given node is taking longer than one minute to start a particular component. In itself, that is not a problem as long as the components actually start and are not blocked.

For the explanation, as a concrete example, we use an info message log file taken from an actual customer to explain what information is logged. Based on this message, the node takes about 11 minutes to start, hence the multiple Node diagnostic INFO messages being logged. The full node.log file is over 1,500 lines long. We simplified that log file by removing identical lines or lines that didn't add any information to this explanation. The number of lines removed is indicated in parentheses.

The simplified logs are available at the bottom of this page.

The node startup started at 2017-01-06 11:01:38,765.

2017-01-06 11:01:40,298 [FelixStartLevel] INFO platform - # STARTING PLATFORM #


After about a minute you can see from the logs that the node hasn't started yet and is still waiting on 627 components.

2017-01-06 11:02:46,268 [Domain-platform-15-availabilityMonitor] INFO platform.availabilityMonitor - Node diagnostic of 1800 components:
  * 1172 components are started
  * 627 components are waiting
  * 1 component is starting

The customer has one partition for storing data. On startup, all of the partitions must be initialized. On average, it takes about five seconds to load the partition while the configuration store takes around 40 seconds.

configuration initialized in 37.516 seconds
partition-0 initialized in 5.018 seconds

The initialization of all these stores takes about 45 seconds and they are part of the initialization of a component called the temporalStoreManager. Until the initialization of the stores is done, the component cannot be started. If the initialization takes more than one minute, every minute the node will output the Node diagnostic INFO log message. Once the temporalStoreManager starts, another component that depends on it can also start.

After the copper.metamodelStore, it is time for the calcium.asynchronousWorkflowEngine to start. The log produced contained the current state of the thread to help in troubleshooting the issue:

2017-01-06 11:02:46,268 [Domain-platform-15-availabilityMonitor] INFO platform.availabilityMonitor - Node diagnostic of 1800 components:
  * 1172 components are started
  * 627 components are waiting
  * 1 component is starting
      - calcium.asynchronousWorkflowEngine
            at java.util.regex.Pattern$BmpCharProperty.match(Pattern.java:3797)
            at java.util.regex.Pattern$Curly.match0(Pattern.java:4260)
            at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
            at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
            at java.util.regex.Pattern$Branch.match(Pattern.java:4604)
            at java.util.regex.Pattern$BmpCharProperty.match(Pattern.java:3798)
            at java.util.regex.Pattern$Start.match(Pattern.java:3461)
            at java.util.regex.Matcher.search(Matcher.java:1248)
            at java.util.regex.Matcher.find(Matcher.java:664)
            at java.util.Formatter.parse(Formatter.java:2549)
            at java.util.Formatter.format(Formatter.java:2501)
            at java.util.Formatter.format(Formatter.java:2455)
            at java.lang.String.format(String.java:2940)
            at com.systar.titanium.impl.disk.SSLevel.toString(SSLevel.java:77)
            at com.systar.titanium.impl.disk.SSTableUrl.<init>(SSTableUrl.java:31)
            at com.systar.titanium.impl.disk.io.FileHelper.getBlobFile(FileHelper.java:234)
            at com.systar.titanium.impl.stream.ki.TableScanner.<init>(TableScanner.java:57)
            at com.systar.titanium.impl.stream.ki.DiskScanner.prepareScanForIndex(DiskScanner.java:136)
            at com.systar.titanium.impl.stream.ki.DiskScanner.<init>(DiskScanner.java:67)
            at com.systar.titanium.impl.TableTemporalKIColumn.scanEntries(TableTemporalKIColumn.java:134)
            at com.systar.titanium.impl.TableTemporalColumn.scan(TableTemporalColumn.java:146)
            at com.systar.titanium.impl.TableTemporalColumn.scan(TableTemporalColumn.java:170)
            at com.systar.copper.impl.member.ModelMemberValueColumnSupport.internalScan(ModelMemberValueColumnSupport.java:202)
            at com.systar.copper.impl.member.ModelMemberValueColumnSupport.scanMemberValues(ModelMemberValueColumnSupport.java:177)
            at com.systar.copper.impl.member.ModelMemberValueColumnImpl.scanMemberValues(ModelMemberValueColumnImpl.java:85)
            at com.systar.calcium.impl.absorption.workflow.EventInterceptorRepository.getWorkflowElementTopicIds(EventInterceptorRepository.java:306)
            at com.systar.calcium.impl.absorption.workflow.EventInterceptorRepository.getWorkflowElementSubscribedTopicIds(EventInterceptorRepository.java:171)
            at com.systar.calcium.impl.absorption.workflow.asynchronous.AsynchronousWorkflowEngine.deployAsynchronousInterceptorHandler(AsynchronousWorkflowEngine.java:132)
            at com.systar.calcium.impl.absorption.workflow.asynchronous.AsynchronousWorkflowEngine.deployAsynchronousEventHandlersOnStartup(AsynchronousWorkflowEngine.java:229)
            at com.systar.calcium.impl.absorption.workflow.asynchronous.AsynchronousWorkflowEngine.onStart(AsynchronousWorkflowEngine.java:89)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)

There is no issue with this component but it's been one minute since the start of the node.

The next log shows that there is more than one component being started:

2017-01-06 11:06:47,336 [Domain-platform-15-availabilityMonitor] INFO platform.availabilityMonitor - Node diagnostic of 1800 components:
  * 1762 components are started
  * 29 components are waiting
  * 9 components are starting
      - aluminium-engine.dataIntegrationInitializer
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer.waitForStatus(PicoComponentContainer.java:223)
            at com.systar.gluon.container.impl.factory.ComponentFactoryInvocationHandler.invokeImpl(ComponentFactoryInvocationHandler.java:48)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy76.create(Unknown Source)
            at com.systar.aluminium.engine.impl.context.ContextRuntimeManager$1.load(ContextRuntimeManager.java:32)
            at com.systar.aluminium.engine.impl.context.ContextRuntimeManager$1.load(ContextRuntimeManager.java:27)
            at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3542)
            at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2323)
            at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2286)
            at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2201)
            at com.google.common.cache.LocalCache.get(LocalCache.java:3953)
            at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3957)
            at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4875)
            at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4881)
            at com.google.common.cache.ForwardingLoadingCache.getUnchecked(ForwardingLoadingCache.java:51)
            at com.systar.tau.util.cache.CacheUtil$LoadingCacheImpl.getUnchecked(CacheUtil.java:26)
            at com.systar.tau.util.collection.FetchMaps$LoadingCacheFetchMap.fetch(FetchMaps.java:203)
            at com.systar.aluminium.engine.impl.context.ContextRuntimeManager.getOrCreate(ContextRuntimeManager.java:77)
            at com.systar.aluminium.engine.impl.workflow.DataIntegrationInitializer.initializeContexts(DataIntegrationInitializer.java:190)
            at com.systar.aluminium.engine.impl.workflow.DataIntegrationInitializer.initialize(DataIntegrationInitializer.java:120)
            at com.systar.aluminium.engine.impl.workflow.DataIntegrationInitializer.onStart(DataIntegrationInitializer.java:102)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.computingReader
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.tau.util.Interrupted.wait(Interrupted.java:104)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:181)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:174)
            at sun.reflect.GeneratedMethodAccessor102.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at com.systar.gluon.osgi.service.ImportedServiceHandler.invokeImpl(ImportedServiceHandler.java:85)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy39.waitForModelAvailability(Unknown Source)
            at com.systar.krypton.scheduler.impl.ComputingReaderImpl.onStart(ComputingReaderImpl.java:140)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.computingTriggerInterceptorManager
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.tau.util.Interrupted.wait(Interrupted.java:104)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:181)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:174)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            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.systar.gluon.osgi.service.ImportedServiceHandler.invokeImpl(ImportedServiceHandler.java:85)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy39.waitForModelAvailability(Unknown Source)
            at com.systar.krypton.scheduler.impl.ComputingTriggerInterceptorManager.onStart(ComputingTriggerInterceptorManager.java:64)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.computingTriggerInterceptorRegistry
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.tau.util.Interrupted.wait(Interrupted.java:104)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:181)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:174)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            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.systar.gluon.osgi.service.ImportedServiceHandler.invokeImpl(ImportedServiceHandler.java:85)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy39.waitForModelAvailability(Unknown Source)
            at com.systar.krypton.scheduler.impl.trigger.ComputingTriggerInterceptorRegistry.onStart(ComputingTriggerInterceptorRegistry.java:66)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.computingTriggerStateInitializer
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.tau.util.Interrupted.wait(Interrupted.java:104)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:181)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:174)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            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.systar.gluon.osgi.service.ImportedServiceHandler.invokeImpl(ImportedServiceHandler.java:85)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy39.waitForModelAvailability(Unknown Source)
            at com.systar.krypton.scheduler.impl.trigger.ComputingTriggerStateInitializer.onStart(ComputingTriggerStateInitializer.java:28)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.defaultCollectorInitializer
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.tau.util.Interrupted.wait(Interrupted.java:104)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:181)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:174)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            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.systar.gluon.osgi.service.ImportedServiceHandler.invokeImpl(ImportedServiceHandler.java:85)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy39.waitForModelAvailability(Unknown Source)
            at com.systar.krypton.scheduler.impl.collector.DefaultCollectorInitializer.onStart(DefaultCollectorInitializer.java:118)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.indicatorObserverInitializer
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.tau.util.Interrupted.wait(Interrupted.java:104)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:181)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:174)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            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.systar.gluon.osgi.service.ImportedServiceHandler.invokeImpl(ImportedServiceHandler.java:85)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy39.waitForModelAvailability(Unknown Source)
            at com.systar.krypton.scheduler.impl.observer.IndicatorObserverInitializer.onStart(IndicatorObserverInitializer.java:39)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.lateDataHandlerInterceptorFactory
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:502)
            at com.systar.tau.util.Interrupted.wait(Interrupted.java:104)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:181)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.waitForModelAvailability(PlatformModelManagerImpl.java:174)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            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.systar.gluon.osgi.service.ImportedServiceHandler.invokeImpl(ImportedServiceHandler.java:85)
            at com.systar.gluon.container.impl.factory.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:35)
            at com.sun.proxy.$Proxy39.waitForModelAvailability(Unknown Source)
            at com.systar.krypton.scheduler.impl.latedata.LateDataHandlerInterceptorFactory.onStart(LateDataHandlerInterceptorFactory.java:45)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)
      - krypton-scheduler.schedulerModelHandler
            at java.lang.Object.wait(Native Method)
            at com.systar.tau.util.Interrupted.timedWait(Interrupted.java:121)
            at com.systar.calcium.impl.absorption.clock.VectorClockImpl.awaitVectorClockProgress(VectorClockImpl.java:83)
            at com.systar.calcium.impl.absorption.bus.AbsorptionClockUpdater.waitForProcessedVectorClock(AbsorptionClockUpdater.java:107)
            at com.systar.calcium.impl.absorption.AbsorptionManagerImpl.absorbRequest(AbsorptionManagerImpl.java:253)
            at com.systar.calcium.impl.absorption.AbsorptionManagerImpl.absorbRequest(AbsorptionManagerImpl.java:220)
            at com.systar.calcium.impl.metamodel.StructuralModelUpdateExecutor.execute(StructuralModelUpdateExecutor.java:32)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.applyModelModifications(PlatformModelManagerImpl.java:332)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.updateModel(PlatformModelManagerImpl.java:316)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.initializeModelHandler(PlatformModelManagerImpl.java:280)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl.processModelHandlers(PlatformModelManagerImpl.java:225)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl$1.addingService(PlatformModelManagerImpl.java:126)
            at com.systar.calcium.impl.metamodel.PlatformModelManagerImpl$1.addingService(PlatformModelManagerImpl.java:108)
            at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)
            at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)
            at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)
            at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)
            at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901)
            at org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCallback(EventDispatcher.java:991)
            at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:839)
            at org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDispatcher.java:546)
            at org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:4557)
            at org.apache.felix.framework.Felix.registerService(Felix.java:3549)
            at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:348)
            at com.systar.gluon.osgi.service.ExportedServiceHandler.onStart(ExportedServiceHandler.java:64)
            at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.doLifecycleMethod(StartableLifecycleStrategy.java:101)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.startComponent(StartableLifecycleStrategy.java:96)
            at org.picocontainer.lifecycle.StartableLifecycleStrategy.start(StartableLifecycleStrategy.java:87)
            at org.picocontainer.injectors.AbstractInjector.start(AbstractInjector.java:131)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:173)
            at org.picocontainer.behaviors.Stored$RealComponentLifecycle.start(Stored.java:134)
            at org.picocontainer.behaviors.Stored.start(Stored.java:111)
            at org.picocontainer.behaviors.AbstractBehavior.start(AbstractBehavior.java:123)
            at org.picocontainer.DefaultPicoContainer.startAdapters(DefaultPicoContainer.java:916)
            at org.picocontainer.DefaultPicoContainer.start(DefaultPicoContainer.java:664)
            at com.systar.gluon.container.impl.pico.PicoComponentContainer$StartRunner.run(PicoComponentContainer.java:561)
            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)


We can see that more components are started but that we still have 29 components waiting

2017-01-06 11:13:29,073 [Domain-platform-15-availabilityMonitor] INFO platform.availabilityMonitor - Node diagnostic of 1800 components:
  * 1800 components are started
...
2017-01-06 11:13:29,074 [Domain-platform-15-availabilityMonitor] INFO platform.availabilityMonitor - Platform started in 12 min 9 sec


Adding all of these elements together, we are up to about 12 minutes. This can be seen as long but during that time the node was never stuck and we saw in the logs that components were being started bit by bit.


Related Links