--- jsr166/src/test/tck/JSR166TestCase.java 2015/09/13 16:28:14 1.143 +++ jsr166/src/test/tck/JSR166TestCase.java 2015/10/03 22:20:05 1.157 @@ -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,6 +16,7 @@ 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; @@ -40,6 +42,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; @@ -185,27 +188,53 @@ public class JSR166TestCase extends Test return (regex == null) ? null : Pattern.compile(regex); } - protected void runTest() throws Throwable { + static volatile TestCase currentTestCase; + static { + Runnable checkForWedgedTest = new Runnable() { public void run() { + // avoid spurious reports with enormous runsPerTest + final int timeoutMinutes = Math.max(runsPerTest / 10, 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); + dumpTestThreads(); + } + lastTestCase = currentTestCase; + }}}; + Thread thread = new Thread(checkForWedgedTest, "checkForWedgedTest"); + thread.setDaemon(true); + thread.start(); + } + + 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++) { + if (profileTests) + runTestProfiled(); + else + super.runTest(); } } protected void runTestProfiled() throws Throwable { - // Warmup run, notably to trigger all needed classloading. - super.runTest(); - long t0 = System.nanoTime(); - try { + for (int i = 0; i < 2; i++) { + long startTime = System.nanoTime(); super.runTest(); - } finally { - long elapsedMillis = millisElapsedSince(t0); - if (elapsedMillis >= profileThreshold) + long elapsedMillis = millisElapsedSince(startTime); + if (elapsedMillis < profileThreshold) + break; + // Never report first run of any test; treat it as a + // warmup run, notably to trigger all needed classloading, + if (i > 0) System.out.printf("%n%s: %d%n", toString(), elapsedMillis); } } @@ -455,7 +484,6 @@ public class JSR166TestCase extends Test } else { return new TestSuite(); } - } // Delays for timing-dependent tests, in milliseconds. @@ -513,6 +541,7 @@ public class JSR166TestCase extends Test * the same test have no effect. */ public void threadRecordFailure(Throwable t) { + dumpTestThreads(); threadFailure.compareAndSet(null, t); } @@ -520,6 +549,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. * @@ -547,7 +583,7 @@ 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(); } @@ -556,7 +592,7 @@ public class JSR166TestCase extends Test * Finds missing try { ... } finally { joinPool(e); } */ 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]; @@ -564,12 +600,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"); } /** @@ -582,7 +621,7 @@ public class JSR166TestCase extends Test fail(reason); } catch (AssertionFailedError t) { threadRecordFailure(t); - fail(reason); + throw t; } } @@ -728,9 +767,19 @@ public class JSR166TestCase extends Test } /** + * Allows use of try-with-resources with per-test thread pools. + */ + static class PoolCloser + implements AutoCloseable { + public final T pool; + public PoolCloser(T pool) { this.pool = pool; } + public void close() { joinPool(pool); } + } + + /** * Waits out termination of a thread pool or fails doing so. */ - void joinPool(ExecutorService pool) { + static void joinPool(ExecutorService pool) { try { pool.shutdown(); if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS)) @@ -752,8 +801,9 @@ public class JSR166TestCase extends Test * necessarily individually slow because they must block. */ void testInParallel(Action ... actions) { - ExecutorService pool = Executors.newCachedThreadPool(); - try { + try (PoolCloser poolCloser + = new PoolCloser<>(Executors.newCachedThreadPool())) { + ExecutorService pool = poolCloser.pool; ArrayList> futures = new ArrayList<>(actions.length); for (final Action action : actions) futures.add(pool.submit(new CheckedRunnable() { @@ -766,19 +816,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 ------"); } /** @@ -1223,7 +1285,10 @@ public class JSR166TestCase extends Test public static final String TEST_STRING = "a test string"; public static class StringTask implements Callable { - public String call() { return TEST_STRING; } + final String value; + public StringTask() { this(TEST_STRING); } + public StringTask(String value) { this.value = value; } + public String call() { return value; } } public Callable latchAwaitingStringTask(final CountDownLatch latch) { @@ -1236,6 +1301,13 @@ public class JSR166TestCase extends Test }}; } + public Runnable countDowner(final CountDownLatch latch) { + return new CheckedRunnable() { + public void realRun() throws InterruptedException { + latch.countDown(); + }}; + } + public Runnable awaiter(final CountDownLatch latch) { return new CheckedRunnable() { public void realRun() throws InterruptedException {