Por que meu System.nanoTime () está quebrado?
Eu e outro desenvolvedor do meu tempo recentemente mudamos de uma máquina Core 2 Duo no trabalho para um novo Core 2 Quad 9505; ambos executando o Windows XP SP3 de 32 bits com o JDK 1.6.0_18.
Ao fazer isso, alguns de nossos testes de unidade automatizados para algum código de agregação de tempo / estatística / métrica começaram a falhar imediatamente, devido ao que parecem ser valores ridículos voltando do System.nanoTime ().
O código de teste que mostra esse comportamento, de maneira confiável, na minha máquina é:
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));
}
}
Saída típica:
millisTaken=5001
nanosTaken=2243785148
Executá-lo 100x produz nano resultados entre 33% e 60% do tempo real de sono; normalmente cerca de 40%.
Entendo os pontos fracos na precisão dos cronômetros no Windows e li tópicos relacionados comoSystem.nanoTime () é consistente entre os segmentos?, no entanto, meu entendimento é que System.nanoTime () se destina exatamente ao objetivo que estamos usando: - medir o tempo decorrido; com mais precisão do que currentTimeMillis ().
Alguém sabe por que está retornando resultados tão loucos? É provável que isso seja um problema de arquitetura de hardware (a única coisa importante que mudou foi a CPU / placa-mãe nesta máquina)? Um problema com o Windows HAL com meu hardware atual? Um problema com o JDK? Devo abandonar o nanoTime ()? Devo registrar um bug em algum lugar ou alguma sugestão sobre como investigar mais?
ATUALIZAÇÃO 19/07 03:15 UTC: Depois de experimentar o caso de teste do finnw abaixo, fiz um pouco mais de pesquisa no Google, encontrando entradas comobugid: 6440250. Também me lembrou algum outro comportamento estranho que notei no final da sexta-feira, onde os pings estavam voltando negativos. Então eu adicionei/ usepmtimer para o meu boot.ini e agora todos os testes se comportam como esperado., e meus pings também são normais.
Estou um pouco confuso sobre por que isso ainda era um problema; da minha leitura, pensei que os problemas de TSC vs PMT foram amplamente resolvidos no Windows XP SP3. Poderia ser porque minha máquina era originalmente SP2 e foi corrigida para o SP3 em vez de instalada originalmente como SP3? Agora também me pergunto se devo instalar patches como o deMS KB896256. Talvez eu deva aceitar isso com a equipe corporativa de criação de desktops?