Strange behavior with Thread.sleep()

[Steve11235]

All-

Would someone please run the following and tell me if they see anything strange? I expect the "Lasted:" value to be something around the "Sleep for:", perhaps a bit longer, but that's not what I get. I especially see strange behavior when "Sleep for:" is 10 or less.

Thanks, Steve

package test;

public class SleepTest {
	public static void main(String[] args) {
		SleepTest instance = new SleepTest();
		instance.run();
	}

	public void run() {
		int i = 0;
		long sleep = 0, start = 0, stop = 0;
		for (i = 0; i < 100; i++) {
			sleep = 100l - i;
			start = System.currentTimeMillis();
			try {
				Thread.sleep(sleep);
			}
			catch (InterruptedException t) {}
			stop = System.currentTimeMillis();
			System.out.println(i
			    + " Sleep for: "
			    + sleep
			    + " Lasted: "
			    + (stop - start)
			    + " start: "
			    + start
			    + " stop: "
			    + stop);
		}
	}
}

[logicbug]

Im getting a varience of about 1 to 10. Im assuming that it is caused by the processers priority.

[Eranga]

What strange behavior you see there, can you provide more details? For me everything is fine, but you have implement it without the Thread class or Runnable interface.

[Eranga]

Im getting a varience of about 1 to 10. Im assuming that it is caused by the processers priority.

Exactly. That's the reason. In your application you have reduce the sleep time with the time. See your result, that unexpected result start to get around 90 iteration. Sleep time is less that 1 second, around 900 millisecond. Actually 1 second time period can conflict with the thread priorities. Pushing to the runnable state and pull back to the running state effected on other threads, your machine currently running.

[Steve11235]

What I'm seeing, using Java 1.6 and Windows XP, is the actual sleep time is a multiple of around 16. Furthermore, the actual sleep time is often less than what I specified. I think the process wakes up around every 16 millis and looks at how much longer the sleep period is. If the remaining sleep is less than half its wake-up interval, it seems to cut the sleep short.

Worst of all, for durations of around 10 or less, it seems to cut the sleep off without waiting at all, so the actual sleep time is zero. If you scroll to the bottom of the output, you can see this behavior. That is really a problem.

I often use short sleep periods in some funky communications code, so I was shocked when I saw this behavior. It has happened on two different Windows XP machines, so I don't think it is anything to do with a particular installation.

Since no one else is seeing this, I assume this is somehow implementation dependent. Thanks for testing and responding. At least the test code works. I thought this was so strange, I wanted to get some feedback before I said what I am getting.

