ViewVC Help
View File | Revision Log | Show Annotations | Download File | Root Listing
root/jsr166/jsr166/src/test/tck/JSR166TestCase.java
(Generate patch)

Comparing jsr166/src/test/tck/JSR166TestCase.java (file contents):
Revision 1.144 by jsr166, Mon Sep 14 03:14:01 2015 UTC vs.
Revision 1.180 by jsr166, Mon Nov 9 05:43:39 2015 UTC

# Line 7 | Line 7
7   */
8  
9   import static java.util.concurrent.TimeUnit.MILLISECONDS;
10 + import static java.util.concurrent.TimeUnit.MINUTES;
11   import static java.util.concurrent.TimeUnit.NANOSECONDS;
12  
13   import java.io.ByteArrayInputStream;
# Line 15 | Line 16 | import java.io.ObjectInputStream;
16   import java.io.ObjectOutputStream;
17   import java.lang.management.ManagementFactory;
18   import java.lang.management.ThreadInfo;
19 + import java.lang.management.ThreadMXBean;
20   import java.lang.reflect.Constructor;
21   import java.lang.reflect.Method;
22   import java.lang.reflect.Modifier;
23 + import java.nio.file.Files;
24 + import java.nio.file.Paths;
25   import java.security.CodeSource;
26   import java.security.Permission;
27   import java.security.PermissionCollection;
# Line 40 | Line 44 | import java.util.concurrent.CyclicBarrie
44   import java.util.concurrent.ExecutionException;
45   import java.util.concurrent.Executors;
46   import java.util.concurrent.ExecutorService;
47 + import java.util.concurrent.ForkJoinPool;
48   import java.util.concurrent.Future;
49   import java.util.concurrent.RecursiveAction;
50   import java.util.concurrent.RecursiveTask;
# Line 49 | Line 54 | import java.util.concurrent.ThreadFactor
54   import java.util.concurrent.ThreadPoolExecutor;
55   import java.util.concurrent.TimeoutException;
56   import java.util.concurrent.atomic.AtomicReference;
57 + import java.util.regex.Matcher;
58   import java.util.regex.Pattern;
59  
60   import junit.framework.AssertionFailedError;
# Line 106 | Line 112 | import junit.framework.TestSuite;
112   * methods as there are exceptions the method can throw. Sometimes
113   * there are multiple tests per JSR166 method when the different
114   * "normal" behaviors differ significantly. And sometimes testcases
115 < * cover multiple methods when they cannot be tested in
110 < * isolation.
115 > * cover multiple methods when they cannot be tested in isolation.
116   *
117   * <li>The documentation style for testcases is to provide as javadoc
118   * a simple sentence or two describing the property that the testcase
# Line 185 | Line 190 | public class JSR166TestCase extends Test
190          return (regex == null) ? null : Pattern.compile(regex);
191      }
192  
193 <    protected void runTest() throws Throwable {
193 >    // Instrumentation to debug very rare, but very annoying hung test runs.
194 >    static volatile TestCase currentTestCase;
195 >    // static volatile int currentRun = 0;
196 >    static {
197 >        Runnable checkForWedgedTest = new Runnable() { public void run() {
198 >            // Avoid spurious reports with enormous runsPerTest.
199 >            // A single test case run should never take more than 1 second.
200 >            // But let's cap it at the high end too ...
201 >            final int timeoutMinutes =
202 >                Math.min(15, Math.max(runsPerTest / 60, 1));
203 >            for (TestCase lastTestCase = currentTestCase;;) {
204 >                try { MINUTES.sleep(timeoutMinutes); }
205 >                catch (InterruptedException unexpected) { break; }
206 >                if (lastTestCase == currentTestCase) {
207 >                    System.err.printf(
208 >                        "Looks like we're stuck running test: %s%n",
209 >                        lastTestCase);
210 > //                     System.err.printf(
211 > //                         "Looks like we're stuck running test: %s (%d/%d)%n",
212 > //                         lastTestCase, currentRun, runsPerTest);
213 > //                     System.err.println("availableProcessors=" +
214 > //                         Runtime.getRuntime().availableProcessors());
215 > //                     System.err.printf("cpu model = %s%n", cpuModel());
216 >                    dumpTestThreads();
217 >                    // one stack dump is probably enough; more would be spam
218 >                    break;
219 >                }
220 >                lastTestCase = currentTestCase;
221 >            }}};
222 >        Thread thread = new Thread(checkForWedgedTest, "checkForWedgedTest");
223 >        thread.setDaemon(true);
224 >        thread.start();
225 >    }
226 >
227 > //     public static String cpuModel() {
228 > //         try {
229 > //             Matcher matcher = Pattern.compile("model name\\s*: (.*)")
230 > //                 .matcher(new String(
231 > //                      Files.readAllBytes(Paths.get("/proc/cpuinfo")), "UTF-8"));
232 > //             matcher.find();
233 > //             return matcher.group(1);
234 > //         } catch (Exception ex) { return null; }
235 > //     }
236 >
237 >    public void runBare() throws Throwable {
238 >        currentTestCase = this;
239          if (methodFilter == null
240 <            || methodFilter.matcher(toString()).find()) {
241 <            for (int i = 0; i < runsPerTest; i++) {
242 <                if (profileTests)
243 <                    runTestProfiled();
244 <                else
245 <                    super.runTest();
246 <            }
240 >            || methodFilter.matcher(toString()).find())
241 >            super.runBare();
242 >    }
243 >
244 >    protected void runTest() throws Throwable {
245 >        for (int i = 0; i < runsPerTest; i++) {
246 >            // currentRun = i;
247 >            if (profileTests)
248 >                runTestProfiled();
249 >            else
250 >                super.runTest();
251          }
252      }
253  
254      protected void runTestProfiled() throws Throwable {
255 <        // Warmup run, notably to trigger all needed classloading.
256 <        super.runTest();
203 <        long t0 = System.nanoTime();
204 <        try {
255 >        for (int i = 0; i < 2; i++) {
256 >            long startTime = System.nanoTime();
257              super.runTest();
258 <        } finally {
259 <            long elapsedMillis = millisElapsedSince(t0);
260 <            if (elapsedMillis >= profileThreshold)
258 >            long elapsedMillis = millisElapsedSince(startTime);
259 >            if (elapsedMillis < profileThreshold)
260 >                break;
261 >            // Never report first run of any test; treat it as a
262 >            // warmup run, notably to trigger all needed classloading,
263 >            if (i > 0)
264                  System.out.printf("%n%s: %d%n", toString(), elapsedMillis);
265          }
266      }
# Line 217 | Line 272 | public class JSR166TestCase extends Test
272          main(suite(), args);
273      }
274  
275 +    static class PithyResultPrinter extends junit.textui.ResultPrinter {
276 +        PithyResultPrinter(java.io.PrintStream writer) { super(writer); }
277 +        long runTime;
278 +        public void startTest(Test test) {}
279 +        protected void printHeader(long runTime) {
280 +            this.runTime = runTime; // defer printing for later
281 +        }
282 +        protected void printFooter(TestResult result) {
283 +            if (result.wasSuccessful()) {
284 +                getWriter().println("OK (" + result.runCount() + " tests)"
285 +                    + "  Time: " + elapsedTimeAsString(runTime));
286 +            } else {
287 +                getWriter().println("Time: " + elapsedTimeAsString(runTime));
288 +                super.printFooter(result);
289 +            }
290 +        }
291 +    }
292 +
293 +    /**
294 +     * Returns a TestRunner that doesn't bother with unnecessary
295 +     * fluff, like printing a "." for each test case.
296 +     */
297 +    static junit.textui.TestRunner newPithyTestRunner() {
298 +        junit.textui.TestRunner runner = new junit.textui.TestRunner();
299 +        runner.setPrinter(new PithyResultPrinter(System.out));
300 +        return runner;
301 +    }
302 +
303      /**
304       * Runs all unit tests in the given test suite.
305       * Actual behavior influenced by jsr166.* system properties.
# Line 228 | Line 311 | public class JSR166TestCase extends Test
311              System.setSecurityManager(new SecurityManager());
312          }
313          for (int i = 0; i < suiteRuns; i++) {
314 <            TestResult result = junit.textui.TestRunner.run(suite);
314 >            TestResult result = newPithyTestRunner().doRun(suite);
315              if (!result.wasSuccessful())
316                  System.exit(1);
317              System.gc();
# Line 455 | Line 538 | public class JSR166TestCase extends Test
538          } else {
539              return new TestSuite();
540          }
458
541      }
542  
543      // Delays for timing-dependent tests, in milliseconds.
# Line 513 | Line 595 | public class JSR166TestCase extends Test
595       * the same test have no effect.
596       */
597      public void threadRecordFailure(Throwable t) {
598 +        System.err.println(t);
599 +        dumpTestThreads();
600          threadFailure.compareAndSet(null, t);
601      }
602  
# Line 520 | Line 604 | public class JSR166TestCase extends Test
604          setDelays();
605      }
606  
607 +    void tearDownFail(String format, Object... args) {
608 +        String msg = toString() + ": " + String.format(format, args);
609 +        System.err.println(msg);
610 +        dumpTestThreads();
611 +        throw new AssertionFailedError(msg);
612 +    }
613 +
614      /**
615       * Extra checks that get done for all test cases.
616       *
# Line 547 | Line 638 | public class JSR166TestCase extends Test
638          }
639  
640          if (Thread.interrupted())
641 <            throw new AssertionFailedError("interrupt status set in main thread");
641 >            tearDownFail("interrupt status set in main thread");
642  
643          checkForkJoinPoolThreadLeaks();
644      }
645  
646      /**
647 <     * Finds missing try { ... } finally { joinPool(e); }
647 >     * Finds missing PoolCleaners
648       */
649      void checkForkJoinPoolThreadLeaks() throws InterruptedException {
650 <        Thread[] survivors = new Thread[5];
650 >        Thread[] survivors = new Thread[7];
651          int count = Thread.enumerate(survivors);
652          for (int i = 0; i < count; i++) {
653              Thread thread = survivors[i];
# Line 564 | Line 655 | public class JSR166TestCase extends Test
655              if (name.startsWith("ForkJoinPool-")) {
656                  // give thread some time to terminate
657                  thread.join(LONG_DELAY_MS);
658 <                if (!thread.isAlive()) continue;
659 <                throw new AssertionFailedError
660 <                    (String.format("Found leaked ForkJoinPool thread test=%s thread=%s%n",
570 <                                   toString(), name));
658 >                if (thread.isAlive())
659 >                    tearDownFail("Found leaked ForkJoinPool thread thread=%s",
660 >                                 thread);
661              }
662          }
663 +
664 +        if (!ForkJoinPool.commonPool()
665 +            .awaitQuiescence(LONG_DELAY_MS, MILLISECONDS))
666 +            tearDownFail("ForkJoin common pool thread stuck");
667      }
668  
669      /**
# Line 582 | Line 676 | public class JSR166TestCase extends Test
676              fail(reason);
677          } catch (AssertionFailedError t) {
678              threadRecordFailure(t);
679 <            fail(reason);
679 >            throw t;
680          }
681      }
682  
# Line 709 | Line 803 | public class JSR166TestCase extends Test
803      /**
804       * Delays, via Thread.sleep, for the given millisecond delay, but
805       * if the sleep is shorter than specified, may re-sleep or yield
806 <     * until time elapses.
806 >     * until time elapses.  Ensures that the given time, as measured
807 >     * by System.nanoTime(), has elapsed.
808       */
809      static void delay(long millis) throws InterruptedException {
810 <        long startTime = System.nanoTime();
811 <        long ns = millis * 1000 * 1000;
812 <        for (;;) {
810 >        long nanos = millis * (1000 * 1000);
811 >        final long wakeupTime = System.nanoTime() + nanos;
812 >        do {
813              if (millis > 0L)
814                  Thread.sleep(millis);
815              else // too short to sleep
816                  Thread.yield();
817 <            long d = ns - (System.nanoTime() - startTime);
818 <            if (d > 0L)
819 <                millis = d / (1000 * 1000);
820 <            else
821 <                break;
817 >            nanos = wakeupTime - System.nanoTime();
818 >            millis = nanos / (1000 * 1000);
819 >        } while (nanos >= 0L);
820 >    }
821 >
822 >    /**
823 >     * Allows use of try-with-resources with per-test thread pools.
824 >     */
825 >    class PoolCleaner implements AutoCloseable {
826 >        private final ExecutorService pool;
827 >        public PoolCleaner(ExecutorService pool) { this.pool = pool; }
828 >        public void close() { joinPool(pool); }
829 >    }
830 >
831 >    /**
832 >     * An extension of PoolCleaner that has an action to release the pool.
833 >     */
834 >    class PoolCleanerWithReleaser extends PoolCleaner {
835 >        private final Runnable releaser;
836 >        public PoolCleanerWithReleaser(ExecutorService pool, Runnable releaser) {
837 >            super(pool);
838 >            this.releaser = releaser;
839 >        }
840 >        public void close() {
841 >            try {
842 >                releaser.run();
843 >            } finally {
844 >                super.close();
845 >            }
846          }
847      }
848  
849 +    PoolCleaner cleaner(ExecutorService pool) {
850 +        return new PoolCleaner(pool);
851 +    }
852 +
853 +    PoolCleaner cleaner(ExecutorService pool, Runnable releaser) {
854 +        return new PoolCleanerWithReleaser(pool, releaser);
855 +    }
856 +
857 +    PoolCleaner cleaner(ExecutorService pool, CountDownLatch latch) {
858 +        return new PoolCleanerWithReleaser(pool, releaser(latch));
859 +    }
860 +
861 +    Runnable releaser(final CountDownLatch latch) {
862 +        return new Runnable() { public void run() {
863 +            do { latch.countDown(); }
864 +            while (latch.getCount() > 0);
865 +        }};
866 +    }
867 +
868      /**
869       * Waits out termination of a thread pool or fails doing so.
870       */
871      void joinPool(ExecutorService pool) {
872          try {
873              pool.shutdown();
874 <            if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS))
875 <                fail("ExecutorService " + pool +
876 <                     " did not terminate in a timely manner");
874 >            if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS)) {
875 >                try {
876 >                    threadFail("ExecutorService " + pool +
877 >                               " did not terminate in a timely manner");
878 >                } finally {
879 >                    // last resort, for the benefit of subsequent tests
880 >                    pool.shutdownNow();
881 >                    pool.awaitTermination(MEDIUM_DELAY_MS, MILLISECONDS);
882 >                }
883 >            }
884          } catch (SecurityException ok) {
885              // Allowed in case test doesn't have privs
886          } catch (InterruptedException fail) {
887 <            fail("Unexpected InterruptedException");
887 >            threadFail("Unexpected InterruptedException");
888          }
889      }
890  
# Line 753 | Line 898 | public class JSR166TestCase extends Test
898       */
899      void testInParallel(Action ... actions) {
900          ExecutorService pool = Executors.newCachedThreadPool();
901 <        try {
901 >        try (PoolCleaner cleaner = cleaner(pool)) {
902              ArrayList<Future<?>> futures = new ArrayList<>(actions.length);
903              for (final Action action : actions)
904                  futures.add(pool.submit(new CheckedRunnable() {
# Line 766 | Line 911 | public class JSR166TestCase extends Test
911                  } catch (Exception ex) {
912                      threadUnexpectedException(ex);
913                  }
769        } finally {
770            joinPool(pool);
914          }
915      }
916  
917      /**
918 <     * A debugging tool to print all stack traces, as jstack does.
918 >     * A debugging tool to print stack traces of most threads, as jstack does.
919 >     * Uninteresting threads are filtered out.
920       */
921 <    static void printAllStackTraces() {
922 <        for (ThreadInfo info :
923 <                 ManagementFactory.getThreadMXBean()
924 <                 .dumpAllThreads(true, true))
921 >    static void dumpTestThreads() {
922 >        ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
923 >        System.err.println("------ stacktrace dump start ------");
924 >        for (ThreadInfo info : threadMXBean.dumpAllThreads(true, true)) {
925 >            String name = info.getThreadName();
926 >            if ("Signal Dispatcher".equals(name))
927 >                continue;
928 >            if ("Reference Handler".equals(name)
929 >                && info.getLockName().startsWith("java.lang.ref.Reference$Lock"))
930 >                continue;
931 >            if ("Finalizer".equals(name)
932 >                && info.getLockName().startsWith("java.lang.ref.ReferenceQueue$Lock"))
933 >                continue;
934 >            if ("checkForWedgedTest".equals(name))
935 >                continue;
936              System.err.print(info);
937 +        }
938 +        System.err.println("------ stacktrace dump end ------");
939      }
940  
941      /**
# Line 798 | Line 955 | public class JSR166TestCase extends Test
955              delay(millis);
956              assertTrue(thread.isAlive());
957          } catch (InterruptedException fail) {
958 <            fail("Unexpected InterruptedException");
958 >            threadFail("Unexpected InterruptedException");
959          }
960      }
961  
# Line 820 | Line 977 | public class JSR166TestCase extends Test
977              for (Thread thread : threads)
978                  assertTrue(thread.isAlive());
979          } catch (InterruptedException fail) {
980 <            fail("Unexpected InterruptedException");
980 >            threadFail("Unexpected InterruptedException");
981          }
982      }
983  
# Line 1098 | Line 1255 | public class JSR166TestCase extends Test
1255          } finally {
1256              if (t.getState() != Thread.State.TERMINATED) {
1257                  t.interrupt();
1258 <                fail("Test timed out");
1258 >                threadFail("timed out waiting for thread to terminate");
1259              }
1260          }
1261      }
# Line 1239 | Line 1396 | public class JSR166TestCase extends Test
1396              }};
1397      }
1398  
1399 <    public Runnable awaiter(final CountDownLatch latch) {
1399 >    public Runnable countDowner(final CountDownLatch latch) {
1400          return new CheckedRunnable() {
1401              public void realRun() throws InterruptedException {
1402 <                await(latch);
1402 >                latch.countDown();
1403              }};
1404      }
1405  
1406 +    class LatchAwaiter extends CheckedRunnable {
1407 +        static final int NEW = 0;
1408 +        static final int RUNNING = 1;
1409 +        static final int DONE = 2;
1410 +        final CountDownLatch latch;
1411 +        int state = NEW;
1412 +        LatchAwaiter(CountDownLatch latch) { this.latch = latch; }
1413 +        public void realRun() throws InterruptedException {
1414 +            state = 1;
1415 +            await(latch);
1416 +            state = 2;
1417 +        }
1418 +    }
1419 +
1420 +    public LatchAwaiter awaiter(CountDownLatch latch) {
1421 +        return new LatchAwaiter(latch);
1422 +    }
1423 +
1424      public void await(CountDownLatch latch) {
1425          try {
1426 <            assertTrue(latch.await(LONG_DELAY_MS, MILLISECONDS));
1426 >            if (!latch.await(LONG_DELAY_MS, MILLISECONDS))
1427 >                fail("timed out waiting for CountDownLatch for "
1428 >                     + (LONG_DELAY_MS/1000) + " sec");
1429          } catch (Throwable fail) {
1430              threadUnexpectedException(fail);
1431          }
# Line 1256 | Line 1433 | public class JSR166TestCase extends Test
1433  
1434      public void await(Semaphore semaphore) {
1435          try {
1436 <            assertTrue(semaphore.tryAcquire(LONG_DELAY_MS, MILLISECONDS));
1436 >            if (!semaphore.tryAcquire(LONG_DELAY_MS, MILLISECONDS))
1437 >                fail("timed out waiting for Semaphore for "
1438 >                     + (LONG_DELAY_MS/1000) + " sec");
1439          } catch (Throwable fail) {
1440              threadUnexpectedException(fail);
1441          }

Diff Legend

Removed lines
+ Added lines
< Changed lines
> Changed lines