Comment chronométrer la vitesse d'exécution du programme Java

85

Comment chronométrez-vous l'exécution d'un programme java? Je ne sais pas quelle classe je devrais utiliser pour cela.

Je recherche quelque chose comme:

// 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
la source

Réponses:

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
la source
2
ça devrait vraiment être nanoTime en fait
Eugene
6
Ne devrait pas être nanoTime. Voir la réponse de rhu.
fabspro
4
Y a-t-il une raison particulière pour laquelle vous avez utilisé «final» ici? Qu'est-ce qui serait différent si vous supprimiez ce mot-clé?
dijxtra
9
@dijxtra using finala l'avantage que vous ne pouvez pas lui attribuer accidentellement (ainsi que d'autres avantages, tels que l'accès anonyme aux classes, etc.). Dans ce code, cela ne ferait aucune différence. C'est une pratique assez courante de tout faire finalet de ne le finalredimensionner que si vous en avez besoin.
wchargin
1
Le code à tester, ainsi que les mesures de temps, doivent être exécutés plusieurs fois et le premier résultat doit être rejeté. Le premier comprendra probablement les temps de chargement des classes, etc. En l'exécutant plusieurs fois, vous obtenez bien sûr une moyenne plus utile et plus fiable.
Arun Ramakrishnan
34

Sachez qu'il y a des problèmes qui System#nanoTime()ne peuvent pas être utilisés de manière fiable sur les processeurs multi-cœurs pour enregistrer le temps écoulé ... chaque cœur a son propre TSC ( Time Stamp Counter ): ce compteur est utilisé pour obtenir le temps nano (vraiment c'est le nombre de ticks depuis le démarrage du CPU).

Par conséquent, à moins que le système d'exploitation ne modifie le temps TSC pour garder les cœurs synchronisés, alors si un thread est programmé sur un cœur lorsque la lecture initiale de l'heure est prise, puis basculé vers un cœur différent, le temps relatif peut sporadiquement sembler sauter en arrière. et en avant.

J'ai observé cela il y a quelque temps sur AMD / Solaris où les temps écoulés entre deux points de synchronisation revenaient parfois sous forme de valeurs négatives ou de nombres positifs inattendus. Il y avait un patch du noyau Solaris et un paramètre BIOS requis pour forcer AMD PowerNow! off, qui a semblé le résoudre.

En outre, il existe (AFAIK) un bogue non résolu jusqu'à présent lors de l'utilisation de java System#nanoTime()dans un environnement VirtualBox; causant toutes sortes de problèmes de threads intermittents bizarres pour nous car une grande partie du java.util.concurrencypaquet repose sur le temps nano.

Voir également:

System.nanoTime () est-il complètement inutile? http://vbox.innotek.de/pipermail/vbox-trac/2010-January/135631.html

rhu
la source
9

Vous obtenez l'heure actuelle du système, en millisecondes:

final long startTime = System.currentTimeMillis();

Ensuite, vous faites ce que vous allez faire:

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

Ensuite, vous voyez combien de temps cela a pris:

final long elapsedTimeMillis = System.currentTimeMillis() - startTime;
Jonathan Feinberg
la source
La réponse de BalusC est également correcte; cela dépend de la résolution de minuterie nécessaire et de la raison pour laquelle vous avez besoin de la synchronisation.
Jonathan Feinberg
9

Vous pouvez utiliser System#nanoTime(). Obtenez-le avant et après l'exécution et faites simplement le calcul. Il est préféré ci System#currentTimeMillis()- dessus car il a une meilleure précision. Selon le matériel et la plate-forme utilisés, vous risquez sinon d'obtenir un écart incorrect dans le temps écoulé. Ici, avec Core2Duo sous Windows, entre environ 0 et ~ 15 ms, rien ne peut être calculé.

Un outil plus avancé est un profileur .

BalusC
la source
Le minuteur sur Windows n'a pas une résolution particulièrement bonne par défaut. Il existe également un minuteur haute performance, mais il est beaucoup plus difficile à utiliser, même à partir de C et Java (AFAIK) ne donne pas accès à ce bas niveau de piratage sans un thunk JNI.
Donal Fellows
1
nanoTime()a un problème (au moins sur Windows); l'horodatage est spécifique au cœur du processeur. J'avais un programme qui avait un temps d'exécution négatif parce qu'il avait l'horodatage "start" sur un core et l'horodatage "stop" sur un autre core.
gustafc
3

Pour des choses simples, System.currentTimeMillis () peut fonctionner.

Il est en fait si courant que mon IDE est configuré de sorte qu'en entrant "t0", il me génère la ligne suivante:

final long t0 = System.currentTimeMillis()

Mais pour des choses plus compliquées, vous voudrez probablement utiliser des mesures de temps statistiques, comme ici (faites défiler un peu vers le bas et regardez les mesures de temps exprimées, y compris les écarts-types, etc.):

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

SyntaxeT3rr0r
la source
+1 pour indiquer le code du générateur automatique. J'utilise une déclaration similaire tout le temps et je ne savais pas comment insérer des modèles de code. Je viens de découvrir comment faire cela avec éclipse, et cela aidera certainement!
Jason
Tous les services Codehaus ont été résiliés. Votre lien est maintenant rompu.
naXa
2

En utilisant AOP / AspectJ et les @Loggableannotations de jcabi-aspects, vous pouvez le faire de manière simple et compacte:

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

Chaque appel à cette méthode sera envoyé à l'installation de journalisation SLF4J avec le DEBUGniveau de journalisation. Et chaque message de journal inclura le temps d'exécution.

yegor256
la source
2

Voici quelques moyens de trouver le temps d'exécution en 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. maintenant ()

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
la source
1

utiliser longtemps startTime=System.currentTimeMillis()pour l'heure de début, en haut de la boucle

mis en long endTime= System.currentTimeMillis();dehors de la fin de la boucle. Vous devrez soustraire les valeurs pour obtenir le temps d'exécution en millisecondes.

Si vous voulez du temps en nanosecondes, consultez System.nanoTime()

Jason
la source
1

J'ai créé une fonction d'ordre supérieur qui prend le code que vous souhaitez mesurer dans / en tant que 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; });
    }
}

Appelez ça comme ça:

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
);

Production:

code 0: 180528 ns
code 1: 12003 ns

Un merci spécial à Andy Turner qui m'a aidé à réduire la redondance. Regardez ici .

Willi Mentzel
la source
0

Vous pouvez également essayer Perf4J. C'est une façon élégante de faire ce que vous recherchez et vous aide à obtenir des statistiques de performances agrégées telles que la moyenne, le minimum, le maximum, l'écart type et les transactions par seconde sur une période donnée. Un extrait 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);
}

Production:

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
la source
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
la source
0

Utiliser System.currentTimeMillis () est la bonne façon de faire cela. Mais, si vous utilisez la ligne de commande et que vous souhaitez chronométrer l'ensemble du programme approximativement et rapidement, pensez à:

time java App

ce qui vous permet de ne pas modifier le code et l'heure de votre application.

MarAja
la source
Cela dépend de la façon dont vous exécutez le code. S'il s'agit d'un morceau de code exécutant un serveur, vous allez inclure l'heure de démarrage qui est incorrecte.
Arun Ramakrishnan