0 Sleep for: 100 Lasted: 109 start: 1231259869281 stop: 1231259869390
1 Sleep for: 99 Lasted: 94 start: 1231259869390 stop: 1231259869484
2 Sleep for: 98 Lasted: 109 start: 1231259869484 stop: 1231259869593
3 Sleep for: 97 Lasted: 94 start: 1231259869593 stop: 1231259869687
4 Sleep for: 96 Lasted: 94 start: 1231259869687 stop: 1231259869781
5 Sleep for: 95 Lasted: 94 start: 1231259869781 stop: 1231259869875
6 Sleep for: 94 Lasted: 93 start: 1231259869875 stop: 1231259869968
7 Sleep for: 93 Lasted: 94 start: 1231259869968 stop: 1231259870062
8 Sleep for: 92 Lasted: 94 start: 1231259870062 stop: 1231259870156
9 Sleep for: 91 Lasted: 94 start: 1231259870156 stop: 1231259870250
10 Sleep for: 90 Lasted: 93 start: 1231259870250 stop: 1231259870343
11 Sleep for: 89 Lasted: 94 start: 1231259870343 stop: 1231259870437
12 Sleep for: 88 Lasted: 78 start: 1231259870437 stop: 1231259870515
13 Sleep for: 87 Lasted: 94 start: 1231259870515 stop: 1231259870609
14 Sleep for: 86 Lasted: 94 start: 1231259870609 stop: 1231259870703
15 Sleep for: 85 Lasted: 78 start: 1231259870703 stop: 1231259870781
16 Sleep for: 84 Lasted: 78 start: 1231259870781 stop: 1231259870859
17 Sleep for: 83 Lasted: 94 start: 1231259870859 stop: 1231259870953
18 Sleep for: 82 Lasted: 78 start: 1231259870953 stop: 1231259871031
19 Sleep for: 81 Lasted: 78 start: 1231259871031 stop: 1231259871109
20 Sleep for: 80 Lasted: 78 start: 1231259871109 stop: 1231259871187
21 Sleep for: 79 Lasted: 78 start: 1231259871203 stop: 1231259871281
22 Sleep for: 78 Lasted: 78 start: 1231259871281 stop: 1231259871359
23 Sleep for: 77 Lasted: 78 start: 1231259871359 stop: 1231259871437
24 Sleep for: 76 Lasted: 78 start: 1231259871437 stop: 1231259871515
25 Sleep for: 75 Lasted: 78 start: 1231259871515 stop: 1231259871593
26 Sleep for: 74 Lasted: 78 start: 1231259871593 stop: 1231259871671
27 Sleep for: 73 Lasted: 63 start: 1231259871671 stop: 1231259871734
28 Sleep for: 72 Lasted: 78 start: 1231259871734 stop: 1231259871812
29 Sleep for: 71 Lasted: 63 start: 1231259871812 stop: 1231259871875
30 Sleep for: 70 Lasted: 78 start: 1231259871875 stop: 1231259871953
31 Sleep for: 69 Lasted: 62 start: 1231259871953 stop: 1231259872015
32 Sleep for: 68 Lasted: 78 start: 1231259872015 stop: 1231259872093
33 Sleep for: 67 Lasted: 63 start: 1231259872093 stop: 1231259872156
34 Sleep for: 66 Lasted: 62 start: 1231259872156 stop: 1231259872218
35 Sleep for: 65 Lasted: 78 start: 1231259872218 stop: 1231259872296
36 Sleep for: 64 Lasted: 63 start: 1231259872296 stop: 1231259872359
37 Sleep for: 63 Lasted: 62 start: 1231259872359 stop: 1231259872421
38 Sleep for: 62 Lasted: 63 start: 1231259872421 stop: 1231259872484
39 Sleep for: 61 Lasted: 62 start: 1231259872484 stop: 1231259872546
40 Sleep for: 60 Lasted: 63 start: 1231259872546 stop: 1231259872609
41 Sleep for: 59 Lasted: 62 start: 1231259872609 stop: 1231259872671
42 Sleep for: 58 Lasted: 63 start: 1231259872671 stop: 1231259872734
43 Sleep for: 57 Lasted: 62 start: 1231259872734 stop: 1231259872796
44 Sleep for: 56 Lasted: 47 start: 1231259872796 stop: 1231259872843
45 Sleep for: 55 Lasted: 63 start: 1231259872843 stop: 1231259872906
46 Sleep for: 54 Lasted: 47 start: 1231259872906 stop: 1231259872953
47 Sleep for: 53 Lasted: 62 start: 1231259872953 stop: 1231259873015
48 Sleep for: 52 Lasted: 47 start: 1231259873015 stop: 1231259873062
49 Sleep for: 51 Lasted: 63 start: 1231259873062 stop: 1231259873125
50 Sleep for: 50 Lasted: 46 start: 1231259873125 stop: 1231259873171
51 Sleep for: 49 Lasted: 47 start: 1231259873171 stop: 1231259873218
52 Sleep for: 48 Lasted: 47 start: 1231259873218 stop: 1231259873265
53 Sleep for: 47 Lasted: 47 start: 1231259873265 stop: 1231259873312
54 Sleep for: 46 Lasted: 47 start: 1231259873312 stop: 1231259873359
55 Sleep for: 45 Lasted: 47 start: 1231259873359 stop: 1231259873406
56 Sleep for: 44 Lasted: 47 start: 1231259873406 stop: 1231259873453
57 Sleep for: 43 Lasted: 47 start: 1231259873453 stop: 1231259873500
58 Sleep for: 42 Lasted: 46 start: 1231259873500 stop: 1231259873546
59 Sleep for: 41 Lasted: 32 start: 1231259873546 stop: 1231259873578
60 Sleep for: 40 Lasted: 47 start: 1231259873578 stop: 1231259873625
61 Sleep for: 39 Lasted: 31 start: 1231259873625 stop: 1231259873656
62 Sleep for: 38 Lasted: 47 start: 1231259873656 stop: 1231259873703
63 Sleep for: 37 Lasted: 31 start: 1231259873703 stop: 1231259873734
64 Sleep for: 36 Lasted: 47 start: 1231259873734 stop: 1231259873781
65 Sleep for: 35 Lasted: 31 start: 1231259873781 stop: 1231259873812
66 Sleep for: 34 Lasted: 31 start: 1231259873812 stop: 1231259873843
67 Sleep for: 33 Lasted: 32 start: 1231259873843 stop: 1231259873875
68 Sleep for: 32 Lasted: 31 start: 1231259873875 stop: 1231259873906
69 Sleep for: 31 Lasted: 31 start: 1231259873906 stop: 1231259873937
70 Sleep for: 30 Lasted: 31 start: 1231259873937 stop: 1231259873968
71 Sleep for: 29 Lasted: 32 start: 1231259873968 stop: 1231259874000
72 Sleep for: 28 Lasted: 31 start: 1231259874000 stop: 1231259874031
73 Sleep for: 27 Lasted: 31 start: 1231259874031 stop: 1231259874062
74 Sleep for: 26 Lasted: 31 start: 1231259874062 stop: 1231259874093
75 Sleep for: 25 Lasted: 16 start: 1231259874093 stop: 1231259874109
76 Sleep for: 24 Lasted: 31 start: 1231259874109 stop: 1231259874140
77 Sleep for: 23 Lasted: 16 start: 1231259874140 stop: 1231259874156
78 Sleep for: 22 Lasted: 31 start: 1231259874156 stop: 1231259874187
79 Sleep for: 21 Lasted: 16 start: 1231259874187 stop: 1231259874203
80 Sleep for: 20 Lasted: 31 start: 1231259874203 stop: 1231259874234
81 Sleep for: 19 Lasted: 16 start: 1231259874234 stop: 1231259874250
82 Sleep for: 18 Lasted: 15 start: 1231259874250 stop: 1231259874265
83 Sleep for: 17 Lasted: 16 start: 1231259874265 stop: 1231259874281
84 Sleep for: 16 Lasted: 15 start: 1231259874281 stop: 1231259874296
85 Sleep for: 15 Lasted: 16 start: 1231259874296 stop: 1231259874312
86 Sleep for: 14 Lasted: 16 start: 1231259874312 stop: 1231259874328
87 Sleep for: 13 Lasted: 15 start: 1231259874328 stop: 1231259874343
88 Sleep for: 12 Lasted: 16 start: 1231259874343 stop: 1231259874359
89 Sleep for: 11 Lasted: 16 start: 1231259874359 stop: 1231259874375
90 Sleep for: 10 Lasted: 15 start: 1231259874375 stop: 1231259874390
91 Sleep for: 9 Lasted: 0 start: 1231259874390 stop: 1231259874390
92 Sleep for: 8 Lasted: 16 start: 1231259874390 stop: 1231259874406
93 Sleep for: 7 Lasted: 15 start: 1231259874406 stop: 1231259874421
94 Sleep for: 6 Lasted: 0 start: 1231259874421 stop: 1231259874421
95 Sleep for: 5 Lasted: 0 start: 1231259874421 stop: 1231259874421
96 Sleep for: 4 Lasted: 16 start: 1231259874421 stop: 1231259874437
97 Sleep for: 3 Lasted: 0 start: 1231259874437 stop: 1231259874437
98 Sleep for: 2 Lasted: 0 start: 1231259874437 stop: 1231259874437
99 Sleep for: 1 Lasted: 0 start: 1231259874437 stop: 1231259874437

