# HG changeset patch # User dl # Date 1457030168 28800 # Node ID 52e0ee9847fb6c02bb1c37b9f48dfea727c3e2fd # Parent ffcbf28059eea4550bcf4d0600db1f77301d4fa2 8150319: ScheduledExecutorTest:testFixedDelaySequence timeout with slow VMs Reviewed-by: martin, psandoz diff -r ffcbf28059ee -r 52e0ee9847fb jdk/test/java/util/concurrent/tck/JSR166TestCase.java --- a/jdk/test/java/util/concurrent/tck/JSR166TestCase.java Thu Mar 03 10:32:35 2016 -0800 +++ b/jdk/test/java/util/concurrent/tck/JSR166TestCase.java Thu Mar 03 10:36:08 2016 -0800 @@ -88,6 +88,7 @@ import java.util.concurrent.ThreadFactory; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeoutException; +import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicReference; import java.util.regex.Matcher; import java.util.regex.Pattern; @@ -210,11 +211,31 @@ private static final int suiteRuns = Integer.getInteger("jsr166.suiteRuns", 1); + private static float systemPropertyValue(String name, float defaultValue) { + String floatString = System.getProperty(name); + if (floatString == null) + return defaultValue; + try { + return Float.parseFloat(floatString); + } catch (NumberFormatException ex) { + throw new IllegalArgumentException( + String.format("Bad float value in system property %s=%s", + name, floatString)); + } + } + /** * The scaling factor to apply to standard delays used in tests. */ - private static final int delayFactor = - Integer.getInteger("jsr166.delay.factor", 1); + private static final float delayFactor = + systemPropertyValue("jsr166.delay.factor", 1.0f); + + /** + * The timeout factor as used in the jtreg test harness. + * See: http://openjdk.java.net/jtreg/tag-spec.html + */ + private static final float jtregTestTimeoutFactor + = systemPropertyValue("test.timeout.factor", 1.0f); public JSR166TestCase() { super(); } public JSR166TestCase(String name) { super(name); } @@ -590,10 +611,12 @@ /** * Returns the shortest timed delay. This can be scaled up for - * slow machines using the jsr166.delay.factor system property. + * slow machines using the jsr166.delay.factor system property, + * or via jtreg's -timeoutFactor: flag. + * http://openjdk.java.net/jtreg/command-help.html */ protected long getShortDelay() { - return 50 * delayFactor; + return (long) (50 * delayFactor * jtregTestTimeoutFactor); } /** @@ -906,6 +929,14 @@ }}; } + PoolCleaner cleaner(ExecutorService pool, AtomicBoolean flag) { + return new PoolCleanerWithReleaser(pool, releaser(flag)); + } + + Runnable releaser(final AtomicBoolean flag) { + return new Runnable() { public void run() { flag.set(true); }}; + } + /** * Waits out termination of a thread pool or fails doing so. */ @@ -1462,16 +1493,20 @@ return new LatchAwaiter(latch); } - public void await(CountDownLatch latch) { + public void await(CountDownLatch latch, long timeoutMillis) { try { - if (!latch.await(LONG_DELAY_MS, MILLISECONDS)) + if (!latch.await(timeoutMillis, MILLISECONDS)) fail("timed out waiting for CountDownLatch for " - + (LONG_DELAY_MS/1000) + " sec"); + + (timeoutMillis/1000) + " sec"); } catch (Throwable fail) { threadUnexpectedException(fail); } } + public void await(CountDownLatch latch) { + await(latch, LONG_DELAY_MS); + } + public void await(Semaphore semaphore) { try { if (!semaphore.tryAcquire(LONG_DELAY_MS, MILLISECONDS)) diff -r ffcbf28059ee -r 52e0ee9847fb jdk/test/java/util/concurrent/tck/ScheduledExecutorSubclassTest.java --- a/jdk/test/java/util/concurrent/tck/ScheduledExecutorSubclassTest.java Thu Mar 03 10:32:35 2016 -0800 +++ b/jdk/test/java/util/concurrent/tck/ScheduledExecutorSubclassTest.java Thu Mar 03 10:36:08 2016 -0800 @@ -32,6 +32,7 @@ */ import static java.util.concurrent.TimeUnit.MILLISECONDS; +import static java.util.concurrent.TimeUnit.NANOSECONDS; import static java.util.concurrent.TimeUnit.SECONDS; import java.util.ArrayList; @@ -55,7 +56,9 @@ import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeoutException; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicLong; import junit.framework.Test; import junit.framework.TestSuite; @@ -226,52 +229,75 @@ } /** - * scheduleAtFixedRate executes series of tasks at given rate + * scheduleAtFixedRate executes series of tasks at given rate. + * Eventually, it must hold that: + * cycles - 1 <= elapsedMillis/delay < cycles */ public void testFixedRateSequence() throws InterruptedException { final CustomExecutor p = new CustomExecutor(1); try (PoolCleaner cleaner = cleaner(p)) { for (int delay = 1; delay <= LONG_DELAY_MS; delay *= 3) { - long startTime = System.nanoTime(); - int cycles = 10; + final long startTime = System.nanoTime(); + final int cycles = 8; final CountDownLatch done = new CountDownLatch(cycles); - Runnable task = new CheckedRunnable() { + final Runnable task = new CheckedRunnable() { public void realRun() { done.countDown(); }}; - ScheduledFuture h = + final ScheduledFuture periodicTask = p.scheduleAtFixedRate(task, 0, delay, MILLISECONDS); - await(done); - h.cancel(true); - double normalizedTime = - (double) millisElapsedSince(startTime) / delay; - if (normalizedTime >= cycles - 1 && - normalizedTime <= cycles) + final int totalDelayMillis = (cycles - 1) * delay; + await(done, totalDelayMillis + LONG_DELAY_MS); + periodicTask.cancel(true); + final long elapsedMillis = millisElapsedSince(startTime); + assertTrue(elapsedMillis >= totalDelayMillis); + if (elapsedMillis <= cycles * delay) return; + // else retry with longer delay } fail("unexpected execution rate"); } } /** - * scheduleWithFixedDelay executes series of tasks with given period + * scheduleWithFixedDelay executes series of tasks with given period. + * Eventually, it must hold that each task starts at least delay and at + * most 2 * delay after the termination of the previous task. */ public void testFixedDelaySequence() throws InterruptedException { final CustomExecutor p = new CustomExecutor(1); try (PoolCleaner cleaner = cleaner(p)) { for (int delay = 1; delay <= LONG_DELAY_MS; delay *= 3) { - long startTime = System.nanoTime(); - int cycles = 10; + final long startTime = System.nanoTime(); + final AtomicLong previous = new AtomicLong(startTime); + final AtomicBoolean tryLongerDelay = new AtomicBoolean(false); + final int cycles = 8; final CountDownLatch done = new CountDownLatch(cycles); - Runnable task = new CheckedRunnable() { - public void realRun() { done.countDown(); }}; - ScheduledFuture h = + final int d = delay; + final Runnable task = new CheckedRunnable() { + public void realRun() { + long now = System.nanoTime(); + long elapsedMillis + = NANOSECONDS.toMillis(now - previous.get()); + if (done.getCount() == cycles) { // first execution + if (elapsedMillis >= d) + tryLongerDelay.set(true); + } else { + assertTrue(elapsedMillis >= d); + if (elapsedMillis >= 2 * d) + tryLongerDelay.set(true); + } + previous.set(now); + done.countDown(); + }}; + final ScheduledFuture periodicTask = p.scheduleWithFixedDelay(task, 0, delay, MILLISECONDS); - await(done); - h.cancel(true); - double normalizedTime = - (double) millisElapsedSince(startTime) / delay; - if (normalizedTime >= cycles - 1 && - normalizedTime <= cycles) + final int totalDelayMillis = (cycles - 1) * delay; + await(done, totalDelayMillis + cycles * LONG_DELAY_MS); + periodicTask.cancel(true); + final long elapsedMillis = millisElapsedSince(startTime); + assertTrue(elapsedMillis >= totalDelayMillis); + if (!tryLongerDelay.get()) return; + // else retry with longer delay } fail("unexpected execution rate"); } diff -r ffcbf28059ee -r 52e0ee9847fb jdk/test/java/util/concurrent/tck/ScheduledExecutorTest.java --- a/jdk/test/java/util/concurrent/tck/ScheduledExecutorTest.java Thu Mar 03 10:32:35 2016 -0800 +++ b/jdk/test/java/util/concurrent/tck/ScheduledExecutorTest.java Thu Mar 03 10:36:08 2016 -0800 @@ -34,6 +34,7 @@ */ import static java.util.concurrent.TimeUnit.MILLISECONDS; +import static java.util.concurrent.TimeUnit.NANOSECONDS; import static java.util.concurrent.TimeUnit.SECONDS; import java.util.ArrayList; @@ -52,7 +53,9 @@ import java.util.concurrent.ScheduledThreadPoolExecutor; import java.util.concurrent.ThreadFactory; import java.util.concurrent.ThreadPoolExecutor; +import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicLong; import junit.framework.Test; import junit.framework.TestSuite; @@ -170,52 +173,75 @@ } /** - * scheduleAtFixedRate executes series of tasks at given rate + * scheduleAtFixedRate executes series of tasks at given rate. + * Eventually, it must hold that: + * cycles - 1 <= elapsedMillis/delay < cycles */ public void testFixedRateSequence() throws InterruptedException { final ScheduledThreadPoolExecutor p = new ScheduledThreadPoolExecutor(1); try (PoolCleaner cleaner = cleaner(p)) { for (int delay = 1; delay <= LONG_DELAY_MS; delay *= 3) { - long startTime = System.nanoTime(); - int cycles = 10; + final long startTime = System.nanoTime(); + final int cycles = 8; final CountDownLatch done = new CountDownLatch(cycles); - Runnable task = new CheckedRunnable() { + final Runnable task = new CheckedRunnable() { public void realRun() { done.countDown(); }}; - ScheduledFuture h = + final ScheduledFuture periodicTask = p.scheduleAtFixedRate(task, 0, delay, MILLISECONDS); - await(done); - h.cancel(true); - double normalizedTime = - (double) millisElapsedSince(startTime) / delay; - if (normalizedTime >= cycles - 1 && - normalizedTime <= cycles) + final int totalDelayMillis = (cycles - 1) * delay; + await(done, totalDelayMillis + LONG_DELAY_MS); + periodicTask.cancel(true); + final long elapsedMillis = millisElapsedSince(startTime); + assertTrue(elapsedMillis >= totalDelayMillis); + if (elapsedMillis <= cycles * delay) return; + // else retry with longer delay } fail("unexpected execution rate"); } } /** - * scheduleWithFixedDelay executes series of tasks with given period + * scheduleWithFixedDelay executes series of tasks with given period. + * Eventually, it must hold that each task starts at least delay and at + * most 2 * delay after the termination of the previous task. */ public void testFixedDelaySequence() throws InterruptedException { final ScheduledThreadPoolExecutor p = new ScheduledThreadPoolExecutor(1); try (PoolCleaner cleaner = cleaner(p)) { for (int delay = 1; delay <= LONG_DELAY_MS; delay *= 3) { - long startTime = System.nanoTime(); - int cycles = 10; + final long startTime = System.nanoTime(); + final AtomicLong previous = new AtomicLong(startTime); + final AtomicBoolean tryLongerDelay = new AtomicBoolean(false); + final int cycles = 8; final CountDownLatch done = new CountDownLatch(cycles); - Runnable task = new CheckedRunnable() { - public void realRun() { done.countDown(); }}; - ScheduledFuture h = + final int d = delay; + final Runnable task = new CheckedRunnable() { + public void realRun() { + long now = System.nanoTime(); + long elapsedMillis + = NANOSECONDS.toMillis(now - previous.get()); + if (done.getCount() == cycles) { // first execution + if (elapsedMillis >= d) + tryLongerDelay.set(true); + } else { + assertTrue(elapsedMillis >= d); + if (elapsedMillis >= 2 * d) + tryLongerDelay.set(true); + } + previous.set(now); + done.countDown(); + }}; + final ScheduledFuture periodicTask = p.scheduleWithFixedDelay(task, 0, delay, MILLISECONDS); - await(done); - h.cancel(true); - double normalizedTime = - (double) millisElapsedSince(startTime) / delay; - if (normalizedTime >= cycles - 1 && - normalizedTime <= cycles) + final int totalDelayMillis = (cycles - 1) * delay; + await(done, totalDelayMillis + cycles * LONG_DELAY_MS); + periodicTask.cancel(true); + final long elapsedMillis = millisElapsedSince(startTime); + assertTrue(elapsedMillis >= totalDelayMillis); + if (!tryLongerDelay.get()) return; + // else retry with longer delay } fail("unexpected execution rate"); }