stan/jdk-24
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

8283222: improve diagnosability of runtime/8176717/TestInheritFD.java timeouts

Browse Source 
Reviewed-by: dholmes, hseigel
This commit is contained in:
Daniel D. Daugherty 2022-03-23 19:18:57 +00:00
parent 138460c004
commit 0b11b576a2
1 changed files with 177 additions and 31 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

208
test/hotspot/jtreg/runtime/8176717/TestInheritFD.java
View File

@ -21,6 +21,7 @@
* questions. * questions.
*/ */
import static java.lang.Character.isDigit;
import static java.lang.Long.parseLong; import static java.lang.Long.parseLong;
import static java.lang.System.getProperty; import static java.lang.System.getProperty;
import static java.nio.file.Files.readAllBytes; import static java.nio.file.Files.readAllBytes;
@ -40,6 +41,7 @@ import java.io.FileOutputStream;
import java.io.IOException; import java.io.IOException;
import java.io.InputStreamReader; import java.io.InputStreamReader;
import java.util.Collection; import java.util.Collection;
import java.util.concurrent.TimeUnit;
import java.util.Optional; import java.util.Optional;
import java.util.stream.Stream; import java.util.stream.Stream;
@ -60,17 +62,18 @@ import java.util.stream.Stream;
* *
* This test is performed in three steps. The first VM starts a second VM with * This test is performed in three steps. The first VM starts a second VM with
* gc logging enabled. The second VM starts a third VM and redirects the third * gc logging enabled. The second VM starts a third VM and redirects the third
* VMs output to the first VM, it then exits and hopefully closes its log file. * VMs output to the first VM. The second VM then exits and hopefully closes
* its log file.
* *
* The third VM waits for the second to exit and close its log file. After that, * The third VM waits for the second to exit and close its log file.
* the third VM tries to rename the log file of the second VM. If it succeeds in * On Windows, the third VM tries to rename the log file of the second VM.
* doing so it means that the third VM did not inherit the open log file * If it succeeds in doing so it means that the third VM did not inherit
* (windows can not rename opened files easily) * the open log file (windows cannot rename opened files easily).
* On unix like systems, the third VM uses "lsof" for verification.
* *
* The third VM communicates the success to rename the file by printing "CLOSED * The third VM communicates success by printing "RETAINS FD". The first VM
* FD". The first VM checks that the string was printed by the third VM. * waits for the third VM to exit and checks that the string was printed by
* * the third VM.
* On unix like systems "lsof" is used.
*/ */
public class TestInheritFD { public class TestInheritFD {
@ -80,9 +83,145 @@ public class TestInheritFD {
public static final String EXIT = "VM RESULT => VM EXIT"; public static final String EXIT = "VM RESULT => VM EXIT";
public static final String LOG_SUFFIX = ".strangelogsuffixthatcanbecheckedfor"; public static final String LOG_SUFFIX = ".strangelogsuffixthatcanbecheckedfor";
public static final String USER_DIR = System.getProperty("user.dir"); public static final String USER_DIR = System.getProperty("user.dir");
public static final String LSOF_PID_PREFIX = " VM lsof pid=";
public static final String SECOND_VM_PID_PREFIX = "Second VM pid=";
public static final String THIRD_VM_PID_PREFIX = "Third VM pid=";
public static final String THIRD_VM_WAITING_PREFIX = "Third VM waiting for second VM pid=";
public static float timeoutFactor = Float.parseFloat(System.getProperty("test.timeout.factor", "1.0"));
public static long subProcessTimeout = (long)(15L * timeoutFactor);
// Extract a pid from the specified String at the specified start offset.
private static long extractPidFromStringOffset(String str, int start) {
int end;
for (end = start; end < str.length(); end++) {
if (!isDigit(str.charAt(end))) {
break;
}
}
if (start == end) { // no digits at all
return -1;
}
return parseLong(str.substring(start, end));
}
// Wait for the sub-process pids identified in commFile to finish executing.
// Returns true if RETAINS_FD was found in the commFile and false otherwise.
private static boolean waitForSubPids(File commFile) throws Exception {
String out = "";
int sleepCnt = 0;
long secondVMPID = -1;
long secondVMlsofPID = -1;
long thirdVMPID = -1;
long thirdVMlsofPID = -1;
// Only have to gather info until the doneWithPattern shows up in the output:
String doneWithPattern;
if (isWindows()) {
doneWithPattern = THIRD_VM_PID_PREFIX;
} else {
doneWithPattern = "Third" + LSOF_PID_PREFIX;
}
do {
out = new String(readAllBytes(commFile.toPath()));
if (secondVMPID == -1) {
int ind = out.indexOf(SECOND_VM_PID_PREFIX);
if (ind != -1) {
int startPid = ind + SECOND_VM_PID_PREFIX.length();
secondVMPID = extractPidFromStringOffset(out, startPid);
System.out.println("secondVMPID=" + secondVMPID);
}
}
if (!isWindows() && secondVMlsofPID == -1) {
String prefix = "Second" + LSOF_PID_PREFIX;
int ind = out.indexOf(prefix);
if (ind != -1) {
int startPid = ind + prefix.length();
secondVMlsofPID = extractPidFromStringOffset(out, startPid);
System.out.println("secondVMlsofPID=" + secondVMlsofPID);
}
}
if (thirdVMPID == -1) {
int ind = out.indexOf(THIRD_VM_PID_PREFIX);
if (ind != -1) {
int startPid = ind + THIRD_VM_PID_PREFIX.length();
thirdVMPID = extractPidFromStringOffset(out, startPid);
System.out.println("thirdVMPID=" + thirdVMPID);
}
}
if (!isWindows() && thirdVMlsofPID == -1) {
String prefix = "Third" + LSOF_PID_PREFIX;
int ind = out.indexOf(prefix);
if (ind != -1) {
int startPid = ind + prefix.length();
thirdVMlsofPID = extractPidFromStringOffset(out, startPid);
System.out.println("thirdVMlsofPID=" + thirdVMlsofPID);
}
}
Thread.sleep(100);
sleepCnt++;
} while (!out.contains(doneWithPattern) && !out.contains(EXIT));
System.out.println("Called Thread.sleep(100) " + sleepCnt + " times.");
long subPids[] = new long[4]; // At most 4 pids to check.
String subNames[] = new String[4]; // At most 4 names for those pids.
int ind = 0;
if (!isWindows() && secondVMlsofPID != -1) {
// The second VM's lsof cmd should be the first non-windows sub-process to finish:
subPids[ind] = secondVMlsofPID;
subNames[ind] = "second VM lsof";
ind++;
}
// The second VM should the second non-windows or first windows sub-process to finish:
subPids[ind] = secondVMPID;
subNames[ind] = "second VM";
ind++;
if (!isWindows() && thirdVMlsofPID != -1) {
// The third VM's lsof cmd should be the third non-windows sub-process to finish:
subPids[ind] = thirdVMlsofPID;
subNames[ind] = "third VM lsof";
ind++;
}
// The third VM should the last sub-process to finish:
subPids[ind] = thirdVMPID;
subNames[ind] = "third VM";
ind++;
if (isWindows()) {
// No lsof pids on windows so we use fewer array slots.
// Make sure they are marked as not used.
for (; ind < subPids.length; ind++) {
subPids[ind] = -1;
}
}
try {
for (ind = 0; ind < subPids.length; ind++) {
if (subPids[ind] == -1) {
continue;
}
System.out.print("subs[" + ind + "]={pid=" + subPids[ind] + ", name=" + subNames[ind] + "}");
ProcessHandle.of(subPids[ind]).ifPresent(handle -> handle.onExit().orTimeout(subProcessTimeout, TimeUnit.SECONDS).join());
System.out.println(" finished.");
}
} catch (Exception e) {
// Terminate the "subs" line from above:
System.out.println(" Exception was thrown while trying to join() subPids: " + e.toString());
throw e;
} finally {
// Reread to get everything in the commFile:
out = new String(readAllBytes(commFile.toPath()));
System.out.println("<BEGIN commFile contents>");
System.out.println(out);
System.out.println("<END commFile contents>");
}
return out.contains(RETAINS_FD);
}
// first VM // first VM
public static void main(String[] args) throws Exception { public static void main(String[] args) throws Exception {
System.out.println("subProcessTimeout=" + subProcessTimeout + " seconds.");
System.out.println("First VM starts.");
String logPath = Utils.createTempFile("logging", LOG_SUFFIX).toFile().getName(); String logPath = Utils.createTempFile("logging", LOG_SUFFIX).toFile().getName();
File commFile = Utils.createTempFile("communication", ".txt").toFile(); File commFile = Utils.createTempFile("communication", ".txt").toFile();
@ -99,24 +238,18 @@ public class TestInheritFD {
pb.redirectOutput(commFile); // use temp file to communicate between processes pb.redirectOutput(commFile); // use temp file to communicate between processes
pb.start(); pb.start();
String out = ""; if (waitForSubPids(commFile)) {
do { System.out.println("Log file was not inherited by third VM.");
out = new String(readAllBytes(commFile.toPath()));
Thread.sleep(100);
System.out.println("SLEEP 100 millis");
} while (!out.contains(EXIT));
System.out.println(out);
if (out.contains(RETAINS_FD)) {
System.out.println("Log file was not inherited by third VM");
} else { } else {
throw new RuntimeException("could not match: " + RETAINS_FD); throw new RuntimeException("Log file was leaked to the third VM.");
} }
System.out.println("First VM ends.");
} }
static class VMStartedWithLogging { static class VMStartedWithLogging {
// second VM // second VM
public static void main(String[] args) throws IOException, InterruptedException { public static void main(String[] args) throws IOException, InterruptedException {
System.out.println(SECOND_VM_PID_PREFIX + ProcessHandle.current().pid());
ProcessBuilder pb = createJavaProcessBuilder( ProcessBuilder pb = createJavaProcessBuilder(
"-Dtest.jdk=" + getProperty("test.jdk"), "-Dtest.jdk=" + getProperty("test.jdk"),
VMShouldNotInheritFileDescriptors.class.getName(), VMShouldNotInheritFileDescriptors.class.getName(),
@ -126,30 +259,43 @@ public class TestInheritFD {
pb.start(); pb.start();
if (!isWindows()) { if (!isWindows()) {
System.out.println("(Second VM) Open file descriptors:\n" + outputContainingFilenames().stream().collect(joining("\n"))); System.out.println("(Second VM) Open file descriptors:\n" + outputContainingFilenames("Second").stream().collect(joining("\n")));
} }
if (false) { // Enable to simulate a timeout in the second VM.
Thread.sleep(300 * 1000);
}
System.out.println("Second VM ends.");
} }
} }
static class VMShouldNotInheritFileDescriptors { static class VMShouldNotInheritFileDescriptors {
// third VM // third VM
public static void main(String[] args) throws InterruptedException { public static void main(String[] args) throws InterruptedException {
System.out.println(THIRD_VM_PID_PREFIX + ProcessHandle.current().pid());
try { try {
File logFile = new File(args[0]); File logFile = new File(args[0]);
long parentPid = parseLong(args[1]); long parentPid = parseLong(args[1]);
fakeLeakyJVM(false); // for debugging of test case fakeLeakyJVM(false); // for debugging of test case
System.out.println(THIRD_VM_WAITING_PREFIX + parentPid);
ProcessHandle.of(parentPid).ifPresent(handle -> handle.onExit().orTimeout(subProcessTimeout, TimeUnit.SECONDS).join());
if (isWindows()) { if (isWindows()) {
windows(logFile, parentPid); windows(logFile);
} else { } else {
Collection<String> output = outputContainingFilenames(); Collection<String> output = outputContainingFilenames("Third");
System.out.println("(Third VM) Open file descriptors:\n" + output.stream().collect(joining("\n"))); System.out.println("(Third VM) Open file descriptors:\n" + output.stream().collect(joining("\n")));
System.out.println(findOpenLogFile(output) ? LEAKS_FD : RETAINS_FD); System.out.println(findOpenLogFile(output) ? LEAKS_FD : RETAINS_FD);
} }
if (false) { // Enable to simulate a timeout in the third VM.
Thread.sleep(300 * 1000);
}
} catch (Exception e) { } catch (Exception e) {
System.out.println(e.toString()); System.out.println("Exception was thrown: " + e.toString());
throw e;
} finally { } finally {
System.out.println(EXIT); System.out.println(EXIT);
System.out.println("Third VM ends.");
} }
} }
} }
@ -165,9 +311,11 @@ public class TestInheritFD {
} }
} }
static Stream<String> run(String... args){ static Stream<String> runLsof(String whichVM, String... args){
try { try {
return new BufferedReader(new InputStreamReader(new ProcessBuilder(args).start().getInputStream())).lines(); Process lsof = new ProcessBuilder(args).start();
System.out.println(whichVM + LSOF_PID_PREFIX + lsof.pid());
return new BufferedReader(new InputStreamReader(lsof.getInputStream())).lines();
} catch (IOException e) { } catch (IOException e) {
throw new RuntimeException(e); throw new RuntimeException(e);
} }
@ -186,12 +334,12 @@ public class TestInheritFD {
return lsofCommandCache; return lsofCommandCache;
} }
static Collection<String> outputContainingFilenames() { static Collection<String> outputContainingFilenames(String whichVM) {
long pid = ProcessHandle.current().pid(); long pid = ProcessHandle.current().pid();
String[] command = lsofCommand().orElseThrow(() -> new RuntimeException("lsof like command not found")); String[] command = lsofCommand().orElseThrow(() -> new RuntimeException("lsof like command not found"));
// Only search the directory in which the VM is running (user.dir property). // Only search the directory in which the VM is running (user.dir property).
System.out.println("using command: " + command[0] + " -a +d " + USER_DIR + " " + command[1] + " " + pid); System.out.println("using command: " + command[0] + " -a +d " + USER_DIR + " " + command[1] + " " + pid);
return run(command[0], "-a", "+d", USER_DIR, command[1], "" + pid).collect(toList()); return runLsof(whichVM, command[0], "-a", "+d", USER_DIR, command[1], "" + pid).collect(toList());
} }
static boolean findOpenLogFile(Collection<String> fileNames) { static boolean findOpenLogFile(Collection<String> fileNames) {
@ -208,9 +356,7 @@ public class TestInheritFD {
.isPresent(); .isPresent();
} }
static void windows(File f, long parentPid) throws InterruptedException { static void windows(File f) throws InterruptedException {
System.out.println("waiting for pid: " + parentPid);
ProcessHandle.of(parentPid).ifPresent(handle -> handle.onExit().join());
System.out.println("trying to rename file to the same name: " + f); System.out.println("trying to rename file to the same name: " + f);
System.out.println(f.renameTo(f) ? RETAINS_FD : LEAKS_FD); // this parts communicates a closed file descriptor by printing "VM RESULT => RETAINS FD" System.out.println(f.renameTo(f) ? RETAINS_FD : LEAKS_FD); // this parts communicates a closed file descriptor by printing "VM RESULT => RETAINS FD"
} }