ScheduledExecutorService very inaccurate?

[Chris Seidel]

Hi,

i'm using a ScheduledExecutorService to schedule a task. The problem is,
that the task gets execute about 10 - 20 percent too late, e.g. when I
schdule it with 20 s delay, it gets executed after 24 s.

Is this "normal"?

Here is the testcode:

package com.foo;

import static junit.framework.Assert.assertEquals;

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

import org.junit.Test;

public class SchedulerTest {
private ScheduledExecutorService s;
private long executedAtMillis;

@Test
public void test1() {
s = Executors.newScheduledThreadPool(1);
final long currentTimeMillis = System.currentTimeMillis();
long delay = 20000L;
s.schedule(new Runnable() {
public void run() {
executedAtMillis = System.currentTimeMillis();
}
}, delay, TimeUnit.MILLISECONDS);
try {
Thread.sleep(delay * 2);
} catch (InterruptedException e) {
}
assertEquals(delay, executedAtMillis - currentTimeMillis);
}
}

When I use java.util.Timer everything is ok:



@Test
public void test2() {
Timer t = new Timer();
final long currentTimeMillis = System.currentTimeMillis();
long delay = 20000L;

t.schedule(new TimerTask() {
@Override
public void run() {
executedAtMillis = System.currentTimeMillis();
}
}, delay);
sleep(delay);
assertEquals(delay, executedAtMillis - currentTimeMillis);
}

Thank you.

 

[Lew]

i'm [sic] using a ScheduledExecutorService to schedule a task. The problem is,  
that the task gets execute about 10 - 20 percent too late, e.g. when I  
schdule it with 20 s delay, it gets executed after 24 s.

Is this "normal"?

Check the Javadocs. There is nothing there to promise that the
scheduled task will occur exactly at the termination of the delay or
even within any time frame thereafter. They only promise to "schedule
commands to run after a given delay", and your description shows that
that promise was kept.

There are two levels where it does not promise what you ask there.
The first is that it only promises to *schedule* the occurrence after
the delay, not to run it at the exact scheduled time. The second is
that the schedule is for *after* the delay, not for *when* the delay
expires.

Furthermore, java.util.Timer doesn't promise that kind of precision
either: "[java.util.Timer] does not offer real-time guarantees: it
schedules tasks using the Object.wait(long) method."
Object#wait(long) waits until "[t]he specified amount of real time has
elapsed, more or less. ... The thread T is then removed from the wait
set for this object and re-enabled for thread scheduling. It then
competes in the usual manner with other threads for the right to
synchronize on the object ...".

ScheduledExecutorService is an interface; its behavior is dependent on
some unknown implementation. Still, neither it nor Timer promises
what you're requesting.

 

[Lew]

When I use java.util.Timer everything is ok:

By coincidence.

        @Test
        public void test2() {
                Timer t = new Timer();
                final long currentTimeMillis = System.currentTimeMillis();
                long delay = 20000L;

                t.schedule(new TimerTask() {
                        @Override
                        public void run() {
                                executedAtMillis = System.currentTimeMillis();
                        }
                }, delay);
                sleep(delay);
                assertEquals(delay, executedAtMillis - currentTimeMillis);
        }

How are you synchronizing 'executedAtMillis'?

 

[Chris Seidel]

ScheduledExecutorService is an interface; its behavior is dependent on
some unknown implementation. Still, neither it nor Timer promises
what you're requesting.

Do you know a Timer-Impl which guarantees the execution time (in that
sense that Java has no real time support)?

And do you know from where the quite constant offset comes, when using
ScheduledThreadPoolExecutor:

delay 2.000 > execution at 2.400
delay 20.000 > execution at 24.000
delay 200.000 > execution at 240.000

 

[Chris Seidel]

By coincidence.

Even when the Timer has only a single task and then gets terminated?

How are you synchronizing 'executedAtMillis'?

Not at all, just a field var:

private long 'executedAtMillis';

There is only a single Timer-Thread running, no need to sync in this test.

 

[Daniel Pitts]

Even when the Timer has only a single task and then gets terminated?


Not at all, just a field var:

private long 'executedAtMillis';

There is only a single Timer-Thread running, no need to sync in this test.

