8209517: com/sun/jdi/BreakpointWithFullGC.java fails with timeout
authoramenkov
Thu, 16 Aug 2018 10:20:00 -0700
changeset 51424 083e731da31a
parent 51423 b2319bbcc867
child 51425 4e9667589c43
child 56857 3284e27e8d5a
8209517: com/sun/jdi/BreakpointWithFullGC.java fails with timeout Reviewed-by: dcubed, mikael
test/jdk/com/sun/jdi/BreakpointWithFullGC.java
test/jdk/com/sun/jdi/lib/jdb/Jdb.java
test/jdk/com/sun/jdi/lib/jdb/JdbCommand.java
test/jdk/com/sun/jdi/lib/jdb/JdbTest.java
--- a/test/jdk/com/sun/jdi/BreakpointWithFullGC.java	Thu Aug 16 15:00:23 2018 +0200
+++ b/test/jdk/com/sun/jdi/BreakpointWithFullGC.java	Thu Aug 16 10:20:00 2018 -0700
@@ -38,9 +38,7 @@
 import lib.jdb.JdbTest;
 
 import java.util.ArrayList;
-import java.util.LinkedList;
 import java.util.List;
-import java.util.stream.Collectors;
 
 class BreakpointWithFullGCTarg {
     public static List<Object> objList = new ArrayList<>();
@@ -68,44 +66,43 @@
         new BreakpointWithFullGC().run();
     }
 
-    public BreakpointWithFullGC() {
+    private BreakpointWithFullGC() {
         super(new Jdb.LaunchOptions(DEBUGGEE_CLASS)
-                     .debuggeeOptions(DEBUGGEE_OPTIONS));
+                     .addDebuggeeOptions(DEBUGGEE_OPTIONS));
     }
 
     private static final String DEBUGGEE_CLASS = BreakpointWithFullGCTarg.class.getName();
     // Hijacking the mode parameter to make sure we use a small amount
     // of memory and can see what GC is doing.
-    private static final String DEBUGGEE_OPTIONS = "-Xmx32m -verbose:gc";
+    private static final String[] DEBUGGEE_OPTIONS = {"-Xmx32m", "-verbose:gc"};
 
     @Override
     protected void runCases() {
         setBreakpoints(System.getProperty("test.src") + "/BreakpointWithFullGC.java", 1);
 
-        List<String> reply = new LinkedList<>();
-
         // get to the first loop breakpoint
-        reply.addAll(jdb.command(JdbCommand.run()));
+        jdb.command(JdbCommand.run());
         // 19 "cont" commands gets us through all the loop breakpoints.
         for (int i = 1; i <= 19; i++) {
-            reply.addAll(jdb.command(JdbCommand.cont()));
+            jdb.command(JdbCommand.cont());
         }
         // get to the last breakpoint
-        reply.addAll(jdb.command(JdbCommand.cont()));
+        jdb.command(JdbCommand.cont());
 
-        new OutputAnalyzer(reply.stream().collect(Collectors.joining(lineSeparator)))
+        jdb.contToExit(1);
+
+        new OutputAnalyzer(jdb.getJdbOutput())
                 // make sure we hit the first breakpoint at least once
                 .stdoutShouldMatch("System\\..*top of loop")
                 // make sure we hit the second breakpoint at least once
                 .stdoutShouldMatch("System\\..*bottom of loop")
                 // make sure we hit the last breakpoint
-                .stdoutShouldMatch("System\\..*end of test")
+                .stdoutShouldMatch("System\\..*end of test");
+        new OutputAnalyzer(jdb.getDebuggeeOutput())
                 // make sure we had at least one full GC
                 // Prior to JDK9-B95, the pattern was 'Full GC'
                 .stdoutShouldContain("Pause Full (System.gc())")
                 // check for error message due to thread ID change
                 .stderrShouldNotContain("Exception in thread \"event-handler\" java.lang.NullPointerException");
-
-        jdb.contToExit(1);
     }
 }
--- a/test/jdk/com/sun/jdi/lib/jdb/Jdb.java	Thu Aug 16 15:00:23 2018 +0200
+++ b/test/jdk/com/sun/jdi/lib/jdb/Jdb.java	Thu Aug 16 10:20:00 2018 -0700
@@ -30,55 +30,91 @@
 import java.util.ArrayList;
 import java.util.Arrays;
 import java.util.Collections;
+import java.util.LinkedList;
 import java.util.List;
 import java.util.concurrent.TimeUnit;
+import java.util.concurrent.TimeoutException;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
 import java.util.stream.Collectors;
 import jdk.test.lib.JDKToolFinder;
