Como cronometrar a velocidade de execução do programa Java

85

Como você cronometra a execução de um programa java? Não tenho certeza de que classe devo usar para fazer isso.

Estou procurando algo como:

// Some timer starts here
for (int i = 0; i < length; i++) {
  // Do something
}
// End timer here

System.out.println("Total execution time: " + totalExecutionTime);
George Mic
fonte

Respostas:

139
final long startTime = System.currentTimeMillis();
for (int i = 0; i < length; i++) {
  // Do something
}
final long endTime = System.currentTimeMillis();

System.out.println("Total execution time: " + (endTime - startTime));
bua
fonte
2
realmente deveria ser nanoTime, na verdade
Eugene
6
Não deve ser nanoTime. Veja a resposta de rhu.
fabspro
4
Existe algum motivo específico para usar "final" aqui? O que seria diferente se você abandonasse essa palavra-chave?
dijxtra
9
O uso de @dijxtra finaltem a vantagem de não ser possível atribuí-lo acidentalmente (além de outras vantagens, como acesso anônimo à classe, etc.). Neste código não faria diferença. É uma prática bastante comum fazer tudo finale apenas finaldesorganizá-lo se for necessário.
wchargin
1
O código a ser testado, junto com as medições de tempo, deve ser executado várias vezes e o primeiro resultado deve ser descartado. O primeiro provavelmente incluirá tempos de carregamento de classe, etc. Executando-o várias vezes, é claro, você obtém uma média que é mais útil e confiável.
Arun Ramakrishnan
34

Esteja ciente de que existem alguns problemas onde System#nanoTime()não pode ser usado de forma confiável em CPUs multi-core para registrar o tempo decorrido ... cada núcleo mantém seu próprio TSC ( Time Stamp Counter ): este contador é usado para obter o tempo nano (realmente é o número de tiques desde que a CPU foi inicializada).

Portanto, a menos que o sistema operacional faça algum sincronismo de tempo TSC para manter os núcleos em sincronia, então, se um encadeamento for agendado em um núcleo quando a leitura de tempo inicial é feita e, em seguida, alternado para um núcleo diferente, o tempo relativo pode esporadicamente parecer retroceder e para a frente.

Observei isso há algum tempo no AMD / Solaris, onde os tempos decorridos entre dois pontos de controle às vezes voltavam como valores negativos ou números positivos inesperadamente grandes. Havia um patch de kernel Solaris e uma configuração de BIOS necessária para forçar o AMD PowerNow! desligado, que parecia resolvê-lo.

Além disso, há (AFAIK) um bug não corrigido até agora ao usar java System#nanoTime()em um ambiente VirtualBox; causando todos os tipos de problemas bizarros de threading intermitente para nós, já que grande parte do java.util.concurrencypacote depende do tempo nano.

Veja também:

System.nanoTime () é completamente inútil? http://vbox.innotek.de/pipermail/vbox-trac/2010-January/135631.html

rhu
fonte
9

Você obtém a hora atual do sistema, em milissegundos:

final long startTime = System.currentTimeMillis();

Então você faz o que vai fazer:

for (int i = 0; i < length; i++) {
  // Do something
}

Então você vê quanto tempo demorou:

final long elapsedTimeMillis = System.currentTimeMillis() - startTime;
Jonathan Feinberg
fonte
A resposta de BalusC também está correta; depende da resolução necessária do temporizador e da razão pela qual você precisa do tempo.
Jonathan Feinberg,
9

Você pode fazer uso de System#nanoTime(). Pegue antes e depois da execução e faça as contas. É preferido acima System#currentTimeMillis()porque tem uma precisão melhor. Dependendo do hardware e da plataforma usada, você pode obter uma lacuna incorreta no tempo decorrido. Aqui, com Core2Duo no Windows, entre cerca de 0 e ~ 15ms, na verdade, nada pode ser calculado.

Uma ferramenta mais avançada é um criador de perfil .

BalusC
fonte
O cronômetro no Windows não tem uma resolução particularmente boa por padrão. Não é um temporizador de alta performance também, mas é muito mais difícil de usar, mesmo a partir de C e Java não (AFAIK) fornecer acesso a esse baixo nível de hackery sem uma JNI conversão.
Donal Fellows,
1
nanoTime()tem um problema (pelo menos no Windows); o carimbo de data / hora é específico do núcleo do processador. Tive um programa que teve um tempo de execução negativo porque obteve o carimbo de data / hora "start" em um núcleo e o carimbo de data / hora "stop" em outro núcleo.
gustafc,
3

Para coisas simples, System.currentTimeMillis () pode funcionar.

Na verdade, é tão comum que meu IDE esteja configurado de forma que, ao inserir "t0", ele gere a seguinte linha:

final long t0 = System.currentTimeMillis()

Mas para coisas mais complicadas, você provavelmente vai querer usar medidas estatísticas de tempo, como aqui (role um pouco para baixo e observe as medidas de tempo expressas, incluindo desvios-padrão, etc.):

http://perf4j.codehaus.org/devguide.html

