15.2 Einfache Zeitmessung und Profiling *
Neben den komfortablen Klassen zum Verwalten von Datumswerten gibt es mit zwei statischen Methoden einfache Möglichkeiten, Zeiten für Programmabschnitte zu messen:
final class java.lang.System
static long currentTimeMillis()
Gibt die seit dem 1.1.1970, 00:00:00 UTC vergangenen Millisekunden zurück.static long nanoTime()
Liefert die Zeit vom genauesten System-Zeitgeber. Sie hat keinen Bezugspunkt zu irgendeinem Datum.
Die Differenz zweier Zeitwerte kann zur groben Abschätzung der Ausführungszeiten von Programmen dienen:
package com.tutego.insel.lang;
import static java.util.concurrent.TimeUnit.NANOSECONDS;
import java.util.Arrays;
import java.util.function.Supplier;
import java.util.function.ToLongFunction;
class Profiling {
final static String ANGIE =
"Aber Angie, Angie, ist es nicht an der Zeit, Goodbye zu sagen? " +
"Ohne Liebe in unseren Seelen und ohne Geld in unseren Mänteln. " +
"Du kannst nicht sagen, dass wir zufrieden sind.";
final static int MAX = 10000;
enum Algorithm {
STRING_BUILDER1( () -> { // StringBuffer(size) und append() zur Konkatenation
StringBuilder sb = new StringBuilder( 2 * MAX * ANGIE.length() );
for ( int i = MAX; i-- > 0; )
sb.append( ANGIE ).append( ANGIE );
return sb.toString().length();
} ),
STRING_BUILDER2( () -> { // StringBuffer und append() zur Konkatenation
StringBuilder sb = new StringBuilder();
for ( int i = MAX; i-- > 0; )
sb.append( ANGIE ).append( ANGIE );
return sb.toString().length();
} ),
STRING_PLUS( () -> { // + zur Konkatenation
String s = "";
for ( int i = MAX; i-- > 0; )
s += ANGIE + ANGIE;
return s.length();
} );
private final Supplier<Integer> supplier;
private Algorithm( Supplier<Integer> supplier ) { this.supplier = supplier; }
int perform() { return supplier.get(); }
}
private static long[] measure() {
ToLongFunction<Algorithm> duration = algorithm -> {
long startTime = System.nanoTime();
int result = algorithm.perform();
try { return NANOSECONDS.toMillis( System.nanoTime() - startTime ); }
finally { System.out.println( result ); }
};
return Arrays.stream( Algorithm.values() ).mapToLong( duration ).toArray();
}
public static void main( String[] args ) {
measure(); System.gc(); measure(); System.gc();
long[] durations = measure();
System.out.printf( "sb(size), append(): %d ms%n", durations[0] );
// sb(size), append(): 6 ms
System.out.printf( "sb(), append() : %d ms%n", durations[1] );
// sb(), append() : 9 ms
System.out.printf( "t+= : %d ms%n", durations[2] );
// t+= : 15982 ms
}
}
Das Testprogramm hängt Zeichenfolgen mit
einem StringBuilder, der nicht in der Endgröße initialisiert ist,
einem StringBuilder, der eine vorinitialisierte Endgröße nutzt, und
dem Plus-Operator von Strings zusammen.
Vor der Messung gibt es zwei Testläufe und ein System.gc(), das die automatische Speicherbereinigung (GC) anweist, Speicher freizugeben. (Das würde in gewöhnlichen Programmen nicht stehen, da der Garbage-Collector schon selbst ganz gut weiß, wann Speicher freizugeben ist. Nur kostet das Freigeben auch Ausführungszeit, und es würde die Messzeiten beeinflussen, was wir hier nicht wollen.)
Auf meinem Rechner (JDK 10) liefert das Programm diese Ausgabe:
sb(size), append(): 7 ms
sb(), append() : 9 ms
t+= : 15982 ms
Das Ergebnis: Bei großen Anhängeoperationen ist es nur unwesentlich besser, einen passend in der Größe initialisierten StringBuilder zu benutzen. Über das + entstehen viele temporäre Objekte, was wirklich teuer kommt. Da in Java 9 die Konkatenation von Strings über den Plus-Operator beschleunigt wurde, sind die Zeiten besser als unter Java 8, wo die Ausführungszeit bei 41.262 ms liegt.
[+] Tipp
Die Werte von nanoTime() sind immer aufsteigend, was für currentTimeMillis() nicht zwingend gelten muss, da sich Java die Zeit vom Betriebssystem holt, und da kann sich die Systemzeit ändern, etwa wenn der Benutzer die Zeit anpasst. Differenzen von currentTimeMillis()-Zeitstempeln sind dann komplett falsch und könnten sogar negativ sein.
Profiler
Wo die JVM im Programm überhaupt Taktzyklen verschwendet zeigt ein Profiler. An diesen Stellen kann dann mit der Optimierung begonnen werden. Java Mission Control ist ein leistungsfähiges Programm des JDK und integriert einen freien Profiler. Java VisualVM ist ein weiteres freies Programm, das bis Java 8 integriert war, jetzt allerdings unter http://visualvm.github.io/ bezogen werden muss. Auf der professionellen und kommerziellen Seite stehen sich JProfiler (http://www.ej-technologies.com/products/jprofiler/overview.html) und YourKit (http://www.yourkit.com/java/profiler) gegenüber. Die Ultimate Version von IntelliJ enthält ebenfalls einen Profiler.