Bug 546380 - Add bundleStartTime trace option
This new option not only records the time to load
and call BundleActivator.start but also the complete
time to start a bundle including resolving and firing
bundle events
Change-Id: I70bc48ca3bfbe08d33a159d7add0164df8bcfa76
Signed-off-by: Thomas Watson <tjwatson@us.ibm.com>
diff --git a/bundles/org.eclipse.osgi/.options b/bundles/org.eclipse.osgi/.options
index 13b000f..8e606f0 100644
--- a/bundles/org.eclipse.osgi/.options
+++ b/bundles/org.eclipse.osgi/.options
@@ -20,8 +20,12 @@
org.eclipse.osgi/debug/startlevel=false
# Prints out package admin service debug information
org.eclipse.osgi/debug/packageadmin=false
-# Prints out timing information for bundle activation
+# Prints out timing information for loading and calling BundleActivator.start
org.eclipse.osgi/debug/bundleTime=false
+# Prints out total time for starting a bundle which includes:
+# - loading and calling BundleActivator.start
+# - other time spent resolving bundles and firing bundle events to listeners
+org.eclipse.osgi/debug/bundleStartTime=false
# Debug the loading of message bundles
org.eclipse.osgi/debug/messageBundles=false
# Debug the object pool additions
diff --git a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/Module.java b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/Module.java
index 86d902e..3d6cfbf 100644
--- a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/Module.java
+++ b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/Module.java
@@ -388,7 +388,12 @@
* @throws BundleException if an errors occurs while starting
*/
public void start(StartOptions... options) throws BundleException {
- revisions.getContainer().checkAdminPermission(getBundle(), AdminPermission.EXECUTE);
+ ModuleContainer container = getContainer();
+ long startTime = 0;
+ if (container.DEBUG_BUNDLE_START_TIME) {
+ startTime = System.nanoTime();
+ }
+ container.checkAdminPermission(getBundle(), AdminPermission.EXECUTE);
if (options == null) {
options = new StartOptions[0];
}
@@ -415,7 +420,7 @@
}
checkFragment();
persistStartOptions(options);
- if (getStartLevel() > getRevisions().getContainer().getStartLevel()) {
+ if (getStartLevel() > container.getStartLevel()) {
if (StartOptions.TRANSIENT.isContained(options)) {
// it is an error to attempt to transient start a bundle without its start level met
throw new BundleException(Msg.Module_Transient_StartError, BundleException.START_TRANSIENT_ERROR);
@@ -432,7 +437,7 @@
unlockStateChange(ModuleEvent.STARTED);
lockedStarted = false;
try {
- report = getRevisions().getContainer().resolve(Collections.singletonList(this), true);
+ report = container.resolve(Collections.singletonList(this), true);
} finally {
lockStateChange(ModuleEvent.STARTED);
lockedStarted = true;
@@ -473,6 +478,10 @@
if (!EnumSet.of(ModuleEvent.STARTED, ModuleEvent.LAZY_ACTIVATION, ModuleEvent.STOPPED).contains(event))
throw new IllegalStateException("Wrong event type: " + event); //$NON-NLS-1$
publishEvent(event);
+ // only print bundleTime information if we actually fired an event for this bundle
+ if (container.DEBUG_BUNDLE_START_TIME) {
+ Debug.println(TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startTime) + "ms for total start time of " + this); //$NON-NLS-1$
+ }
}
if (startError != null) {
diff --git a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/ModuleContainer.java b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/ModuleContainer.java
index e51ef84..0b63d1a 100644
--- a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/ModuleContainer.java
+++ b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/container/ModuleContainer.java
@@ -132,6 +132,7 @@
private final boolean autoStartOnResolve;
boolean DEBUG_MONITOR_LAZY = false;
+ boolean DEBUG_BUNDLE_START_TIME = false;
/**
* Constructs a new container with the specified adaptor, module database.
@@ -1554,6 +1555,7 @@
frameworkStartLevel.setDebugOptions();
if (options != null) {
this.DEBUG_MONITOR_LAZY = options.getBooleanOption(Debug.OPTION_MONITOR_LAZY, false);
+ this.DEBUG_BUNDLE_START_TIME = options.getBooleanOption(Debug.OPTION_DEBUG_BUNDLE_START_TIME, false);
}
}
diff --git a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/debug/Debug.java b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/debug/Debug.java
index 5b153f2..645b99b 100644
--- a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/debug/Debug.java
+++ b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/debug/Debug.java
@@ -38,6 +38,11 @@
* Bundle time Debug option key.
*/
public static final String OPTION_DEBUG_BUNDLE_TIME = ECLIPSE_OSGI + "/debug/bundleTime"; //$NON-NLS-1$
+
+ /**
+ * Bundle start time Debug option key.
+ */
+ public static final String OPTION_DEBUG_BUNDLE_START_TIME = ECLIPSE_OSGI + "/debug/bundleStartTime"; //$NON-NLS-1$
/**
* Loader Debug option key.
*/