SintaxeT3rr0r
fonte
1 para apontar o código do gerador automático. Eu uso uma instrução semelhante o tempo todo e não sabia como inserir modelos de código. Acabei de descobrir como fazer isso com o eclipse, e com certeza vai ajudar!
Jason,
Todos os serviços da Codehaus foram encerrados. Seu link agora está quebrado.
naXa
2

Usando AOP / AspectJ e @Loggableanotações de jcabi-aspect você pode fazer isso de forma fácil e compacta:

@Loggable(Loggable.DEBUG)
public String getSomeResult() {
  // return some value
}

Cada chamada para este método será enviada ao recurso de registro SLF4J com DEBUGnível de registro. E cada mensagem de log incluirá o tempo de execução.

Yegor256
fonte
2

Aqui estão algumas maneiras de encontrar o tempo de execução em Java:

1) System.nanoTime ()

long startTime = System.nanoTime();
.....your code....
long endTime   = System.nanoTime();
long totalTime = endTime - startTime;
System.out.println("Execution time in nanoseconds  : " + totalTime);
System.out.println("Execution time in milliseconds : " + totalTime / 1000000);

2) System.currentTimeMillis ()

long startTime = System.currentTimeMillis();
.....your code....
long endTime = System.currentTimeMillis();
long totalTime = endTime - startTime;
System.out.println("Execution time in milliseconds  : " + totalTime);

3) Instant.now ()

long startTime = Instant.now().toEpochMilli();
.....your code....
long endTime = Instant.now().toEpochMilli();
long totalTime = endTime - startTime;
System.out.println("Execution time in milliseconds: " + totalTime);

ou

Instant start = Instant.now();
.....your code....
Instant end = Instant.now();
Duration interval = Duration.between(start, end);
System.out.println("Execution time in seconds: " +interval.getSeconds());

4) Date.getTime ()

long startTime = new Date().getTime();
.....your code....
long endTime = new Date().getTime();
long totalTime = endTime - startTime;
System.out.println("Execution time in milliseconds: " + totalTime);
SumiSujith
fonte
1

use long startTime=System.currentTimeMillis()para o tempo de início, no topo do loop

colocado long endTime= System.currentTimeMillis();fora do final do loop. Você terá que subtrair os valores para obter o tempo de execução em milissegundos.

Se você quiser tempo em nanossegundos, dê uma olhada System.nanoTime()

Jason
fonte
1

Eu criei uma função de ordem superior que pega o código que você deseja medir em / como um lambda:

class Utils {

    public static <T> T timeIt(String msg, Supplier<T> s) {
        long startTime = System.nanoTime();
        T t = s.get();
        long endTime = System.nanoTime();
        System.out.println(msg + ": " + (endTime - startTime) + " ns");
        return t;
    }

    public static void timeIt(String msg, Runnable r) {
       timeIt(msg, () -> {r.run(); return null; });
    }
}

Chame assim:

Utils.timeIt("code 0", () ->
        System.out.println("Hallo")
);

// in case you need the result of the lambda
int i = Utils.timeIt("code 1", () ->
        5 * 5
);

Resultado:

código 0: 180528 ns
código 1: 12003 ns

Agradecimentos especiais a Andy Turner, que me ajudou a reduzir a redundância. Veja aqui .

Willi Mentzel
fonte
0

Você também pode experimentar o Perf4J. É uma maneira elegante de fazer o que você está procurando e ajuda nas estatísticas de desempenho agregadas como média, mínimo, máximo, desvio padrão e transações por segundo em um intervalo de tempo definido. Um trecho de http://perf4j.codehaus.org/devguide.html :

StopWatch stopWatch = new LoggingStopWatch();

try {
    // the code block being timed - this is just a dummy example
    long sleepTime = (long)(Math.random() * 1000L);
    Thread.sleep(sleepTime);
    if (sleepTime > 500L) {
        throw new Exception("Throwing exception");
    }

    stopWatch.stop("codeBlock2.success", "Sleep time was < 500 ms");
} catch (Exception e) {
    stopWatch.stop("codeBlock2.failure", "Exception was: " + e);
}

Resultado:

INFO: start[1230493236109] time[447] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493236719] time[567] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]
INFO: start[1230493237286] time[986] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]
INFO: start[1230493238273] time[194] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493238467] time[463] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493238930] time[310] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493239241] time[610] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]
INFO: start[1230493239852] time[84] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493239937] time[30] tag[codeBlock2.success] message[Sleep time was < 500 ms]
INFO: start[1230493239968] time[852] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]
dotrc
fonte
0
public class someClass
{
   public static void main(String[] args) // your app start point
   {
       long start = java.util.Calendar.getInstance().getTimeInMillis();

       ... your stuff ...

       long end = java.util.Calendar.getInstance().getTimeInMillis();
       System.out.println("it took this long to complete this stuff: " + (end - start) + "ms");
   }
}
luis.espinal
fonte
0

Usar System.currentTimeMillis () é a maneira correta de fazer isso. Mas, se você usar a linha de comando e quiser cronometrar todo o programa de forma aproximada e rápida, pense em:

time java App

que permite que você não modifique o código e o tempo de seu aplicativo.

MarAja
fonte
Isso depende de como você executa o código. Se for um trecho de código executando um servidor, você incluirá o tempo de inicialização incorreto.
Arun Ramakrishnan