aspose file tools*
The moose likes Java in General and the fly likes currentTimeMillis() returning wrong value ? Big Moose Saloon
  Search | Java FAQ | Recent Topics | Flagged Topics | Hot Topics | Zero Replies
Register / Login


Win a copy of Spring in Action this week in the Spring forum!
JavaRanch » Java Forums » Java » Java in General
Bookmark "currentTimeMillis() returning wrong value ?" Watch "currentTimeMillis() returning wrong value ?" New topic
Author

currentTimeMillis() returning wrong value ?

David Bala�ic
Greenhorn

Joined: May 15, 2008
Posts: 8
Hi!

Yesterday I run into this very strange problem.

I call the renderPicture() method several times per second (from 5 to 40 times). Among other things, it prints the time past since program start (T is initialized on object creation; only one object is created)

The method is called from a loop, which puts the Graphics on screen and then Thread.sleep()'s a while.

On some program runs, it counts two times too fast. It is not hard to notice, but I also measured with a wristwatch. When 10 real seconds passed, the printed value increased by 20.

I use JDK 6 Update 6 on Windows 2003, CPU is Intel Q6600.

Is this a known issue ? Or did I just misprogram something ?
I did not reproduce this yet on another PC, but will try to do that.

So, to conclude: usually, this method prints second values, that increase by one as one real second passes. But in some cases (depending on the argument for the sleep() method; on the test system, the value 45 caused problems) it count too fast by a factor of two.


Ernest Friedman-Hill
author and iconoclast
Marshal

Joined: Jul 08, 2003
Posts: 24187
    
  34

Are you assuming, in your calculation, that sleep() sleeps for exactly the amount of time you ask it to? It won't -- it can sleep for less time (if interrupted) or more time (if another thread won't reliquish the CPU).


[Jess in Action][AskingGoodQuestions]
David Bala�ic
Greenhorn

Joined: May 15, 2008
Posts: 8
No, the print (as one can see) makes no assumptions about the sleep time.
I explicitly run the loop with different delays. The print should always simply print the time passed, irrelevant how often it is called.
John Robertson
Greenhorn

Joined: Feb 12, 2007
Posts: 7
Doesn't getSystemTimeInMillis return a long? If so using a double drops a lot of decimal places worth of accuracy (since it is the last decimal places you care about this could potentially matter) and you could be getting near random answers. That would be a first place to check. Also maybe I am misunderstanding what you wrote but your math looks wrong to me offhand. Maybe I am hurrying too much, but it looks like you are calculating the total seconds elapsed and the total minutes elapsed and displaying each of them as just part of the total time elapsed.
David Bala�ic
Greenhorn

Joined: May 15, 2008
Posts: 8
The number of milliseconds since 1970 is about 2^40. Double uses 53 bits for precision, so there is no problem.

it looks like you are calculating the total seconds elapsed

Yes, that is exactly what I am doing.
David Balažic
Ranch Hand

Joined: May 15, 2008
Posts: 86
I posted the complete source code at pastebin.ca/1037606
(it is over 100 lines; if I should post it here directly, say so)

The problem occurs only with some values used for sleep in line 76.
(it probably depends on the used hardware and who knows what else).
[ June 03, 2008: Message edited by: David Bala�ic ]
Campbell Ritchie
Sheriff

Joined: Oct 13, 2005
Posts: 39427
    
  28
This prints that they are the same, so your 53 bits is sufficient to hold the long value.
Taariq San
Ranch Hand

Joined: Nov 20, 2007
Posts: 192
I've found Windows to be off by 10 milliseconds or so, while Unix tells time to the millisecond.
Campbell Ritchie
Sheriff

Joined: Oct 13, 2005
Posts: 39427
    
  28
I tried your code and it had a little arc which went round and round in circles. Is that what it is supposed to do?
David Balažic
Ranch Hand

Joined: May 15, 2008
Posts: 86
Ignore that, watch the console output.
(among other things) it should count the seconds since program start.
(the line : System.out.println("MS: "+minute+":"+seconds) ;)

(the speed of the arc is also time dependent, that is how I noticed the problem)
[ June 03, 2008: Message edited by: David Bala�ic ]
David Balažic
Ranch Hand

Joined: May 15, 2008
Posts: 86
Argh, it is a bug in Windows :-(

For some reason, when this program is executing, the system clock runs faster than normal.

Details:
- I set up two PCs, with their system clocks running at the same value
- I wait 1 minute, recheck that both clocks show the exact (plus/minus one second) same time
- I run the problem code on one PC
- after 30 seconds I stop the java program (it prints 35 seconds passed)
- I compare the system clock of the two PCs

Result: After the test, the test has its system clock ahead by 5 seconds compared to the other PC.

OS: Windows XP SP2
hardware: HP nw8440 laptop
java: Sun 1.5.0_15-b04

Run from command line (cmd.exe).
Time checked with the command : time

Is this a known issue ?

(I hate discovering bugs)

Regards,
David
Campbell Ritchie
Sheriff

Joined: Oct 13, 2005
Posts: 39427
    
  28
I have got 1.0 minutes, 107 seconds, and it will presumably show 2.0 minutes after 120 seconds (yes, it does), so there is nothing wrong with currentTimeMillis. Unusual arithmetic, I think. This is on Linux.
Ernest Friedman-Hill
author and iconoclast
Marshal

Joined: Jul 08, 2003
Posts: 24187
    
  34

Originally posted by David Bala�ic:
Argh, it is a bug in Windows :-(


Hey, you're right -- it is a known issue. Here's a currently open bug that references some other bugs which go back years and years:

http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6435126

That's Windows for you -- setting the system timer interrupt interval corrupts the system clock. Gotta love it!

It sounds like one easy workaround is to only sleep multiples of 10 msec -- so round 45 up to 50 and the problems should go away.
 
Consider Paul's rocket mass heater.
 
subject: currentTimeMillis() returning wrong value ?