7144861: speed up RMI activation tests

Reviewed-by: alanb, smarks, dholmes, dmocek

test/java/rmi/activation/checkusage/CheckUsage.java

@@ -53,12 +53,9 @@ public class CheckUsage {
             rmidVM.start();
 
             // wait for registry exit
+            int rmidVMExitStatus = rmidVM.getVM().waitFor();
             System.err.println("rmid exited with status: " +
-                               rmidVM.getVM().waitFor());
-            try {
-                Thread.sleep(7000);
-            } catch (InterruptedException ie) {
-            }
+                               rmidVMExitStatus);
 
             String usage = new String(berr.toByteArray());
 

test/java/rmi/testlibrary/ActivationLibrary.java

@@ -63,19 +63,30 @@ public class ActivationLibrary {
      */
     public static void deactivate(Remote remote,
                                   ActivationID id) {
-        for (int i = 0; i < 5; i ++) {
+        // We do as much as 50 deactivation trials, each separated by
+        // at least 100 milliseconds sleep time (max sleep time of 5 secs).
+        final long deactivateSleepTime = 100;
+        for (int i = 0; i < 50; i ++) {
             try {
                 if (Activatable.inactive(id) == true) {
                     mesg("inactive successful");
                     return;
                 } else {
-                    Thread.sleep(1000);
+                    mesg("inactive trial failed. Sleeping " +
+                         deactivateSleepTime +
+                         " milliseconds before next trial");
+                    Thread.sleep(deactivateSleepTime);
                 }
             } catch (InterruptedException e) {
-                continue;
+                Thread.currentThread().interrupt();
+                mesg("Thread interrupted while trying to deactivate activatable. Exiting deactivation");
+                return;
             } catch (Exception e) {
                 try {
                     // forcibly unexport the object
+                    mesg("Unexpected exception. Have to forcibly unexport the object." +
+                         " Exception was :");
+                    e.printStackTrace();
                     Activatable.unexportObject(remote, true);
                 } catch (NoSuchObjectException ex) {
                 }
@@ -99,37 +110,61 @@ public class ActivationLibrary {
      * activation system.
      */
     public static boolean rmidRunning(int port) {
-        int allowedNotReady = 10;
+        int allowedNotReady = 50;
         int connectionRefusedExceptions = 0;
 
-        for (int i = 0; i < 15 ; i++) {
+        /* We wait as much as a total of 7.5 secs trying to see Rmid running.
+         * We do this by pausing steps of 100 milliseconds (so up to 75 steps),
+         * right after trying to lookup and find RMID running in the other vm.
+         */
+        final long rmidWaitingStepTime = 100;
+        for (int i = 0; i <= 74; i++) {
 
             try {
-                Thread.sleep(500);
                 LocateRegistry.getRegistry(port).lookup(SYSTEM_NAME);
+                mesg("Activation System available after " +
+                     (i * rmidWaitingStepTime) + " milliseconds");
                 return true;
 
             } catch (java.rmi.ConnectException e) {
-                // ignore connect exceptions until we decide rmid is not up
+                mesg("Remote connection refused after " +
+                     (i * rmidWaitingStepTime) + " milliseconds");
 
+                // ignore connect exceptions until we decide rmid is not up
                 if ((connectionRefusedExceptions ++) >= allowedNotReady) {
                     return false;
                 }
 
-            } catch (NotBoundException e) {
+            } catch (java.rmi.NoSuchObjectException nsoe) {
+                /* Activation System still unavailable.
+                 * Ignore this since we are just waiting for its availibility.
+                 * Just signal unavailibility.
+                 */
+                mesg("Activation System still unavailable after more than " +
+                     (i * rmidWaitingStepTime) + " milliseconds");
 
+            } catch (NotBoundException e) {
                 return false;
 
             } catch (Exception e) {
-                // print out other types of exceptions as an FYI.
-                // test should not fail as rmid is likely to be in an
-                // undetermined state at this point.
-
+                /* print out other types of exceptions as an FYI.
+                 * test should not fail as rmid is likely to be in an
+                 * undetermined state at this point.
+                 */
                 mesg("caught an exception trying to" +
                      " start rmid, last exception was: " +
                      e.getMessage());
                 e.printStackTrace();
             }
+
+            // Waiting for another 100 milliseconds.
+            try {
+                Thread.sleep(100);
+            } catch (InterruptedException e) {
+                Thread.currentThread().interrupt();
+                mesg("Thread interrupted while checking if Activation System is running. Exiting check");
+                return false;
+            }
         }
         return false;
     }

test/java/rmi/testlibrary/JavaVM.java

@@ -36,7 +36,6 @@ import java.util.StringTokenizer;
  */
 public class JavaVM {
 
-    // need to
     protected Process vm = null;
 
     private String classname = "";
@@ -46,6 +45,10 @@ public class JavaVM {
     private OutputStream errorStream = System.err;
     private String policyFileName = null;
 
+    // This is used to shorten waiting time at startup.
+    private volatile boolean started = false;
+    private boolean forcesOutput = true; // default behavior
+
     private static void mesg(Object mesg) {
         System.err.println("JAVAVM: " + mesg.toString());
     }
@@ -79,6 +82,25 @@ public class JavaVM {
         this.errorStream = err;
     }
 
+    /* This constructor will instantiate a JavaVM object for which caller
+     * can ask for forcing initial version output on child vm process
+     * (if forcesVersionOutput is true), or letting the started vm behave freely
+     * (when forcesVersionOutput is false).
+     */
+    public JavaVM(String classname,
+                  String options, String args,
+                  OutputStream out, OutputStream err,
+                  boolean forcesVersionOutput) {
+        this(classname, options, args, out, err);
+        this.forcesOutput = forcesVersionOutput;
+    }
+
+
+    public void setStarted() {
+        started = true;
+    }
+
+    // Prepends passed opts array to current options
     public void addOptions(String[] opts) {
         String newOpts = "";
         for (int i = 0 ; i < opts.length ; i ++) {
@@ -87,6 +109,8 @@ public class JavaVM {
         newOpts += " ";
         options = newOpts + options;
     }
+
+    // Prepends passed arguments array to current args
     public void addArguments(String[] arguments) {
         String newArgs = "";
         for (int i = 0 ; i < arguments.length ; i ++) {
@@ -127,6 +151,18 @@ public class JavaVM {
 
         addOptions(new String[] { getCodeCoverageOptions() });
 
+        /*
+         * If forcesOutput is true :
+         *  We force the new starting vm to output something so that we can know
+         *  when it is effectively started by redirecting standard output through
+         *  the next StreamPipe call (the vm is considered started when a first
+         *  output has been streamed out).
+         *  We do this by prepnding a "-showversion" option in the command line.
+         */
+        if (forcesOutput) {
+            addOptions(new String[] {"-showversion"});
+        }
+
         StringTokenizer optionsTokenizer = new StringTokenizer(options);
         StringTokenizer argsTokenizer = new StringTokenizer(args);
         int optionsCount = optionsTokenizer.countTokens();
@@ -150,15 +186,43 @@ public class JavaVM {
         vm = Runtime.getRuntime().exec(javaCommand);
 
         /* output from the execed process may optionally be captured. */
-        StreamPipe.plugTogether(vm.getInputStream(), this.outputStream);
-        StreamPipe.plugTogether(vm.getErrorStream(), this.errorStream);
+        StreamPipe.plugTogether(this, vm.getInputStream(), this.outputStream);
+        StreamPipe.plugTogether(this, vm.getErrorStream(), this.errorStream);
 
         try {
+            if (forcesOutput) {
+                // Wait distant vm to start, by using waiting time slices of 100 ms.
+                // Wait at most for 2secs, after it considers the vm to be started.
+                final long vmStartSleepTime = 100;
+                final int maxTrials = 20;
+                int numTrials = 0;
+                while (!started && numTrials < maxTrials) {
+                    numTrials++;
+                    Thread.sleep(vmStartSleepTime);
+                }
+
+                // Outputs running status of distant vm
+                String message =
+                    "after " + (numTrials * vmStartSleepTime) + " milliseconds";
+                if (started) {
+                    mesg("distant vm process running, " + message);
+                }
+                else {
+                    mesg("unknown running status of distant vm process, " + message);
+                }
+            }
+            else {
+                // Since we have no way to know if the distant vm is started,
+                // we just consider the vm to be started after a 2secs waiting time.
                 Thread.sleep(2000);
-        } catch (Exception ignore) {
+                mesg("distant vm considered to be started after a waiting time of 2 secs");
+            }
+        } catch (InterruptedException e) {
+            Thread.currentThread().interrupt();
+            mesg("Thread interrupted while checking if distant vm is started. Giving up check.");
+            mesg("Distant vm state unknown");
+            return;
         }
-
-        mesg("finished starting vm.");
     }
 
     public void destroy() {

test/java/rmi/testlibrary/RMID.java

@@ -218,20 +218,30 @@ public class RMID extends JavaVM {
         } catch (NumberFormatException ignore) {}
         waitTime = waitTime * slopFactor;
 
-        // give rmid time to come up
+        // We check several times (as many as provides passed waitTime) to
+        // see if Rmid is currently running. Waiting steps last 100 msecs.
+        final long rmidStartSleepTime = 100;
         do {
+            // Sleeping for another rmidStartSleepTime time slice.
             try {
-                Thread.sleep(Math.min(waitTime, 10000));
+                Thread.sleep(Math.min(waitTime, rmidStartSleepTime));
             } catch (InterruptedException ie) {
                 Thread.currentThread().interrupt();
+                mesg("Thread interrupted while checking for start of Activation System. Giving up check.");
+                mesg("Activation System state unknown");
+                return;
             }
-            waitTime -= 10000;
+            waitTime -= rmidStartSleepTime;
 
-            // is rmid present?
+            // Checking if rmid is present
             if (ActivationLibrary.rmidRunning(port)) {
                 mesg("finished starting rmid.");
                 return;
             }
+            else {
+                mesg("rmid still not started");
+            }
+
         } while (waitTime > 0);
         TestLibrary.bomb("start rmid failed... giving up", null);
     }
@@ -264,6 +274,8 @@ public class RMID extends JavaVM {
                     port +
                     "/java.rmi.activation.ActivationSystem");
                 mesg("obtained a reference to the activation system");
+            } catch (RemoteException re) {
+                mesg("could not contact registry while trying to shutdown activation system");
             } catch (java.net.MalformedURLException mue) {
             }
 
@@ -272,19 +284,14 @@ public class RMID extends JavaVM {
             }
             system.shutdown();
 
+        } catch (RemoteException re) {
+            mesg("shutting down the activation daemon failed");
         } catch (Exception e) {
             mesg("caught exception trying to shutdown rmid");
             mesg(e.getMessage());
             e.printStackTrace();
         }
 
-        try {
-            // wait for the shutdown to happen
-            Thread.sleep(5000);
-        } catch (InterruptedException ie) {
-            Thread.currentThread().interrupt();
-        }
-
         mesg("testlibrary finished shutting down rmid");
     }
 
@@ -301,18 +308,47 @@ public class RMID extends JavaVM {
 
         if (vm != null) {
             try {
-                // destroy rmid if it is still running...
+                /* Waiting for distant RMID process to shutdown.
+                 * Waiting is bounded at a hardcoded max of 60 secs (1 min).
+                 * Waiting by steps of 200 msecs, thus at most 300 such attempts
+                 * for termination of distant RMID process. If process is not
+                 * known to be terminated properly after that time,
+                 * we give up for a gracefull termination, and thus go for
+                 * forcibly destroying the process.
+                 */
+                boolean vmEnded = false;
+                int waitingTrials = 0;
+                final int maxTrials = 300;
+                final long vmProcessEndWaitInterval = 200;
+                int vmExitValue;
+                do {
                     try {
-                    vm.exitValue();
+                        Thread.sleep(vmProcessEndWaitInterval);
+                        waitingTrials++;
+                        vmExitValue = vm.exitValue();
                         mesg("rmid exited on shutdown request");
+                        vmEnded = true;
                     } catch (IllegalThreadStateException illegal) {
-                    mesg("Had to destroy RMID's process " +
-                         "using Process.destroy()");
+                        mesg("RMID's process still not terminated after more than " +
+                             (waitingTrials * vmProcessEndWaitInterval) + " milliseconds");
+                    }
+                }
+                while (!vmEnded &&
+                       (waitingTrials < maxTrials));
+
+                if (waitingTrials >= maxTrials) {
+                    mesg("RMID's process still not terminated after more than " +
+                         (waitingTrials * vmProcessEndWaitInterval) + " milliseconds." +
+                         "Givinp up gracefull termination...");
+                    mesg("destroying RMID's process using Process.destroy()");
                     super.destroy();
                 }
 
+            } catch (InterruptedException ie) {
+                Thread.currentThread().interrupt();
+                mesg("Thread interrupted while checking for termination of distant rmid vm. Giving up check.");
             } catch (Exception e) {
-                mesg("caught exception trying to destroy rmid: " +
+                mesg("caught unexpected exception trying to destroy rmid: " +
                      e.getMessage());
                 e.printStackTrace();
             }

test/java/rmi/testlibrary/StreamPipe.java

@@ -35,46 +35,89 @@ public class StreamPipe extends Thread {
     private InputStream in;
     private OutputStream out;
     private String preamble;
+    private JavaVM javaVM;
     private static Object lock = new Object();
     private static int count = 0;
 
-    public StreamPipe(InputStream in, OutputStream out, String name) {
+
+    /* StreamPipe constructor : should only be called by plugTogether() method !!
+     * If passed vm is not null :
+     * -  This is StreamPipe usage when streams to pipe come from a given
+     *    vm (JavaVM) process (the vm process must be started with a prefixed
+     *    "-showversion" option to be able to determine as soon as possible when
+     *    the vm process is started through the redirection of the streams).
+     *    There must be a close connection between the StreamPipe instance and
+     *    the JavaVM object on which a start() call has been done.
+     *    run() method will flag distant JavaVM as started.
+     * If passed vm is null :
+     * -  We don't have control on the process which we want to redirect the passed
+     *    streams.
+     *    run() method will ignore distant process.
+     */
+    private StreamPipe(JavaVM vm, InputStream in, OutputStream out, String name) {
         super(name);
         this.in  = in;
         this.out = out;
         this.preamble = "# ";
+        this.javaVM = vm;
+    }
+
+    // Install redirection of passed InputStream and OutputStream from passed JavaVM
+    // to this vm standard output and input streams.
+    public static void plugTogether(JavaVM vm, InputStream in, OutputStream out) {
+        String name = null;
+
+        synchronized (lock) {
+            name = "TestLibrary: StreamPipe-" + (count ++ );
+        }
+
+        Thread pipe = new StreamPipe(vm, in, out, name);
+        pipe.setDaemon(true);
+        pipe.start();
+    }
+
+    /* Redirects the InputStream and OutputStream passed by caller to this
+     * vm standard output and input streams.
+     * (we just have to use fully parametered plugTogether() call with a null
+     *  JavaVM input to do this).
+     */
+    public static void plugTogether(InputStream in, OutputStream out) {
+        plugTogether(null, in, out);
     }
 
+    // Starts redirection of streams.
     public void run() {
         BufferedReader r = new BufferedReader(new InputStreamReader(in), 1);
         BufferedWriter w = new BufferedWriter(new OutputStreamWriter(out));
         byte[] buf = new byte[256];
-        boolean bol = true;     // beginning-of-line
-        int count;
 
         try {
             String line;
-            while ((line = r.readLine()) != null) {
+
+            /* This is to check that the distant vm has started,
+             * if such a vm has been provided at construction :
+             * - As soon as we can read something from r BufferedReader,
+             *   that means the distant vm is already started.
+             * Thus we signal associated JavaVM object that it is now started.
+             */
+            if (((line = r.readLine()) != null) &&
+                (javaVM != null)) {
+                javaVM.setStarted();
+            }
+
+            // Redirects r on w.
+            while (line != null) {
                 w.write(preamble);
                 w.write(line);
                 w.newLine();
                 w.flush();
+                line = r.readLine();
             }
+
         } catch (IOException e) {
             System.err.println("*** IOException in StreamPipe.run:");
             e.printStackTrace();
         }
     }
 
-    public static void plugTogether(InputStream in, OutputStream out) {
-        String name = null;
-
-        synchronized (lock) {
-            name = "TestLibrary: StreamPipe-" + (count ++ );
-        }
-
-        Thread pipe = new StreamPipe(in, out, name);
-        pipe.setDaemon(true);
-        pipe.start();
-    }
 }

test/sun/rmi/runtime/Log/6409194/NoConsoleOutput.java

@@ -60,9 +60,12 @@ public class NoConsoleOutput {
             File.separatorChar + "logging.properties";
         ByteArrayOutputStream out = new ByteArrayOutputStream();
         ByteArrayOutputStream err = new ByteArrayOutputStream();
+
+        // We instantiate a JavaVM that should not produce any console output
+        // (neither on standard output, nor on standard err streams).
         JavaVM vm = new JavaVM(DoRMIStuff.class.getName(),
             "-Djava.util.logging.config.file=" + loggingPropertiesFile,
-                               "", out, err);
+                               "", out, err, false);
         vm.start();
         vm.getVM().waitFor();