代码之家 › 专栏 › 技术社区 › Chad

为什么我的系统。nanoTime()坏了?

nanotime timestamp java

Chad · 技术社区 · 16 年前

我自己和另一个开发人员最近从一个核心2双核机工作到一个新的核心2四核9505;两者都运行Windows XP SP3 32位和JDK 1.6.0\U 18。

在这样做之后,我们对一些计时/统计/度量聚合代码的几个自动单元测试立即开始失败,原因是从System.nanoTime()返回的值看起来很荒谬。

在我的机器上可靠地显示此行为的测试代码是:

import static org.junit.Assert.assertThat;

import org.hamcrest.Matchers;
import org.junit.Test;

public class NanoTest {

  @Test
  public void testNanoTime() throws InterruptedException {
    final long sleepMillis = 5000;

    long nanosBefore = System.nanoTime();
    long millisBefore = System.currentTimeMillis();

    Thread.sleep(sleepMillis);

    long nanosTaken = System.nanoTime() - nanosBefore;
    long millisTaken = System.currentTimeMillis() - millisBefore;

    System.out.println("nanosTaken="+nanosTaken);
    System.out.println("millisTaken="+millisTaken);

    // Check it slept within 10% of requested time
    assertThat((double)millisTaken, Matchers.closeTo(sleepMillis, sleepMillis * 0.1));
    assertThat((double)nanosTaken, Matchers.closeTo(sleepMillis * 1000000, sleepMillis * 1000000 * 0.1));
  }

}

典型输出:

millisTaken=5001
nanosTaken=2243785148

运行它100倍产生纳米结果之间的33%和60%的实际睡眠时间;不过通常是40%左右。

我了解Windows中计时器准确性的弱点,并阅读过类似的相关文章 Is System.nanoTime() consistent across threads? 然而,我的理解是System.nanoTime()正是为了我们使用它的目的:测量经过的时间;比currentTimeMillis()更精确。

有人知道为什么它会返回如此疯狂的结果吗?这可能是硬件架构问题吗(唯一主要的变化是这台机器上的CPU/主板)?我当前的硬件有问题吗?JDK问题?我应该放弃nanoTime()吗?我是否应该在某个地方记录一个bug,或者对如何进一步调查有什么建议?

:在尝试了下面finnw的测试用例之后,我又在Google上搜索了一些条目,比如 bugid:6440250 /使用计时器 到我的boot.ini,现在所有的测试都按预期进行,我的ping也正常。

MS KB896256 . 也许我应该和公司桌面构建团队谈谈?

4 回复 | 直到 9 年前

Chad 16 年前

问题解决了(有人公开怀疑nanoTime()是否适合多核系统!)通过添加 /使用计时器 直到我生命的尽头 C:\boot.ini文件

mikera 16 年前

nanosTaken=4999902563
millisTaken=5001

System.nanoTime()使用特定于操作系统的调用,因此我希望您在Windows/处理器组合中看到一个bug。

Community Mohan Dere 9 年前

您可能想阅读另一个堆栈溢出问题的答案: Is System.nanoTime() completely useless? .

总之,nanoTime似乎依赖于操作系统计时器,这些计时器可能会受到多个核心cpu的影响。因此,nanoTime在操作系统和CPU的某些组合上可能没有那么大的用处,在您打算在多个目标平台上运行的可移植Java代码中使用nanoTime时应该小心。在这个问题上,网络上似乎有很多抱怨,但对于一个有意义的替代方案却没有多少共识。

finnw 16 年前

很难判断这是一个bug还是内核之间的正常定时器变化。

另外,为了排除电源管理的影响,可以尝试在一个循环中旋转作为替代 sleep() :

import com.sun.jna.Native;
import com.sun.jna.NativeLong;
import com.sun.jna.platform.win32.Kernel32;
import com.sun.jna.platform.win32.W32API;

public class AffinityTest {

    private static void testNanoTime(boolean sameCore, boolean spin)
    throws InterruptedException {
        W32API.HANDLE hThread = kernel.GetCurrentThread();
        final long sleepMillis = 5000;

        kernel.SetThreadAffinityMask(hThread, new NativeLong(1L));
        Thread.yield();
        long nanosBefore = System.nanoTime();
        long millisBefore = System.currentTimeMillis();

        kernel.SetThreadAffinityMask(hThread, new NativeLong(sameCore? 1L: 2L));
        if (spin) {
            Thread.yield();
            while (System.currentTimeMillis() - millisBefore < sleepMillis)
                ;
        } else {
            Thread.sleep(sleepMillis);
        }

        long nanosTaken = System.nanoTime() - nanosBefore;
        long millisTaken = System.currentTimeMillis() - millisBefore;

        System.out.println("nanosTaken="+nanosTaken);
        System.out.println("millisTaken="+millisTaken);
    }

    public static void main(String[] args) throws InterruptedException {
        System.out.println("Sleeping, different cores");
        testNanoTime(false, false);
        System.out.println("\nSleeping, same core");
        testNanoTime(true, false);
        System.out.println("\nSpinning, different cores");
        testNanoTime(false, true);
        System.out.println("\nSpinning, same core");
        testNanoTime(true, true);
    }

    private static final Kernel32Ex kernel =
        (Kernel32Ex) Native.loadLibrary(Kernel32Ex.class);

}

interface Kernel32Ex extends Kernel32 {
    NativeLong SetThreadAffinityMask(HANDLE hThread, NativeLong dwAffinityMask);
}

如果你从睡眠和旋转中得到了截然不同的结果,那很可能是因为电源管理减慢了时钟。

如果 没有人