Mailing-List: contact commits-help@geode.incubator.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@geode.incubator.apache.org
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
From: klund@apache.org
To: commits@geode.incubator.apache.org
Message-Id: <e1a6aea5031944009e48b2af2d5f20d9@git.apache.org>
Subject: incubator-geode git commit: GEODE-291: Improve debugging of
 test.process wrapper and readers.
Date: Tue, 15 Sep 2015 23:18:42 +0000 (UTC)

Repository: incubator-geode
Updated Branches:
  refs/heads/feature/GEODE-291 [created] 646affa04


GEODE-291: Improve debugging of test.process wrapper and readers.

Remove unused methods and variables.

Change waitFor() to match the Process.waitFor(long, TimeUnit) method in
JDK 1.8 (this still compiles/works under 1.7). Pass in timeout
parameters from ProcessWrapper instead of hardcoding it.

Separate waitFor() into waitFor(long, TimeUnit) and start(). Previously
waitFor() was performing both of these actions.

Improve debugging by: 1) adding minor lifecycle to ProcessOutputReader,
2) include command string in stack trace of ProcessStreamReader. This
will allow me to identify the source of GEODE-291 -- once I've
identified it then I'll determine if there are any further changes that
need to be made. If it the output is truly not a real issue then I'll
suppress the stack trace from being printed.


Project: http://git-wip-us.apache.org/repos/asf/incubator-geode/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-geode/commit/646affa0
Tree: http://git-wip-us.apache.org/repos/asf/incubator-geode/tree/646affa0
Diff: http://git-wip-us.apache.org/repos/asf/incubator-geode/diff/646affa0

Branch: refs/heads/feature/GEODE-291
Commit: 646affa04868f3fd50f7d24018d98ba2fa96ac47
Parents: 4e65f0c
Author: Kirk Lund <klund@pivotal.io>
Authored: Tue Sep 15 16:15:33 2015 -0700
Committer: Kirk Lund <klund@pivotal.io>
Committed: Tue Sep 15 16:15:33 2015 -0700

----------------------------------------------------------------------
 .../test/process/ProcessOutputReader.java       | 101 +++++++++----------
 .../test/process/ProcessStreamReader.java       |  42 +++-----
 .../gemfire/test/process/ProcessWrapper.java    |   7 +-
 3 files changed, 67 insertions(+), 83 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/incubator-geode/blob/646affa0/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessOutputReader.java
----------------------------------------------------------------------
diff --git a/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessOutputReader.java b/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessOutputReader.java
index 6255b14..e5153fd 100755
--- a/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessOutputReader.java
+++ b/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessOutputReader.java
@@ -1,82 +1,73 @@
 package com.gemstone.gemfire.test.process;
 
