diff options
author | Stefan Xenos | 2016-04-22 15:17:10 +0000 |
---|---|---|
committer | Stefan Xenos | 2016-04-22 19:42:19 +0000 |
commit | cbfe3daa3a92b858cc0def6d7c94ce127411142a (patch) | |
tree | feecc8a4e945dc8a1f7b5246b010abb03dd254b5 | |
parent | 52244550143ecf350f5af6686988fb56b1fb6627 (diff) | |
download | rt.equinox.bundles-cbfe3daa3a92b858cc0def6d7c94ce127411142a.tar.gz rt.equinox.bundles-cbfe3daa3a92b858cc0def6d7c94ce127411142a.tar.xz rt.equinox.bundles-cbfe3daa3a92b858cc0def6d7c94ce127411142a.zip |
Bug 482062 - Add diagnostic logging to SubMonitorI20160425-1300I20160425-0800I20160424-2245I20160424-2000
Change-Id: I8514964dc80a48a990e4d12bb4b0ff8b6dcefaed
Signed-off-by: Stefan Xenos <sxenos@gmail.com>
4 files changed, 116 insertions, 6 deletions
diff --git a/bundles/org.eclipse.equinox.common/.options b/bundles/org.eclipse.equinox.common/.options index 0f8426666..71347b055 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 355ba8adf..fb5cbde09 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.equinox.log.ExtendedLogService; 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 @@ import org.osgi.util.tracker.ServiceTracker; * 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 @@ public class Activator implements BundleActivator { 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 @@ public class Activator implements BundleActivator { 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 @@ public class Activator implements BundleActivator { 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 000000000..930ddd674 --- /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 0e8385800..6008727de 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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { 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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { */ 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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { totalParent = (totalWork > 0) ? totalWork : 0; this.totalForChildren = availableToChildren; this.flags = flags; + ticksAllocated = availableToChildren > 0; } /** @@ -492,8 +510,9 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { // 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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { * @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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { * @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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { */ @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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { @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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { * @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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { // 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 @@ public final class SubMonitor implements IProgressMonitorWithBlocking { 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$ + } } |