Topic
  • 3 replies
  • Latest Post - ‏2008-10-24T12:33:00Z by SystemAdmin
SystemAdmin
SystemAdmin
2736 Posts

Pinned topic currentTimeMillis returns a date in the past

‏2008-10-20T14:42:23Z |
Hi,

I have identified a problem with System.currentTimeMillis() which is returning times in the past on multi cpu systems running ibm jvms. I have a test program that demonstrates the problem on SLES (Linux Intel) with package java-1_5_0-ibm-devel-1.5.0_sr8-1.3 . Can anyone with a later version of the jvm reproduce this issue ?

The source is as follows (or save attached file):

/*
*/
public class ThreadTest {

public static void main(String[] args) {
final long started = System.currentTimeMillis();

Runnable r = new Runnable() {

long time = 0;

public void run() {
while(true) {
try {
Thread.sleep((long)(Math.random()*1000));
time = System.currentTimeMillis();
if(time < started)
System.out.println("Time: "time", "+(new java.util.Date(time)));
}
catch (InterruptedException e) { e.printStackTrace(); }
}
}//end run()
};

for (int x=0; x<1000; x++)
new Thread(r).start();
}
}
/*
*/

Which outputs any times which are in the past :

Time: 447816564000, Mon Oct 20 14:38:15 GMT 2008
Time: 447816616000, Sun Mar 11 01:30:16 GMT 1984
Time: 447816844000, Mon Oct 20 14:38:16 GMT 2008
Time: 1224513496296, Mon Oct 20 14:38:16 GMT 2008
Time: 447816948000, Mon Oct 20 14:38:16 GMT 2008
Time: 447817048000, Mon Oct 20 14:38:16 GMT 2008
Time: 447817332000, Mon Oct 20 14:38:16 GMT 2008
Time: 447817340000, Mon Oct 20 14:38:16 GMT 2008
Time: 447817368000, Sun Mar 11 01:42:48 GMT 1984
Time: 1224513496876, Mon Oct 20 14:38:16 GMT 2008
Time: 447817656000, Mon Oct 20 14:38:17 GMT 2008
Time: 447817764000, Mon Oct 20 14:38:17 GMT 2008
Time: 447818000000, Mon Oct 20 14:38:17 GMT 2008
Time: 1224513497740, Mon Oct 20 14:38:17 GMT 2008
Time: 447818400000, Sun Mar 11 02:00:00 GMT 1984
Time: 447818521000, Sun Mar 11 02:02:01 GMT 1984
Time: 447818701000, Sun Mar 11 02:05:01 GMT 1984
Time: 447818729000, Mon Oct 20 14:38:18 GMT 2008
Time: 447818769000, Sun Mar 11 02:06:09 GMT 1984
Time: 447818865000, Sun Mar 11 02:07:45 GMT 1984
Time: 1224513498557, Mon Oct 20 14:38:18 GMT 2008
Time: 447819221000, Mon Oct 20 14:38:18 GMT 2008
Many thanks,
Phil.
Updated on 2008-10-24T12:33:00Z at 2008-10-24T12:33:00Z by SystemAdmin
  • SystemAdmin
    SystemAdmin
    2736 Posts

    Re: BUG: currentTimeMillis returns a date in the past (and also Date)

    ‏2008-10-24T11:21:42Z  
    I have now tested on the latest release of 1.6 (ibm-java-i386-sdk-6.0-2.0.i386.rpm) and it is still a problem there.
    An additional problem is that Date is not giving correct values either.

    For example:
    Time: 780508511000, Sun Sep 25 15:55:11 GMT 1994
    Time: 780508664000, Fri Oct 24 11:03:08 GMT 2008

    The two long values are only 153 seconds apart but when passed to new Date(long) and printed out, they are 14 years apart !
    The real problem we have is that incorrect times cause Apache Tomcat to expire valid HttpSession's.
    Is this correct place to report a bug ?

    Regards,
    Phil.
  • SystemAdmin
    SystemAdmin
    2736 Posts

    Re: BUG: currentTimeMillis returns a date in the past (and also Date)

    ‏2008-10-24T12:13:35Z  
    I have now tested on the latest release of 1.6 (ibm-java-i386-sdk-6.0-2.0.i386.rpm) and it is still a problem there.
    An additional problem is that Date is not giving correct values either.

    For example:
    Time: 780508511000, Sun Sep 25 15:55:11 GMT 1994
    Time: 780508664000, Fri Oct 24 11:03:08 GMT 2008

    The two long values are only 153 seconds apart but when passed to new Date(long) and printed out, they are 14 years apart !
    The real problem we have is that incorrect times cause Apache Tomcat to expire valid HttpSession's.
    Is this correct place to report a bug ?

    Regards,
    Phil.
    Hi,

    This is not a bug with the JVM. The problem is you have 1000 threads all updating the same variable and trying to read from it at the same time.

    At least in the testcase you only have 1 instance of the long and it needs to be marked as volatile to ensure it is flushed to memory when every it is read or written to.

    Ben Hardill
  • SystemAdmin
    SystemAdmin
    2736 Posts

    Re: BUG: currentTimeMillis returns a date in the past (and also Date)

    ‏2008-10-24T12:33:00Z  
    Hi,

    This is not a bug with the JVM. The problem is you have 1000 threads all updating the same variable and trying to read from it at the same time.

    At least in the testcase you only have 1 instance of the long and it needs to be marked as volatile to ensure it is flushed to memory when every it is read or written to.

    Ben Hardill
    Thanks Ben, you are right. Marking the time variable as volatile indeed fixes the problem, as does making time local to the run method.

    We had exactly the same behaviour in Tomcat 6.0.18 so the volatile fix might just work there too.

    Many thanks,
    Phil.