Merge pull request #22 from CleverTap/run-shell-read-stderr

Enhance mvn test execution to prevent process being stuck

Author: tpetrov-lp

pom.xml

@@ -7,7 +7,7 @@
     <groupId>com.clevertap</groupId>
     <artifactId>supertest-maven-plugin</artifactId>
     <packaging>maven-plugin</packaging>
-    <version>1.10</version>
+    <version>1.11</version>
     <description>A wrapper for Maven's Surefire Plugin, with advanced re-run capabilities.
     </description>
     <name>supertest-maven-plugin</name>

src/main/java/com/clevertap/maven/plugins/supertest/SuperTestMavenPlugin.java

@@ -5,9 +5,18 @@
 import java.io.IOException;
 import java.io.InputStream;
 import java.io.InputStreamReader;
+import java.io.PrintWriter;
+import java.io.StringWriter;
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.StringTokenizer;
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.Future;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicLong;
 import javax.xml.parsers.ParserConfigurationException;
 import org.apache.maven.plugin.AbstractMojo;
 import org.apache.maven.plugin.MojoExecutionException;
@@ -18,6 +27,11 @@
 
 @Mojo(name = "supertest")
 public class SuperTestMavenPlugin extends AbstractMojo {
+    // this is the max time to wait in seconds for process termination after the stdout read is
+    // finished or terminated
+    private static final int STDOUT_POST_READ_WAIT_TIMEOUT = 10;
+
+    private ExecutorService pool;
 
     @Parameter(defaultValue = "${project}", readonly = true)
     MavenProject project;
@@ -31,6 +45,10 @@ public class SuperTestMavenPlugin extends AbstractMojo {
     @Parameter(property = "retryRunCount", readonly = true, defaultValue = "1")
     Integer retryRunCount;
 
+    // in seconds
+    @Parameter(property = "shellNoActivityTimeout", readonly = true, defaultValue = "300")
+    Integer shellNoActivityTimeout;
+
     public void execute() throws MojoExecutionException {
 
         if (mvnTestOpts == null) {
@@ -50,6 +68,8 @@ public void execute() throws MojoExecutionException {
         final String artifactId = project.getArtifactId();
         final String groupId = project.getGroupId();
 
+        pool = Executors.newFixedThreadPool(1);
+
         int exitCode;
         final String command = "mvn test " + buildProcessedMvnTestOpts(artifactId, groupId);
         try {
@@ -81,6 +101,12 @@ public void execute() throws MojoExecutionException {
             }
 
             final String runCommand = createRerunCommand(classnameToTestcaseList);
+
+            // previous run exited with code > 0, but all tests were actually run successfully
+            if (runCommand == null) {
+                return;
+            }
+
             final StringBuilder rerunCommand = new StringBuilder(runCommand);
             rerunCommand.append(buildProcessedMvnTestOpts(artifactId, groupId));
             if (rerunProfile != null) {
@@ -101,6 +127,8 @@ public void execute() throws MojoExecutionException {
             }
         }
 
+        pool.shutdown();
+
         if (exitCode != 0) {
             System.exit(1);
         }
@@ -121,16 +149,89 @@ private StringBuilder buildProcessedMvnTestOpts(String artifactId, String groupI
     public int runShellCommand(final String command, final String commandDescriptor)
             throws IOException, InterruptedException {
         getLog().info("Running " + command);
-        Process proc = Runtime.getRuntime().exec(command);
+        ProcessBuilder pb = new ProcessBuilder(getShellCommandAsArray(command));
+        pb.redirectErrorStream(true);
+        Process proc = pb.start();
+        readProcessStdOut(proc, commandDescriptor);
+
+        // we don't want to wait forever, if something breaks
+        boolean exited = proc.waitFor(STDOUT_POST_READ_WAIT_TIMEOUT, TimeUnit.SECONDS);
+
+        if (exited) {
+            return proc.exitValue();
+        } else {
+            proc.destroyForcibly();
+            return 1;
+        }
+    }
+
+    private String[] getShellCommandAsArray(String command) {
+        // this is what Runtime.getRuntime().exec(...) is doing internally
+        StringTokenizer tokenizer = new StringTokenizer(command);
+        String[] cmdArray = new String[tokenizer.countTokens()];
+        for (int i = 0; tokenizer.hasMoreTokens(); i++) {
+            cmdArray[i] = tokenizer.nextToken();
+        }
+
+        return cmdArray;
+    }
+
+    private void readProcessStdOut(Process proc, String commandDescriptor) {
         InputStream inputStream = proc.getInputStream();
         InputStreamReader inputStreamReader = new InputStreamReader(inputStream);
         BufferedReader bufferedReader = new BufferedReader(inputStreamReader);
-        String line;
-        while ((line = bufferedReader.readLine()) != null) {
-            getLog().info(commandDescriptor + ": " + line);
+        AtomicLong lastOutputTime = new AtomicLong(System.currentTimeMillis());
+        CountDownLatch countDownLatch = new CountDownLatch(1);
+
+        Future<?> task = pool.submit(() -> {
+            String line;
+
+            try {
+                while ((line = bufferedReader.readLine()) != null) {
+                    getLog().info(commandDescriptor + ": " + line);
+                    lastOutputTime.set(System.currentTimeMillis());
+                }
+            } catch (IOException e) {
+                throw new RuntimeException(e);
+            }
+
+            // task has finished
+            countDownLatch.countDown();
+        });
+
+        boolean isDone = task.isDone();
+
+        while (!isDone && hasRecentShellActivity(lastOutputTime.get())) {
+            try {
+                isDone = countDownLatch.await(shellNoActivityTimeout, TimeUnit.SECONDS);
+            } catch (InterruptedException e) {
+                Thread.currentThread().interrupt();
+            }
+        }
+
+        try {
+            // task is either done or it timed out, no need to wait much
+            task.get(1, TimeUnit.SECONDS);
+        } catch (Exception e) {
+            if (e instanceof InterruptedException) {
+                Thread.currentThread().interrupt();
+            }
+
+            getLog().info(commandDescriptor + ": Read stdout error - " + getStackTrace(e));
         }
-        proc.waitFor();
-        return proc.exitValue();
+    }
+
+    private boolean hasRecentShellActivity(long lastTime) {
+        return System.currentTimeMillis() - lastTime
+                < TimeUnit.SECONDS.toMillis(shellNoActivityTimeout);
+    }
+
+    private String getStackTrace(Exception e) {
+        StringWriter stringWriter = new StringWriter();
+        PrintWriter printWriter = new PrintWriter(stringWriter);
+        e.printStackTrace(printWriter);
+
+        return stringWriter.getBuffer().toString();
     }
 
     /**
@@ -151,13 +252,15 @@ public File[] getXmlFileList(File baseDir) {
      * @return rerunCommand
      */
     public String createRerunCommand(Map<String, List<String>> classnameToTestcaseList) {
+        boolean hasTestsAppended = false;
         final StringBuilder retryRun = new StringBuilder("mvn test");
         retryRun.append(" -Dtest=");
         // TODO: 04/02/2022 replace with Java 8 streams
         for (String className : classnameToTestcaseList.keySet()) {
             List<String> failedTestCaseList = classnameToTestcaseList.get(className);
             if (!failedTestCaseList.isEmpty()) {
                 retryRun.append(className);
+                hasTestsAppended = true;
                 if(failedTestCaseList.contains("")) {
                     retryRun.append(",");
                     continue;
@@ -173,6 +276,6 @@ public String createRerunCommand(Map<String, List<String>> classnameToTestcaseLi
                 }
             }
         }
-        return retryRun.toString();
+        return hasTestsAppended ? retryRun.toString() : null;
     }
 }