System.nanotime运行缓慢？

Question

我的一个朋友向我展示了他做的一些事情，我很困惑地解释为什么会发生这种情况:他使用System.nanotime来计时，它每秒都会给用户更新一次，告诉用户已经过去了多少时间(这部分是Thread.sleep(1000) )，而且似乎永远都要花(等待10秒的事情大约需要3分钟才能完成)。我们尝试使用毫秒时间来查看经过了多少时间:它打印出每秒经过了多少纳米时间，我们看到，对于每一秒，纳米时间每秒大约移动40-50毫秒。

我检查了与System.nanotime和Java相关的bug，但似乎我唯一能找到的东西就是突然出现的nanotime greatly increasing and then stopping。我还根据我在另一个问题中读到的东西浏览了this blog entry，但这并没有任何可能导致它的东西。

显然，可以通过使用毫秒时间来解决这种情况；有很多解决方法可以解决这个问题，但我好奇的是，除了系统时钟的硬件问题，或者至少是CPU拥有的最准确的时钟(因为这就是System.nanotime似乎使用的时钟)之外，是否有任何其他问题会导致它像这样持续运行缓慢？

long initialNano = System.nanoTime();
long initialMili = System.currentTimeMillis();
//Obviously the code isn't actually doing a while(true), 
//but it illustrates the point
while(true) {
    Thread.sleep(1000);
    long currentNano = System.nanoTime();
    long currentMili = System.currentTimeMillis();
    double secondsNano = ((double) (currentNano - initialNano))/1000000000D;
    double secondsMili = ((double) (currentMili - initialMili))/1000D;
    System.out.println(secondsNano);
    System.out.println(secondsMili);
}

secondsNano将打印0.04行的内容，而secondsMili将打印非常接近1的内容。

这看起来像是在Sun's bug database上报告了一个bug，但他们将其作为副本关闭了，但他们的链接并没有指向现有的bug。它似乎是非常系统特定的，所以我越来越确定这是一个硬件问题。

Answer 1

...他使用System.nanotime使程序在执行某些操作之前等待，然后...

你能给我们看一下他到底在做什么的代码吗？是不是有一种奇怪的繁忙循环，像这样：

long t = System.nanoTime() + 1000000000L;
while (System.nanoTime() < t) { /* do nothing */ }

如果是，那么这不是让你的程序暂停一段时间的正确方式。改用Thread.sleep(...)使程序等待指定的毫秒数。

Answer 2

你是否意识到你正在使用的循环并不需要1秒的时间来运行？首先，不能保证Thread.sleep()是准确的，并且循环中的其余代码确实需要一些时间来执行( nanoTime()和currentTimeMillis()实际上都可能相当慢，这取决于底层实现)。其次，也不能保证System.currentTimeMillis()是准确的(在某些操作系统和硬件组合上，它每50ms才更新一次)。你还提到它不准确到上面的40-50毫秒，然后继续说0.004s，实际上只有4毫秒。

我建议您将System.out.println()更改为：

System.out.println(secondsNano - secondsMili);

这样，您将能够看到两个时钟在每秒的基础上有多大的差异。我让它在我的笔记本上运行了大约12个小时，它在1.46秒(快，而不是慢)出来了。这表明这两个时钟有一些漂移。

我认为currentTimeMillis()方法在很长一段时间内提供了更准确的时间，而nanoTime()具有更高的分辨率，适合于计时代码或在短时间内提供亚毫秒级的计时。

Answer 3

我也遇到过同样的问题。除了在我的例子中，它更明显。

使用这个简单的程序：

public class test {
    public static void main(String[] args) {
        while (true) {
            try { 
                Thread.sleep(1000); 
            } 
            catch (InterruptedException e) { 
            }

            OStream.out("\t" + System.currentTimeMillis() + "\t" + nanoTimeMillis());
        }
    }

    static long nanoTimeMillis() {
        return Math.round(System.nanoTime() / 1000000.0);
    }
}

我得到了以下结果：

13:05:16:380 main:  1288199116375   61530042
13:05:16:764 main:  1288199117375   61530438
13:05:17:134 main:  1288199118375   61530808
13:05:17:510 main:  1288199119375   61531183
13:05:17:886 main:  1288199120375   61531559

nanoTime显示每秒仅运行约400ms。