I'm encountering a really unusual issue here. It seems that the calling of Thread.sleep(n), where n > 0 would cause the following System.nanoTime() calls to be less predictable.
The code below demonstrates the issue.
Running it on my computer (rMBP 15" 2015, OS X 10.11, jre 1.8.0_40-b26) outputs the following result:
Control: 48497
Random: 36719
Thread.sleep(0): 48044
Thread.sleep(1): 832271
On a Virtual Machine running Windows 8 (VMware Horizon, Windows 8.1, are 1.8.0_60-b27):
Control: 98974
Random: 61019
Thread.sleep(0): 115623
Thread.sleep(1): 282451
However, running it on an enterprise server (VMware, RHEL 6.7, jre 1.6.0_45-b06):
Control: 1385670
Random: 1202695
Thread.sleep(0): 1393994
Thread.sleep(1): 1413220
Which is surprisingly the result I expect.
Clearly the Thread.sleep(1) affects the computation of the below code. I have no idea why this happens. Does anyone have a clue?
Thanks!
public class Main {
public static void main(String[] args) {
int N = 1000;
long timeElapsed = 0;
long startTime, endTime = 0;
for (int i = 0; i < N; i++) {
startTime = System.nanoTime();
//search runs here
endTime = System.nanoTime();
timeElapsed += endTime - startTime;
}
System.out.println("Control: " + timeElapsed);
timeElapsed = 0;
for (int i = 0; i < N; i++) {
startTime = System.nanoTime();
//search runs here
endTime = System.nanoTime();
timeElapsed += endTime - startTime;
for (int j = 0; j < N; j++) {
int k = (int) Math.pow(i, j);
}
}
System.out.println("Random: " + timeElapsed);
timeElapsed = 0;
for (int i = 0; i < N; i++) {
startTime = System.nanoTime();
//search runs here
endTime = System.nanoTime();
timeElapsed += endTime - startTime;
try {
Thread.sleep(0);
} catch (InterruptedException e) {
break;
}
}
System.out.println("Thread.sleep(0): " + timeElapsed);
timeElapsed = 0;
for (int i = 0; i < N; i++) {
startTime = System.nanoTime();
//search runs here
endTime = System.nanoTime();
timeElapsed += endTime - startTime;
try {
Thread.sleep(2);
} catch (InterruptedException e) {
break;
}
}
System.out.println("Thread.sleep(1): " + timeElapsed);
}
}
Basically I'm running a search within a while-loop which takes a break every iteration by calling Thread.sleep(). I want to exclude the sleep time from the overall time taken to run the search, so I'm using System.nanoTime() to record the start and finishing times. However, as you notice above, this doesn't work well.
Is there a way to remedy this?
Thanks for any input!
mainbody into the separate method and call it 100 times in a loop. The results of the consequent calls will be significantly different. – DilatometerstartTimeandendTimevariables out of the loops, because making that many unnecessary allocations should be considered a capital sin. =P – Fathom