-import java.util.List;
+import java.util.concurrent.TimeUnit;
 
 /**
- * Reads the stdout and stderr from a running process and stores then for test 
- * validation. Also provides a mechanism to waitFor the process to terminate. 
+ * Starts the stdout and stderr reader threads for a running process. Provides
+ * a mechanism to waitFor the process to terminate.
+ * </p>
  * Extracted from ProcessWrapper.
  * 
  * @author Kirk Lund
  */
 public class ProcessOutputReader {
 
-  private static final long PROCESS_TIMEOUT_MILLIS = 10 * 60 * 1000L; // 10 minutes
-
-  private int exitCode;
+  private boolean started;
   
-  private final Process p;
+  private final Process process;
   private final ProcessStreamReader stdout;
   private final ProcessStreamReader stderr;
-  private final List<String> lines;
   
-  public ProcessOutputReader(final Process p, final ProcessStreamReader stdout, final ProcessStreamReader stderr, final List<String> lines) {
-    this.p = p;
+  public ProcessOutputReader(final Process process, final ProcessStreamReader stdout, final ProcessStreamReader stderr) {
+    this.process = process;
     this.stdout = stdout;
     this.stderr = stderr;
-    this.lines = lines;
   }
-  
-  public void waitFor() {
-    stdout.start();
-    stderr.start();
 
-    long startMillis = System.currentTimeMillis();
-    try {
-      stderr.join(PROCESS_TIMEOUT_MILLIS);
-    } catch (Exception ignore) {
+  public void start() {
+    synchronized(this) {
+      this.stdout.start();
+      this.stderr.start();
+      this.started = true;
     }
-
-    long timeLeft = System.currentTimeMillis() + PROCESS_TIMEOUT_MILLIS - startMillis;
-    try {
-      stdout.join(timeLeft);
-    } catch (Exception ignore) {
+  }
+  
+  public boolean waitFor(final long timeout, final TimeUnit unit) throws InterruptedException {
+    synchronized(this) {
+      if (!this.started) {
+        throw new IllegalStateException("Must be started before waitFor");
+      }
     }
+    
+    final long startTime = System.nanoTime();
+    
+    long millisToJoin = unit.toMillis(timeout);
+    this.stderr.join(millisToJoin);
 
-    this.exitCode = 0;
-    int retryCount = 9;
-    while (retryCount > 0) {
-      retryCount--;
+    long nanosRemaining = unit.toNanos(timeout) - (System.nanoTime() - startTime);
+    millisToJoin = unit.toMillis(nanosRemaining);
+    this.stdout.join(millisToJoin);
+
+    nanosRemaining = unit.toNanos(timeout) - (System.nanoTime() - startTime);
+    return waitForProcess(nanosRemaining, unit);
+  }
+
+  private boolean waitForProcess(final long timeout, final TimeUnit unit) throws InterruptedException {
+    long startTime = System.nanoTime();
+    long nanosRemaining = unit.toNanos(timeout);
+
+    while (nanosRemaining > 0) {
       try {
-        exitCode = p.exitValue();
-        break;
-      } catch (IllegalThreadStateException e) {
-        // due to bugs in Process we may not be able to get
-        // a process's exit value.
-        // We can't use Process.waitFor() because it can hang forever
-        if (retryCount == 0) {
-          if (stderr.linecount > 0) {
-            // The process wrote to stderr so manufacture
-            // an error exist code
-            synchronized (lines) {
-              lines.add("Failed to get exit status and it wrote"
-                  + " to stderr so setting exit status to 1.");
-            }
-            exitCode = 1;
-          }
-        } else {
-          // We need to wait around to give a chance for
-          // the child to be reaped.See bug 19682
-          try {
-            Thread.sleep(1000);
-          } catch (InterruptedException ignore) {
-          }
+        this.process.exitValue();
+        return true;
+      } catch(IllegalThreadStateException ex) {
+        if (nanosRemaining > 0) {
+          long millisToSleep =Math.min(TimeUnit.NANOSECONDS.toMillis(nanosRemaining) + 1, 100);
+          Thread.sleep(millisToSleep);
         }
       }
+      nanosRemaining = unit.toNanos(timeout) - (System.nanoTime() - startTime);
     }
-  }
-
-  public int getExitCode() {
-    return exitCode;
+    return false;
   }
 }

http://git-wip-us.apache.org/repos/asf/incubator-geode/blob/646affa0/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessStreamReader.java
----------------------------------------------------------------------
diff --git a/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessStreamReader.java b/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessStreamReader.java
index 567279c..c81fabe 100755
--- a/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessStreamReader.java
+++ b/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessStreamReader.java
@@ -1,20 +1,23 @@
 package com.gemstone.gemfire.test.process;
 
 import java.io.BufferedReader;
+import java.io.IOException;
 import java.io.InputStream;
 import java.io.InputStreamReader;
 import java.util.List;
 import java.util.Queue;
 
 /**
- * Reads the output from a stream and stores it for test validation. Extracted
- * from ProcessWrapper.
+ * Reads the output from a process stream and stores it for test validation. 
+ * </p>
+ * Extracted from ProcessWrapper.
  * 
  * @author Kirk Lund
  */
 public class ProcessStreamReader extends Thread {
   
-  private volatile Throwable startStack;
+  private volatile RuntimeException startStack;
+  
   private final String command;
   private final BufferedReader reader;
   private final Queue<String> lineBuffer;
@@ -22,28 +25,16 @@ public class ProcessStreamReader extends Thread {
 
   public int linecount = 0;
 
-  public ProcessStreamReader(String command, InputStream stream, Queue<String> lineBuffer, List<String> allLines) {
+  public ProcessStreamReader(final String command, final InputStream stream, final Queue<String> lineBuffer, final List<String> allLines) {
     this.command = command;
     this.reader = new BufferedReader(new InputStreamReader(stream));
     this.lineBuffer = lineBuffer;
     this.allLines = allLines;
   }
 
-  public Throwable getStart() {
-    return this.startStack;
-  }
-  
-  public Throwable getFailure() {
-    if (this.startStack.getCause() != null) {
-      return this.startStack.getCause();
-    } else {
-      return null;
-    }
-  }
-  
   @Override
   public void start() {
-    this.startStack = new Throwable();
+    this.startStack = new RuntimeException(this.command);
     super.start();
   }
   
@@ -51,18 +42,17 @@ public class ProcessStreamReader extends Thread {
   public void run() {
     try {
       String line;
-      while ((line = reader.readLine()) != null) {
-        linecount++;
-        lineBuffer.offer(line);
-        allLines.add(line);
+      while ((line = this.reader.readLine()) != null) {
+        this.linecount++;
+        this.lineBuffer.offer(line);
+        this.allLines.add(line);
       }
 
       // EOF
-      reader.close();
-    } catch (Exception cause) {
-      this.startStack.initCause(cause);
-      System.err.println("ProcessStreamReader: Failure while reading from child process: " + this.command + " " + this.startStack.getMessage());
-      this.startStack.printStackTrace();
+      this.reader.close();
+    } catch (IOException streamClosed) {
+      this.startStack.initCause(streamClosed);
+      throw this.startStack;
     }
   }
 }

http://git-wip-us.apache.org/repos/asf/incubator-geode/blob/646affa0/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessWrapper.java
----------------------------------------------------------------------
diff --git a/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessWrapper.java b/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessWrapper.java
index 5bf2408..1868110 100644
--- a/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessWrapper.java
+++ b/gemfire-core/src/test/java/com/gemstone/gemfire/test/process/ProcessWrapper.java
@@ -31,6 +31,8 @@ import com.gemstone.gemfire.internal.logging.LogService;
 public class ProcessWrapper {
   private static final Logger logger = LogService.getLogger();
 
+  private static final long PROCESS_TIMEOUT_MILLIS = 10 * 60 * 1000L; // 10 minutes
+
   protected static final String TIMEOUT_MILLIS_PROPERTY = "process.test.timeoutMillis";
   protected static final long TIMEOUT_MILLIS_DEFAULT = 5 * 60 * 1000;
   private static final long DELAY = 10;
@@ -307,11 +309,12 @@ public class ProcessWrapper {
   
         this.stdout = stdOut;
         this.stderr = stdErr;
-        this.outputReader = new ProcessOutputReader(this.process, stdOut, stdErr, this.allLines);
+        this.outputReader = new ProcessOutputReader(this.process, stdOut, stdErr);
         this.started = true;
       }
       
-      this.outputReader.waitFor();
+      this.outputReader.start();
+      this.outputReader.waitFor(PROCESS_TIMEOUT_MILLIS, TimeUnit.MILLISECONDS);
       int code = this.process.waitFor();
       
       synchronized (this.exitValue) {