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.172 by jsr166, Fri Oct 9 01:26:36 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 185 | Line 191 | public class JSR166TestCase extends Test
191          return (regex == null) ? null : Pattern.compile(regex);
192      }
193  
194 <    protected void runTest() throws Throwable {
194 >    // Instrumentation to debug very rare, but very annoying hung test runs.
195 >    static volatile TestCase currentTestCase;
196 >    static volatile int currentRun = 0;
197 >    static {
198 >        Runnable checkForWedgedTest = new Runnable() { public void run() {
199 >            // avoid spurious reports with enormous runsPerTest
200 >            final int timeoutMinutes = Math.max(runsPerTest / 10, 1);
201 >            for (TestCase lastTestCase = currentTestCase;;) {
202 >                try { MINUTES.sleep(timeoutMinutes); }
203 >                catch (InterruptedException unexpected) { break; }
204 >                if (lastTestCase == currentTestCase) {
205 >                    System.err.printf(
206 >                        "Looks like we're stuck running test: %s (%d/%d)%n",
207 >                        lastTestCase, currentRun, runsPerTest);
208 >                    System.err.println("availableProcessors=" +
209 >                        Runtime.getRuntime().availableProcessors());
210 >                    System.err.printf("cpu model = %s%n", cpuModel());
211 >                    dumpTestThreads();
212 >                    // one stack dump is probably enough; more would be spam
213 >                    break;
214 >                }
215 >                lastTestCase = currentTestCase;
216 >            }}};
217 >        Thread thread = new Thread(checkForWedgedTest, "checkForWedgedTest");
218 >        thread.setDaemon(true);
219 >        thread.start();
220 >    }
221 >
222 >    public static String cpuModel() {
223 >        try {
224 >            Matcher matcher = Pattern.compile("model name\\s*: (.*)")
225 >                .matcher(new String(
226 >                     Files.readAllBytes(Paths.get("/proc/cpuinfo")), "UTF-8"));
227 >            matcher.find();
228 >            return matcher.group(1);
229 >        } catch (Exception ex) { return null; }
230 >    }
231 >
232 >    public void runBare() throws Throwable {
233 >        currentTestCase = this;
234          if (methodFilter == null
235 <            || methodFilter.matcher(toString()).find()) {
236 <            for (int i = 0; i < runsPerTest; i++) {
237 <                if (profileTests)
238 <                    runTestProfiled();
239 <                else
240 <                    super.runTest();
241 <            }
235 >            || methodFilter.matcher(toString()).find())
236 >            super.runBare();
237 >    }
238 >
239 >    protected void runTest() throws Throwable {
240 >        for (int i = 0; i < runsPerTest; i++) {
241 >            currentRun = i;
242 >            if (profileTests)
243 >                runTestProfiled();
244 >            else
245 >                super.runTest();
246          }
247      }
248  
249      protected void runTestProfiled() throws Throwable {
250 <        // Warmup run, notably to trigger all needed classloading.
251 <        super.runTest();
203 <        long t0 = System.nanoTime();
204 <        try {
250 >        for (int i = 0; i < 2; i++) {
251 >            long startTime = System.nanoTime();
252              super.runTest();
253 <        } finally {
254 <            long elapsedMillis = millisElapsedSince(t0);
255 <            if (elapsedMillis >= profileThreshold)
253 >            long elapsedMillis = millisElapsedSince(startTime);
254 >            if (elapsedMillis < profileThreshold)
255 >                break;
256 >            // Never report first run of any test; treat it as a
257 >            // warmup run, notably to trigger all needed classloading,
258 >            if (i > 0)
259                  System.out.printf("%n%s: %d%n", toString(), elapsedMillis);
260          }
261      }
# Line 455 | Line 505 | public class JSR166TestCase extends Test
505          } else {
506              return new TestSuite();
507          }
458
508      }
509  
510      // Delays for timing-dependent tests, in milliseconds.
# Line 513 | Line 562 | public class JSR166TestCase extends Test
562       * the same test have no effect.
563       */
564      public void threadRecordFailure(Throwable t) {
565 +        System.err.println(t);
566 +        dumpTestThreads();
567          threadFailure.compareAndSet(null, t);
568      }
569  
# Line 520 | Line 571 | public class JSR166TestCase extends Test
571          setDelays();
572      }
573  
574 +    void tearDownFail(String format, Object... args) {
575 +        String msg = toString() + ": " + String.format(format, args);
576 +        System.err.println(msg);
577 +        dumpTestThreads();
578 +        throw new AssertionFailedError(msg);
579 +    }
580 +
581      /**
582       * Extra checks that get done for all test cases.
583       *
# Line 547 | Line 605 | public class JSR166TestCase extends Test
605          }
606  
607          if (Thread.interrupted())
608 <            throw new AssertionFailedError("interrupt status set in main thread");
608 >            tearDownFail("interrupt status set in main thread");
609  
610          checkForkJoinPoolThreadLeaks();
611      }
612  
613      /**
614 <     * Finds missing try { ... } finally { joinPool(e); }
614 >     * Finds missing PoolCleaners
615       */
616      void checkForkJoinPoolThreadLeaks() throws InterruptedException {
617 <        Thread[] survivors = new Thread[5];
617 >        Thread[] survivors = new Thread[7];
618          int count = Thread.enumerate(survivors);
619          for (int i = 0; i < count; i++) {
620              Thread thread = survivors[i];
# Line 564 | Line 622 | public class JSR166TestCase extends Test
622              if (name.startsWith("ForkJoinPool-")) {
623                  // give thread some time to terminate
624                  thread.join(LONG_DELAY_MS);
625 <                if (!thread.isAlive()) continue;
626 <                throw new AssertionFailedError
627 <                    (String.format("Found leaked ForkJoinPool thread test=%s thread=%s%n",
570 <                                   toString(), name));
625 >                if (thread.isAlive())
626 >                    tearDownFail("Found leaked ForkJoinPool thread thread=%s",
627 >                                 thread);
628              }
629          }
630 +
631 +        if (!ForkJoinPool.commonPool()
632 +            .awaitQuiescence(LONG_DELAY_MS, MILLISECONDS))
633 +            tearDownFail("ForkJoin common pool thread stuck");
634      }
635  
636      /**
# Line 582 | Line 643 | public class JSR166TestCase extends Test
643              fail(reason);
644          } catch (AssertionFailedError t) {
645              threadRecordFailure(t);
646 <            fail(reason);
646 >            throw t;
647          }
648      }
649  
# Line 709 | Line 770 | public class JSR166TestCase extends Test
770      /**
771       * Delays, via Thread.sleep, for the given millisecond delay, but
772       * if the sleep is shorter than specified, may re-sleep or yield
773 <     * until time elapses.
773 >     * until time elapses.  Ensures that the given time, as measured
774 >     * by System.nanoTime(), has elapsed.
775       */
776      static void delay(long millis) throws InterruptedException {
777 <        long startTime = System.nanoTime();
778 <        long ns = millis * 1000 * 1000;
779 <        for (;;) {
777 >        long nanos = millis * (1000 * 1000);
778 >        final long wakeupTime = System.nanoTime() + nanos;
779 >        do {
780              if (millis > 0L)
781                  Thread.sleep(millis);
782              else // too short to sleep
783                  Thread.yield();
784 <            long d = ns - (System.nanoTime() - startTime);
785 <            if (d > 0L)
786 <                millis = d / (1000 * 1000);
787 <            else
788 <                break;
784 >            nanos = wakeupTime - System.nanoTime();
785 >            millis = nanos / (1000 * 1000);
786 >        } while (nanos >= 0L);
787 >    }
788 >
789 >    /**
790 >     * Allows use of try-with-resources with per-test thread pools.
791 >     */
792 >    class PoolCleaner implements AutoCloseable {
793 >        private final ExecutorService pool;
794 >        public PoolCleaner(ExecutorService pool) { this.pool = pool; }
795 >        public void close() { joinPool(pool); }
796 >    }
797 >
798 >    /**
799 >     * An extension of PoolCleaner that has an action to release the pool.
800 >     */
801 >    class PoolCleanerWithReleaser extends PoolCleaner {
802 >        private final Runnable releaser;
803 >        public PoolCleanerWithReleaser(ExecutorService pool, Runnable releaser) {
804 >            super(pool);
805 >            this.releaser = releaser;
806 >        }
807 >        public void close() {
808 >            try {
809 >                releaser.run();
810 >            } finally {
811 >                super.close();
812 >            }
813          }
814      }
815  
816 +    PoolCleaner cleaner(ExecutorService pool) {
817 +        return new PoolCleaner(pool);
818 +    }
819 +
820 +    PoolCleaner cleaner(ExecutorService pool, Runnable releaser) {
821 +        return new PoolCleanerWithReleaser(pool, releaser);
822 +    }
823 +
824 +    PoolCleaner cleaner(ExecutorService pool, CountDownLatch latch) {
825 +        return new PoolCleanerWithReleaser(pool, releaser(latch));
826 +    }
827 +
828 +    Runnable releaser(final CountDownLatch latch) {
829 +        return new Runnable() { public void run() {
830 +            do { latch.countDown(); }
831 +            while (latch.getCount() > 0);
832 +        }};
833 +    }
834 +
835      /**
836       * Waits out termination of a thread pool or fails doing so.
837       */
838      void joinPool(ExecutorService pool) {
839          try {
840              pool.shutdown();
841 <            if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS))
842 <                fail("ExecutorService " + pool +
843 <                     " did not terminate in a timely manner");
841 >            if (!pool.awaitTermination(2 * LONG_DELAY_MS, MILLISECONDS)) {
842 >                try {
843 >                    threadFail("ExecutorService " + pool +
844 >                               " did not terminate in a timely manner");
845 >                } finally {
846 >                    // last resort, for the benefit of subsequent tests
847 >                    pool.shutdownNow();
848 >                    pool.awaitTermination(MEDIUM_DELAY_MS, MILLISECONDS);
849 >                }
850 >            }
851          } catch (SecurityException ok) {
852              // Allowed in case test doesn't have privs
853          } catch (InterruptedException fail) {
854 <            fail("Unexpected InterruptedException");
854 >            threadFail("Unexpected InterruptedException");
855          }
856      }
857  
# Line 753 | Line 865 | public class JSR166TestCase extends Test
865       */
866      void testInParallel(Action ... actions) {
867          ExecutorService pool = Executors.newCachedThreadPool();
868 <        try {
868 >        try (PoolCleaner cleaner = cleaner(pool)) {
869              ArrayList<Future<?>> futures = new ArrayList<>(actions.length);
870              for (final Action action : actions)
871                  futures.add(pool.submit(new CheckedRunnable() {
# Line 766 | Line 878 | public class JSR166TestCase extends Test
878                  } catch (Exception ex) {
879                      threadUnexpectedException(ex);
880                  }
769        } finally {
770            joinPool(pool);
881          }
882      }
883  
884      /**
885 <     * A debugging tool to print all stack traces, as jstack does.
885 >     * A debugging tool to print stack traces of most threads, as jstack does.
886 >     * Uninteresting threads are filtered out.
887       */
888 <    static void printAllStackTraces() {
889 <        for (ThreadInfo info :
890 <                 ManagementFactory.getThreadMXBean()
891 <                 .dumpAllThreads(true, true))
888 >    static void dumpTestThreads() {
889 >        ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
890 >        System.err.println("------ stacktrace dump start ------");
891 >        for (ThreadInfo info : threadMXBean.dumpAllThreads(true, true)) {
892 >            String name = info.getThreadName();
893 >            if ("Signal Dispatcher".equals(name))
894 >                continue;
895 >            if ("Reference Handler".equals(name)
896 >                && info.getLockName().startsWith("java.lang.ref.Reference$Lock"))
897 >                continue;
898 >            if ("Finalizer".equals(name)
899 >                && info.getLockName().startsWith("java.lang.ref.ReferenceQueue$Lock"))
900 >                continue;
901 >            if ("checkForWedgedTest".equals(name))
902 >                continue;
903              System.err.print(info);
904 +        }
905 +        System.err.println("------ stacktrace dump end ------");
906      }
907  
908      /**
# Line 798 | Line 922 | public class JSR166TestCase extends Test
922              delay(millis);
923              assertTrue(thread.isAlive());
924          } catch (InterruptedException fail) {
925 <            fail("Unexpected InterruptedException");
925 >            threadFail("Unexpected InterruptedException");
926          }
927      }
928  
# Line 820 | Line 944 | public class JSR166TestCase extends Test
944              for (Thread thread : threads)
945                  assertTrue(thread.isAlive());
946          } catch (InterruptedException fail) {
947 <            fail("Unexpected InterruptedException");
947 >            threadFail("Unexpected InterruptedException");
948          }
949      }
950  
# Line 1098 | Line 1222 | public class JSR166TestCase extends Test
1222          } finally {
1223              if (t.getState() != Thread.State.TERMINATED) {
1224                  t.interrupt();
1225 <                fail("Test timed out");
1225 >                threadFail("Test timed out");
1226              }
1227          }
1228      }
# Line 1239 | Line 1363 | public class JSR166TestCase extends Test
1363              }};
1364      }
1365  
1366 <    public Runnable awaiter(final CountDownLatch latch) {
1366 >    public Runnable countDowner(final CountDownLatch latch) {
1367          return new CheckedRunnable() {
1368              public void realRun() throws InterruptedException {
1369 <                await(latch);
1369 >                latch.countDown();
1370              }};
1371      }
1372  
1373 +    class LatchAwaiter extends CheckedRunnable {
1374 +        static final int NEW = 0;
1375 +        static final int RUNNING = 1;
1376 +        static final int DONE = 2;
1377 +        final CountDownLatch latch;
1378 +        int state = NEW;
1379 +        LatchAwaiter(CountDownLatch latch) { this.latch = latch; }
1380 +        public void realRun() throws InterruptedException {
1381 +            state = 1;
1382 +            await(latch);
1383 +            state = 2;
1384 +        }
1385 +    }
1386 +
1387 +    public LatchAwaiter awaiter(CountDownLatch latch) {
1388 +        return new LatchAwaiter(latch);
1389 +    }
1390 +
1391      public void await(CountDownLatch latch) {
1392          try {
1393              assertTrue(latch.await(LONG_DELAY_MS, MILLISECONDS));

Diff Legend

Removed lines
+ Added lines
< Changed lines
> Changed lines