JDK-6313903 : Thread.sleep(3) might wake up immediately on windows
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: hs13,6
  • Priority: P5
  • Status: Closed
  • Resolution: Won't Fix
  • OS: windows_2000,windows_2003
  • CPU: x86
  • Submitted: 2005-08-22
  • Updated: 2014-09-18
  • Resolved: 2014-01-24
Related Reports
Relates :  
Relates :  
Relates :  
Relates :  
Description
This program:
---------------------------------------------------
public class uu {
    public static void main(String[] args) throws Throwable {
	long t0 = System.currentTimeMillis();
	java.util.concurrent.TimeUnit.MILLISECONDS.sleep(3);
	System.out.println(System.currentTimeMillis()-t0);
    }
}
---------------------------------------------------
should print a number no less than 3, but on windows-amd64
and more rarely, windows-i586, it often prints 0.
Probably a hotspot bug (but it could conceivably be core libraries)

This causes j2se regtest test/java/util/concurrent/TimeUnit/Basic.java to fail
Doug Lea asked,

What happens if you instead just call Thread.sleep(3)?

Good question.

-----------------------------------------------------
public class uu {
    public static void main(String[] args) throws Throwable {
	if (args.length == 1 && args[0].equals("TimeUnit")) {
	    long t0 = System.currentTimeMillis();
	    java.util.concurrent.TimeUnit.MILLISECONDS.sleep(3);
	    System.out.println(System.currentTimeMillis()-t0);
	} else if (args.length == 1 && args[0].equals("Thread")) {
	    long t0 = System.currentTimeMillis();
	    Thread.sleep(3);
	    System.out.println(System.currentTimeMillis()-t0);
	}
    }
}
-----------------------------------------------------
The above program, when invoked with either argument "Thread" or "TimeUnit"
prints "0" on windows-amd64 most of the time.
So this is definitely not a TimeUnit bug.

Comments
This issue is not specific to Windows XP. This is a general problem on all Windows platforms - the Thread.sleep time is wildly unpredictable. D:\testcode>more SleepAccuracy.java public class SleepAccuracy { public static void main(String[] args) throws Throwable { long delay = 1; for (int i = 0; i < 5; i++) { long start = System.nanoTime(); Thread.sleep(delay); long end = System.nanoTime(); System.out.printf("Expected %dms, actual %.2fms%n", delay, (end-start)/(1000.0*1000)); } } } D:\testcode>d:\tools\apps\Java\64\jdk1.8.0\bin\java SleepAccuracy Expected 1ms, actual 4.33ms Expected 1ms, actual 14.61ms Expected 1ms, actual 13.98ms Expected 1ms, actual 0.74ms Expected 1ms, actual 14.87ms D:\testcode>d:\tools\apps\Java\64\jdk1.8.0\bin\java -XX:+ForceTimeHighResolution SleepAccuracy Expected 1ms, actual 12.51ms Expected 1ms, actual 14.22ms Expected 1ms, actual 14.62ms Expected 1ms, actual 14.89ms Expected 1ms, actual 13.61ms D:\testcode>d:\tools\apps\Java\64\jdk1.8.0\bin\java -XX:+ForceTimeHighResolution SleepAccuracy Expected 1ms, actual 8.92ms Expected 1ms, actual 14.81ms Expected 1ms, actual 14.59ms Expected 1ms, actual 11.79ms Expected 1ms, actual 13.40ms D:\testcode>ver Microsoft Windows [Version 6.1.7601] ie Windows 7. Please re-open.
2014-01-27

We don't support Windows XP anymore, anyone running into this on Windows 2003 probably already has applied the patch from Microsoft.
2014-01-24

EVALUATION Note as per 5068368 there is no explicit requirement that a sleep last for at least the amount of time requested, so an early return is valid according to the JLS third edition. That said, the very short sleeps that have been observed seem to fall outside the realm of expected behaviour and so require further investigation. It is unclear at this stage whether the problem is with the sleep, or the use of System.nanoTime to measure the elapsed time.
2006-06-02

