RFR for bug JDK-8004807: java/util/Timer/Args.java failing intermittently in HS testing

Eric Wang yiming.wang at oracle.com
Tue Jun 3 13:51:19 UTC 2014


Hi Martin,

Glad to know you are the original author and thank you to rewrite the 
test using modern way.

I have some concerns about the limit of elapsed time (DELAY_MS / 2 = 
50000ms) which is much higher than the old value (500ms).
The reason is that i checked the nightly failure histories, there are 
dozens of failures which are caused by exception thrown at the call 
"check(latch.getCount() > 0)" in the run method of TimerTask. it is 
actually caused by the the task scheduled with fixed rate is not 
cancelled after latch reaches zero. None of the test failed due to the 
elapsed time larger than 500 ms.

Sorry that I should paste the failure to clarify the problem: 
http://cr.openjdk.java.net/~ewang/JDK-8004807/failure.txt

So are you OK that i adopt your test with 2 small changes: 
http://cr.openjdk.java.net/~ewang/JDK-8004807/webrev.01/
1. keep the limit of elapsed time 500ms as it was.
2. cancel the task when latch reached zero.

Thanks,
Eric

On 2014/5/31 4:26, Martin Buchholz wrote:
> HI Eric,
>
> Thanks for working on my old dusty tests.
>
> I can't view the bug report - I get Permission Violation.
>
> It does look like you're making the test more robust, but at the cost 
> of throwing away much of what the test is testing, which is not so good.
>
> This test hardcodes 1 second as the period - it assumes all 13 task 
> invocations can be performed in 500ms, which may be a little 
> over-optimistic.  Nevertheless, this failure should be very rare, eh? 
>  But  bump the period to a much higher number and we should be OK.
>
> I think making this an othervm test is overkill.  Better to make the 
> test itself more robust.
>
> I propose instead this major rewrite:
>
>
>
> public class Args {
>     static final long DELAY_MS = 100 * 1000L;
>
>     void schedule(final Timer t, final TimerTask task, final Date d) {
>         t.schedule(task, d);
>         assertThrows
>             (IllegalStateException.class,
>              () -> t.schedule(task, d));
>     }
>
>     void schedule(final Timer t, final TimerTask task, final Date d, 
> final long period) {
>         t.schedule(task, d, period);
>         assertThrows
>             (IllegalStateException.class,
>              () -> t.schedule(task, d, period));
>     }
>
>     void scheduleAtFixedRate(final Timer t, final TimerTask task, 
> final Date d, final long period) {
>         t.scheduleAtFixedRate(task, d, period);
>         assertThrows
>             (IllegalStateException.class,
>              () -> t.scheduleAtFixedRate(task, d, period));
>     }
>
>     TimerTask counter(final CountDownLatch latch) {
>         return new TimerTask() { public void run() {
>             check(latch.getCount() > 0);
>             latch.countDown();
>         }};
>     }
>
>     TimerTask nop() {
>         return new TimerTask() { public void run() { }};
>     }
>
>     void test(String[] args) throws Throwable {
>         final Timer t = new Timer();
>         try {
>             test(t);
>         } finally {
>             // Ensure this test doesn't interfere with subsequent
>             // tests even in case of failure.
>             t.cancel();
>         }
>
>         // Attempts to schedule tasks on a cancelled Timer result in ISE.
>
>         final Date past = new Date(System.currentTimeMillis() - DELAY_MS);
>         final Date future = new Date(System.currentTimeMillis() + 
> DELAY_MS);
>         assertThrows
>             (IllegalStateException.class,
>              () -> t.schedule(nop(), 42),
>              () -> t.schedule(nop(), 42),
>              () -> t.schedule(nop(), past),
>              () -> t.schedule(nop(), 42, 42),
>              () -> t.schedule(nop(), past, 42),
>              () -> t.scheduleAtFixedRate(nop(), 42, 42),
>              () -> t.scheduleAtFixedRate(nop(), past, 42),
>              () -> t.scheduleAtFixedRate(nop(), future, 42));
>     }
>
>     void test(Timer t) throws Throwable {
>         final TimerTask x = new TimerTask() { public void run() {}};
>         assertThrows
>             (IllegalArgumentException.class,
>              () -> t.schedule(x, -42),
>              () -> t.schedule(x, new Date(-42)),
>
>              () -> t.schedule(x, Long.MAX_VALUE),
>              () -> t.schedule(x, -42, 42),
>              () -> t.schedule(x, new Date(-42), 42),
>              () -> t.schedule(x, Long.MAX_VALUE, 42),
>              () -> t.schedule(x, 42, 0),
>              () -> t.schedule(x, new Date(42), 0),
>              () -> t.schedule(x, 42, -42),
>              () -> t.schedule(x, new Date(42), -42),
>
>              () -> t.scheduleAtFixedRate(x, -42, 42),
>              () -> t.scheduleAtFixedRate(x, new Date(-42), 42),
>              () -> t.scheduleAtFixedRate(x, Long.MAX_VALUE, 42),
>              () -> t.scheduleAtFixedRate(x, 42, 0),
>              () -> t.scheduleAtFixedRate(x, new Date(42), 0),
>              () -> t.scheduleAtFixedRate(x, 42, -42),
>              () -> t.scheduleAtFixedRate(x, new Date(42), -42));
>
>         assertThrows
>             (NullPointerException.class,
>              () -> t.schedule(null, 42),
>              () -> t.schedule(x, (Date)null),
>
>              () -> t.schedule(null, 42, 42),
>              () -> t.schedule(x, (Date)null, 42),
>
>              () -> t.scheduleAtFixedRate(null, 42, 42),
>              () -> t.scheduleAtFixedRate(x, (Date)null, 42));
>
>         final CountDownLatch y1 = new CountDownLatch(1);
>         final CountDownLatch y2 = new CountDownLatch(1);
>         final CountDownLatch y3 = new CountDownLatch(11);
>         final long start = System.currentTimeMillis();
>         final Date past = new Date(start - (10 * DELAY_MS + DELAY_MS / 
> 2));
>
>         schedule(           t, counter(y1), past);
>         schedule(           t, counter(y2), past, DELAY_MS);
>         scheduleAtFixedRate(t, counter(y3), past, DELAY_MS);
>         y3.await();
>         y1.await();
>         y2.await();
>
>         final long elapsed = System.currentTimeMillis() - start;
>         if (elapsed >= DELAY_MS / 2)
>             fail(String.format("Test took too long: elapsed=%d%n", 
> elapsed));
>     }
>
>     //--------------------- Infrastructure ---------------------------
>     volatile int passed = 0, failed = 0;
>     void pass() {passed++;}
>     void fail() {failed++; Thread.dumpStack();}
>     void fail(String msg) {System.err.println(msg); fail();}
>     void unexpected(Throwable t) {failed++; t.printStackTrace();}
>     void check(boolean cond) {if (cond) pass(); else fail();}
>     void equal(Object x, Object y) {
>         if (x == null ? y == null : x.equals(y)) pass();
>         else fail(x + " not equal to " + y);}
>     public static void main(String[] args) throws Throwable {
>         new Args().instanceMain(args);}
>     void instanceMain(String[] args) throws Throwable {
>         try {test(args);} catch (Throwable t) {unexpected(t);}
>         System.out.printf("%nPassed = %d, failed = %d%n%n", passed, 
> failed);
>         if (failed > 0) throw new AssertionError("Some tests failed");}
>     interface F { void f() throws Throwable; }
>     void assertThrows(Class<? extends Throwable> k, F... fs) {
>         for (F f : fs)
>             try {f.f(); fail("Expected " + k.getName() + " not thrown");}
>             catch (Throwable t) {
>                 if (k.isAssignableFrom(t.getClass())) pass();
>                 else unexpected(t);}}
> }
>
>
>
> On Fri, May 30, 2014 at 12:27 AM, Eric Wang <yiming.wang at oracle.com 
> <mailto:yiming.wang at oracle.com>> wrote:
>
>     Hi,
>
>     Please help to review the fix for bug
>     https://bugs.openjdk.java.net/browse/JDK-8004807 as below:
>     http://cr.openjdk.java.net/~ewang/JDK-8004807/webrev.00/
>     <http://cr.openjdk.java.net/%7Eewang/JDK-8004807/webrev.00/>
>
>     The root cause of the failure is if Timer.cancel() is not called
>     in time, the recurring timer task keeps running which cause the
>     the assertion "check(latch.getCount() > 0)" failed.
>
>     The fix includes:
>     1. As the purpose of the assertion "check(latch.getCount() > 0)"
>     in timer task is used to check if the unrepeatable task is
>     executed repeatedly and this assertion is meaningless for a
>     repeatable task. it can be replaced by other way, see the webrev.
>     2. The timer thread should be terminated ASAP once all tasks are
>     finished to avoid time spent on thread switch.
>     3. The test should be executed in othervm mode to avoid time spent
>     on thread switch.
>
>     Thanks,
>     Eric
>
>




More information about the core-libs-dev mailing list