[Eranga]

So what you basically think is that on XP there is some strange behavior. Did you check this on any other OS?

As far I'm as aware, XP thread poling have some strange behavior. Actually that's the way it's implemented. Once more threads are in runnable state, poll pull back one at a time to the running state, as we know. In between each pull up there is sleep take place in poll. It's not fix value, but I don't know how exactly it's calculated. But it's get effected with threads running in very short sleep. Once that value close to zero, in very very very short time period, almost zero as you get at the end, thread put into runnable state and running state and back to runnable state and so on.

[neilcoffey]

@Steve11235 I think the 16ms granularity you're seeing is just that of System.currentTimeMillis(). Use System.nanoTime() instead.

In general, both Windows and (recent versions of) Linux can honour a sleep granularity of 1ms on non-busy systems. If you want to know more exact details of how sleep interacts with system business and thread scheduling, I've written on the topic:

• Thread sleep behaviour and granularity
• Thread scheduling

[Steve11235]

Neil-

Thanks for responding. I tested by commenting out the Thread.sleep(), and currentTimeMillis() consistently retrieves zero. I have also tested it against new Date() and found they provide identical results.

I'll try nanoTime() as well, but I think I already tried that in the past.

The puzzling aspect is that, for longer sleep periods, the actual duration is always a multiple of 15 or 16. I'm also baffled that others are running my code and getting expected results.

