java - scheduledThreadPool.scheduleAtFixedRate() 奇怪的行为

Question

我有这个简单的测试:

import java.util.Timer;
import java.util.TimerTask;

public class ScheduleTest {

  private static long last;

  public static void main(String[] args) {

    last = System.currentTimeMillis();

    Timer timer = new Timer();
    timer.schedule(new TimerTask() {

      @Override
      public void run() {
        Long current = System.currentTimeMillis();
        System.out.println(current - last);
        last = current;

      }
    }, 0, 1000);
  }
}

这给了我预期的结果:

0
1000
1000
1000

如果我用 ScheduleThreadPoool 替换 Timer，它会给我奇怪的结果:

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

public class ScheduleTest {

  private static long last;

  public static void main(String[] args) {

    last = System.currentTimeMillis();

    ScheduledExecutorService scheduledThreadPool = Executors.newScheduledThreadPool(1);

    last = System.currentTimeMillis();
    scheduledThreadPool.scheduleAtFixedRate(new Runnable() {

      @Override
      public void run() {

        Long current = System.currentTimeMillis();
        System.out.println(current - last);
        last = current;

      }
    }, 0, 1000, TimeUnit.MILLISECONDS);
  }
}

结果:

0
2359
2079
2312
1844
2266

有什么期待吗？

Answer 1

我想我有一个线索。

ScheduledThreadPool 使用 DelayQueue 来存储下一个要启动的任务。 DelayQueue 使用 System.nanoTime() 计算任务运行前的剩余时间。

但是 System.nanoTime() 在我的 PC (XP 64 SP2) 上似乎有问题:

    while (true) {
        long start = System.currentTimeMillis();
        long startNanos = System.nanoTime();
        LockSupport.parkNanos(Thread.currentThread(), 1000000000);
        System.out.println("after: " + (System.currentTimeMillis() - start) + " - nanos: "
                + (System.nanoTime() - startNanos) + " - nanos converted: "
                + TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNanos));
    }

结果:

after: 1000 - nanos: 499769959 - nanos converted: 500
after: 1000 - nanos: 415454114 - nanos converted: 415
after: 1000 - nanos: 416274224 - nanos converted: 416
after: 1000 - nanos: 416141257 - nanos converted: 416
after: 1000 - nanos: 418547153 - nanos converted: 418

因此，基于有偏见的纳米，任务的重新规划是不正确的。计时器使用 System.currentTimeMillis() 效果很好。

有很多关于 System.nanoTimes() 的讨论:

Is System.nanoTime() completely useless?

Why is my System.nanoTime() broken?