为什么我的System.nanoTime（）被破坏？

Question

我和我的另一位开发人员最近从工作中的Core 2 Duo机器迁移到新的Core 2 Quad 9505;两者都使用JDK 1.6.0_18运行Windows XP SP3 32位。

一旦这样做，由于什么似乎是从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 

运行它100X产率33％，实际60％之间的纳米结果睡觉时间;通常在40％左右。我知道Windows中定时器的精确性的弱点，并且已经阅读了相关的线程，比如Is System.nanoTime() consistent across threads?，但是我的理解是System.nanoTime（）的目的正是为了我们使用它的目的： - 测量已用时间;比currentTimeMillis（）更准确。

有谁知道它为什么会返回这样疯狂的结果吗？这可能是一个硬件架构问题（唯一主要的改变是这台机器上的CPU /主板）？ Windows HAL与我目前的硬件有问题？ JDK问题？我应该放弃nanoTime（）吗？我应该在什么地方记录一个错误，或者有关我如何进一步调查的建议？

UPDATE 19/07 03:15 UTC：在尝试下面的finnw测试用例之后，我做了一些更多的谷歌搜索，碰到一些条目，如bugid:6440250。这也让我想起了周五晚些时候我注意到的其他一些奇怪的行为，在那里ping回来了。所以我在我的boot.ini中加入了/usepmtimer，现在所有的测试都按照预期运行，并且我的ping也是正常的。

我有点困惑，为什么这仍然是一个问题，虽然;从我的阅读中，我认为TSC vs PMT问题在Windows XP SP3中得到了很大程度的解决。难道是因为我的机器最初是SP2，并且已经修补到SP3而不是最初安装为SP3？我现在也想知道我是否应该安装像MS KB896256那样的补丁。也许我应该将这与企业桌面构建团队一起考虑？

Answer 1

的问题，通过加入/usepmtimer我C的最终解决（约nanoTime（）在多核系统的适用性一些开放的怀疑！）：\ boot.ini的串;迫使Windows使用电源管理计时器而不是TSC。这是一个悬而未决的问题，为什么我需要这样做，因为我在XP SP3上，因为我知道这是默认的，但也许是因为我的机器被修补到SP3的方式。

Answer 2

您可能想要阅读其他堆栈溢出问题的答案：Is System.nanoTime() completely useless?。

总之，看起来nanoTime依赖于操作系统定时器，这些定时器可能会受多核CPU的影响。因此，nanoTime可能对OS和CPU的某些组合没有用处，在将其用于可能在多个目标平台上运行的可移植Java代码中时应该小心。网上似乎有很多关于这个问题的抱怨，但对于一个有意义的替代方案没有多少共识。

Answer 3

在我的系统（Windows 7的64位，酷睿i7 980X）：

nanosTaken=4999902563 
millisTaken=5001 

System.nanoTime（）使用操作系统特定的电话，所以我希望您看到的错误在你的Windows /处理器组合。

Answer 4

很难判断这是一个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); 
} 

如果你得到同样的核心，但2200ms取决于核心精选截然不同的结果（例如，5000毫秒在不同的核心上），这表明问题只是核心之间的自然计时器变化。

如果你从睡眠与纺纱得到非常不同的结果，但更可能是由于电源管理减慢时钟。

如果没有的四个结果都接近5000ms，那么它可能是一个bug。