Thanks for the links. I'll follow them now.

[Steve11235]

Neil-

Your first link explains the problem, but the proposed solution didn't help under XP Pro. I started a daemon thread as you described, but it did not affect the output. I'm running on a Pentium M on both machines, which explains the 15 ms. The OS's refusal to go to 1 ms may also have to do with the processor.

Thank you so much for helping me with this. Our software runs on Windows PC's, so the 10/15 milli rule is something I will just live with and code for. The round down behavior is particularly surprising.

From Neil's first link:

Bugs with Thread.sleep() under Windows

As mentioned, to try and alleviate the low granularity, the VM actually makes a special call to set the interrupt period to 1ms while any Java thread is sleeping, if it requests a sleep interval that is not a multiple of 10ms. This means you are actually make a system-wide change to interrupt behaviour (although generally not such a problem). Generally, the solution works well enough, but:

• there is also a bug in Windows whereby repeatedly altering the interrupt period (and hence, repeatedly sleeping in Java for periods that are not multiples of 10ms) can make the system clock run fast;
• Hotspot assumes that the default interrupt period is 10ms, but on some hardware it is 15ms.

If timing is crucial to your application, then an inelegant but practical way to get round these bugs is to leave a daemon thread running throughout the duration of your application that simply sleeps for a large prime number of milliseconds (Long.MAX_VALUE will do). This way, the interrupt period will be set once per invocation of your application, minimising the effect on the system clock, and setting the sleep granularity to 1ms even where the default interrupt period isn't 15ms.

[angryboy]

I know this is old, but I've found something interesting.

my changes in bold:

import sun.misc.Perf;
public class SleepTest3 {
  public static void main(String[] args) {
    SleepTest3 instance = new SleepTest3();
    instance.run();
  }

[B]  Perf p;
  public SleepTest3(){
    p = Perf.getPerf();
  }[/B]
  
  public void run() {
    int i = 0;
    long sleep = 0, start = 0, stop = 0;
    for (i = 0; i < 100; i++) {
      sleep = 100l - i;
      //start = System.currentTimeMillis();
[B]      start = this.currentTimeMillis();[/B]
      try {
        //Thread.sleep(sleep);
[B]        this.sleep(sleep);[/B]
      }
      catch (InterruptedException t) {}
      //stop = System.currentTimeMillis();
[B]      stop = this.currentTimeMillis();[/B]
      System.out.println(i + " Sleep for: "
      + sleep + " Lasted: "
      + (stop - start)
      + " start: " + start
      + " stop: " + stop
      );
    }
  }
  
[B]  public long currentTimeMillis() {
    return p.highResCounter()*1000/p.highResFrequency();
  }
  
  // CPU intensive, find better algo.
  public void sleep(long delay) throws InterruptedException {
    long t = this.currentTimeMillis();
    while ((delay-(this.currentTimeMillis()-t))>0){}
  }[/B]
}

OUTPUT:

SleepTest3.java:1: warning: sun.misc.Perf is Sun proprietary API and may be remo
ved in a future release
import sun.misc.Perf;
               ^
SleepTest3.java:8: warning: sun.misc.Perf is Sun proprietary API and may be remo
ved in a future release
  Perf p;
  ^
SleepTest3.java:10: warning: sun.misc.Perf is Sun proprietary API and may be rem
oved in a future release
    p = Perf.getPerf();
        ^
