JDK-8144167 : [OS_X] ConditionObject#awaitNanos waits too long if system clock is turned back
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.util.concurrent
  • Affected Version: 7u79
  • Priority: P4
  • Status: Closed
  • Resolution: Cannot Reproduce
  • OS: os_x
  • CPU: x86
  • Submitted: 2015-10-02
  • Updated: 2015-11-27
  • Resolved: 2015-11-27
Related Reports
Relates :  
Description
FULL PRODUCT VERSION :
java version "1.7.0_79"
Java(TM) SE Runtime Environment (build 1.7.0_79-b15)
Java HotSpot(TM) 64-Bit Server VM (build 24.79-b02, mixed mode)

ADDITIONAL OS VERSION INFORMATION :
Darwin Kernel Version 15.0.0: Wed Aug 26 16:57:32 PDT 2015; root:xnu-3247.1.106~1/RELEASE_X86_64 x86_64

EXTRA RELEVANT SYSTEM CONFIGURATION :
should not matter, the problem is obvious from the source code

A DESCRIPTION OF THE PROBLEM :
the method java.util.concurrent.locks.AbstractQueuedSynchronizer.ConditionObject#awaitNanos has a Problem in cases where the system time is turned back by several minutes.

The source code of the method illustrates this when you consider a case where the system clock is turned back

 public final long awaitNanos(long nanosTimeout)
                throws InterruptedException {
            if (Thread.interrupted())
                throw new InterruptedException();
            Node node = addConditionWaiter();
            int savedState = fullyRelease(node);
            long lastTime = System.nanoTime();
            int interruptMode = 0;
            while (!isOnSyncQueue(node)) {
                if (nanosTimeout <= 0L) {
                    transferAfterCancelledWait(node);
                    break;
                }
                LockSupport.parkNanos(this, nanosTimeout);
                if ((interruptMode = checkInterruptWhileWaiting(node)) != 0)
                    break;

                long now = System.nanoTime();
                nanosTimeout -= now - lastTime;
                lastTime = now;
            }

basically line tries to reduce the timeout by a negative number (in case the clock was turned back) which ends up increasing the wait time. So if the clock was turned back by 10 minutes then the call to 

awaitNanos(10 * 1000 * 1000) 

will end up waiting for 10 minutes and 10 seconds instead of the requested 10 seconds. 

Java 8s implementation seems to handle this problem properly.

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
1. record the current system time
2. start call awaitNanos on the condition object with a timeout of 10 seconds
3. turn back the clock for 10 minutes


EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Expected: awaitNanos returns after 10s 

ACTUAL -
Actual: awaitNanos returns after 10 minutes 10s


REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
package eu.emundo;

import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.TimeUnit;

public class Main {

    public static void main(String[] args) {
        final ArrayBlockingQueue<String> queue = new ArrayBlockingQueue<String>(1);

        long startTime = System.currentTimeMillis();
        System.err.println("starting to wait " + startTime);
        try {
            queue.poll(10, TimeUnit.SECONDS);
            long endTime = System.currentTimeMillis();
            System.err.println("done waiting " + endTime+ " delta: " + ((endTime - startTime) / 1000) + "s");
        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            System.err.println("DONE");
        }
    }
}

---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
none on Java 7


Comments
We have not seen this kind of problem on OSX before. For Linux it was a major problem that was finally addressed with JDK-6900441. Did we test this on "Mac OSX El Capitan" or earlier OSX versions?
27-11-2015

This works as expected with JDK 8 and 9 versions. So closing the issue.
27-11-2015