[concurrency-interest] ScheduledThreadPoolExecutor schdeuling problem ?

Hanson Char hanson.char at gmail.com
Mon Dec 31 14:19:39 EST 2007


Interestingly when I changed the test to replace all uses of
milli-time with nano-time, the earlier-than-expected problem seems to
go away.  (Nano-test code below.)

The lesson/solution seems apparent.  Replace all use of
System.currentTimeMillis() with System.nanoTime().

Regards,
Hanson Char

import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;

public class TestNanoScheduledThreadPoolExecutor {
	
	private static final long PERIOD = 1000*1000*1000;
	
	public void test() {
		final ScheduledExecutorService ses = Executors.newScheduledThreadPool(1);
		final long[] start = {System.nanoTime()};
		final int[] count = {0};
		
		ses.schedule(new Runnable() {
			public void run() {
				long elapsed = System.nanoTime() - start[0];
				System.out.println(elapsed);
				
				if (elapsed < PERIOD)
					System.err.println("Oops " + (PERIOD-elapsed));
				if (++count[0] < 30) {
					start[0] = System.nanoTime();
					ses.schedule(this, PERIOD, TimeUnit.NANOSECONDS);
				}
				else
					System.exit(0);
			}
		}, PERIOD, TimeUnit.NANOSECONDS);
	}
	
	public static void main(String...args) {
		new TestNanoScheduledThreadPoolExecutor().test();
	}
}


On Dec 31, 2007 11:10 AM, Hanson Char <hanson.char at gmail.com> wrote:
> Please find below is a simple test that consistently exhibits the
> earlier-than-expected scheduling problem under java version "1.6.0_01"
> on Windows XP.  So far it doesn't seem to have the problem when run on
> Linux, though.
>
> So does this mean the delay of ScheduledThreadPoolExecutor is not
> guaranteed to be at least equal to the specified amount, but could be
> earlier ?  It would be nice if this could be fixed to work on all
> platforms.
>
> Hanson Char
>
> import java.util.concurrent.Executors;
> import java.util.concurrent.ScheduledExecutorService;
> import java.util.concurrent.TimeUnit;
>
> public class TestScheduledThreadPoolExecutor {
>         private static final long PERIOD = 1000;
>
>         public void test() {
>                 final ScheduledExecutorService ses = Executors.newScheduledThreadPool(1);
>                 final long[] start = {System.currentTimeMillis()};
>                 final int[] count = {0};
>
>                 ses.schedule(new Runnable() {
>                         public void run() {
>                                 long elapsed = System.currentTimeMillis() - start[0];
>                                 System.out.println(elapsed);
>
>                                 if (elapsed < PERIOD)
>                                         System.err.println("Oops " + (PERIOD-elapsed));
>                                 if (++count[0] < 30) {
>                                         start[0] = System.currentTimeMillis();
>                                         ses.schedule(this, PERIOD, TimeUnit.MILLISECONDS);
>                                 }
>                                 else
>                                         System.exit(0);
>                         }
>                 }, PERIOD, TimeUnit.MILLISECONDS);
>         }
>
>         public static void main(String...args) {
>                 new TestScheduledThreadPoolExecutor().test();
>         }
> }
>
> Sample output:
>
> 1001
> 1002
> 1001
> 1001
> 1002
> 1001
> 1002
> 1001
> 1002
> 991
> Oops 9
> 1002
> 1001
> 1001
> 1002
> 1001
> 1002
> 1001
> 1002
> 1001
> 1001
> 1002
> 1001
> 1002
> 1001
> 1002
> 1001
> Oops 8
> 992
> 1001
> 1001
> 1002
>
> On Dec 31, 2007 9:01 AM, Hanson Char <hanson.char at gmail.com> wrote:
>
> > This is really strange.  The problem occurred at least on Linux
> > platforms.  The one I am using is
> >
> >   Linux version 2.4.21-37a8 (gcc version 3.2.3 20030502 (Red Hat Linux
> > 3.2.3-47))
> >
> > Hey John, you mentioned you had a unit test that exhibits the problem
> > intermittently.  Would you mind sharing it so we potentially can have
> > it fixed by the experts ?
> >
> > Regards,
> > Hanson Char
> >
> >
> > On Dec 31, 2007 5:59 AM, Doug Lea <dl at cs.oswego.edu> wrote:
> > > Hanson Char wrote:
> > > > (I refer to JDK 6+). It seems a scheduled event via
> > > >
> > > >   ScheduledThreadPoolExecutor.schedule(Runnable command, long delay,
> > > > TimeUnit unit)
> > > >
> > > > may occur before the target time.  For example, if an event is
> > > > scheduled to occur 1000ms from now.  The event could actually get
> > > > triggered after 990ms ie 10 ms less than the specified delay.
> > > >
> > > > Is this a known issue ?  Shouldn't the event be delayed for at least
> > > > the specified delay time ?
> > > >
> > >
> > > I hope David Holmes also answers this, since he knows most about
> > > platform-level timing issues. But I don't know of any problems
> > > that affect ScheduledThreadPoolExecutor in this way. Internally,
> > > methods recheck times to ensure that they do not fire too early.
> > > (See DelayQueue.take and related methods). On some platforms
> > > (including Windows), there may be some *apparent* differences
> > > in times if you are monitoring times with System.currentTimeMillis()
> > > versus System.nanoTime() -- these use different clocks that may become
> > > out of sync. ScheduledThreadPoolExecutor uses nanoTime, which should in
> > > general be more accurate.
> > >
> > > -Doug
>


More information about the Concurrency-interest mailing list