3 warnings
0 Sleep for: 100 Lasted: 100 start: 99 stop: 199
[B]1 Sleep for: 99 Lasted: 100 start: 200 stop: 300[/B]
2 Sleep for: 98 Lasted: 98 start: 301 stop: 399
3 Sleep for: 97 Lasted: 97 start: 399 stop: 496
4 Sleep for: 96 Lasted: 96 start: 496 stop: 592
5 Sleep for: 95 Lasted: 95 start: 592 stop: 687
6 Sleep for: 94 Lasted: 94 start: 687 stop: 781
7 Sleep for: 93 Lasted: 93 start: 781 stop: 874
8 Sleep for: 92 Lasted: 92 start: 874 stop: 966
9 Sleep for: 91 Lasted: 91 start: 966 stop: 1057
10 Sleep for: 90 Lasted: 90 start: 1057 stop: 1147
11 Sleep for: 89 Lasted: 89 start: 1147 stop: 1236
12 Sleep for: 88 Lasted: 88 start: 1236 stop: 1324
13 Sleep for: 87 Lasted: 87 start: 1324 stop: 1411
14 Sleep for: 86 Lasted: 86 start: 1411 stop: 1497
15 Sleep for: 85 Lasted: 85 start: 1497 stop: 1582
16 Sleep for: 84 Lasted: 84 start: 1582 stop: 1666
17 Sleep for: 83 Lasted: 83 start: 1666 stop: 1749
18 Sleep for: 82 Lasted: 82 start: 1749 stop: 1831
19 Sleep for: 81 Lasted: 81 start: 1831 stop: 1912
20 Sleep for: 80 Lasted: 80 start: 1912 stop: 1992
21 Sleep for: 79 Lasted: 79 start: 1992 stop: 2071
22 Sleep for: 78 Lasted: 78 start: 2071 stop: 2149
23 Sleep for: 77 Lasted: 77 start: 2149 stop: 2226
24 Sleep for: 76 Lasted: 76 start: 2226 stop: 2302
25 Sleep for: 75 Lasted: 75 start: 2302 stop: 2377
26 Sleep for: 74 Lasted: 74 start: 2377 stop: 2451
27 Sleep for: 73 Lasted: 73 start: 2451 stop: 2524
28 Sleep for: 72 Lasted: 72 start: 2524 stop: 2596
29 Sleep for: 71 Lasted: 71 start: 2607 stop: 2678
30 Sleep for: 70 Lasted: 70 start: 2678 stop: 2748
31 Sleep for: 69 Lasted: 69 start: 2748 stop: 2817
32 Sleep for: 68 Lasted: 68 start: 2817 stop: 2885
33 Sleep for: 67 Lasted: 68 start: 2885 stop: 2953
34 Sleep for: 66 Lasted: 66 start: 2953 stop: 3019
35 Sleep for: 65 Lasted: 65 start: 3019 stop: 3084
36 Sleep for: 64 Lasted: 64 start: 3084 stop: 3148
37 Sleep for: 63 Lasted: 63 start: 3148 stop: 3211
38 Sleep for: 62 Lasted: 62 start: 3211 stop: 3273
39 Sleep for: 61 Lasted: 61 start: 3273 stop: 3334
40 Sleep for: 60 Lasted: 60 start: 3334 stop: 3394
41 Sleep for: 59 Lasted: 59 start: 3394 stop: 3453
42 Sleep for: 58 Lasted: 58 start: 3453 stop: 3511
43 Sleep for: 57 Lasted: 57 start: 3511 stop: 3568
44 Sleep for: 56 Lasted: 56 start: 3568 stop: 3624
45 Sleep for: 55 Lasted: 55 start: 3624 stop: 3679
46 Sleep for: 54 Lasted: 54 start: 3679 stop: 3733
47 Sleep for: 53 Lasted: 53 start: 3733 stop: 3786
48 Sleep for: 52 Lasted: 52 start: 3786 stop: 3838
49 Sleep for: 51 Lasted: 51 start: 3839 stop: 3890
50 Sleep for: 50 Lasted: 50 start: 3890 stop: 3940
51 Sleep for: 49 Lasted: 49 start: 3940 stop: 3989
52 Sleep for: 48 Lasted: 48 start: 3989 stop: 4037
53 Sleep for: 47 Lasted: 47 start: 4037 stop: 4084
54 Sleep for: 46 Lasted: 46 start: 4084 stop: 4130
55 Sleep for: 45 Lasted: 45 start: 4130 stop: 4175
56 Sleep for: 44 Lasted: 44 start: 4175 stop: 4219
57 Sleep for: 43 Lasted: 43 start: 4219 stop: 4262
58 Sleep for: 42 Lasted: 42 start: 4262 stop: 4304
59 Sleep for: 41 Lasted: 43 start: 4304 stop: 4347
60 Sleep for: 40 Lasted: 40 start: 4347 stop: 4387
61 Sleep for: 39 Lasted: 39 start: 4387 stop: 4426
62 Sleep for: 38 Lasted: 38 start: 4426 stop: 4464
63 Sleep for: 37 Lasted: 37 start: 4464 stop: 4501
64 Sleep for: 36 Lasted: 36 start: 4501 stop: 4537
65 Sleep for: 35 Lasted: 35 start: 4537 stop: 4572
66 Sleep for: 34 Lasted: 34 start: 4572 stop: 4606
67 Sleep for: 33 Lasted: 33 start: 4606 stop: 4639
68 Sleep for: 32 Lasted: 32 start: 4639 stop: 4671
69 Sleep for: 31 Lasted: 31 start: 4671 stop: 4702
70 Sleep for: 30 Lasted: 30 start: 4702 stop: 4732
71 Sleep for: 29 Lasted: 29 start: 4732 stop: 4761
72 Sleep for: 28 Lasted: 28 start: 4761 stop: 4789
73 Sleep for: 27 Lasted: 27 start: 4789 stop: 4816
74 Sleep for: 26 Lasted: 26 start: 4816 stop: 4842
75 Sleep for: 25 Lasted: 25 start: 4842 stop: 4867
76 Sleep for: 24 Lasted: 24 start: 4867 stop: 4891
77 Sleep for: 23 Lasted: 23 start: 4891 stop: 4914
78 Sleep for: 22 Lasted: 22 start: 4915 stop: 4937
79 Sleep for: 21 Lasted: 21 start: 4937 stop: 4958
80 Sleep for: 20 Lasted: 20 start: 4958 stop: 4978
81 Sleep for: 19 Lasted: 19 start: 4978 stop: 4997
82 Sleep for: 18 Lasted: 18 start: 4997 stop: 5015
83 Sleep for: 17 Lasted: 17 start: 5015 stop: 5032
84 Sleep for: 16 Lasted: 16 start: 5032 stop: 5048
85 Sleep for: 15 Lasted: 15 start: 5048 stop: 5063
86 Sleep for: 14 Lasted: 14 start: 5063 stop: 5077
87 Sleep for: 13 Lasted: 13 start: 5077 stop: 5090
88 Sleep for: 12 Lasted: 12 start: 5090 stop: 5102
89 Sleep for: 11 Lasted: 11 start: 5102 stop: 5113
90 Sleep for: 10 Lasted: 10 start: 5113 stop: 5123
91 Sleep for: 9 Lasted: 9 start: 5123 stop: 5132
92 Sleep for: 8 Lasted: 8 start: 5132 stop: 5140
93 Sleep for: 7 Lasted: 7 start: 5140 stop: 5147
94 Sleep for: 6 Lasted: 6 start: 5147 stop: 5153
95 Sleep for: 5 Lasted: 5 start: 5153 stop: 5158
96 Sleep for: 4 Lasted: 4 start: 5160 stop: 5164
97 Sleep for: 3 Lasted: 3 start: 5164 stop: 5167
98 Sleep for: 2 Lasted: 2 start: 5167 stop: 5169
99 Sleep for: 1 Lasted: 1 start: 5169 stop: 5170

