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

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

    Details

    • Subcomponent:
    • Resolved In Build:
      b78
    • CPU:
      x86_64
    • OS:
      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 ----------

          Issue Links

            Activity

            Hide
            pardesha Pardeep Sharma added a comment -
            1. Run the attached test code (TimerQueueBug.java) in Windows 7.

            2. Checked this with JDK 8u45, 8u60 ea b21, and 9 ea b71.
            8u45: OK
            8u60 ea b21: OK
            9ea b71: OK

            3. Output with JDK 8u45:
            Testcase run forever as expected.

            4. The issue is not reproducible as reported by the submitter.
            Show
            pardesha Pardeep Sharma added a comment - 1. Run the attached test code (TimerQueueBug.java) in Windows 7. 2. Checked this with JDK 8u45, 8u60 ea b21, and 9 ea b71. 8u45: OK 8u60 ea b21: OK 9ea b71: OK 3. Output with JDK 8u45: Testcase run forever as expected. 4. The issue is not reproducible as reported by the submitter.
            Hide
            ssadetsky Semyon Sadetsky added a comment -
            it is hard to reproduce.
            Show
            ssadetsky Semyon Sadetsky added a comment - it is hard to reproduce.
            Hide
            hgupdate HG Updates added a comment -
            URL: http://hg.openjdk.java.net/jdk9/client/jdk/rev/5eca1e6a1236
            User: ssadetsky
            Date: 2015-07-28 17:59:46 +0000
            Show
            hgupdate HG Updates added a comment - URL: http://hg.openjdk.java.net/jdk9/client/jdk/rev/5eca1e6a1236 User: ssadetsky Date: 2015-07-28 17:59:46 +0000
            Hide
            hgupdate HG Updates added a comment -
            URL: http://hg.openjdk.java.net/jdk9/jdk9/jdk/rev/5eca1e6a1236
            User: lana
            Date: 2015-08-19 22:04:45 +0000
            Show
            hgupdate HG Updates added a comment - URL: http://hg.openjdk.java.net/jdk9/jdk9/jdk/rev/5eca1e6a1236 User: lana Date: 2015-08-19 22:04:45 +0000
            Hide
            bvaidya Balchandra Vaidya added a comment -
            Show
            bvaidya Balchandra Vaidya added a comment - Backport request is through https://bugs.openjdk.java.net/browse/JDK-8146334

              People

              • Assignee:
                ssadetsky Semyon Sadetsky
                Reporter:
                webbuggrp Webbug Group
              • Votes:
                0 Vote for this issue
                Watchers:
                6 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: