8209517: com/sun/jdi/BreakpointWithFullGC.java fails with timeout

Reviewed-by: dcubed, mikael
This commit is contained in:
Alex Menkov 2018-08-16 10:20:00 -07:00
parent 19a7a3b69e
commit d2a9e11aeb
4 changed files with 132 additions and 89 deletions

@ -38,9 +38,7 @@ import lib.jdb.JdbCommand;
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 @@ public class BreakpointWithFullGC extends JdbTest {
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);
}
}

@ -30,55 +30,91 @@ import java.io.PrintWriter;
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 @@ public class Jdb {
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 class Jdb {
public static final String APPLICATION_DISCONNECTED = "The application has been disconnected";
// Check whether the process has been terminated
public boolean terminated() {
try {
p.exitValue();
return true;
} catch (IllegalThreadStateException e) {
return false;
}
}
// waits until the process shutdown or crash
public boolean waitFor (long timeout, TimeUnit unit) {
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 @@ public class Jdb {
#
# 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 @@ public class Jdb {
}
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 @@ public class Jdb {
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 class Jdb {
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 @@ public class Jdb {
}
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:

@ -117,18 +117,12 @@ import java.util.stream.Collectors;
*/
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;

@ -28,7 +28,6 @@ import java.nio.file.Files;
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 @@ public abstract class JdbTest {
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 abstract class JdbTest {
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);