I ran it couple of times and get the same result. #1 lasted 100 everytime.

[Steve11235]

AB- LOL! I read the post on my iPhone, so I rushed back to my desk to read the details. I was wondering what CPU impact your "sleep" method had. I would rename that method "insomnia" ;-)

That's the whole catch, isn't it? Finding a way to wait without wasting a bunch of cycles. I'll run the test on Linux some time. That might be the best solution: an OS that actually supports 1 ms sleep periods.

[angryboy]

yeah i was still testing the sleep part. my point was sun.misc.Perf.

EDIT:
---/* stuff removed */---

pretty good w/o threads, but fail w/ threads.

  // modded from neilcoffey's method.
  public void sleep(long millis) throws InterruptedException {
    ++millis;
    long t0 = this.currentTimeMillis();
    long t1;
    long millisLeft = millis/2;
    while (millisLeft>0) {
      Thread.sleep(millisLeft);
      t1 = this.currentTimeMillis();
      millisLeft = (millis - (t1 - t0))/2;
    }
  }

This one works nicely w/ threads at 0-1% cpu usage, but starts to get inaccurate as the delay gets smaller.

  // modded from neilcoffey's method.
  public void sleep(long millis) throws InterruptedException {
    long t0 = this.currentTimeMillis();
    long millisLeft = (long)(millis/1.2);
    while (millisLeft>0){
      Thread.sleep(millisLeft);
      millisLeft = (millis-(this.currentTimeMillis()-t0));
    }
  }

