--- jsr166/src/test/tck/JSR166TestCase.java 2015/09/25 05:41:29 1.145
+++ jsr166/src/test/tck/JSR166TestCase.java 2015/11/09 06:06:54 1.181
@@ -7,6 +7,7 @@
*/
import static java.util.concurrent.TimeUnit.MILLISECONDS;
+import static java.util.concurrent.TimeUnit.MINUTES;
import static java.util.concurrent.TimeUnit.NANOSECONDS;
import java.io.ByteArrayInputStream;
@@ -15,9 +16,12 @@ import java.io.ObjectInputStream;
import java.io.ObjectOutputStream;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
+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;
@@ -40,6 +44,7 @@ import java.util.concurrent.CyclicBarrie
import java.util.concurrent.ExecutionException;
import java.util.concurrent.Executors;
import java.util.concurrent.ExecutorService;
+import java.util.concurrent.ForkJoinPool;
import java.util.concurrent.Future;
import java.util.concurrent.RecursiveAction;
import java.util.concurrent.RecursiveTask;
@@ -49,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;
@@ -106,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
@@ -170,6 +175,12 @@ public class JSR166TestCase extends Test
private static final int suiteRuns =
Integer.getInteger("jsr166.suiteRuns", 1);
+ /**
+ * The scaling factor to apply to standard delays used in tests.
+ */
+ private static final int delayFactor =
+ Integer.getInteger("jsr166.delay.factor", 1);
+
public JSR166TestCase() { super(); }
public JSR166TestCase(String name) { super(name); }
@@ -185,15 +196,64 @@ public class JSR166TestCase extends Test
return (regex == null) ? null : Pattern.compile(regex);
}
- protected void runTest() throws Throwable {
+ // 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.
+ // 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.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;
+ }
+ lastTestCase = currentTestCase;
+ }}};
+ Thread thread = new Thread(checkForWedgedTest, "checkForWedgedTest");
+ thread.setDaemon(true);
+ 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
- || methodFilter.matcher(toString()).find()) {
- for (int i = 0; i < runsPerTest; i++) {
- if (profileTests)
- runTestProfiled();
- else
- super.runTest();
- }
+ || methodFilter.matcher(toString()).find())
+ super.runBare();
+ }
+
+ protected void runTest() throws Throwable {
+ for (int i = 0; i < runsPerTest; i++) {
+ // currentRun = i;
+ if (profileTests)
+ runTestProfiled();
+ else
+ super.runTest();
}
}
@@ -218,6 +278,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.
@@ -229,7 +317,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();
@@ -456,7 +544,6 @@ public class JSR166TestCase extends Test
} else {
return new TestSuite();
}
-
}
// Delays for timing-dependent tests, in milliseconds.
@@ -467,11 +554,11 @@ public class JSR166TestCase extends Test
public static long LONG_DELAY_MS;
/**
- * Returns the shortest timed delay. This could
- * be reimplemented to use for example a Property.
+ * Returns the shortest timed delay. This can be scaled up for
+ * slow machines using the jsr166.delay.factor system property.
*/
protected long getShortDelay() {
- return 50;
+ return 50 * delayFactor;
}
/**
@@ -514,6 +601,8 @@ public class JSR166TestCase extends Test
* the same test have no effect.
*/
public void threadRecordFailure(Throwable t) {
+ System.err.println(t);
+ dumpTestThreads();
threadFailure.compareAndSet(null, t);
}
@@ -521,6 +610,13 @@ public class JSR166TestCase extends Test
setDelays();
}
+ void tearDownFail(String format, Object... args) {
+ String msg = toString() + ": " + String.format(format, args);
+ System.err.println(msg);
+ dumpTestThreads();
+ throw new AssertionFailedError(msg);
+ }
+
/**
* Extra checks that get done for all test cases.
*
@@ -548,16 +644,16 @@ public class JSR166TestCase extends Test
}
if (Thread.interrupted())
- throw new AssertionFailedError("interrupt status set in main thread");
+ tearDownFail("interrupt status set in main thread");
checkForkJoinPoolThreadLeaks();
}
/**
- * Finds missing try { ... } finally { joinPool(e); }
+ * Finds missing PoolCleaners
*/
void checkForkJoinPoolThreadLeaks() throws InterruptedException {
- Thread[] survivors = new Thread[5];
+ Thread[] survivors = new Thread[7];
int count = Thread.enumerate(survivors);
for (int i = 0; i < count; i++) {
Thread thread = survivors[i];
@@ -565,12 +661,15 @@ public class JSR166TestCase extends Test
if (name.startsWith("ForkJoinPool-")) {
// give thread some time to terminate
thread.join(LONG_DELAY_MS);
- if (!thread.isAlive()) continue;
- throw new AssertionFailedError
- (String.format("Found leaked ForkJoinPool thread test=%s thread=%s%n",
- toString(), name));
+ if (thread.isAlive())
+ tearDownFail("Found leaked ForkJoinPool thread thread=%s",
+ thread);
}
}
+
+ if (!ForkJoinPool.commonPool()
+ .awaitQuiescence(LONG_DELAY_MS, MILLISECONDS))
+ tearDownFail("ForkJoin common pool thread stuck");
}
/**
@@ -583,7 +682,7 @@ public class JSR166TestCase extends Test
fail(reason);
} catch (AssertionFailedError t) {
threadRecordFailure(t);
- fail(reason);
+ throw t;
}
}
@@ -710,37 +809,88 @@ public class JSR166TestCase extends Test
/**
* Delays, via Thread.sleep, for the given millisecond delay, but
* if the sleep is shorter than specified, may re-sleep or yield
- * until time elapses.
+ * until time elapses. Ensures that the given time, as measured
+ * by System.nanoTime(), has elapsed.
*/
static void delay(long millis) throws InterruptedException {
- long startTime = System.nanoTime();
- long ns = millis * 1000 * 1000;
- for (;;) {
+ long nanos = millis * (1000 * 1000);
+ final long wakeupTime = System.nanoTime() + nanos;
+ do {
if (millis > 0L)
Thread.sleep(millis);
else // too short to sleep
Thread.yield();
- long d = ns - (System.nanoTime() - startTime);
- if (d > 0L)
- millis = d / (1000 * 1000);
- else
- break;
+ nanos = wakeupTime - System.nanoTime();
+ millis = nanos / (1000 * 1000);
+ } while (nanos >= 0L);
+ }
+
+ /**
+ * Allows use of try-with-resources with per-test thread pools.
+ */
+ class PoolCleaner implements AutoCloseable {
+ private final ExecutorService pool;
+ public PoolCleaner(ExecutorService pool) { this.pool = pool; }
+ public void close() { joinPool(pool); }
+ }
+
+ /**
+ * An extension of PoolCleaner that has an action to release the pool.
+ */
+ class PoolCleanerWithReleaser extends PoolCleaner {
+ private final Runnable releaser;
+ public PoolCleanerWithReleaser(ExecutorService pool, Runnable releaser) {
+ super(pool);
+ this.releaser = releaser;
+ }
+ public void close() {
+ try {
+ releaser.run();
+ } finally {
+ super.close();
+ }
}
}
+ PoolCleaner cleaner(ExecutorService pool) {
+ return new PoolCleaner(pool);
+ }
+
+ PoolCleaner cleaner(ExecutorService pool, Runnable releaser) {
+ return new PoolCleanerWithReleaser(pool, releaser);
+ }
+
+ PoolCleaner cleaner(ExecutorService pool, CountDownLatch latch) {
+ return new PoolCleanerWithReleaser(pool, releaser(latch));
+ }
+
+ Runnable releaser(final CountDownLatch latch) {
+ return new Runnable() { public void run() {
+ do { latch.countDown(); }
+ while (latch.getCount() > 0);
+ }};
+ }
+
/**
* Waits out termination of a thread pool or fails doing so.
*/
void joinPool(ExecutorService pool) {
try {
pool.shutdown();
- if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS))
- fail("ExecutorService " + pool +
- " did not terminate in a timely manner");
+ if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS)) {
+ try {
+ threadFail("ExecutorService " + pool +
+ " did not terminate in a timely manner");
+ } finally {
+ // last resort, for the benefit of subsequent tests
+ pool.shutdownNow();
+ pool.awaitTermination(MEDIUM_DELAY_MS, MILLISECONDS);
+ }
+ }
} catch (SecurityException ok) {
// Allowed in case test doesn't have privs
} catch (InterruptedException fail) {
- fail("Unexpected InterruptedException");
+ threadFail("Unexpected InterruptedException");
}
}
@@ -754,7 +904,7 @@ public class JSR166TestCase extends Test
*/
void testInParallel(Action ... actions) {
ExecutorService pool = Executors.newCachedThreadPool();
- try {
+ try (PoolCleaner cleaner = cleaner(pool)) {
ArrayList> futures = new ArrayList<>(actions.length);
for (final Action action : actions)
futures.add(pool.submit(new CheckedRunnable() {
@@ -767,19 +917,31 @@ public class JSR166TestCase extends Test
} catch (Exception ex) {
threadUnexpectedException(ex);
}
- } finally {
- joinPool(pool);
}
}
/**
- * A debugging tool to print all stack traces, as jstack does.
+ * A debugging tool to print stack traces of most threads, as jstack does.
+ * Uninteresting threads are filtered out.
*/
- static void printAllStackTraces() {
- for (ThreadInfo info :
- ManagementFactory.getThreadMXBean()
- .dumpAllThreads(true, true))
+ static void dumpTestThreads() {
+ ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
+ System.err.println("------ stacktrace dump start ------");
+ for (ThreadInfo info : threadMXBean.dumpAllThreads(true, true)) {
+ String name = info.getThreadName();
+ if ("Signal Dispatcher".equals(name))
+ continue;
+ if ("Reference Handler".equals(name)
+ && info.getLockName().startsWith("java.lang.ref.Reference$Lock"))
+ continue;
+ if ("Finalizer".equals(name)
+ && info.getLockName().startsWith("java.lang.ref.ReferenceQueue$Lock"))
+ continue;
+ if ("checkForWedgedTest".equals(name))
+ continue;
System.err.print(info);
+ }
+ System.err.println("------ stacktrace dump end ------");
}
/**
@@ -799,7 +961,7 @@ public class JSR166TestCase extends Test
delay(millis);
assertTrue(thread.isAlive());
} catch (InterruptedException fail) {
- fail("Unexpected InterruptedException");
+ threadFail("Unexpected InterruptedException");
}
}
@@ -821,7 +983,7 @@ public class JSR166TestCase extends Test
for (Thread thread : threads)
assertTrue(thread.isAlive());
} catch (InterruptedException fail) {
- fail("Unexpected InterruptedException");
+ threadFail("Unexpected InterruptedException");
}
}
@@ -1099,7 +1261,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");
}
}
}
@@ -1240,16 +1402,36 @@ public class JSR166TestCase extends Test
}};
}
- public Runnable awaiter(final CountDownLatch latch) {
+ public Runnable countDowner(final CountDownLatch latch) {
return new CheckedRunnable() {
public void realRun() throws InterruptedException {
- await(latch);
+ latch.countDown();
}};
}
+ class LatchAwaiter extends CheckedRunnable {
+ static final int NEW = 0;
+ static final int RUNNING = 1;
+ static final int DONE = 2;
+ final CountDownLatch latch;
+ int state = NEW;
+ LatchAwaiter(CountDownLatch latch) { this.latch = latch; }
+ public void realRun() throws InterruptedException {
+ state = 1;
+ await(latch);
+ state = 2;
+ }
+ }
+
+ public LatchAwaiter awaiter(CountDownLatch latch) {
+ return new LatchAwaiter(latch);
+ }
+
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);
}
@@ -1257,7 +1439,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);
}