EVALUATION First of all the test is not quite accurate, System.currentTimeMillis has a granularity of 10ms, if the code is changed to use System.nanoTime. The VM (1.6.0-b55) does sleep for the required time with no signs of chronic insomnia, as observed earlier. [K:/L/A/HS/6313903] cat ut.java public class ut { public static void dojuc() throws InterruptedException { //long t0 = System.currentTimeMillis(); long t0 = System.nanoTime(); java.util.concurrent.TimeUnit.MILLISECONDS.sleep(3); //System.out.println("timeunit:" + (System.currentTimeMillis()-t0)); System.out.println("timeunit:" + (System.nanoTime()-t0)/1000000); } public static void main(String[] args) throws Throwable { for (int i = 0 ; i < 10 ; i++) { dojuc(); } } } [K:/L/A/HS/6313903] java ut timeunit:15 timeunit:1 timeunit:3 timeunit:3 timeunit:3 timeunit:3 timeunit:3 timeunit:3 timeunit:3 timeunit:3 However the testing revealed that the first time it sleeps, it seems to sleep for a long time, and the second time its for a very short time and then it stabilizes to 3msec (perhaps thread scheduling/clock transients), this is also consistent with a native test case, as follows: [C:/XXXX] ./Insomnia on MIN res : 1 MAX res : 1000000 sleepy time = 3, elapsed time=12.08533 secs HighRes(on) sleepy time = 3, elapsed time=0.42910 secs HighRes(on) sleepy time = 3, elapsed time=3.85608 secs HighRes(on) sleepy time = 3, elapsed time=3.86530 secs HighRes(on) sleepy time = 3, elapsed time=3.86613 secs HighRes(on) sleepy time = 3, elapsed time=3.86697 secs HighRes(on) sleepy time = 3, elapsed time=3.86865 secs HighRes(on) sleepy time = 3, elapsed time=3.86530 secs HighRes(on) sleepy time = 3, elapsed time=3.86166 secs HighRes(on) sleepy time = 3, elapsed time=3.86837 secs HighRes(on) Hit CR to coninue...... Here is the native test case: // Insomnia.cpp : Defines the entry point for the console application. #pragma comment( lib, "winmm" ) #include <iostream> #include <tchar.h> #include <windows.h> class HighResolutionInterval { // The default timer resolution seems to be 10 milliseconds. // (Where is this written down?) // If someone wants to sleep for only a fraction of the default, // then we set the timer resolution down to 1 millisecond for // the duration of their interval. // We carefully set the resolution back, since otherwise we // seem to incur an overhead (3%?) that we don't need. private: static const int DEFAULT_RESOLUTION=1; public: HighResolutionInterval(long ms) { MMRESULT result = timeBeginPeriod(DEFAULT_RESOLUTION); } ~HighResolutionInterval() { MMRESULT result = timeEndPeriod(DEFAULT_RESOLUTION); } }; int os_sleep(long ms, bool highResMode) { HANDLE events[1]; events[0] = CreateEvent( NULL, // no security attributes FALSE, // auto-reset event object FALSE, // initial state is nonsignaled NULL); // unnamed object int result = -1; HighResolutionInterval *phri=NULL; if(highResMode) phri = new HighResolutionInterval( ms ); if (WaitForMultipleObjects(1, events, FALSE, (DWORD)ms) == WAIT_TIMEOUT) { result = -3; } else { printf("Error in WaitForMultipleObjects\n"); result = -2; } delete phri; //if it is NULL, harmless return result; } double gethrTime(LARGE_INTEGER freq) { LARGE_INTEGER hrcount; if (QueryPerformanceCounter(&hrcount) != TRUE) { printf("Error: QueryPerformanceCounter\n"); exit(-12); } return ((double)(hrcount.QuadPart)/(double)(freq.QuadPart))*1000; } int _tmain(int argc, _TCHAR* argv[]) { bool highResMode = (argc > 1 && _stricmp(argv[1],"on") == 0) ? TRUE : FALSE; long ms = ((argc > 2 && *argv[2] != '\0') ? atol(argv[2]) : 3L); TIMECAPS tc; memset(&tc,0,sizeof(tc)); if (timeGetDevCaps(&tc, sizeof(TIMECAPS)) != TIMERR_NOERROR) { printf("Error: timeGetDevCaps failed\n"); exit(-1); } printf("MIN res : %d\n", tc.wPeriodMin); printf("MAX res : %d\n", tc.wPeriodMax); LARGE_INTEGER freq; if (QueryPerformanceFrequency(&freq) != TRUE) { printf("Error: QueryPerformanceFrequency\n"); exit(-10); } if (freq.QuadPart == 1000) { printf("Error: QueryPerformanceFrequency resolution not supported\n"); exit(-11); } for (int i = 0 ; i < 10 ; i++) { double t0 = gethrTime(freq); os_sleep(ms, highResMode); double t1 = gethrTime(freq); printf("sleepy time = %d, elapsed time=%2.5f secs HighRes%s\n", ms, t1-t0, (highResMode) ? "(on)" : "(off)" ); } printf("Hit CR to continue......\n"); while (getchar() != '\n'); return 0; } based on the above test result,I am downgrading this bug to P5 and will be reporting this to Microsoft through the established channels, until then.....
2005-10-10