s:\>java SleepTest4 | sort
 0 Sleep for: 100 Lasted: 100 start: 128 stop: 228
 1 Sleep for: 99 Lasted: 99 start: 128 stop: 227
 2 Sleep for: 98 Lasted: 98 start: 128 stop: 226
 3 Sleep for: 97 Lasted: 97 start: 128 stop: 225
 4 Sleep for: 96 Lasted: 97 start: 130 stop: 227
 5 Sleep for: 95 Lasted: 96 start: 130 stop: 226
 6 Sleep for: 94 Lasted: 95 start: 130 stop: 225
 7 Sleep for: 93 Lasted: 93 start: 131 stop: 224
 8 Sleep for: 92 Lasted: 92 start: 131 stop: 223
 9 Sleep for: 91 Lasted: 91 start: 131 stop: 222
10 Sleep for: 90 Lasted: 91 start: 131 stop: 222
11 Sleep for: 89 Lasted: 91 start: 131 stop: 222
12 Sleep for: 88 Lasted: 88 start: 131 stop: 219
13 Sleep for: 87 Lasted: 87 start: 131 stop: 218
14 Sleep for: 86 Lasted: 86 start: 131 stop: 217
15 Sleep for: 85 Lasted: 85 start: 131 stop: 216
16 Sleep for: 84 Lasted: 84 start: 131 stop: 215
17 Sleep for: 83 Lasted: 84 start: 131 stop: 215
18 Sleep for: 82 Lasted: 83 start: 131 stop: 214
19 Sleep for: 81 Lasted: 81 start: 132 stop: 213
20 Sleep for: 80 Lasted: 81 start: 134 stop: 215
21 Sleep for: 79 Lasted: 80 start: 134 stop: 214
22 Sleep for: 78 Lasted: 78 start: 134 stop: 212
23 Sleep for: 77 Lasted: 77 start: 134 stop: 211
24 Sleep for: 76 Lasted: 76 start: 134 stop: 210
25 Sleep for: 75 Lasted: 76 start: 134 stop: 210
26 Sleep for: 74 Lasted: 76 start: 134 stop: 210
27 Sleep for: 73 Lasted: 73 start: 134 stop: 207
28 Sleep for: 72 Lasted: 73 start: 135 stop: 208
29 Sleep for: 71 Lasted: 71 start: 135 stop: 206
30 Sleep for: 70 Lasted: 70 start: 135 stop: 205
31 Sleep for: 69 Lasted: 70 start: 135 stop: 205
32 Sleep for: 68 Lasted: 69 start: 135 stop: 204
33 Sleep for: 67 Lasted: 68 start: 135 stop: 203
34 Sleep for: 66 Lasted: 69 start: 135 stop: 204
35 Sleep for: 65 Lasted: 69 start: 135 stop: 204
36 Sleep for: 64 Lasted: 68 start: 135 stop: 203
...

[toadaly]

That's the whole catch, isn't it? Finding a way to wait without wasting a bunch of cycles.

I agree. ...and while there are times when thread.sleep can not be avoided, most of the time it results from a poor design.

[Gudradain]

Are you making a gameloop() ?? (Probably not but it's so similar :))

I'm no expert on this but from what I heard on Windows the time is not exact. On Mac and Linux it's suppose to be. For game they use a library to fix this problem. You can check that :

GageTimer
Info on timing

N.B. Never tried it for myself so can't be sure

[angryboy]

followed the link and found this:

There's a bug in GAGETimer! It makes my CPU run at 100%!

Amazingly enough, this is not a bug! It's a feature! No. Really. I'm not kidding. Stop laughing!!!

...

If you are writing a game server, it is important to avoid the GAGETimer sleep() functions. You can still use it for timing, but the sleep methods will degrade the performance of a multithreaded program.

went through the src and saw this:

    public void sleep(long ticks) throws IllegalStateException
    {
        long tick = getClockTicks();
        if(!running) throw new IllegalStateException("Timer not running!");
        [B]while(getClockTicks() < tick+ticks) Thread.yield();[/B]
    }

Looks like my insomnia code is not a bug either. Its a feature ;-)
I then tested the out performace, I'm getting pretty much the same results.

