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.170 by jsr166, Thu Oct 8 22:39:57 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;
# Line 40 | Line 42 | import java.util.concurrent.CyclicBarrie
42   import java.util.concurrent.ExecutionException;
43   import java.util.concurrent.Executors;
44   import java.util.concurrent.ExecutorService;
45 + import java.util.concurrent.ForkJoinPool;
46   import java.util.concurrent.Future;
47   import java.util.concurrent.RecursiveAction;
48   import java.util.concurrent.RecursiveTask;
# Line 185 | Line 188 | public class JSR166TestCase extends Test
188          return (regex == null) ? null : Pattern.compile(regex);
189      }
190  
191 <    protected void runTest() throws Throwable {
191 >    // Instrumentation to debug very rare, but very annoying hung test runs.
192 >    static volatile TestCase currentTestCase;
193 >    static volatile int currentRun = 0;
194 >    static {
195 >        Runnable checkForWedgedTest = new Runnable() { public void run() {
196 >            // avoid spurious reports with enormous runsPerTest
197 >            final int timeoutMinutes = Math.max(runsPerTest / 10, 1);
198 >            for (TestCase lastTestCase = currentTestCase;;) {
199 >                try { MINUTES.sleep(timeoutMinutes); }
200 >                catch (InterruptedException unexpected) { break; }
201 >                if (lastTestCase == currentTestCase) {
202 >                    System.err.printf(
203 >                        "Looks like we're stuck running test: %s (%d/%d)%n",
204 >                        lastTestCase, currentRun, runsPerTest);
205 >                    System.err.println
206 >                        ("Looks like we're stuck running test: "
207 >                         + lastTestCase + " (" + currentRun + "/" + runsPerTest + ")");
208 >                    System.err.println("availableProcessors=" +
209 >                        Runtime.getRuntime().availableProcessors());
210 >                    dumpTestThreads();
211 >                    // one stack dump is probably enough; more would be spam
212 >                    break;
213 >                }
214 >                lastTestCase = currentTestCase;
215 >            }}};
216 >        Thread thread = new Thread(checkForWedgedTest, "checkForWedgedTest");
217 >        thread.setDaemon(true);
218 >        thread.start();
219 >    }
220 >
221 >    public void runBare() throws Throwable {
222 >        currentTestCase = this;
223          if (methodFilter == null
224 <            || methodFilter.matcher(toString()).find()) {
225 <            for (int i = 0; i < runsPerTest; i++) {
226 <                if (profileTests)
227 <                    runTestProfiled();
228 <                else
229 <                    super.runTest();
230 <            }
224 >            || methodFilter.matcher(toString()).find())
225 >            super.runBare();
226 >    }
227 >
228 >    protected void runTest() throws Throwable {
229 >        for (int i = 0; i < runsPerTest; i++) {
230 >            currentRun = i;
231 >            if (profileTests)
232 >                runTestProfiled();
233 >            else
234 >                super.runTest();
235          }
236      }
237  
238      protected void runTestProfiled() throws Throwable {
239 <        // Warmup run, notably to trigger all needed classloading.
240 <        super.runTest();
203 <        long t0 = System.nanoTime();
204 <        try {
239 >        for (int i = 0; i < 2; i++) {
240 >            long startTime = System.nanoTime();
241              super.runTest();
242 <        } finally {
243 <            long elapsedMillis = millisElapsedSince(t0);
244 <            if (elapsedMillis >= profileThreshold)
242 >            long elapsedMillis = millisElapsedSince(startTime);
243 >            if (elapsedMillis < profileThreshold)
244 >                break;
245 >            // Never report first run of any test; treat it as a
246 >            // warmup run, notably to trigger all needed classloading,
247 >            if (i > 0)
248                  System.out.printf("%n%s: %d%n", toString(), elapsedMillis);
249          }
250      }
# Line 455 | Line 494 | public class JSR166TestCase extends Test
494          } else {
495              return new TestSuite();
496          }
458
497      }
498  
499      // Delays for timing-dependent tests, in milliseconds.
# Line 513 | Line 551 | public class JSR166TestCase extends Test
551       * the same test have no effect.
552       */
553      public void threadRecordFailure(Throwable t) {
554 +        System.err.println(t);
555 +        dumpTestThreads();
556          threadFailure.compareAndSet(null, t);
557      }
558  
# Line 520 | Line 560 | public class JSR166TestCase extends Test
560          setDelays();
561      }
562  
563 +    void tearDownFail(String format, Object... args) {
564 +        String msg = toString() + ": " + String.format(format, args);
565 +        System.err.println(msg);
566 +        dumpTestThreads();
567 +        throw new AssertionFailedError(msg);
568 +    }
569 +
570      /**
571       * Extra checks that get done for all test cases.
572       *
# Line 547 | Line 594 | public class JSR166TestCase extends Test
594          }
595  
596          if (Thread.interrupted())
597 <            throw new AssertionFailedError("interrupt status set in main thread");
597 >            tearDownFail("interrupt status set in main thread");
598  
599          checkForkJoinPoolThreadLeaks();
600      }
601  
602      /**
603 <     * Finds missing try { ... } finally { joinPool(e); }
603 >     * Finds missing PoolCleaners
604       */
605      void checkForkJoinPoolThreadLeaks() throws InterruptedException {
606 <        Thread[] survivors = new Thread[5];
606 >        Thread[] survivors = new Thread[7];
607          int count = Thread.enumerate(survivors);
608          for (int i = 0; i < count; i++) {
609              Thread thread = survivors[i];
# Line 564 | Line 611 | public class JSR166TestCase extends Test
611              if (name.startsWith("ForkJoinPool-")) {
612                  // give thread some time to terminate
613                  thread.join(LONG_DELAY_MS);
614 <                if (!thread.isAlive()) continue;
615 <                throw new AssertionFailedError
616 <                    (String.format("Found leaked ForkJoinPool thread test=%s thread=%s%n",
570 <                                   toString(), name));
614 >                if (thread.isAlive())
615 >                    tearDownFail("Found leaked ForkJoinPool thread thread=%s",
616 >                                 thread);
617              }
618          }
619 +
620 +        if (!ForkJoinPool.commonPool()
621 +            .awaitQuiescence(LONG_DELAY_MS, MILLISECONDS))
622 +            tearDownFail("ForkJoin common pool thread stuck");
623      }
624  
625      /**
# Line 582 | Line 632 | public class JSR166TestCase extends Test
632              fail(reason);
633          } catch (AssertionFailedError t) {
634              threadRecordFailure(t);
635 <            fail(reason);
635 >            throw t;
636          }
637      }
638  
# Line 709 | Line 759 | public class JSR166TestCase extends Test
759      /**
760       * Delays, via Thread.sleep, for the given millisecond delay, but
761       * if the sleep is shorter than specified, may re-sleep or yield
762 <     * until time elapses.
762 >     * until time elapses.  Ensures that the given time, as measured
763 >     * by System.nanoTime(), has elapsed.
764       */
765      static void delay(long millis) throws InterruptedException {
766 <        long startTime = System.nanoTime();
767 <        long ns = millis * 1000 * 1000;
768 <        for (;;) {
766 >        long nanos = millis * (1000 * 1000);
767 >        final long wakeupTime = System.nanoTime() + nanos;
768 >        do {
769              if (millis > 0L)
770                  Thread.sleep(millis);
771              else // too short to sleep
772                  Thread.yield();
773 <            long d = ns - (System.nanoTime() - startTime);
774 <            if (d > 0L)
775 <                millis = d / (1000 * 1000);
776 <            else
777 <                break;
773 >            nanos = wakeupTime - System.nanoTime();
774 >            millis = nanos / (1000 * 1000);
775 >        } while (nanos >= 0L);
776 >    }
777 >
778 >    /**
779 >     * Allows use of try-with-resources with per-test thread pools.
780 >     */
781 >    class PoolCleaner implements AutoCloseable {
782 >        private final ExecutorService pool;
783 >        public PoolCleaner(ExecutorService pool) { this.pool = pool; }
784 >        public void close() { joinPool(pool); }
785 >    }
786 >
787 >    /**
788 >     * An extension of PoolCleaner that has an action to release the pool.
789 >     */
790 >    class PoolCleanerWithReleaser extends PoolCleaner {
791 >        private final Runnable releaser;
792 >        public PoolCleanerWithReleaser(ExecutorService pool, Runnable releaser) {
793 >            super(pool);
794 >            this.releaser = releaser;
795 >        }
796 >        public void close() {
797 >            try {
798 >                releaser.run();
799 >            } finally {
800 >                super.close();
801 >            }
802          }
803      }
804  
805 +    PoolCleaner cleaner(ExecutorService pool) {
806 +        return new PoolCleaner(pool);
807 +    }
808 +
809 +    PoolCleaner cleaner(ExecutorService pool, Runnable releaser) {
810 +        return new PoolCleanerWithReleaser(pool, releaser);
811 +    }
812 +
813 +    PoolCleaner cleaner(ExecutorService pool, CountDownLatch latch) {
814 +        return new PoolCleanerWithReleaser(pool, releaser(latch));
815 +    }
816 +
817 +    Runnable releaser(final CountDownLatch latch) {
818 +        return new Runnable() { public void run() {
819 +            do { latch.countDown(); }
820 +            while (latch.getCount() > 0);
821 +        }};
822 +    }
823 +
824      /**
825       * Waits out termination of a thread pool or fails doing so.
826       */
827      void joinPool(ExecutorService pool) {
828          try {
829              pool.shutdown();
830 <            if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS))
831 <                fail("ExecutorService " + pool +
832 <                     " did not terminate in a timely manner");
830 >            if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS)) {
831 >                try {
832 >                    threadFail("ExecutorService " + pool +
833 >                               " did not terminate in a timely manner");
834 >                } finally {
835 >                    // last resort, for the benefit of subsequent tests
836 >                    pool.shutdownNow();
837 >                    pool.awaitTermination(MEDIUM_DELAY_MS, MILLISECONDS);
838 >                }
839 >            }
840          } catch (SecurityException ok) {
841              // Allowed in case test doesn't have privs
842          } catch (InterruptedException fail) {
843 <            fail("Unexpected InterruptedException");
843 >            threadFail("Unexpected InterruptedException");
844          }
845      }
846  
# Line 753 | Line 854 | public class JSR166TestCase extends Test
854       */
855      void testInParallel(Action ... actions) {
856          ExecutorService pool = Executors.newCachedThreadPool();
857 <        try {
857 >        try (PoolCleaner cleaner = cleaner(pool)) {
858              ArrayList<Future<?>> futures = new ArrayList<>(actions.length);
859              for (final Action action : actions)
860                  futures.add(pool.submit(new CheckedRunnable() {
# Line 766 | Line 867 | public class JSR166TestCase extends Test
867                  } catch (Exception ex) {
868                      threadUnexpectedException(ex);
869                  }
769        } finally {
770            joinPool(pool);
870          }
871      }
872  
873      /**
874 <     * A debugging tool to print all stack traces, as jstack does.
874 >     * A debugging tool to print stack traces of most threads, as jstack does.
875 >     * Uninteresting threads are filtered out.
876       */
877 <    static void printAllStackTraces() {
878 <        for (ThreadInfo info :
879 <                 ManagementFactory.getThreadMXBean()
880 <                 .dumpAllThreads(true, true))
877 >    static void dumpTestThreads() {
878 >        ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
879 >        System.err.println("------ stacktrace dump start ------");
880 >        for (ThreadInfo info : threadMXBean.dumpAllThreads(true, true)) {
881 >            String name = info.getThreadName();
882 >            if ("Signal Dispatcher".equals(name))
883 >                continue;
884 >            if ("Reference Handler".equals(name)
885 >                && info.getLockName().startsWith("java.lang.ref.Reference$Lock"))
886 >                continue;
887 >            if ("Finalizer".equals(name)
888 >                && info.getLockName().startsWith("java.lang.ref.ReferenceQueue$Lock"))
889 >                continue;
890 >            if ("checkForWedgedTest".equals(name))
891 >                continue;
892              System.err.print(info);
893 +        }
894 +        System.err.println("------ stacktrace dump end ------");
895      }
896  
897      /**
# Line 798 | Line 911 | public class JSR166TestCase extends Test
911              delay(millis);
912              assertTrue(thread.isAlive());
913          } catch (InterruptedException fail) {
914 <            fail("Unexpected InterruptedException");
914 >            threadFail("Unexpected InterruptedException");
915          }
916      }
917  
# Line 820 | Line 933 | public class JSR166TestCase extends Test
933              for (Thread thread : threads)
934                  assertTrue(thread.isAlive());
935          } catch (InterruptedException fail) {
936 <            fail("Unexpected InterruptedException");
936 >            threadFail("Unexpected InterruptedException");
937          }
938      }
939  
# Line 1098 | Line 1211 | public class JSR166TestCase extends Test
1211          } finally {
1212              if (t.getState() != Thread.State.TERMINATED) {
1213                  t.interrupt();
1214 <                fail("Test timed out");
1214 >                threadFail("Test timed out");
1215              }
1216          }
1217      }
# Line 1239 | Line 1352 | public class JSR166TestCase extends Test
1352              }};
1353      }
1354  
1355 <    public Runnable awaiter(final CountDownLatch latch) {
1355 >    public Runnable countDowner(final CountDownLatch latch) {
1356          return new CheckedRunnable() {
1357              public void realRun() throws InterruptedException {
1358 <                await(latch);
1358 >                latch.countDown();
1359              }};
1360      }
1361  
1362 +    class LatchAwaiter extends CheckedRunnable {
1363 +        static final int NEW = 0;
1364 +        static final int RUNNING = 1;
1365 +        static final int DONE = 2;
1366 +        final CountDownLatch latch;
1367 +        int state = NEW;
1368 +        LatchAwaiter(CountDownLatch latch) { this.latch = latch; }
1369 +        public void realRun() throws InterruptedException {
1370 +            state = 1;
1371 +            await(latch);
1372 +            state = 2;
1373 +        }
1374 +    }
1375 +
1376 +    public LatchAwaiter awaiter(CountDownLatch latch) {
1377 +        return new LatchAwaiter(latch);
1378 +    }
1379 +
1380      public void await(CountDownLatch latch) {
1381          try {
1382              assertTrue(latch.await(LONG_DELAY_MS, MILLISECONDS));

Diff Legend

Removed lines
+ Added lines
< Changed lines
> Changed lines