7903580: Allow for re-attempting agent creation when an attempt fails

jaikiran · jonathan-gibbons · commit 0cf6ed21edfc · 2024-01-22T17:50:44.000Z
Reviewed-by: jjg, cstein
diff --git a/src/share/classes/com/sun/javatest/regtest/exec/Agent.java b/src/share/classes/com/sun/javatest/regtest/exec/Agent.java
@@ -37,6 +37,7 @@
 import java.io.InputStreamReader;
 import java.io.PrintStream;
 import java.io.PrintWriter;
+import java.lang.reflect.Method;
 import java.net.InetSocketAddress;
 import java.net.ServerSocket;
 import java.net.Socket;
@@ -90,12 +91,30 @@ public static class Fault extends Exception {
     static final boolean showAgent = Flags.get("showAgent");
     static final boolean traceAgent = Flags.get("traceAgent");
 
+    // the following code here allows us to run jtreg on older
+    // JDKs where the pid() method is unavailable on the
+    // Process class. we use PID only for debug purposes and
+    // the inability to get the PID of a launched AgentServer
+    // is OK.
+    private static final long UNKNOWN_PID = -1;
+    private static final Method PID_METHOD;
+    static {
+        Method pidMethod = null;
+        try {
+            pidMethod = Process.class.getDeclaredMethod("pid"); // only available in Java 9+
+        } catch (Exception e) {
+            pidMethod = null;
+        }
+        PID_METHOD = pidMethod;
+    }
+
     /**
      * Start a JDK with given JVM options.
      */
     private Agent(File dir, JDK jdk, List<String> vmOpts, Map<String, String> envVars,
             File policyFile, float timeoutFactor, Logger logger,
             String testThreadFactory, String testThreadFactoryPath) throws Fault {
+        Process agentServerProcess = null;
         try {
             id = ++count;
             this.jdk = jdk;
@@ -127,8 +146,9 @@ private Agent(File dir, JDK jdk, List<String> vmOpts, Map<String, String> envVar
             // is platform-specific, and Solaris has it on by default.
             ss.setReuseAddress(false);
             ss.bind(new InetSocketAddress(/*port:*/ 0), /*backlog:*/ 1);
+            final int port = ss.getLocalPort();
             cmd.add(AgentServer.PORT);
-            cmd.add(String.valueOf(ss.getLocalPort()));
+            cmd.add(String.valueOf(port));
 
             if (timeoutFactor != 1.0f) {
                 cmd.add(AgentServer.TIMEOUTFACTOR);
@@ -144,22 +164,27 @@ private Agent(File dir, JDK jdk, List<String> vmOpts, Map<String, String> envVar
                 cmd.add(CUSTOM_TEST_THREAD_FACTORY_PATH);
                 cmd.add(testThreadFactoryPath);
             }
-            log("Started " + cmd);
+            log("Launching " + cmd);
 
             ProcessBuilder pb = new ProcessBuilder(cmd);
             pb.directory(dir);
             Map<String, String> env = pb.environment();
             env.clear();
             env.putAll(envVars);
-            process = pb.start();
+            agentServerProcess = process = pb.start();
+            final long pid = getPid(process);
             copyAgentProcessStream("stdout", process.getInputStream());
             copyAgentProcessStream("stderr", process.getErrorStream());
 
             try {
                 final int ACCEPT_TIMEOUT = (int) (60 * 1000 * timeoutFactor);
-                    // default 60 seconds, for server to start and "phone home"
+                // default 60 seconds, for server to start and "phone home"
                 ss.setSoTimeout(ACCEPT_TIMEOUT);
+                log("Waiting up to " + ACCEPT_TIMEOUT + " milli seconds for a" +
+                        " socket connection on port " + port +
+                        (pid != UNKNOWN_PID ? " from process " + pid : ""));
                 Socket s = ss.accept();
+                log("Received connection on port " + port + " from " + s);
                 s.setSoTimeout((int)(KeepAlive.READ_TIMEOUT * timeoutFactor));
                 in = new DataInputStream(s.getInputStream());
                 out = new DataOutputStream(s.getOutputStream());
@@ -171,6 +196,16 @@ private Agent(File dir, JDK jdk, List<String> vmOpts, Map<String, String> envVar
             // send keep-alive messages to server while not executing actions
             keepAlive.setEnabled(true);
         } catch (IOException e) {
+            log("Agent creation failed due to " + e);
+            if (agentServerProcess != null) {
+                // kill the launched process
+                log("killing AgentServer process");
+                try {
+                    ProcessUtils.destroyForcibly(agentServerProcess);
+                } catch (Exception ignored) {
+                    // ignore
+                }
+            }
             throw new Fault(e);
         }
     }
@@ -578,6 +613,17 @@ private void log(String message, PrintStream out) {
         out.println("[" + AgentServer.logDateFormat.format(new Date()) + "] Agent[" + getId() + "]: " + message);
     }
 
+    private static long getPid(final Process process) {
+        if (PID_METHOD == null) {
+            return UNKNOWN_PID;
+        }
+        try {
+            return (long) PID_METHOD.invoke(process);
+        } catch (Exception e) {
+            return UNKNOWN_PID;
+        }
+    }
+
     final JDK jdk;
     final List<String> vmOpts;
     final File execDir;
@@ -730,6 +776,20 @@ public void setMaxPoolSize(int size) {
             logger.log(null, "POOL: max pool size: " + maxPoolSize);
         }
 
+        /**
+         * Sets the maximum attempts to create or obtain an agent VM
+         * @param numAttempts number of attempts
+         * @throws IllegalArgumentException if {@code numAttempts} is less than {@code 1}
+         */
+        public void setNumAgentSelectionAttempts(final int numAttempts) {
+            if (numAttempts < 1) {
+                throw new IllegalArgumentException("invalid value for agent selection attempts: "
+                        + numAttempts);
+            }
+            this.numAgentSelectionAttempts = numAttempts;
+            logger.log(null, "POOL: agent selection attempts: " + numAttempts);
+        }
+
         /**
          * Obtains an agent with the desired properties.
          * If a suitable agent already exists in the pool, it will be removed from the pool and
@@ -745,7 +805,48 @@ public void setMaxPoolSize(int size) {
          * @return the agent
          * @throws Fault if there is a problem obtaining a suitable agent
          */
-        synchronized Agent getAgent(File dir,
+        Agent getAgent(File dir,
+                       JDK jdk,
+                       List<String> vmOpts,
+                       Map<String, String> envVars,
+                       String testThreadFactory,
+                       String testThreadFactoryPath)
+                throws Fault {
+            final int numAttempts = this.numAgentSelectionAttempts;
+            assert numAttempts > 0 : "unexpected agent selection attempts: " + numAttempts;
+            Agent.Fault toThrow = null;
+            for (int i = 1; i <= numAttempts; i++) {
+                try {
+                    if (i != 1) {
+                        logger.log(null, "POOL: re-attempting agent creation, attempt number " + i);
+                    }
+                    return doGetAgent(dir, jdk, vmOpts, envVars, testThreadFactory,
+                            testThreadFactoryPath);
+                } catch (Agent.Fault f) {
+                    logger.log(null, "POOL: agent creation failed due to " + f.getCause());
+                    // keep track of the fault and reattempt to get an agent if within limit
+                    if (toThrow == null) {
+                        toThrow = f;
+                    } else {
+                        // add the previous exception as a suppressed exception
+                        // of the current one
+                        if (toThrow.getCause() != null) {
+                            f.addSuppressed(toThrow.getCause());
+                        }
+                        toThrow = f;
+                    }
+                    if (i == numAttempts || !(f.getCause() instanceof IOException)) {
+                        // we either made enough attempts or we failed due to a non IOException.
+                        // In either case we don't attempt to create an agent again and instead
+                        // throw the captured failure(s)
+                        throw toThrow;
+                    }
+                }
+            }
+            throw new AssertionError("should not reach here");
+        }
+
+        synchronized Agent doGetAgent(File dir,
                                     JDK jdk,
                                     List<String> vmOpts,
                                     Map<String, String> envVars,
@@ -927,6 +1028,7 @@ private static String getKey(File dir, JDK jdk, List<String> vmOpts) {
         private float timeoutFactor = 1.0f;
         private int maxPoolSize;
         private Duration idleTimeout;
+        private int numAgentSelectionAttempts;
     }
 
     static class Stats {
diff --git a/src/share/classes/com/sun/javatest/regtest/tool/Tool.java b/src/share/classes/com/sun/javatest/regtest/tool/Tool.java
@@ -461,6 +461,22 @@ public void process(String opt, String arg) throws BadArgs {
             }
         },
 
+        new Option(GNU, AGENT_POOL, null, "--agent-attempts") {
+            @Override
+            public void process(String opt, String arg) throws BadArgs {
+                int numTimes;
+                try {
+                    numTimes = Integer.parseInt(arg);
+                } catch (NumberFormatException e) {
+                    throw new BadArgs(i18n, "main.badAgentSelAttempt", arg);
+                }
+                if (numTimes < 1) {
+                    throw new BadArgs(i18n, "main.badAgentSelAttempt", numTimes);
+                }
+                numAgentSelectionAttempt = numTimes;
+            }
+        },
+
         new Option(STD, MAIN, "", "-conc", "-concurrency") {
             @Override
             public void process(String opt, String arg) {
@@ -1343,6 +1359,7 @@ public int run() throws BadArgs, Fault, Harness.Fault, InterruptedException {
                     }
                     p.setMaxPoolSize(maxPoolSize);
                     p.setIdleTimeout(poolIdleTimeout);
+                    p.setNumAgentSelectionAttempts(numAgentSelectionAttempt);
                     break;
                 case OTHERVM:
                     break;
@@ -2373,6 +2390,8 @@ public enum ReportMode { NONE, EXECUTED, FILES, ALL_EXECUTED, ALL }
     private String testThreadFactoryPathArg;
     private int maxPoolSize = -1;
     private Duration poolIdleTimeout = Duration.ofSeconds(30);
+    // number of attempts to get an agent for an action
+    private int numAgentSelectionAttempt = DEFAULT_NUM_AGENT_SEL_ATTEMPT;
     private List<String> testCompilerOpts = new ArrayList<>();
     private List<String> testJavaOpts = new ArrayList<>();
     private List<String> testVMOpts = new ArrayList<>();
@@ -2421,5 +2440,9 @@ public enum ReportMode { NONE, EXECUTED, FILES, ALL_EXECUTED, ALL }
             "windir"
     };
 
+    // default value for agent selection attempts. we default to 1, which implies
+    // by default we don't re-attempt on a failure
+    private static final int DEFAULT_NUM_AGENT_SEL_ATTEMPT = 1;
+
     private static final I18NResourceBundle i18n = I18NResourceBundle.getBundleForClass(Tool.class);
 }
diff --git a/src/share/classes/com/sun/javatest/regtest/tool/i18n.properties b/src/share/classes/com/sun/javatest/regtest/tool/i18n.properties
@@ -294,6 +294,12 @@ help.pool.pool_idle_timeout.arg=<number>
 help.pool.pool_idle_timeout.desc=\
      The time, in seconds, before an idle VM in the pool is \
      automatically closed.
+help.pool.agent_attempts.arg=<number>
+help.pool.agent_attempts.desc=\
+    The number of attempts jtreg will make to access an agent \
+    with the desired characteristics, either by creating a new one, \
+    or obtaining one from the pool of reusable VMs. The minimum value, \
+    and the default value, is 1.
 
 help.select.name=Test Selection Options
 help.select.desc=These options can be used to refine the set of tests to \
@@ -446,6 +452,7 @@ help.version.txt={0} {1}\nInstalled in {2}\nRunning on platform version {3} from
 help.version.unknown=(unknown)
 
 main.badArgs=Error: {0}
+main.badAgentSelAttempt=Bad value for agent selection attempts: {0}
 main.badConcurrency=Bad use of -concurrency
 main.badKeywords=Bad keyword expression: {0}
 main.badLockFile=Bad lock file: {0}
diff --git a/src/share/doc/javatest/regtest/faq.md b/src/share/doc/javatest/regtest/faq.md
@@ -699,6 +699,24 @@ if the default mode was not used.  For example,
     elapsed time (seconds): 0.141
 ````
 
+#### jtreg has trouble starting agents; what can I do?
+
+When running in agent mode, JTReg creates agent VMs as and when necessary.
+Agent VM creation involves launching a process and communicating with it over
+a socket. The initial handshake between the newly launched process and JTReg
+can sometimes timeout if the system is under heavy load. This then causes the
+agent creation to fail. By default, JTReg does not re-attempt creation of the
+agent VM and instead the failure is propagated as a test action failure and
+that action gets reported as a failed.
+
+This default behaviour can be overridden by passing the `--agent-attempts` option
+to `jtreg` command. This option takes an integer value which represents the number
+of attempts to make when attempting to get an agent for a test action. By default,
+the value of this option is `1`, implying JTReg will not re-attempt a failed
+attempt. Passing a higher value for this option will allow JTReg to re-attempt a
+failed attempt. For example, a value of `2` will allow JTReg to re-attempt once
+for each failed attempt.
+
 ### How do I specify whether to run tests concurrently?
 
 jtreg provides the ability to run tests in parallel, using multiple
diff --git a/test/badtests/BadTests.gmk b/test/badtests/BadTests.gmk
@@ -68,7 +68,7 @@ $(BUILDTESTDIR)/BadTests.agentvm.ok: \
 			> $(@:%.ok=%/jt.log) 2>&1 || \
 	    true "non-zero exit code from JavaTest intentionally ignored"
 	$(GREP) -s 'Test results: passed: 17; failed: 1; error: 2' $(@:%.ok=%/jt.log)  > /dev/null
-	agents=`$(GREP) '^\[[-0-9 :,]*\] Agent\[[0-9][0-9]*\]: Started' $(@:%.ok=%/jt.log) | wc -l` ; \
+	agents=`$(GREP) '^\[[-0-9 :,]*\] Agent\[[0-9][0-9]*\]: Launching' $(@:%.ok=%/jt.log) | wc -l` ; \
 	if [ $${agents} -ne 4 ]; then echo "Unexpected number of agents used: $${agents}" ; exit 1 ; fi
 	echo "test passed at `date`" > $@
 
diff --git a/test/debug/DebugTest.gmk b/test/debug/DebugTest.gmk
@@ -62,10 +62,10 @@ $(BUILDTESTDIR)/DebugTest.agentvm.ok: \
 		-debug:-Ddebug=true \
 		$(TESTDIR)/debug \
 			> $(@:%.ok=%/jt.log) 2>&1 ; rc=$$?
-	agents=`$(GREP) '^\[[-0-9 :,]*\] Agent...: Started' $(@:%.ok=%)/jt.log | wc -l | tr -d ' '` ; \
- 	debugAgents=`$(GREP) '^\[[-0-9 :,]*\] Agent...: Started.*-Ddebug=true' $(@:%.ok=%)/jt.log | wc -l | tr -d ' '` ; \
+	agents=`$(GREP) '^\[[-0-9 :,]*\] Agent...: Launching' $(@:%.ok=%)/jt.log | wc -l | tr -d ' '` ; \
+	debugAgents=`$(GREP) '^\[[-0-9 :,]*\] Agent...: Launching.*-Ddebug=true' $(@:%.ok=%)/jt.log | wc -l | tr -d ' '` ; \
 	if [ "$$agents" != 2 -o "$$debugAgents" != 1 ]; then \
-	    $(GREP) '^\[[-0-9 :,]*\] Agent...: Started' $(@:%.ok=%)/jt.log ; \
+	    $(GREP) '^\[[-0-9 :,]*\] Agent...: Launching' $(@:%.ok=%)/jt.log ; \
 	    echo "unexpected use of -debug options"; exit 1; \
 	fi
 	echo "test passed at `date`" > $@