[angryboy]

I just tested the demon thread out and it worked for me. I'm getting ~1ms interrupt. I didn't see the difference with System.currentTimeMillis(), but when I changed it to nanoTime(), I saw a difference. Then added code to animation... WOW!

...the proposed solution didn't help under XP Pro. I started a daemon thread as you described, but it did not affect the output. I'm running on a Pentium M on both machines, which explains the 15 ms. The OS's refusal to go to 1 ms may also have to do with the processor.

I tested this on thunderbird and pentiumIII-M, both XP-Pro sp3 and sp2 respectively. But I wonder if this depends on processor/OS??



RESOURCES:
this is from the sun bug database:Bug ID: 6435126 ForceTimeHighResolution switch doesn't operate as intended

...at the start of the application create and start a daemon Thread that simply sleeps for a very long time (that isn't a multiple of 10ms) as this will set the timer period to be 1ms for the duration of that sleep - which in this case is the lifetime of the VM:

       new Thread() {
            { this.setDaemon(true); this.start(); }
            public void run() {
                    while(true) {
                        try {
                            Thread.sleep(Integer.MAX_VALUE);
                        }
                        catch(InterruptedException ex) {
                        }
                    }
            }
        };

this link show how to tell interrupts using perfmon: David Holmes' Weblog

You can see what interrupt period is being used in Windows by running the perfmon tool. After you bring it up you'll need to add a new item to watch (click the + icon above the graph - even if it appears grayed/disabled). Select the interrupts/sec items and add it. Then right click on interrupts/sec under the graph and edit its properties. On the "data" tab, change the "scale" to 1 and on the graph tab, the vertical max to be 1000. Let the system settle for a few seconds and you should see the graph drawing a steady line. If you have a 10ms interrupt then it will be 100, for 1ms it will be 1000, for 15ms it will be 66.6, etc. Note: on a multiprocessor system show the interrupts/sec for each processor individually, not the total - one processor will be fielding the timer interrupts.

[angryboy]

I just tested the demon thread out and it worked for me. I'm getting ~1ms interrupt. I didn't see the difference with System.currentTimeMillis(), but when I changed it to nanoTime(), I saw a difference. Then added code to animation... WOW!

...the proposed solution didn't help under XP Pro. I started a daemon thread as you described, but it did not affect the output. I'm running on a Pentium M on both machines, which explains the 15 ms. The OS's refusal to go to 1 ms may also have to do with the processor.

I tested this on thunderbird and pentiumIII-M, both XP-Pro sp3 and sp2 respectively. But I wonder if this depends on processor/OS??



RESOURCES:
this is from the sun bug database: *LINK REMOVED

...at the start of the application create and start a daemon Thread that simply sleeps for a very long time (that isn't a multiple of 10ms) as this will set the timer period to be 1ms for the duration of that sleep - which in this case is the lifetime of the VM:

       new Thread() {
            { this.setDaemon(true); this.start(); }
            public void run() {
                    while(true) {
                        try {
                            Thread.sleep(Integer.MAX_VALUE);
                        }
                        catch(InterruptedException ex) {
                        }
                    }
            }
        };

this link show how to tell interrupts using perfmon: *LINK REMOVED (google david holmes)

You can see what interrupt period is being used in Windows by running the perfmon tool. After you bring it up you'll need to add a new item to watch (click the + icon above the graph - even if it appears grayed/disabled). Select the interrupts/sec items and add it. Then right click on interrupts/sec under the graph and edit its properties. On the "data" tab, change the "scale" to 1 and on the graph tab, the vertical max to be 1000. Let the system settle for a few seconds and you should see the graph drawing a steady line. If you have a 10ms interrupt then it will be 100, for 1ms it will be 1000, for 15ms it will be 66.6, etc. Note: on a multiprocessor system show the interrupts/sec for each processor individually, not the total - one processor will be fielding the timer interrupts.