Bug 458347 - [UI monitoring] freeze warnings with no stacktraces

The change fixed a loss of stack samples when the monitoring thread
starved for CPU and added more detailed logging when no stack samples
were collected.

Change-Id: I6bf379d8275087a7898b0486cc69235ca2450b3e
Signed-off-by: Sergey Prigogin <eclipse.sprigogin@gmail.com>

8 files changed, 170 insertions, 133 deletions

diff --git a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/DefaultUiFreezeEventLogger.java b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/DefaultUiFreezeEventLogger.java
index 9349e4fac4e..1cdb3958b09 100644
--- a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/DefaultUiFreezeEventLogger.java
+++ b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/DefaultUiFreezeEventLogger.java
@@ -53,19 +53,29 @@ public class DefaultUiFreezeEventLogger implements IUiFreezeEventLogger {
 		long lastTimestamp = event.getStartTimestamp();
 		String startTime = dateFormat.format(new Date(lastTimestamp));
 
-		String pattern = event.isStillRunning()
+		String template = event.isStillRunning()
 				? Messages.DefaultUiFreezeEventLogger_ui_freeze_ongoing_header_2
 				: Messages.DefaultUiFreezeEventLogger_ui_freeze_finished_header_2;
 		long duration = event.getTotalDuration();
 		String format = duration >= 100000 ? "%.0f" : duration >= 10 ? "%.2g" : "%.1g"; //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$
-		String header = NLS.bind(pattern, String.format(format, duration / 1000.0), startTime);
+		String header = NLS.bind(template, String.format(format, duration / 1000.0), startTime);
+
+		StackSample[] stackTraceSamples = event.getStackTraceSamples();
+		if (stackTraceSamples.length == 0 && (event.isStarvedAwake() || event.isStarvedAsleep())) {
+			String note =
+					(event.isStarvedAwake() || event.isStarvedAsleep()) ?
+							Messages.DefaultUiFreezeEventLogger_starved_awake_and_asleep :
+					event.isStarvedAwake() ?
+							Messages.DefaultUiFreezeEventLogger_starved_awake :
+							Messages.DefaultUiFreezeEventLogger_starved_asleep;
+			header += note;
+		}
 
 		int severity = duration >= longEventErrorThresholdMillis ?
 				IStatus.ERROR : IStatus.WARNING;
 		MultiStatus loggedEvent =
 				new SeverityMultiStatus(severity, PreferenceConstants.PLUGIN_ID, header, null);
 
-		StackSample[] stackTraceSamples = event.getStackTraceSamples();
 		for (StackSample sample : stackTraceSamples) {
 			double deltaInSeconds = (sample.getTimestamp() - lastTimestamp) / 1000.0;
 			ThreadInfo[] threads = sample.getStackTraces();
diff --git a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThread.java b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThread.java
index 5eeaafee020..4c9537628ad 100644
--- a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThread.java
+++ b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThread.java
@@ -1,5 +1,5 @@
 /*******************************************************************************
- * Copyright (C) 2014, Google Inc and others.
+ * Copyright (C) 2014, 2015 Google Inc and others.
  * All rights reserved. This program and the accompanying materials
  * are made available under the terms of the Eclipse Public License v1.0
  * which accompanies this distribution, and is available at
@@ -246,47 +246,6 @@ public class EventLoopMonitorThread extends Thread {
 	}
 
 	/**
-	 * Tracks and reports potential deadlocks.
-	 */
-	private class DeadlockTracker {
-		private boolean haveAlreadyLoggedPossibleDeadlock;
-
-		// The last time a state transition between events or sleep/wake was seen. May be set to
-		// zero to indicate that deadlocks should not be tracked.
-		private long lastActive;
-
-		/**
-		 * Logs a possible deadlock to the remote log. {@code lastActive} is zero if the interval is
-		 * for a sleep, in which case we don't log a deadlock.
-		 *
-		 * @param currTime the current time
-		 * @param stackSamples stack trace samples for the currently stalled event
-		 * @param numSamples the number of valid stack trace samples in the stackSamples array
-		 */
-		public void logPossibleDeadlock(long currTime, StackSample[] stackSamples, int numSamples) {
-			long totalDuration = currTime - lastActive;
-
-			if (!haveAlreadyLoggedPossibleDeadlock && lastActive > 0 &&
-					totalDuration > deadlockThreshold &&
-					uiThreadFilter.shouldLogEvent(stackSamples, numSamples, uiThreadId)) {
-				stackSamples = Arrays.copyOf(stackSamples, numSamples);
-				logEvent(new UiFreezeEvent(lastActive, totalDuration,
-						Arrays.copyOf(stackSamples, numSamples), true));
-				haveAlreadyLoggedPossibleDeadlock = true;
-				Arrays.fill(stackSamples, null);
-			}
-		}
-
-		/**
-		 * Resets the deadlock tracker's state.
-		 */
-		public void reset(long lastActive) {
-			this.lastActive = lastActive;
-			haveAlreadyLoggedPossibleDeadlock = false;
-		}
-	}
-
-	/**
 	 * Circular buffer recording SWT events. Used for tracing.
 	 */
 	private static class EventHistory {
@@ -377,7 +336,7 @@ public class EventLoopMonitorThread extends Thread {
 	// Accessed by both the UI and monitoring threads.
 	private final int longEventWarningThreshold;
 	private final AtomicBoolean cancelled = new AtomicBoolean(false);
-	private final AtomicReference<LongEventInfo> publishEvent =
+	private final AtomicReference<LongEventInfo> eventToPublish =
 			new AtomicReference<LongEventInfo>(null);
 
 	// Accessed only by the monitoring thread.
@@ -464,10 +423,10 @@ public class EventLoopMonitorThread extends Thread {
 		 * state and possibly publish a long delay message. Updating eventStartOrResumeTime causes
 		 * the polling thread to reset its stack traces, so it should always be changed *after*
 		 * the event is published. The indeterminacy of threading may cause the polling thread to
-		 * see both changes or only the (first) publishEvent change, but the only difference is
-		 * a small window where if an additional stack trace was scheduled to be sampled, a bogus
-		 * stack trace sample will be appended to the end of the samples. Analysis code needs to be
-		 * aware that the last sample may not be relevant to the issue which caused the freeze.
+		 * see both changes or only the (first) eventToPublish change, but the only difference is
+		 * a small window where, if an additional stack trace was scheduled to be sampled, a bogus
+		 * stack trace sample will be appended to the end of the samples. This bogus sample is
+		 * removed before logging.
 		 */
 		long currTime = getTimestamp();
 		if (attemptToLogLongDelay) {
@@ -476,7 +435,7 @@ public class EventLoopMonitorThread extends Thread {
 				int duration = (int) (currTime - startTime);
 				if (duration >= longEventWarningThreshold) {
 					LongEventInfo info = new LongEventInfo(startTime, duration);
-					publishEvent.set(info);
+					eventToPublish.set(info);
 					wakeUp();
 				}
 			}
@@ -511,7 +470,7 @@ public class EventLoopMonitorThread extends Thread {
 		 */
 		boolean resetStalledEventState = true;
 
-		DeadlockTracker deadlockTracker = new DeadlockTracker();
+		long deadlockTimerStart = 0;
 
 		final long pollingNyquistDelay = sampleInterval / 2;
 		long pollingDelay = 0; // Immediately updated by resetStalledEventState.
@@ -521,6 +480,9 @@ public class EventLoopMonitorThread extends Thread {
 		StackSample[] stackSamples = new StackSample[maxStackSamples];
 		int numSamples = 0;
 
+		boolean starvedAwake = false;
+		boolean starvedAsleep = false;
+
 		boolean dumpAllThreads = false;
 
 		// Register for events
@@ -537,12 +499,14 @@ public class EventLoopMonitorThread extends Thread {
 			long sleepFor;
 			if (resetStalledEventState) {
 				long eventTime = eventStartOrResumeTime;
-				deadlockTracker.reset(eventTime);
+				deadlockTimerStart = eventTime;
 				if (eventTime == 0) {
 					eventTime = currTime;
 				}
 				grabStackSampleAt = eventTime + sampleInterval;
 				numSamples = 0;
+				starvedAwake = false;
+				starvedAsleep = false;
 				if (dumpAllThreads) {
 					// Stop capturing stacks of all threads.
 					dumpAllThreads = false;
@@ -559,6 +523,11 @@ public class EventLoopMonitorThread extends Thread {
 				sleepFor = Math.min(pollingNyquistDelay, Math.max(1, grabStackSampleAt - currTime));
 			}
 
+			// Allow the discarded stack samples to be garbage collected.
+			for (int i = numSamples; i < stackSamples.length && stackSamples[i] != null; i++) {
+				stackSamples[i] = null;
+			}
+
 			// This is the top of the polling loop.
 			long sleepAt = getTimestamp();
 
@@ -569,13 +538,19 @@ public class EventLoopMonitorThread extends Thread {
 			 * useful information, so don't log them.
 			 */
 			long awakeDuration = currTime - sleepAt;
-			boolean starvedAwake = awakeDuration > (sleepFor + longEventWarningThreshold / 2);
+			boolean starvedAwakeCurrentCycle = awakeDuration > (sleepFor + longEventWarningThreshold / 2);
+			if (starvedAwakeCurrentCycle) {
+				starvedAwake = true;
+			}
 			sleepForMillis(sleepFor);
 			currTime = getTimestamp();
 			long currEventStartOrResumeTime = eventStartOrResumeTime;
 			long sleepDuration = currTime - sleepAt;
-			boolean starvedSleep = sleepDuration > (sleepFor + longEventWarningThreshold / 2);
-			boolean starved = starvedSleep || starvedAwake;
+			boolean starvedAsleepCurrentCycle = sleepDuration > (sleepFor + longEventWarningThreshold / 2);
+			if (starvedAsleepCurrentCycle) {
+				starvedAsleep = true;
+			}
+			boolean starved = starvedAsleepCurrentCycle || starvedAwakeCurrentCycle;
 
 			/*
 			 * If after sleeping we see that a new event has been dispatched, mark that we should
@@ -585,13 +560,13 @@ public class EventLoopMonitorThread extends Thread {
 			if (lastEventStartOrResumeTime != currEventStartOrResumeTime || starved) {
 				resetStalledEventState = true;
 				if (tracer != null && starved) {
-					if (starvedAwake) {
+					if (starvedAwakeCurrentCycle) {
 						tracer.trace(String.format(
 								"Starvation detected! Polling loop took a significant amount of threshold: %dms", //$NON-NLS-1$
 								awakeDuration));
 					}
 
-					if (starvedSleep) {
+					if (starvedAsleepCurrentCycle) {
 						tracer.trace(String.format(
 								"Starvation detected! Expected to sleep for %dms but actually slept for %dms", //$NON-NLS-1$
 								sleepFor, sleepDuration));
@@ -606,10 +581,24 @@ public class EventLoopMonitorThread extends Thread {
 					}
 				}
 
-				deadlockTracker.logPossibleDeadlock(currTime, stackSamples, numSamples);
+				if (deadlockTimerStart != 0) {
+					long totalDuration = currTime - deadlockTimerStart;
+					if (totalDuration >= deadlockThreshold) {
+						if (numSamples > maxLoggedStackSamples) {
+							decimate(stackSamples, numSamples, maxLoggedStackSamples);
+							numSamples = maxLoggedStackSamples;
+						}
+						if (uiThreadFilter.shouldLogEvent(stackSamples, numSamples, uiThreadId)) {
+							logEvent(new UiFreezeEvent(deadlockTimerStart, totalDuration,
+									Arrays.copyOf(stackSamples, numSamples),
+									true, starvedAwake, starvedAsleep));
+							deadlockTimerStart = 0; // Don't log potential deadlock more than once.
+						}
+					}
+				}
 
 				// Collect additional stack traces if enough time has elapsed.
-				if (maxStackSamples > 0 && currTime > grabStackSampleAt) {
+				if (maxStackSamples > 0 && currTime >= grabStackSampleAt) {
 					if (numSamples == maxStackSamples) {
 						numSamples = maxStackSamples / 2;
 						decimate(stackSamples, maxStackSamples, numSamples);
@@ -626,30 +615,32 @@ public class EventLoopMonitorThread extends Thread {
 
 			// If a stalled event has finished, publish it and mark that the information should
 			// be reset.
-			LongEventInfo eventSnapshot = publishEvent.getAndSet(null);
-			if (starved || eventSnapshot != null) {
-				if (eventSnapshot != null) {
+			LongEventInfo eventSnapshot = eventToPublish.getAndSet(null);
+			if (eventSnapshot != null) {
+				long eventEnd = eventSnapshot.start + eventSnapshot.duration;
+				// Remove stack samples collected after the end of the event.
+				while (numSamples > 0 && eventEnd <= stackSamples[numSamples - 1].getTimestamp()) {
+					--numSamples;
+				}
+				if (numSamples > maxLoggedStackSamples) {
 					// Remove the last stack sample if it is too close to the end of the event.
-					if (numSamples > maxLoggedStackSamples) {
-						long eventEnd = eventSnapshot.start + eventSnapshot.duration;
-						if (eventEnd - stackSamples[numSamples - 1].getTimestamp() < sampleInterval) {
-							--numSamples;
-						}
+					if (eventEnd - stackSamples[numSamples - 1].getTimestamp() < sampleInterval) {
+						--numSamples;
 					}
+				}
 
-					if (numSamples > maxLoggedStackSamples) {
-						decimate(stackSamples, numSamples, maxLoggedStackSamples);
-						numSamples = maxLoggedStackSamples;
-					}
+				if (numSamples > maxLoggedStackSamples) {
+					decimate(stackSamples, numSamples, maxLoggedStackSamples);
+					numSamples = maxLoggedStackSamples;
+				}
 
-					if (uiThreadFilter.shouldLogEvent(stackSamples, numSamples, uiThreadId)) {
-						logEvent(new UiFreezeEvent(eventSnapshot.start, eventSnapshot.duration,
-								Arrays.copyOf(stackSamples, numSamples), false));
-					}
+				if (uiThreadFilter.shouldLogEvent(stackSamples, numSamples, uiThreadId)) {
+					logEvent(new UiFreezeEvent(eventSnapshot.start, eventSnapshot.duration,
+							Arrays.copyOf(stackSamples, numSamples),
+							false, starvedAwake, starvedAsleep));
 				}
 
 				resetStalledEventState = true;
-				Arrays.fill(stackSamples, null); // Allow the stack samples to be garbage collected.
 			}
 
 			lastEventStartOrResumeTime = currEventStartOrResumeTime;
diff --git a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.java b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.java
index 53eddf687c7..b46e138f266 100644
--- a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.java
+++ b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.java
@@ -13,10 +13,13 @@ package org.eclipse.ui.internal.monitoring;
 
 import org.eclipse.osgi.util.NLS;
 
-public final class Messages extends NLS {
+final class Messages extends NLS {
 	public static String DefaultUiFreezeEventLogger_holding_1;
 	public static String DefaultUiFreezeEventLogger_sample_header_2;
 	public static String DefaultUiFreezeEventLogger_stack_trace_header;
+	public static String DefaultUiFreezeEventLogger_starved_awake_and_asleep;
+	public static String DefaultUiFreezeEventLogger_starved_awake;
+	public static String DefaultUiFreezeEventLogger_starved_asleep;
 	public static String DefaultUiFreezeEventLogger_thread_details;
 	public static String DefaultUiFreezeEventLogger_thread_header_2;
 	public static String DefaultUiFreezeEventLogger_ui_freeze_finished_header_2;
diff --git a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.properties b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.properties
index 515083dfaf5..8e3a9eff82f 100644
--- a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.properties
+++ b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/internal/monitoring/Messages.properties
@@ -12,6 +12,9 @@
 DefaultUiFreezeEventLogger_holding_1=\nHolding: {0}
 DefaultUiFreezeEventLogger_sample_header_2=Sample at {0} (+{1}s)
 DefaultUiFreezeEventLogger_stack_trace_header=Stack Trace
+DefaultUiFreezeEventLogger_starved_awake_and_asleep=\n(no stack samples were collected because the monitoring thread starved for CPU)
+DefaultUiFreezeEventLogger_starved_awake=\n(no stack samples were collected because the monitoring thread starved for CPU while awake)
+DefaultUiFreezeEventLogger_starved_asleep=\n(no stack samples were collected because the monitoring thread starved for CPU while asleep)
 DefaultUiFreezeEventLogger_thread_details= tid={0} ({1})
 DefaultUiFreezeEventLogger_thread_header_2=Thread ''{0}'' {1}
 DefaultUiFreezeEventLogger_ui_freeze_finished_header_2=UI freeze of {0}s at {1}
diff --git a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/StackSample.java b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/StackSample.java
index eedc16020d3..24b0cd75334 100644
--- a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/StackSample.java
+++ b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/StackSample.java
@@ -1,5 +1,5 @@
 /*******************************************************************************
- * Copyright (C) 2014, Google Inc and others.
+ * Copyright (C) 2014, 2015 Google Inc and others.
  * All rights reserved. This program and the accompanying materials
  * are made available under the terms of the Eclipse Public License v1.0
  * which accompanies this distribution, and is available at
@@ -40,7 +40,7 @@ public class StackSample {
 	 * Returns the time stamp in milliseconds since January 1, 1970 UTC for this
 	 * {@code StackSample}.
 	 */
-	public long getTimestamp() {
+	public final long getTimestamp() {
 		return timestamp;
 	}
 
@@ -48,7 +48,7 @@ public class StackSample {
 	 * Returns an array of {@code ThreadInfo}s for this {@code StackSample}. The display thread is
 	 * always the first in the array.
 	 */
-	public ThreadInfo[] getStackTraces() {
+	public final ThreadInfo[] getStackTraces() {
 		return traces;
 	}
 
diff --git a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/UiFreezeEvent.java b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/UiFreezeEvent.java
index 0c6ab15d4fe..2d8c97b3182 100644
--- a/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/UiFreezeEvent.java
+++ b/bundles/org.eclipse.ui.monitoring/src/org/eclipse/ui/monitoring/UiFreezeEvent.java
@@ -22,6 +22,8 @@ public class UiFreezeEvent {
 	private final long totalDuration;
 	private final StackSample[] stackTraceSamples;
 	private final boolean isStillRunning;
+	private final boolean isStarvedAwake;
+	private final boolean isStarvedAsleep;
 
 	/**
 	 * Creates a UiFreezeEvent.
@@ -34,31 +36,33 @@ public class UiFreezeEvent {
 	 *     was created. If {@code true}, this UiFreezeEvent may indicate a deadlock.
 	 */
 	public UiFreezeEvent(long startTime, long duration, StackSample[] samples,
-			boolean stillRunning) {
+			boolean stillRunning, boolean starvedAwake, boolean starvedAsleep) {
 		this.startTimestamp = startTime;
 		this.stackTraceSamples = samples;
 		this.totalDuration = duration;
 		this.isStillRunning = stillRunning;
+		this.isStarvedAwake = starvedAwake;
+		this.isStarvedAsleep = starvedAsleep;
 	}
 
 	/**
 	 * Returns the time when the UI thread froze, in milliseconds since January 1, 1970 UTC.
 	 */
-	public long getStartTimestamp() {
+	public final long getStartTimestamp() {
 		return startTimestamp;
 	}
 
 	/**
 	 * Returns the total amount of time in milliseconds that the UI thread remained frozen.
 	 */
-	public long getTotalDuration() {
+	public final long getTotalDuration() {
 		return totalDuration;
 	}
 
 	/**
 	 * Returns the stack trace samples obtained during the event.
 	 */
-	public StackSample[] getStackTraceSamples() {
+	public final StackSample[] getStackTraceSamples() {
 		return stackTraceSamples;
 	}
 
@@ -66,10 +70,24 @@ public class UiFreezeEvent {
 	 * Returns {@code true} if this event was still ongoing at the time the event was logged,
 	 * which can happen for deadlocks.
 	 */
-	public boolean isStillRunning() {
+	public final boolean isStillRunning() {
 		return isStillRunning;
 	}
 
+	/**
+	 * Returns {@code true} if the monitoring thread starved for CPU while awake.
+	 */
+	public final boolean isStarvedAwake() {
+		return isStarvedAwake;
+	}
+
+	/**
+	 * Returns {@code true} if the monitoring thread starved for CPU while asleep.
+	 */
+	public final boolean isStarvedAsleep() {
+		return isStarvedAsleep;
+	}
+
 	/** For debugging only. */
 	@Override
 	public String toString() {
@@ -83,6 +101,12 @@ public class UiFreezeEvent {
 		}
 		buf.append(totalDuration);
 		buf.append("ms"); //$NON-NLS-1$
+		if (isStarvedAwake || isStarvedAsleep) {
+			String when =
+					isStarvedAwake && isStarvedAsleep ?	"awake and asleep" : //$NON-NLS-1$
+					isStarvedAwake ? "awake" : "asleep"; //$NON-NLS-1$ //$NON-NLS-2$
+			buf.append(", monitoring thread starved for CPU while " + when); //$NON-NLS-1$
+		}
 		if (stackTraceSamples.length != 0) {
 			buf.append("\nStack trace samples:"); //$NON-NLS-1$
 			for (StackSample stackTraceSample : stackTraceSamples) {
diff --git a/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/DefaultLoggerTests.java b/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/DefaultLoggerTests.java
index 5110289d050..dc5ca37f6fb 100644
--- a/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/DefaultLoggerTests.java
+++ b/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/DefaultLoggerTests.java
@@ -1,5 +1,5 @@
 /*******************************************************************************
- * Copyright (C) 2014, Google Inc and others.
+ * Copyright (C) 2014, 2015 Google Inc and others.
  * All rights reserved. This program and the accompanying materials
  * are made available under the terms of the Eclipse Public License v1.0
  * which accompanies this distribution, and is available at
@@ -64,7 +64,7 @@ public class DefaultLoggerTests {
 		thread = jvmThreadManager.getThreadInfo(Thread.currentThread().getId(), Integer.MAX_VALUE);
 
 		StackSample[] samples = { new StackSample(TIME, new ThreadInfo[] { thread }) };
-		UiFreezeEvent event = new UiFreezeEvent(TIME, DURATION, samples, false);
+		UiFreezeEvent event = new UiFreezeEvent(TIME, DURATION, samples, false, false, false);
 		return event;
 	}
 
diff --git a/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThreadTests.java b/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThreadTests.java
index c410fa872e3..23f1da0e2be 100644
--- a/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThreadTests.java
+++ b/tests/org.eclipse.ui.monitoring.tests/src/org/eclipse/ui/internal/monitoring/EventLoopMonitorThreadTests.java
@@ -1,5 +1,5 @@
 /*******************************************************************************
- * Copyright (C) 2014, Google Inc and others.
+ * Copyright (C) 2014, 2015 Google Inc and others.
  * All rights reserved. This program and the accompanying materials
  * are made available under the terms of the Eclipse Public License v1.0
  * which accompanies this distribution, and is available at
@@ -24,6 +24,7 @@ import org.eclipse.swt.SWT;
 import org.eclipse.swt.widgets.Event;
 import org.eclipse.ui.internal.monitoring.EventLoopMonitorThread.Parameters;
 import org.eclipse.ui.monitoring.PreferenceConstants;
+import org.eclipse.ui.monitoring.StackSample;
 import org.eclipse.ui.monitoring.UiFreezeEvent;
 import org.junit.After;
 import org.junit.Before;
@@ -75,9 +76,9 @@ public class EventLoopMonitorThreadTests {
 			+ ",org.eclipse.core.internal.jobs.Worker.run";
 	/* NOTE: All time-related values in this class are in milliseconds. */
 	private static final long MAX_TIMEOUT_MS = 1 * 1000; // 1 second
-	private static final int THRESHOLD_MS = 100;
-	private static final int SAMPLE_INTERVAL_MS = THRESHOLD_MS * 2 / 3;
-	public static final int FORCE_DEADLOCK_LOG_TIME_MILLIS = 10 * 60 * 1000; // == 10 minutes
+	private static final int FREEZE_THRESHOLD_MS = 100;
+	private static final int SAMPLE_INTERVAL_MS = FREEZE_THRESHOLD_MS * 2 / 3;
+	public static final int FORCE_DEADLOCK_LOG_TIME_MS = 10 * 60 * 1000; // == 10 minutes
 	private static final int MIN_STACK_TRACES = 5;
 	private static final int MAX_STACK_TRACES = 11;
 	private static final int MIN_MAX_STACK_TRACE_DELTA = MAX_STACK_TRACES - MIN_STACK_TRACES;
@@ -121,7 +122,7 @@ public class EventLoopMonitorThreadTests {
 		args.longEventWarningThreshold = threshold - 1;
 		args.longEventErrorThreshold = threshold - 1;
 		args.maxStackSamples = MIN_STACK_TRACES;
-		args.deadlockThreshold = FORCE_DEADLOCK_LOG_TIME_MILLIS;
+		args.deadlockThreshold = FORCE_DEADLOCK_LOG_TIME_MS;
 		args.uiThreadFilter = UI_THREAD_FILTER;
 		args.noninterestingThreadFilter = NONINTERESTING_THREAD_FILTER;
 
@@ -182,7 +183,7 @@ public class EventLoopMonitorThreadTests {
 	public void testStackDecimation() throws Exception {
 		UiFreezeEvent event;
 
-		monitoringThread = createTestThread(THRESHOLD_MS * 2);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS * 2);
 		monitoringThread.start();
 		sendEvent(SWT.PreEvent);
 
@@ -243,7 +244,7 @@ public class EventLoopMonitorThreadTests {
 	public void testPublishPossibleDeadlock() throws Exception {
 		monitoringThread = createTestThread(SAMPLE_INTERVAL_MS * 4);
 		monitoringThread.start();
-		long maxDeadlock = FORCE_DEADLOCK_LOG_TIME_MILLIS;
+		long maxDeadlock = FORCE_DEADLOCK_LOG_TIME_MS;
 		sendEvent(SWT.PreEvent);
 
 		synchronized (sleepLock) {
@@ -280,7 +281,7 @@ public class EventLoopMonitorThreadTests {
 
 	@Test
 	public void testPublishNoDeadlocksWhenSleeping() throws Exception {
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 		sendEvent(SWT.PreEvent);
 
@@ -294,7 +295,7 @@ public class EventLoopMonitorThreadTests {
 			sendEvent(SWT.PreExternalEventDispatch);
 
 			// Wait for the end of the event to propagate to the deadlock tracker.
-			runForTime(FORCE_DEADLOCK_LOG_TIME_MILLIS * 2);
+			runForTime(FORCE_DEADLOCK_LOG_TIME_MS * 2);
 			runForCycles(3);
 		}
 
@@ -304,7 +305,7 @@ public class EventLoopMonitorThreadTests {
 	@Test
 	public void testNoLoggingForSleep() throws Exception {
 		int eventFactor = 5;
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 
 		// One level deep
@@ -322,17 +323,17 @@ public class EventLoopMonitorThreadTests {
 	public void testEventLogging() throws Exception {
 		int eventFactor = 5;
 		long eventStartTime = 0;
-		long eventStallDuration = 0;
+		long freezeDuration = 0;
 
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 
 		// One level deep
 		synchronized (sleepLock) {
 			sendEvent(SWT.PreEvent); // level 1
 			eventStartTime = timestamp;
-			runForTime(eventFactor * THRESHOLD_MS);
-			eventStallDuration = timestamp - eventStartTime;
+			runForTime(eventFactor * FREEZE_THRESHOLD_MS);
+			freezeDuration = timestamp - eventStartTime;
 			sendEvent(SWT.PostEvent);
 			runForCycles(3);
 		}
@@ -341,20 +342,25 @@ public class EventLoopMonitorThreadTests {
 		UiFreezeEvent event = loggedEvents.get(0);
 		assertEquals("A long running event log has an incorrect start time", eventStartTime,
 				event.getStartTimestamp());
-		assertEquals("A long running event's duration was incorrect", eventStallDuration,
+		assertEquals("A long running event's duration was incorrect", freezeDuration,
 				event.getTotalDuration());
-		assertEquals("A long running event didn't capture a good range of stack traces",
-				expectedStackCount(eventStallDuration), event.getStackTraceSamples().length);
+		StringBuilder buf = new StringBuilder(" Timeline: ");
+		for (StackSample sample : event.getStackTraceSamples()) {
+			buf.append(sample.getTimestamp());
+			buf.append(' ');
+		}
+		assertEquals("A long running event didn't capture a good range of stack traces" + buf.toString(),
+				expectedStackCount(freezeDuration), event.getStackTraceSamples().length);
 	}
 
 	@Test
 	public void testNestedEventLogging() throws Exception {
 		int eventFactor = 6;
 
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 		long eventStartTime = 0;
-		long eventStallDuration = 0;
+		long freezeDuration = 0;
 
 		// Two levels deep
 		synchronized (sleepLock) {
@@ -362,8 +368,8 @@ public class EventLoopMonitorThreadTests {
 			runForCycles(1);
 			sendEvent(SWT.PreEvent); // level 2
 			eventStartTime = timestamp;
-			runForTime(eventFactor * THRESHOLD_MS);
-			eventStallDuration = timestamp - eventStartTime;
+			runForTime(eventFactor * FREEZE_THRESHOLD_MS);
+			freezeDuration = timestamp - eventStartTime;
 			sendEvent(SWT.PostEvent);
 			sendEvent(SWT.PostEvent);
 			runForCycles(3);
@@ -373,20 +379,20 @@ public class EventLoopMonitorThreadTests {
 		UiFreezeEvent event = loggedEvents.get(0);
 		assertEquals("A long running event log has an incorrect start time", eventStartTime,
 				event.getStartTimestamp());
-		assertEquals("A long running event's duration was incorrect", eventStallDuration,
+		assertEquals("A long running event's duration was incorrect", freezeDuration,
 				event.getTotalDuration());
 		assertEquals("A long running event didn't capture a good range of stack traces",
-				expectedStackCount(eventStallDuration), event.getStackTraceSamples().length);
+				expectedStackCount(freezeDuration), event.getStackTraceSamples().length);
 	}
 
 	@Test
 	public void testDoublyNestedEventLogging() throws Exception {
 		int eventFactor = 7;
 
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 		long eventStartTime = 0;
-		long eventStallDuration = 0;
+		long freezeDuration = 0;
 
 		// Three levels deep
 		synchronized (sleepLock) {
@@ -396,8 +402,8 @@ public class EventLoopMonitorThreadTests {
 			runForCycles(1);
 			sendEvent(SWT.PreEvent); // level 3
 			eventStartTime = timestamp;
-			runForTime(eventFactor * THRESHOLD_MS);
-			eventStallDuration = timestamp - eventStartTime;
+			runForTime(eventFactor * FREEZE_THRESHOLD_MS);
+			freezeDuration = timestamp - eventStartTime;
 			sendEvent(SWT.PostEvent);
 			sendEvent(SWT.PostEvent);
 			sendEvent(SWT.PostEvent);
@@ -408,20 +414,20 @@ public class EventLoopMonitorThreadTests {
 		UiFreezeEvent event = loggedEvents.get(0);
 		assertEquals("A long running event log has an incorrect start time", eventStartTime,
 				event.getStartTimestamp());
-		assertEquals("A long running event's duration was incorrect", eventStallDuration,
+		assertEquals("A long running event's duration was incorrect", freezeDuration,
 				event.getTotalDuration());
 		assertEquals("A long running event didn't capture a good range of stack traces",
-				expectedStackCount(eventStallDuration), event.getStackTraceSamples().length);
+				expectedStackCount(freezeDuration), event.getStackTraceSamples().length);
 	}
 
 	@Test
 	public void testSeeLongEventInContinuationAfterNestedCall() throws Exception {
 		int eventFactor = 4;
 
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 		long eventResumeTime = 0;
-		long eventStallDuration = 0;
+		long freezeDuration = 0;
 
 		// Exceed the threshold after the thread is started in the middle of an event, then end the
 		// event and validate that no long event was logged.
@@ -435,9 +441,9 @@ public class EventLoopMonitorThreadTests {
 			}
 
 			eventResumeTime = timestamp;
-			runForTime(eventFactor * THRESHOLD_MS);
+			runForTime(eventFactor * FREEZE_THRESHOLD_MS);
 			sendEvent(SWT.PostEvent);
-			eventStallDuration = timestamp - eventResumeTime;
+			freezeDuration = timestamp - eventResumeTime;
 			runForCycles(3);
 		}
 
@@ -445,19 +451,19 @@ public class EventLoopMonitorThreadTests {
 		UiFreezeEvent event = loggedEvents.get(0);
 		assertEquals("A long running event didn't start from the nested return point",
 				eventResumeTime, event.getStartTimestamp());
-		assertEquals("A long running event's duration was incorrect", eventStallDuration,
+		assertEquals("A long running event's duration was incorrect", freezeDuration,
 				event.getTotalDuration());
 		assertEquals("A long running event didn't capture a good range of stack traces",
-				expectedStackCount(eventStallDuration), event.getStackTraceSamples().length);
+				expectedStackCount(freezeDuration), event.getStackTraceSamples().length);
 	}
 
 	@Test
 	public void testSeeLongEventInTheMiddleOfNestedCalls() throws Exception {
 		int eventFactor = 4;
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 		long eventResumeTime = 0;
-		long eventStallDuration = 0;
+		long freezeDuration = 0;
 
 		// Exceed the threshold after the thread is started in the middle of an event, then end
 		// the event and validate that no long event was logged.
@@ -472,8 +478,8 @@ public class EventLoopMonitorThreadTests {
 
 			// This is the nested event UI freeze
 			eventResumeTime = timestamp;
-			runForTime(eventFactor * THRESHOLD_MS);
-			eventStallDuration = timestamp - eventResumeTime;
+			runForTime(eventFactor * FREEZE_THRESHOLD_MS);
+			freezeDuration = timestamp - eventResumeTime;
 
 			// Before exiting the outer thread is invoking nested events that are responsive.
 			for (int i = 0; i < 3; i++) {
@@ -490,16 +496,16 @@ public class EventLoopMonitorThreadTests {
 		UiFreezeEvent event = loggedEvents.get(0);
 		assertEquals("A long running event didn't start from the nested return point",
 				eventResumeTime, event.getStartTimestamp());
-		assertEquals("A long running event's duration was incorrect", eventStallDuration,
+		assertEquals("A long running event's duration was incorrect", freezeDuration,
 				event.getTotalDuration());
 		assertEquals("A long running event didn't capture a good range of stack traces",
-				expectedStackCount(eventStallDuration), event.getStackTraceSamples().length);
+				expectedStackCount(freezeDuration), event.getStackTraceSamples().length);
 	}
 
 	@Test
 	public void testSeeSleepInTheMiddleOfNestedCalls() throws Exception {
 		int eventFactor = 4;
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 
 		// Exceed the threshold after the thread is started in the middle of an event, then end
@@ -540,13 +546,13 @@ public class EventLoopMonitorThreadTests {
 		long eventStartTime = 0;
 		long eventDuration = 0;
 
-		monitoringThread = createTestThread(THRESHOLD_MS);
+		monitoringThread = createTestThread(FREEZE_THRESHOLD_MS);
 		monitoringThread.start();
 
 		synchronized (sleepLock) {
 			sendEvent(SWT.PreEvent);
 			sendEvent(SWT.PreExternalEventDispatch);
-			runForTime(THRESHOLD_MS);
+			runForTime(FREEZE_THRESHOLD_MS);
 			sendEvent(SWT.PostExternalEventDispatch);
 			eventStartTime = timestamp;
 			runForCycles(3);
@@ -558,7 +564,7 @@ public class EventLoopMonitorThreadTests {
 		// Let a long time elapse between the last PostExternalEventDispatch and the next
 		// PreExternalEventDispatch.
 		synchronized (sleepLock) {
-			runForTime(THRESHOLD_MS * eventFactor);
+			runForTime(FREEZE_THRESHOLD_MS * eventFactor);
 			eventDuration = timestamp - eventStartTime;
 			sendEvent(SWT.PreExternalEventDispatch);
 			sendEvent(SWT.PostExternalEventDispatch);