diff --git a/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerImpl.java b/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerImpl.java index 4896c4b18..addb1e46e 100644 --- a/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerImpl.java +++ b/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerImpl.java @@ -15,6 +15,8 @@ */ package li.strolch.agent.impl; +import static li.strolch.utils.helper.StringHelper.formatNanoDuration; + import java.lang.reflect.Constructor; import java.lang.reflect.InvocationTargetException; import java.text.MessageFormat; @@ -180,6 +182,8 @@ public class ComponentContainerImpl implements ComponentContainer { public void setup(StrolchConfiguration strolchConfiguration) { this.state.validateStateChange(ComponentState.SETUP, "agent"); + long start = System.nanoTime(); + // set the application locale Locale.setDefault(strolchConfiguration.getRuntimeConfiguration().getLocale()); String msg = "Application {0}:{1} is using locale {2}"; //$NON-NLS-1$ @@ -215,13 +219,17 @@ public class ComponentContainerImpl implements ComponentContainer { this.state = ComponentState.SETUP; - msg = "{0}:{1} Strolch Container setup with {2} components."; //$NON-NLS-1$ - logger.info(MessageFormat.format(msg, applicationName, environment, this.componentMap.size())); + long took = System.nanoTime() - start; + msg = "{0}:{1} Strolch Container setup with {2} components. Took {3}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, applicationName, environment, this.componentMap.size(), + formatNanoDuration(took))); } public void initialize(StrolchConfiguration strolchConfiguration) { this.state.validateStateChange(ComponentState.INITIALIZED, "agent"); + long start = System.nanoTime(); + // now we can initialize the components String msg = "{0}:{1} Initializing {2} Strolch Components..."; //$NON-NLS-1$ String environment = getEnvironment(); @@ -233,13 +241,17 @@ public class ComponentContainerImpl implements ComponentContainer { this.state = ComponentState.INITIALIZED; - msg = "{0}:{1} All {2} Strolch Components have been initialized."; //$NON-NLS-1$ - logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size())); + long took = System.nanoTime() - start; + msg = "{0}:{1} All {2} Strolch Components have been initialized. Took {3}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size(), + formatNanoDuration(took))); } public void start() { this.state.validateStateChange(ComponentState.STARTED, "agent"); + long start = System.nanoTime(); + String msg = "{0}:{1} Starting {2} Strolch Components..."; //$NON-NLS-1$ String environment = getEnvironment(); String applicationName = getApplicationName(); @@ -250,8 +262,10 @@ public class ComponentContainerImpl implements ComponentContainer { this.state = ComponentState.STARTED; - msg = "{0}:{1} All {2} Strolch Components started. Strolch is now ready to be used. Have fun =))"; //$NON-NLS-1$ - logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size())); + long took = System.nanoTime() - start; + msg = "{0}:{1} All {2} Strolch Components started. Took {3}. Strolch is now ready to be used. Have fun =))"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size(), + formatNanoDuration(took))); logger.info(MessageFormat.format("System: {0}", SystemHelper.asString())); //$NON-NLS-1$ logger.info(MessageFormat.format("Memory: {0}", SystemHelper.getMemorySummary())); //$NON-NLS-1$ } @@ -259,6 +273,8 @@ public class ComponentContainerImpl implements ComponentContainer { public void stop() { this.state.validateStateChange(ComponentState.STOPPED, "agent"); + long start = System.nanoTime(); + String msg = "{0}:{1} Stopping {2} Strolch Components..."; //$NON-NLS-1$ String environment = getEnvironment(); String applicationName = getApplicationName(); @@ -270,8 +286,10 @@ public class ComponentContainerImpl implements ComponentContainer { Set rootUpstreamComponents = this.dependencyAnalyzer.findRootDownstreamComponents(); containerStateHandler.stop(rootUpstreamComponents); - msg = "{0}:{1} All {2} Strolch Components have been stopped."; //$NON-NLS-1$ - logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size())); + long took = System.nanoTime() - start; + msg = "{0}:{1} All {2} Strolch Components have been stopped. Took {3}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size(), + formatNanoDuration(took))); } this.state = ComponentState.STOPPED; @@ -280,6 +298,8 @@ public class ComponentContainerImpl implements ComponentContainer { public void destroy() { this.state.validateStateChange(ComponentState.DESTROYED, "agent"); + long start = System.nanoTime(); + String msg = "{0}:{1} Destroying {2} Strolch Components..."; //$NON-NLS-1$ String environment = getEnvironment(); String applicationName = getApplicationName(); @@ -291,8 +311,10 @@ public class ComponentContainerImpl implements ComponentContainer { Set rootUpstreamComponents = this.dependencyAnalyzer.findRootDownstreamComponents(); containerStateHandler.destroy(rootUpstreamComponents); - msg = "{0}:{1} All {2} Strolch Components have been destroyed!"; //$NON-NLS-1$ - logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size())); + long took = System.nanoTime() - start; + msg = "{0}:{1} All {2} Strolch Components have been destroyed! Took {3}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, applicationName, environment, this.controllerMap.size(), + formatNanoDuration(took))); this.controllerMap.clear(); this.componentMap.clear(); } diff --git a/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerStateHandler.java b/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerStateHandler.java index 254a50e1c..a6b2035e0 100644 --- a/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerStateHandler.java +++ b/li.strolch.agent/src/main/java/li/strolch/agent/impl/ComponentContainerStateHandler.java @@ -15,6 +15,8 @@ */ package li.strolch.agent.impl; +import static li.strolch.utils.helper.StringHelper.formatNanoDuration; + import java.text.MessageFormat; import java.util.Set; @@ -49,18 +51,24 @@ public class ComponentContainerStateHandler { if (controller.getState() == ComponentState.INITIALIZED) continue; + long start = System.nanoTime(); + StrolchComponent component = controller.getComponent(); String componentName = component.getName(); ComponentConfiguration componentConfiguration = this.strolchConfiguration .getComponentConfiguration(componentName); - String msg = "Initializing component {0}..."; //$NON-NLS-1$ - logger.info(MessageFormat.format(msg, componentName)); try { component.initialize(componentConfiguration); } catch (Exception e) { - throw new StrolchException(MessageFormat.format("Failed to initialize component {0}", componentName), e); + throw new StrolchException(MessageFormat.format("Failed to initialize component {0}", componentName), + e); } + + long took = System.nanoTime() - start; + String msg = "Initialized component {0}. Took {1}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, componentName, formatNanoDuration(took))); + } // initialize direct downstream components @@ -77,15 +85,19 @@ public class ComponentContainerStateHandler { if (controller.getState() == ComponentState.STARTED) continue; + long start = System.nanoTime(); + StrolchComponent component = controller.getComponent(); - String msg = "Starting component {0}..."; //$NON-NLS-1$ String componentName = component.getName(); - logger.info(MessageFormat.format(msg, componentName)); try { component.start(); } catch (Exception e) { throw new StrolchException(MessageFormat.format("Failed to start component {0}", componentName), e); } + + long took = System.nanoTime() - start; + String msg = "Started component {0}. Took {1}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, componentName, formatNanoDuration(took))); } // Start direct downstream components @@ -102,17 +114,21 @@ public class ComponentContainerStateHandler { if (controller.getState() == ComponentState.STOPPED) continue; + long start = System.nanoTime(); + StrolchComponent component = controller.getComponent(); - String msg = "Stopping component {0}..."; //$NON-NLS-1$ String componentName = component.getName(); - logger.info(MessageFormat.format(msg, componentName)); try { component.stop(); } catch (Exception e) { - msg = "Failed to stop component {0} due to {1}"; //$NON-NLS-1$ + String msg = "Failed to stop component {0} due to {1}"; //$NON-NLS-1$ msg = MessageFormat.format(msg, componentName, e.getMessage()); logger.error(msg, e); } + + long took = System.nanoTime() - start; + String msg = "Stopped component {0}. Took {1}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, componentName, formatNanoDuration(took))); } // Stop direct upstream components @@ -128,17 +144,21 @@ public class ComponentContainerStateHandler { if (controller.getState() == ComponentState.DESTROYED) continue; + long start = System.nanoTime(); + StrolchComponent component = controller.getComponent(); - String msg = "Destroying component {0}..."; //$NON-NLS-1$ String componentName = component.getName(); - logger.info(MessageFormat.format(msg, componentName)); try { component.destroy(); } catch (Exception e) { - msg = "Failed to destroy component {0} due to {1}"; //$NON-NLS-1$ + String msg = "Failed to destroy component {0} due to {1}"; //$NON-NLS-1$ msg = MessageFormat.format(msg, componentName, e.getMessage()); logger.error(msg, e); } + + long took = System.nanoTime() - start; + String msg = "Destroyed component {0}. Took {1}"; //$NON-NLS-1$ + logger.info(MessageFormat.format(msg, componentName, formatNanoDuration(took))); } // Destroy direct upstream components