JDK-8130735 : javax.swing.TimerQueue: timer fires late when another timer starts
  • Type: Bug
  • Component: client-libs
  • Sub-Component: javax.swing
  • Affected Version: 8u45
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: windows_7
  • CPU: x86_64
  • Submitted: 2015-07-03
  • Updated: 2016-08-03
  • Resolved: 2015-07-28
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 8 JDK 9 Other
8u101Fixed 9 b78Fixed openjdk7uFixed
Related Reports
Duplicate :  
Duplicate :  
Duplicate :  
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 ----------

Comments
Backport request is through https://bugs.openjdk.java.net/browse/JDK-8146334
30-12-2015

it is hard to reproduce.
09-07-2015

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.
08-07-2015