--- jsr166/src/test/tck/JSR166TestCase.java 2015/10/05 21:39:39 1.166
+++ jsr166/src/test/tck/JSR166TestCase.java 2015/11/09 05:43:39 1.180
@@ -20,6 +20,8 @@ import java.lang.management.ThreadMXBean
import java.lang.reflect.Constructor;
import java.lang.reflect.Method;
import java.lang.reflect.Modifier;
+import java.nio.file.Files;
+import java.nio.file.Paths;
import java.security.CodeSource;
import java.security.Permission;
import java.security.PermissionCollection;
@@ -52,6 +54,7 @@ import java.util.concurrent.ThreadFactor
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeoutException;
import java.util.concurrent.atomic.AtomicReference;
+import java.util.regex.Matcher;
import java.util.regex.Pattern;
import junit.framework.AssertionFailedError;
@@ -109,8 +112,7 @@ import junit.framework.TestSuite;
* methods as there are exceptions the method can throw. Sometimes
* there are multiple tests per JSR166 method when the different
* "normal" behaviors differ significantly. And sometimes testcases
- * cover multiple methods when they cannot be tested in
- * isolation.
+ * cover multiple methods when they cannot be tested in isolation.
*
*
The documentation style for testcases is to provide as javadoc
* a simple sentence or two describing the property that the testcase
@@ -188,18 +190,29 @@ public class JSR166TestCase extends Test
return (regex == null) ? null : Pattern.compile(regex);
}
+ // Instrumentation to debug very rare, but very annoying hung test runs.
static volatile TestCase currentTestCase;
+ // static volatile int currentRun = 0;
static {
Runnable checkForWedgedTest = new Runnable() { public void run() {
- // avoid spurious reports with enormous runsPerTest
- final int timeoutMinutes = Math.max(runsPerTest / 10, 1);
+ // Avoid spurious reports with enormous runsPerTest.
+ // A single test case run should never take more than 1 second.
+ // But let's cap it at the high end too ...
+ final int timeoutMinutes =
+ Math.min(15, Math.max(runsPerTest / 60, 1));
for (TestCase lastTestCase = currentTestCase;;) {
try { MINUTES.sleep(timeoutMinutes); }
catch (InterruptedException unexpected) { break; }
if (lastTestCase == currentTestCase) {
- System.err.println
- ("Looks like we're stuck running test: "
- + lastTestCase);
+ System.err.printf(
+ "Looks like we're stuck running test: %s%n",
+ lastTestCase);
+// System.err.printf(
+// "Looks like we're stuck running test: %s (%d/%d)%n",
+// lastTestCase, currentRun, runsPerTest);
+// System.err.println("availableProcessors=" +
+// Runtime.getRuntime().availableProcessors());
+// System.err.printf("cpu model = %s%n", cpuModel());
dumpTestThreads();
// one stack dump is probably enough; more would be spam
break;
@@ -211,6 +224,16 @@ public class JSR166TestCase extends Test
thread.start();
}
+// public static String cpuModel() {
+// try {
+// Matcher matcher = Pattern.compile("model name\\s*: (.*)")
+// .matcher(new String(
+// Files.readAllBytes(Paths.get("/proc/cpuinfo")), "UTF-8"));
+// matcher.find();
+// return matcher.group(1);
+// } catch (Exception ex) { return null; }
+// }
+
public void runBare() throws Throwable {
currentTestCase = this;
if (methodFilter == null
@@ -220,6 +243,7 @@ public class JSR166TestCase extends Test
protected void runTest() throws Throwable {
for (int i = 0; i < runsPerTest; i++) {
+ // currentRun = i;
if (profileTests)
runTestProfiled();
else
@@ -248,6 +272,34 @@ public class JSR166TestCase extends Test
main(suite(), args);
}
+ static class PithyResultPrinter extends junit.textui.ResultPrinter {
+ PithyResultPrinter(java.io.PrintStream writer) { super(writer); }
+ long runTime;
+ public void startTest(Test test) {}
+ protected void printHeader(long runTime) {
+ this.runTime = runTime; // defer printing for later
+ }
+ protected void printFooter(TestResult result) {
+ if (result.wasSuccessful()) {
+ getWriter().println("OK (" + result.runCount() + " tests)"
+ + " Time: " + elapsedTimeAsString(runTime));
+ } else {
+ getWriter().println("Time: " + elapsedTimeAsString(runTime));
+ super.printFooter(result);
+ }
+ }
+ }
+
+ /**
+ * Returns a TestRunner that doesn't bother with unnecessary
+ * fluff, like printing a "." for each test case.
+ */
+ static junit.textui.TestRunner newPithyTestRunner() {
+ junit.textui.TestRunner runner = new junit.textui.TestRunner();
+ runner.setPrinter(new PithyResultPrinter(System.out));
+ return runner;
+ }
+
/**
* Runs all unit tests in the given test suite.
* Actual behavior influenced by jsr166.* system properties.
@@ -259,7 +311,7 @@ public class JSR166TestCase extends Test
System.setSecurityManager(new SecurityManager());
}
for (int i = 0; i < suiteRuns; i++) {
- TestResult result = junit.textui.TestRunner.run(suite);
+ TestResult result = newPithyTestRunner().doRun(suite);
if (!result.wasSuccessful())
System.exit(1);
System.gc();
@@ -826,7 +878,7 @@ public class JSR166TestCase extends Test
} finally {
// last resort, for the benefit of subsequent tests
pool.shutdownNow();
- pool.awaitTermination(SMALL_DELAY_MS, MILLISECONDS);
+ pool.awaitTermination(MEDIUM_DELAY_MS, MILLISECONDS);
}
}
} catch (SecurityException ok) {
@@ -1203,7 +1255,7 @@ public class JSR166TestCase extends Test
} finally {
if (t.getState() != Thread.State.TERMINATED) {
t.interrupt();
- fail("Test timed out");
+ threadFail("timed out waiting for thread to terminate");
}
}
}
@@ -1371,7 +1423,9 @@ public class JSR166TestCase extends Test
public void await(CountDownLatch latch) {
try {
- assertTrue(latch.await(LONG_DELAY_MS, MILLISECONDS));
+ if (!latch.await(LONG_DELAY_MS, MILLISECONDS))
+ fail("timed out waiting for CountDownLatch for "
+ + (LONG_DELAY_MS/1000) + " sec");
} catch (Throwable fail) {
threadUnexpectedException(fail);
}
@@ -1379,7 +1433,9 @@ public class JSR166TestCase extends Test
public void await(Semaphore semaphore) {
try {
- assertTrue(semaphore.tryAcquire(LONG_DELAY_MS, MILLISECONDS));
+ if (!semaphore.tryAcquire(LONG_DELAY_MS, MILLISECONDS))
+ fail("timed out waiting for Semaphore for "
+ + (LONG_DELAY_MS/1000) + " sec");
} catch (Throwable fail) {
threadUnexpectedException(fail);
}