爲什麼我的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。