Bug 536943 - give the reader thread a chance to start reading

Added a wait in OutputStreamMonitor.getContents(), until stream reading
is done or until a timeout of default 10 seconds occurs. If the timeout
is reached before stream reading is done, a warning is logged.

The timeout can be configured by specifying VM property:

-Dorg.eclipse.debug.core.msMaxWaitTimeForStreamMonitorReading=5000

The VM property time unit is milliseconds.

The wait ensures that callers of OutputStreamMonitor.getContents()
actually see correct stream contents in cases such as accessing contents
before the reading has even started, which could cause bug 536943.

Change-Id: I7e4af3d06ef528030df5b263b3d664b853f12456
Signed-off-by: Andrey Loskutov <loskutov@gmx.de>
Signed-off-by: Simeon Andreev <simeon.danailov.andreev@gmail.com>
diff --git a/org.eclipse.debug.core/core/org/eclipse/debug/internal/core/OutputStreamMonitor.java b/org.eclipse.debug.core/core/org/eclipse/debug/internal/core/OutputStreamMonitor.java
index 330e661..3a1ae19 100644
--- a/org.eclipse.debug.core/core/org/eclipse/debug/internal/core/OutputStreamMonitor.java
+++ b/org.eclipse.debug.core/core/org/eclipse/debug/internal/core/OutputStreamMonitor.java
@@ -17,10 +17,13 @@
 import java.io.BufferedInputStream;
 import java.io.IOException;
 import java.io.InputStream;
+import java.util.concurrent.atomic.AtomicBoolean;
 
 import org.eclipse.core.runtime.ISafeRunnable;
+import org.eclipse.core.runtime.IStatus;
 import org.eclipse.core.runtime.ListenerList;
 import org.eclipse.core.runtime.SafeRunner;
+import org.eclipse.core.runtime.Status;
 import org.eclipse.debug.core.DebugPlugin;
 import org.eclipse.debug.core.IStreamListener;
 import org.eclipse.debug.core.model.IFlushableStreamMonitor;
@@ -33,6 +36,19 @@
  * and input stream.
  */
 public class OutputStreamMonitor implements IFlushableStreamMonitor {
+
+	/**
+	 * VM property which indicates maximum wait time (in milliseconds) for
+	 * reading to finish, when calling {@link #getContents()}.
+	 */
+	private static final String MAX_WAIT_TIME_FOR_STREAM_READING_PROPERTY = "org.eclipse.debug.core.msMaxWaitTimeForStreamMonitorReading"; //$NON-NLS-1$
+
+	/**
+	 * Wait max n milliseconds for the thread to finish reading when calling
+	 * {@link #getContents()}.
+	 */
+	private static final long MAX_WAIT_TIME_FOR_STREAM_READING = maxWaitTimeForStreamReading();
+
 	/**
 	 * The stream being monitored (connected system out or err).
 	 */
@@ -70,11 +86,19 @@
 	 */
 	private boolean fKilled= false;
 
-    private long lastSleep;
+	/**
+	 * Last time we've read something from the stream
+	 */
+	private long lastSleep;
 
 	private String fEncoding;
 
 	/**
+	 * Indicates whether the monitor is done reading from the stream.
+	 */
+	private final AtomicBoolean fReadingDone;
+
+	/**
 	 * Creates an output stream monitor on the
 	 * given stream (connected to system out or err).
 	 *
@@ -85,6 +109,7 @@
         fStream = new BufferedInputStream(stream, 8192);
         fEncoding = encoding;
 		fContents= new StringBuilder();
+		fReadingDone = new AtomicBoolean(false);
 	}
 
 	/* (non-Javadoc)
@@ -126,9 +151,22 @@
 	 */
 	@Override
 	public synchronized String getContents() {
+		boolean doneReading = waitForReadingToFinish(MAX_WAIT_TIME_FOR_STREAM_READING);
+		if (!doneReading) {
+			logWarning("OutputStreamMonitor::startMonitoring() was unable to start reading stream after " + MAX_WAIT_TIME_FOR_STREAM_READING + " ms."); //$NON-NLS-1$ //$NON-NLS-2$
+		}
 		return fContents.toString();
 	}
 
+	private void read() {
+		fReadingDone.set(false);
+		try {
+			readInternal();
+		} finally {
+			fReadingDone.set(true);
+		}
+	}
+
 	/**
 	 * Continually reads from the stream.
 	 * <p>
@@ -137,7 +175,7 @@
 	 * to implement <code>Runnable</code> without publicly
 	 * exposing a <code>run</code> method.
 	 */
-	private void read() {
+	private void readInternal() {
         lastSleep = System.currentTimeMillis();
         long currentTime = lastSleep;
 		byte[] bytes= new byte[BUFFER_SIZE];
@@ -244,6 +282,53 @@
 		return new ContentNotifier();
 	}
 
+	/**
+	 * Blocking call to make sure the stream reading thread is done (and so
+	 * {@link #readInternal()} was called).
+	 *
+	 * @param timeout max time to wait for reading the entire stream
+	 *
+	 * @return {@code true} if the stream reading is done
+	 */
+	protected boolean waitForReadingToFinish(long timeout) {
+		final long start = System.currentTimeMillis();
+		while (!fReadingDone.get() && System.currentTimeMillis() - start < timeout) {
+			try {
+				Thread.sleep(10);
+			} catch (InterruptedException e) {
+				Thread.currentThread().interrupt();
+				break;
+			}
+		}
+		return fReadingDone.get();
+	}
+
+	private static long maxWaitTimeForStreamReading() {
+		long maxTime = 10_000;
+		String systemPropertyValue = System.getProperty(MAX_WAIT_TIME_FOR_STREAM_READING_PROPERTY);
+		if (systemPropertyValue != null) {
+			try {
+				maxTime = Long.parseLong(systemPropertyValue);
+			} catch (NumberFormatException e) {
+				logError("Failed to read default value for max stream monitor read time: " + MAX_WAIT_TIME_FOR_STREAM_READING_PROPERTY, e); //$NON-NLS-1$
+			}
+		}
+		return maxTime;
+	}
+
+	private static void logWarning(String warningMessage) {
+		log(IStatus.WARNING, warningMessage, null);
+	}
+
+	private static void logError(String errorMessage, Exception e) {
+		log(IStatus.ERROR, errorMessage, e);
+	}
+
+	private static void log(int statusCode, String errorMessage, Exception e) {
+		IStatus errorStatus = new Status(statusCode, DebugPlugin.getUniqueIdentifier(), errorMessage, e);
+		DebugPlugin.log(errorStatus);
+	}
+
 	class ContentNotifier implements ISafeRunnable {
 
 		private IStreamListener fListener;