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

Martin Buchholz martinrb at google.com
Tue Jun 3 17:48:10 UTC 2014


We can compromise and set the DELAY_MS to 10 seconds instead of 100 seconds.
Note that the test is supposed to run quickly and should never actually hit
DELAY_MS, so making it large is not a problem.

I continue to not understand why you would need to cancel the task when the
count reaches zero.  Checking that the tasks are run the expected number of
times, and no more ....

===>  IS THE WHOLE POINT OF THIS TEST.  <===

Maybe there's actually a bug in Timer that this test has discovered.  Or
perhaps there's a misunderstanding on my part about how many task
scheduling is supposed to work.  Please explain.



On Tue, Jun 3, 2014 at 6:51 AM, Eric Wang <yiming.wang at oracle.com> wrote:

>  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>
> 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/
>>
>> 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