+import jdk.test.lib.process.ProcessTools;
 import jdk.test.lib.process.StreamPumper;
 
 public class Jdb {
 
     public static class LaunchOptions {
         public final String debuggeeClass;
-        public String debuggeeOptions;
+        public final List<String> debuggeeOptions = new LinkedList<>();
 
         public LaunchOptions(String debuggeeClass) {
             this.debuggeeClass = debuggeeClass;
         }
-        public LaunchOptions debuggeeOptions(String options) {
-            debuggeeOptions = options;
+        public LaunchOptions addDebuggeeOption(String option) {
+            debuggeeOptions.add(option);
+            return this;
+        }
+        public LaunchOptions addDebuggeeOptions(String[] options) {
+            debuggeeOptions.addAll(Arrays.asList(options));
             return this;
         }
     }
 
     public static Jdb launchLocal(LaunchOptions options) {
-        StringBuilder connOpts = new StringBuilder("com.sun.jdi.CommandLineLaunch:");
-        if (options.debuggeeOptions != null) {
-            connOpts.append("options=")
-                    .append(options.debuggeeOptions)
-                    .append(",");
-        }
-        connOpts.append("main=")
-                .append(options.debuggeeClass);
-
-        return new Jdb("-connect", connOpts.toString());
+        return new Jdb(options);
     }
 
     public static Jdb launchLocal(String debuggeeClass) {
-        return new Jdb("-connect", "com.sun.jdi.CommandLineLaunch:main=" + debuggeeClass);
+        return new Jdb(new LaunchOptions(debuggeeClass));
     }
 
-    public Jdb(String... args) {
+    public Jdb(LaunchOptions options) {
+        /* run debuggee as:
+            java -agentlib:jdwp=transport=dt_socket,address=0,server=n,suspend=y <debuggeeClass>
+        it reports something like : Listening for transport dt_socket at address: 60810
+        after that connect jdb by:
+            jdb -connect com.sun.jdi.SocketAttach:port=60810
+        */
+        // launch debuggee
+        List<String> debuggeeArgs = new LinkedList<>();
+        // specify address=0 to automatically select free port
+        debuggeeArgs.add("-agentlib:jdwp=transport=dt_socket,address=0,server=y,suspend=y");
+        debuggeeArgs.addAll(options.debuggeeOptions);
+        debuggeeArgs.add(options.debuggeeClass);
+        ProcessBuilder pbDebuggee = ProcessTools.createJavaProcessBuilder(true, debuggeeArgs.toArray(new String[0]));
+
+        // debuggeeListen[0] - transport, debuggeeListen[1] - address
+        String[] debuggeeListen = new String[2];
+        Pattern listenRegexp = Pattern.compile("Listening for transport \\b(.+)\\b at address: \\b(\\d+)\\b");
+        try {
+            debuggee = ProcessTools.startProcess("debuggee", pbDebuggee,
+                    s -> debuggeeOutput.add(s),  // output consumer
+                    s -> {  // warm-up predicate
+                        Matcher m = listenRegexp.matcher(s);
+                        if (!m.matches()) {
+                            return false;
+                        }
+                        debuggeeListen[0] = m.group(1);
+                        debuggeeListen[1] = m.group(2);
+                        return true;
+                    },
+                    30, TimeUnit.SECONDS);
+        } catch (IOException | InterruptedException | TimeoutException ex) {
+            throw new RuntimeException("failed to launch debuggee", ex);
+        }
+
+        // launch jdb
         ProcessBuilder pb = new ProcessBuilder(JDKToolFinder.getTestJDKTool("jdb"));
-        pb.command().addAll(Arrays.asList(args));
+        pb.command().add("-connect");
+        pb.command().add("com.sun.jdi.SocketAttach:port=" + debuggeeListen[1]);
         System.out.println("Launching jdb:" + pb.command().stream().collect(Collectors.joining(" ")));
         try {
-            p = pb.start();
+            jdb = pb.start();
         } catch (IOException ex) {
             throw new RuntimeException("failed to launch pdb", ex);
         }
-        StreamPumper stdout = new StreamPumper(p.getInputStream());
-        StreamPumper stderr = new StreamPumper(p.getErrorStream());
+        StreamPumper stdout = new StreamPumper(jdb.getInputStream());
+        StreamPumper stderr = new StreamPumper(jdb.getErrorStream());
 
         stdout.addPump(new StreamPumper.StreamPump(outputHandler));
         stderr.addPump(new StreamPumper.StreamPump(outputHandler));
@@ -86,12 +122,17 @@
         stdout.process();
         stderr.process();
 
-        inputWriter = new PrintWriter(p.getOutputStream(), true);
+        inputWriter = new PrintWriter(jdb.getOutputStream(), true);
+
     }
 
-    private final Process p;
+    private final Process jdb;
+    private final Process debuggee;
     private final OutputHandler outputHandler = new OutputHandler();
     private final PrintWriter inputWriter;
+    // contains all jdb output (to be used by getJdbOutput())
+    private final List<String> jdbOutput = new LinkedList<>();
+    private final List<String> debuggeeOutput = new LinkedList<>();
 
     private static final String lineSeparator = System.getProperty("line.separator");
     // wait time before check jdb output (in ms)
@@ -109,28 +150,40 @@
     public static final String APPLICATION_DISCONNECTED = "The application has been disconnected";
 
 
-    // Check whether the process has been terminated
-    public boolean terminated() {
+    // waits until the process shutdown or crash
+    public boolean waitFor(long timeout, TimeUnit unit) {
         try {
-            p.exitValue();
-            return true;
-        } catch (IllegalThreadStateException e) {
-            return false;
-        }
-    }
-
-    // waits until the process shutdown or crash
-    public boolean waitFor (long timeout, TimeUnit unit) {
-        try {
-            return p.waitFor(timeout, unit);
+            return jdb.waitFor(timeout, unit);
         } catch (InterruptedException e) {
             return false;
         }
     }
 
-    // ugly cleanup
-    public void terminate() {
-        p.destroy();
+    public void shutdown() {
+        // shutdown jdb
+        if (jdb.isAlive()) {
+            try {
+                quit();
+                // wait some time after the command for the process termination
+                waitFor(10, TimeUnit.SECONDS);
+            } finally {
+                if (jdb.isAlive()) {
+                    jdb.destroy();
+                }
+            }
+        }
+        // shutdown debuggee
+        if (debuggee.isAlive()) {
+            try {
+                debuggee.waitFor(10, TimeUnit.SECONDS);
+            } catch (InterruptedException e) {
+                // ignore
+            } finally {
+                if (debuggee.isAlive()) {
+                    debuggee.destroy();
+                }
+            }
+        }
     }
 
 
@@ -168,7 +221,10 @@
         #
         # i.e., the > prompt comes out AFTER the prompt we we need to wait for.
     */
-    public List<String> waitForMsg(String pattern, boolean allowSimplePrompt, int lines, boolean allowExit) {
+    // compile regexp once
+    private final String promptPattern = "[a-zA-Z0-9_-][a-zA-Z0-9_-]*\\[[1-9][0-9]*\\] [ >]*$";
+    private final Pattern promptRegexp = Pattern.compile(promptPattern);
+    public List<String> waitForPrompt(int lines, boolean allowExit) {
         long startTime = System.currentTimeMillis();
         while (System.currentTimeMillis() - startTime < timeout) {
             try {
@@ -190,33 +246,30 @@
             }
             List<String> reply = outputHandler.get();
             for (String line: reply.subList(Math.max(0, reply.size() - lines), reply.size())) {
-                if (line.matches(pattern) || (allowSimplePrompt && line.contains(SIMPLE_PROMPT))) {
+                if (promptRegexp.matcher(line).find()) {
                     logJdb(reply);
                     return outputHandler.reset();
                 }
             }
-            if (terminated()) {
-                logJdb(outputHandler.get());
+            if (!jdb.isAlive()) {
+                // ensure we get the whole output
+                reply = outputHandler.reset();
+                logJdb(reply);
                 if (!allowExit) {
-                    throw new RuntimeException("waitForMsg timed out after " + (timeout/1000)
-                            + " seconds, looking for '" + pattern + "', in " + lines + " lines");
+                    throw new RuntimeException("waitForPrompt timed out after " + (timeout/1000)
+                            + " seconds, looking for '" + promptPattern + "', in " + lines + " lines");
                 }
-                return new ArrayList<>(reply);
+                return reply;
             }
         }
         // timeout
         logJdb(outputHandler.get());
-        throw new RuntimeException("waitForMsg timed out after " + (timeout/1000)
-                + " seconds, looking for '" + pattern + "', in " + lines + " lines");
-    }
-
-    //
-    public List<String> waitForSimplePrompt() {
-        return waitForMsg(SIMPLE_PROMPT, true, 1, false);
+        throw new RuntimeException("waitForPrompt timed out after " + (timeout/1000)
+                + " seconds, looking for '" + promptPattern + "', in " + lines + " lines");
     }
 
     public List<String> command(JdbCommand cmd) {
-        if (terminated()) {
+        if (!jdb.isAlive()) {
             if (cmd.allowExit) {
                 // return remaining output
                 return outputHandler.reset();
@@ -232,7 +285,7 @@
             throw new RuntimeException("Unexpected IO error while writing command '" + cmd.cmd + "' to jdb stdin stream");
         }
 
-        return waitForMsg("[a-zA-Z0-9_-][a-zA-Z0-9_-]*\\[[1-9][0-9]*\\] [ >]*$", cmd.allowSimplePrompt, 1, cmd.allowExit);
+        return waitForPrompt(1, cmd.allowExit);
     }
 
     public List<String> command(String cmd) {
@@ -243,14 +296,14 @@
     public void contToExit(int maxTimes) {
         boolean exited = false;
         JdbCommand cont = JdbCommand.cont().allowExit();
-        for (int i = 0; i < maxTimes && !terminated(); i++) {
+        for (int i = 0; i < maxTimes && jdb.isAlive(); i++) {
             String reply = command(cont).stream().collect(Collectors.joining(lineSeparator));
             if (reply.contains(APPLICATION_EXIT)) {
                 exited = true;
                 break;
             }
         }
-        if (!exited && !terminated()) {
+        if (!exited && jdb.isAlive()) {
             throw new RuntimeException("Debuggee did not exit after " + maxTimes + " <cont> commands");
         }
     }
@@ -265,9 +318,20 @@
     }
 
     private void logJdb(List<String> reply) {
+        jdbOutput.addAll(reply);
         reply.forEach(s -> System.out.println("[jdb] " + s));
     }
 
+    // returns the whole jdb output as a string
+    public String getJdbOutput() {
+        return jdbOutput.stream().collect(Collectors.joining(lineSeparator));
+    }
+
+    // returns the whole debuggee output as a string
+    public String getDebuggeeOutput() {
+        return debuggeeOutput.stream().collect(Collectors.joining(lineSeparator));
+    }
+
     // handler for out/err of the pdb process
     private class OutputHandler extends OutputStream {
         // there are 2 buffers:
--- a/test/jdk/com/sun/jdi/lib/jdb/JdbCommand.java	Thu Aug 16 15:00:23 2018 +0200
+++ b/test/jdk/com/sun/jdi/lib/jdb/JdbCommand.java	Thu Aug 16 10:20:00 2018 -0700
@@ -117,18 +117,12 @@
  */
 public class JdbCommand {
     final String cmd;
-    boolean allowSimplePrompt = false;
     boolean allowExit = false;
 
     public JdbCommand(String cmd) {
         this.cmd = cmd.endsWith(ls) ? cmd.substring(0, cmd.length() - 1) : cmd;
     }
 
-    public JdbCommand allowSimplePrompt() {
-        allowSimplePrompt = true;
-        return this;
-    }
-
     public JdbCommand allowExit() {
         allowExit = true;
         return this;
--- a/test/jdk/com/sun/jdi/lib/jdb/JdbTest.java	Thu Aug 16 15:00:23 2018 +0200
+++ b/test/jdk/com/sun/jdi/lib/jdb/JdbTest.java	Thu Aug 16 10:20:00 2018 -0700
@@ -28,7 +28,6 @@
 import java.nio.file.Paths;
 import java.util.LinkedList;
 import java.util.List;
-import java.util.concurrent.TimeUnit;
 import java.util.stream.Collectors;
 
 public abstract class JdbTest {
@@ -57,24 +56,14 @@
     protected void setup() {
         jdb = Jdb.launchLocal(jdbOptions);
         // wait while jdb is initialized
-        jdb.waitForSimplePrompt();
+        jdb.waitForPrompt(1, false);
 
     }
 
     protected abstract void runCases();
 
     protected void shutdown() {
-        try {
-            if (!jdb.terminated()) {
-                jdb.quit();
-                // wait some time after the command for the process termination
-                jdb.waitFor(10, TimeUnit.SECONDS);
-            }
-        } finally {
-            if (!jdb.terminated()) {
-                jdb.terminate();
-            }
-        }
+        jdb.shutdown();
     }
 
     protected static final String lineSeparator = System.getProperty("line.separator");
@@ -106,8 +95,7 @@
     public static int setBreakpoints(Jdb jdb, String debuggeeClass, String sourcePath, int id) {
         List<Integer> bps = parseBreakpoints(sourcePath, id);
         for (int bp : bps) {
-            // usually we set breakpoints before the debuggee is run, so we allow simple prompt
-            String reply = jdb.command(JdbCommand.stopAt(debuggeeClass, bp).allowSimplePrompt()).stream()
+            String reply = jdb.command(JdbCommand.stopAt(debuggeeClass, bp)).stream()
                     .collect(Collectors.joining("\n"));
             if (reply.contains("Unable to set")) {
                 throw new RuntimeException("jdb failed to set breakpoint at " + debuggeeClass + ":" + bp);