Except you are reading it from a different thread, so there is a need to
sync. I doubt that is causing the problem, but it is still necessary.
Making the field volatile should be enough for this example.

 

[Lew]

Even when the Timer has only a single task and then gets terminated?

See the quotes I already cited upthread from Timer's Javadocs.

 

[Chris Seidel]

See the quotes I already cited upthread from Timer's Javadocs.

OK, so a GC or too many threads and too many task at the same time can
delay the execution time.

 

[Daniel Pitts]

OK, so a GC or too many threads and too many task at the same time can
delay the execution time.

Or the OS process scheduler, or a disk-read, or a solar eclipse, or many
different things.

There is no guarantee of the latest it will run, only the earliest.

 

[Arne Vajhøj]

Do you know a Timer-Impl which guarantees the execution time (in that
sense that Java has no real time support)?

Java can not really do much on a non-realtime OS.

Arne

 

[Kevin McMurtrie]

You're allocating memory, allocating threads, and probably loading
classes between your clock starting and the executor's clock starting.

Sun's Delayed interface is also badly flawed. It's a Comparable
relative to the current time so comparing X to Y produces a different
result than comparing Y to X. The time shifting scrambles the
PriorityQueue to some degree, especially on GC pauses. In your specific
case below, Sun has a workaround for the problem by casting the other
Comparable to an internal implementation class to compare absolute
times. There are other uses of ScheduledThreadPoolExecutor where it
can't do the cast and it makes a mess.

 

[Chris Seidel]

Java can not really do much on a non-realtime OS.

OK, OK... but we are talking about many seconds or minutes difference, not
about milli- or microseconds!
This cannot be in a simple test where nothing runs besides this simple
test in the VM.

 

[Chris Seidel]

There is no guarantee of the latest it will run, only the earliest.

I know. But in my opinion there is absolute no reason for a CONSTANT
offset in percent between delay and execution. This is absolute weird.

 

[Chris Seidel]

I know. But in my opinion there is absolute no reason for a CONSTANT
offset in percent between delay and execution. This is absolute weird.

OK; I got it:

http://communities.vmware.com/thread/215461

Damned, so my Software will not run in VMWare!? :/

 

[Lew]

OK, OK... but we are talking about many seconds or minutes difference,
not about milli- or microseconds!
This cannot be in a simple test where nothing runs besides this simple
test in the VM.

It cannot be, yet you observed it. This is the great conundrum, Grasshopper.

 

[Lew]

OK; I got it:

http://communities.vmware.com/thread/215461

Damned, so my Software will not run in VMWare!? :/

The answer lies in the information you neglect to provide.

Your evidence shows that your software does run under VMWare, further, that it
runs according to spec, just not the way you hoped.

 

[Chris Seidel]

No. And I do not have that problem.

I already found out, that the problem is that VMWare does not give the
correct values for System.nanoTime() on which SES relies.
Running it outside of VMWARE - everything is ok, only a small diff (ms)
which is acceptable.

Thank you

 

[Kevin McMurtrie]

OK; I got it:

http://communities.vmware.com/thread/215461

Damned, so my Software will not run in VMWare!? :/

This is a Solaris bug, not a VMWare bug. Many threads or processes
reading the high resolution system clock concurrently will cause a
random extra bit along a 32 bit word boundary. A patch is available.

This isn't the bug you're seeing. The extra bit causes an extreme clock
jump that scrambles the JVM. GC and HotSpot will self-tune into
oblivion and scheduled tasks completely halt until the next glitch.

 

[Chris Seidel]

This is a Solaris bug, not a VMWare bug.

No.

I could fix it with the following VMWare settings:

monitor_control.disable_tsc_offsetting=TRUE
monitor_control.disable_rdtscopt_bt=TRUE

Now everything schedules fine, no more constant offset.

 

[Kevin McMurtrie]

No.

I could fix it with the following VMWare settings:

monitor_control.disable_tsc_offsetting=TRUE
monitor_control.disable_rdtscopt_bt=TRUE

Now everything schedules fine, no more constant offset.

You've fixed another bug then. The one you linked to is about extremely
large jumps and it happens without VMware.