Einfache Zeitmessung und Profiling

Neben den komfortablen Klassen zum Verwalten von Datumswerten gibt es mit zwei Funktionen einfache Möglichkeiten, Zeiten für Programmabschnitte zu messen:

final class java.lang.System

• static long currentTimeMillis(). Gibt die seit dem 1.1.1970 vergangenen Millisekunden zurück.
• static long nanoTime(). Liefert vom genauesten System-Zeitgeber die Zeit. Sie hat keinen Bezugspunkt zu irgendeinem Datum; vom 1.1.1970 sind so viele Nanosekunden vergangen, dass sie gar nicht in den long passen würden.

Die Differenz zweier Zeitwerte kann zur groben Abschätzung von Ausführungszeiten für Programme dienen.

package com.tutego.insel.lang;

import static java.util.concurrent.TimeUnit.NANOSECONDS;

class Profiling
{
  private static long[] measure()
  {
    final int MAX = 3000;

    final String string = "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 int    number     = 123;
    final double nullnummer = 0.0;

    // StringBuffer(size) und append() zur Konkatenation

    long time1 = System.nanoTime();

    final StringBuilder sb1 = new StringBuilder( MAX * (string.length() + 6) );
    for ( int i = MAX; i-- > 0; )
      sb1.append( string ).append( number ).append( nullnummer );
    sb1.toString();

    time1 = NANOSECONDS.toMillis( System.nanoTime() - time1 );

    // StringBuffer und append() zur Konkatenation

    long time2 = System.nanoTime();

    final StringBuilder sb2 = new StringBuilder();
    for ( int i = MAX; i-- > 0; )
      sb2.append( string ).append( number ).append( nullnummer );
    sb2.toString();
    
    time2 = NANOSECONDS.toMillis( System.nanoTime() - time2 );
    
    // + zur Konkatenation
    
    long time3 = System.nanoTime();

    String t = "";
    for ( int i = MAX; i-- > 0; )
      t += string + number + nullnummer;

    time3 = NANOSECONDS.toMillis( System.nanoTime() - time3 );

    return new long[] { time1, time2, time3 };
  }

  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(): 2 ms
    System.out.printf( "sb(), append()    : %d ms%n", durations[1] ); // sb(), append()    : 21 ms
    System.out.printf( "t+=               : %d ms%n", durations[2] ); // t+=               : 10661 ms
  }
}

Das Testprogramm hängt Zeichenfolgen mit

• einem StringBuilder, der nicht in der Endgrößte initialisiert ist,
• einen 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(), was den Garbage Collector anweist, Speicher freizugeben. (Das würde in gewöhnlichen Programmen nicht stehen, da der GC 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 – Intel Pentium D 920 (2 Prozessoren), Java SE 6 – liefert das Programm die Ausgabe:

sb(size), append(): 3 ms
sb(), append() : 5 ms
t+= : 26948 ms

Das Ergebnis: Bei großen Anhänge-Operationen ist es ein wenig besser, einen passend in der Größe initialisierten StringBuilder zu benutzen. Über das + entstehen viele temporäre Objekte, was wirklich teuer kommt. Aber auch, wenn der StringBuilder nicht die passende Größe enthält, sind die Differenzen nahezu unbedeutend.

Wo im Programm überhaupt Taktzyklen verbraten werden, zeigt ein Profiler. An diesen Stellen kann dann mit der Optimierung begonnen werden. Eclipse sieht mit dem TPTP (http://www.eclipse.org/tptp/) eine solche Messumgebung vor.