Java Solaris Communities Sun Store Join SDN My Profile Why Join?
 
Bug Database
Bug Detail
Quick Lists
Top 25 Bugs
Top 25 RFE's
Recently Closed Bugs
Printable Page Printable Page


Bug Database
Bug ID: 6313903
Votes 0
Synopsis Thread.sleep(3) might wake up immediately on windows
Category hotspot:runtime_system
Reported Against b02
Release Fixed
State 5-Cause Known, bug
Priority: 5-Very Low
Related Bugs 5005837 , 6435126 , 6458302 , 6766174 , 6824583 , 5068368
Submit Date 22-AUG-2005
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
Posted Date : 2005-08-22 05:06:43.0

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.
Posted Date : 2005-08-22 16:05:03.0
Work Around
N/A
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.....
Posted Date : 2005-10-10 21:50:49.0

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.
Posted Date : 2006-06-02 04:46:45.0
Comments
  
  Include a link with my name & email   


PLEASE NOTE: JDK6 is formerly known as Project Mustang