Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8130735

javax.swing.TimerQueue: timer fires late when another timer starts

    XMLWordPrintable

Details

    • b78
    • x86_64
    • windows_7

    Backports

      Description

        FULL PRODUCT VERSION :


        A DESCRIPTION OF THE PROBLEM :
        There is a logic bug in javax.swing.TimerQueue.
        The result is that a timer with a long delay prevent
        other timers with shorter delays to get fired.

        I have include a test case. It runs 30-60 seconds, then prints "Delay abnormal: XXX"
        and JVM exit with 1.

        Sequence of the test:

        1) 80 short delay repeating timers are started with a delay of 100ms.
        The action listener check if it get invoked every 100ms.
        If the delay is more than 5 seconds, it prints "Delay abnormal: XXX" and exit the JVM.

        2) one repeating timer is started which changes his own delay from short to long and back if it get fired.
        If this timer changes from short back to long delay, it will stress the TimerQueue with "start" calls.

        This timer with dynamic delay cause a logic bug in TimerQueue.
        This can be reproduced with the latest Java 8 (u45) and Java 7 (u79/80) version


        Explanation of the logic bug:

        Method TimerQueue#run() (executed by the TimerThread) does this:

            Line 171: Timer timer = queue.take().getTimer();
            Line 172: timer.getLock().lock();

        Line 171 waits for the timer with the shortest delay and remove it.
        After the timer is removed from the queue, the timer is locked (line 172).

        It's possible that TimerQueue#addTimer(Timer, long) is invoked (by the EDT)
        "between" Line 171 and Line 172. At this moment, the timer is not locked
        so addTimer is not prevented to add the (same) timer instance to the queue.
        If the timer reference in run() and addTimer() points to the same timer instance, everything gets bad:

        The timer is now in the queue and TimerQueue#run() will:
        a) add the timer again to the queue -> The queue contains the same timer instance more than once.
        b) changes the time "DelayedTimer.time" by setTime -> The order of the PriorityQueue is incorrect



        Possible solution:

        Introduce a separate Lock which guarantee that this code from TimerQueue#addTimer(Timer, long):

        if (! containsTimer(timer)) {
            addTimer(..);
        }

        is NOT invoked while the TimerThread "remove and lock" the timer (Line 171/172).

        STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
        Run the testcase with Java 8 or Java 7 and wait 30-60 seconds

        EXPECTED VERSUS ACTUAL BEHAVIOR :
        EXPECTED -
        Testcase should run forever
        ACTUAL -
        Testcase runs 30-60 seconds, then prints "Delay abnormal: XXX" and JVM exit with 1

        REPRODUCIBILITY :
        This bug can be reproduced often.

        ---------- BEGIN SOURCE (updated from another similar report) ----------
        import javax.swing.Timer;
        import java.awt.event.ActionEvent;
        import java.awt.event.ActionListener;

        public class TimerQueueBug {

          public static void main(String[] args) throws Exception{

            for (int i = 0; i < 80; i++) {
              startShortTimer();
            }

            final boolean[] longDelay = new boolean[1];
            final Timer dyn = new Timer(100, null);
            dyn.addActionListener( new ActionListener() {
              @Override
              public void actionPerformed( ActionEvent e ) {
                try {
                  if ( longDelay[0] ) {
                    dyn.setDelay(50);
                    dyn.start();
                  } else {
                    dyn.setDelay(500);
                    for ( int i = 0; i < 100; i++ ) {
                      dyn.start();
                    }
                  }
                  longDelay[0] = !longDelay[0];
                } catch ( Throwable ex ) {
                  ex.printStackTrace();
                  System.exit(99);
                }
              }
            } );
            dyn.setRepeats(true);
            dyn.start();


            while (true) {
              Thread.sleep(1);
            }

          }


          private static void startShortTimer() {
            final int delay = 100;
            Timer t = new Timer( delay, new ActionListener() {
              long nextActionExpectedAt;
              @Override
              public void actionPerformed( ActionEvent e ) {
                if (nextActionExpectedAt != 0) {
                  final long diff = System.currentTimeMillis() - nextActionExpectedAt;
                  if (diff > 400) {
                    System.out.println("Delay abnormal: " + diff);
                    System.exit(1);
                  }
                }
                nextActionExpectedAt = System.currentTimeMillis() + delay;
              }
            } );
            t.setRepeats(true);
            t.start();
          }

        }
        ---------- END SOURCE ----------

        Attachments

          Issue Links

            Activity

              People

                ssadetsky Semyon Sadetsky (Inactive)
                webbuggrp Webbug Group
                Votes:
                0 Vote for this issue
                Watchers:
                6 Start watching this issue

                Dates

                  Created:
                  Updated:
                  Resolved: