Bug 482062 - Add diagnostic logging to SubMonitor
Change-Id: I8514964dc80a48a990e4d12bb4b0ff8b6dcefaed
Signed-off-by: Stefan Xenos <sxenos@gmail.com>
diff --git a/bundles/org.eclipse.equinox.common/.options b/bundles/org.eclipse.equinox.common/.options
index 0f84266..71347b0 100644
--- a/bundles/org.eclipse.equinox.common/.options
+++ b/bundles/org.eclipse.equinox.common/.options
@@ -2,3 +2,6 @@
# Turn on general debugging for the org.eclipse.equinox.common plugin.
org.eclipse.equinox.common/debug=false
+
+# Enable diagnostic logging for progress monitoring
+org.eclipse.equinox.common/progress_monitors=false
diff --git a/bundles/org.eclipse.equinox.common/src/org/eclipse/core/internal/runtime/Activator.java b/bundles/org.eclipse.equinox.common/src/org/eclipse/core/internal/runtime/Activator.java
index 355ba8a..fb5cbde 100644
--- a/bundles/org.eclipse.equinox.common/src/org/eclipse/core/internal/runtime/Activator.java
+++ b/bundles/org.eclipse.equinox.common/src/org/eclipse/core/internal/runtime/Activator.java
@@ -21,6 +21,7 @@
import org.eclipse.osgi.framework.log.FrameworkLog;
import org.eclipse.osgi.service.datalocation.Location;
import org.eclipse.osgi.service.debug.DebugOptions;
+import org.eclipse.osgi.service.debug.DebugOptionsListener;
import org.eclipse.osgi.service.localization.BundleLocalization;
import org.eclipse.osgi.service.urlconversion.URLConverter;
import org.eclipse.osgi.util.NLS;
@@ -36,6 +37,7 @@
* This class can only be used if OSGi plugin is available.
*/
public class Activator implements BundleActivator {
+ public static final String PLUGIN_ID = "org.eclipse.equinox.common"; //$NON-NLS-1$
/**
* Table to keep track of all the URL converter services.
@@ -52,6 +54,7 @@
private ServiceTracker<Object, DebugOptions> debugTracker = null;
private ServiceTracker<Object, FrameworkLog> logTracker = null;
private ServiceTracker<Object, BundleLocalization> localizationTracker = null;
+ private ServiceRegistration<DebugOptionsListener> debugRegistration;
/*
* Returns the singleton for this Activator. Callers should be aware that
@@ -71,6 +74,9 @@
platformURLConverterService = context.registerService(URLConverter.class, new PlatformURLConverter(), urlProperties);
adapterManagerService = context.registerService(IAdapterManager.class, AdapterManager.getDefault(), null);
installPlatformURLSupport();
+ Hashtable<String, String> properties = new Hashtable<>(2);
+ properties.put(DebugOptions.LISTENER_SYMBOLICNAME, PLUGIN_ID);
+ debugRegistration = context.registerService(DebugOptionsListener.class, TracingOptions.DEBUG_OPTIONS_LISTENER, properties);
}
private PlatformLogWriter getPlatformWriter(BundleContext context) {
@@ -282,6 +288,10 @@
localizationTracker.close();
localizationTracker = null;
}
+ if (debugRegistration != null) {
+ debugRegistration.unregister();
+ debugRegistration = null;
+ }
RuntimeLog.setLogWriter(null);
bundleContext = null;
singleton = null;
diff --git a/bundles/org.eclipse.equinox.common/src/org/eclipse/core/internal/runtime/TracingOptions.java b/bundles/org.eclipse.equinox.common/src/org/eclipse/core/internal/runtime/TracingOptions.java
new file mode 100644
index 0000000..930ddd6
--- /dev/null
+++ b/bundles/org.eclipse.equinox.common/src/org/eclipse/core/internal/runtime/TracingOptions.java
@@ -0,0 +1,18 @@
+package org.eclipse.core.internal.runtime;
+
+import org.eclipse.osgi.service.debug.DebugOptions;
+import org.eclipse.osgi.service.debug.DebugOptionsListener;
+
+public class TracingOptions {
+ public static DebugOptionsListener DEBUG_OPTIONS_LISTENER = new DebugOptionsListener() {
+ @Override
+ public void optionsChanged(DebugOptions options) {
+ debug = options.getBooleanOption(Activator.PLUGIN_ID + "/debug", false); //$NON-NLS-1$
+
+ debugProgressMonitors = debug && options.getBooleanOption(Activator.PLUGIN_ID + "/progress_monitors", false); //$NON-NLS-1$
+ }
+ };
+
+ public static boolean debug;
+ public static boolean debugProgressMonitors;
+}
diff --git a/bundles/org.eclipse.equinox.common/src/org/eclipse/core/runtime/SubMonitor.java b/bundles/org.eclipse.equinox.common/src/org/eclipse/core/runtime/SubMonitor.java
index 0e83858..6008727 100644
--- a/bundles/org.eclipse.equinox.common/src/org/eclipse/core/runtime/SubMonitor.java
+++ b/bundles/org.eclipse.equinox.common/src/org/eclipse/core/runtime/SubMonitor.java
@@ -16,6 +16,11 @@
*******************************************************************************/
package org.eclipse.core.runtime;
+import java.util.HashSet;
+import java.util.Set;
+import org.eclipse.core.internal.runtime.RuntimeLog;
+import org.eclipse.core.internal.runtime.TracingOptions;
+
/**
* <p>A progress monitor that uses a given amount of work ticks from a parent monitor. This is intended as a
* safer, easier-to-use alternative to SubProgressMonitor. The main benefits of SubMonitor over
@@ -357,6 +362,16 @@
private final int flags;
/**
+ * True iff beginTask has been called on the public interface yet.
+ */
+ private boolean beginTaskCalled;
+
+ /**
+ * True iff ticks have been allocated yet.
+ */
+ private boolean ticksAllocated;
+
+ /**
* May be passed as a flag to {@link #split}. Indicates that the calls
* to subTask on the child should be ignored. Without this flag,
* calling subTask on the child will result in a call to subTask
@@ -413,6 +428,8 @@
*/
private static final int ALL_INHERITED_FLAGS = SUPPRESS_SUBTASK | SUPPRESS_ISCANCELED;
+ private static final Set<String> knownBuggyMethods = new HashSet<>();
+
/**
* Creates a new SubMonitor that will report its progress via
* the given RootInfo.
@@ -426,6 +443,7 @@
totalParent = (totalWork > 0) ? totalWork : 0;
this.totalForChildren = availableToChildren;
this.flags = flags;
+ ticksAllocated = availableToChildren > 0;
}
/**
@@ -492,8 +510,9 @@
// Optimization: if the given monitor already a SubMonitor, no conversion is necessary
if (monitor instanceof SubMonitor) {
- monitor.beginTask(taskName, work);
- return (SubMonitor) monitor;
+ SubMonitor subMonitor = (SubMonitor) monitor;
+ subMonitor.beginTaskImpl(taskName, work);
+ return subMonitor;
}
monitor.beginTask(taskName, MINIMUM_RESOLUTION);
@@ -531,8 +550,19 @@
* @return the receiver
*/
public SubMonitor setWorkRemaining(int workRemaining) {
+ if (TracingOptions.debugProgressMonitors && ticksAllocated && usedForChildren >= totalForChildren && workRemaining > 0) {
+ logProblem("Attempted to allocate ticks on a SubMonitor which had no space available. " //$NON-NLS-1$
+ + "This may indicate that a SubMonitor was reused inappropriately (which is a bug) " //$NON-NLS-1$
+ + "or may indicate that the caller was implementing infinite progress and overflowed " //$NON-NLS-1$
+ + "(which may not be a bug but may require selecting a higher ratio)"); //$NON-NLS-1$
+ }
+
// Ensure we don't try to allocate negative ticks
- workRemaining = Math.max(0, workRemaining);
+ if (workRemaining > 0) {
+ ticksAllocated = true;
+ } else {
+ workRemaining = 0;
+ }
// Ensure we don't cause division by zero
if (totalForChildren > 0 && totalParent > usedForParent) {
@@ -556,14 +586,21 @@
* @return ticks the number of ticks to be consumed from parent
*/
private int consume(double ticks) {
+ if (TracingOptions.debugProgressMonitors && !ticksAllocated && ticks > 0) {
+ logProblem("You must allocate ticks using beginTask or setWorkRemaining before trying to consume them"); //$NON-NLS-1$
+ }
+
if (totalParent == 0 || totalForChildren == 0) // this monitor has no available work to report
return 0;
usedForChildren += ticks;
- if (usedForChildren > totalForChildren)
+ if (usedForChildren > totalForChildren) {
usedForChildren = totalForChildren;
- else if (usedForChildren < 0.0)
+ if (TracingOptions.debugProgressMonitors) {
+ logProblem("This progress monitor consumed more ticks than were allocated for it."); //$NON-NLS-1$
+ }
+ } else if (usedForChildren < 0.0)
usedForChildren = 0.0;
int parentPosition = (int) (totalParent * usedForChildren / totalForChildren);
@@ -603,9 +640,17 @@
*/
@Override
public void beginTask(String name, int totalWork) {
+ if (TracingOptions.debugProgressMonitors && beginTaskCalled) {
+ logProblem("beginTask was called on this instance more than once"); //$NON-NLS-1$
+ }
+ beginTaskImpl(name, totalWork);
+ }
+
+ private void beginTaskImpl(String name, int totalWork) {
if ((flags & SUPPRESS_BEGINTASK) == 0 && name != null)
root.setTaskName(name);
setWorkRemaining(totalWork);
+ beginTaskCalled = true;
}
@Override
@@ -638,6 +683,10 @@
@Override
public void worked(int work) {
+ if (TracingOptions.debugProgressMonitors && work == 0) {
+ logProblem("Attempted to report 0 ticks of work"); //$NON-NLS-1$
+ }
+
internalWorked(work);
}
@@ -726,6 +775,10 @@
* @return new sub progress monitor that may be used in place of a new SubMonitor
*/
public SubMonitor newChild(int totalWork, int suppressFlags) {
+ if (TracingOptions.debugProgressMonitors && totalWork == 0) {
+ logProblem("Attempted to create a child without providing it with any ticks"); //$NON-NLS-1$
+ }
+
double totalWorkDouble = (totalWork > 0) ? totalWork : 0.0d;
totalWorkDouble = Math.min(totalWorkDouble, totalForChildren - usedForChildren);
cleanupActiveChild();
@@ -748,7 +801,7 @@
// is no method on the child that would delegate to beginTask on the parent.
childFlags |= (suppressFlags & ALL_PUBLIC_FLAGS);
- SubMonitor result = new SubMonitor(root, consume(totalWorkDouble), (int) totalWorkDouble, childFlags);
+ SubMonitor result = new SubMonitor(root, consume(totalWorkDouble), 0, childFlags);
lastSubMonitor = result;
return result;
}
@@ -944,4 +997,30 @@
return false;
return o1.equals(o2);
}
+
+ private static String getCallerName() {
+ StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace();
+
+ String ourClassName = SubMonitor.class.getCanonicalName();
+ for (int idx = 1; idx < stackTrace.length; idx++) {
+ String className = stackTrace[idx].getClassName();
+ if (className.equals(ourClassName)) {
+ continue;
+ }
+
+ return stackTrace[idx].toString();
+ }
+
+ return "Unknown"; //$NON-NLS-1$
+ }
+
+ private static void logProblem(String message) {
+ String caller = getCallerName();
+ synchronized (knownBuggyMethods) {
+ if (!knownBuggyMethods.add(caller)) {
+ return;
+ }
+ }
+ RuntimeLog.log(new Status(IStatus.WARNING, "org.eclipse.core.runtime", message, new Throwable())); //$NON-NLS-1$
+ }
}
