8150319: ScheduledExecutorTest:testFixedDelaySequence timeout with slow VMs

Reviewed-by: martin, psandoz

jdk/test/java/util/concurrent/tck/JSR166TestCase.java

@@ -88,6 +88,7 @@ import java.util.concurrent.Semaphore;
 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 @@ public class JSR166TestCase extends TestCase {
     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 @@ public class JSR166TestCase extends TestCase {
 
     /**
      * 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 @@ public class JSR166TestCase extends TestCase {
         }};
     }
 
+    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 @@ public class JSR166TestCase extends TestCase {
         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))

jdk/test/java/util/concurrent/tck/ScheduledExecutorSubclassTest.java

@@ -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.ThreadFactory;
 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 @@ public class ScheduledExecutorSubclassTest extends JSR166TestCase {
     }
 
     /**
-     * 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");
         }

jdk/test/java/util/concurrent/tck/ScheduledExecutorTest.java

@@ -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.ScheduledFuture;
 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 @@ public class ScheduledExecutorTest extends JSR166TestCase {
     }
 
     /**
-     * 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");
         }