© Excellent backgrounds/Shutterstock.com
Kolumne: Java-Trickkiste

Wie schnell läuft das? Von den Tücken bei Performancemessungen


„Ausprobieren“ ist ein verbreitetes Verfahren, um zu überprüfen, wie viel Zeit ein verdächtiges Stück Code tatsächlich benötigt. Dabei kann aber überraschend viel schiefgehen ...

Vor einiger Zeit arbeitete ich an einer Messaging-Middleware mit. Dort wurden viele UUIDs erzeugt, und das Profiling deutete darauf hin, dass Aufrufe von UUID.randomUUID() spürbaren negativen Einfluss auf die Gesamtperformance hatten.

Ein ad hoc durchgeführter Minimaltest (Listing 1) ließ uns den Schreck in die Glieder fahren: Das Erzeugen einer einzigen UUID dauert 10 Millisekunden – indiskutabel lange. Dazu ein Hinweis: Hier und im Folgenden erscheinen gemessene Zeiten. Diese sind erstens mit großer Vorsicht zu genießen – darum geht es ja gerade – und außerdem spezifisch für einen konkreten Computer, auf dem sie erfasst wurden. Sie können also höchstens grobe Anhaltspunkte sein. Im Sinne der Lesbarkeit verzichte ich aber darauf, das bei jedem einzelnen Messwert zu wiederholen.

Listing 1

final long start = System.nanoTime(); UUID.randomUUID(); System.out.println(System.nanoTime() - start);

Steigen wir also in die Welt der Mikrobenchmarks ein. Es gibt fertige Frameworks, die einem hier viel Arbeit abnehmen können (z. B. [1]), aber betrachten wir einmal die Schwierigkeiten bei der Performancemessung im Kleinen.

Wenn wir vor der Messung ein paar andere UUIDs erzeugen (Listing 2), erhalten wir erheblich kürzere Zeiten. Schon für n=1 sind es nur noch etwa 25 µs. Offenbar passieren beim ersten Aufruf teure Initialisierungen, die nur dort zu Buche schlagen. Außerdem wird schon beim ersten Aufruf der Hotspot-Compiler aktiv, wie man mit dem JVM-Schalter -XX:+PrintCompile sehen kann: Er kompiliert vier interne Methoden, die ab der zweiten UUID entsprechend schneller laufen. Das zeigt, wie eine naive Einmalmessung im Wesentlichen keinen Aussagewert hat. Ein Vergrößern des Werts von n führt zu schrittweise kürzeren Messzeiten, weil Hotspot nach und nach immer mehr interne Methoden kompiliert.

Listing 2

for(int i=0; i<n; i++) UUID.randomUUID(); final long start = System.nanoTime(); UUID.randomUUID(); System.out.println(System.nanoTime() - start);

Hotspot

Für die Praxis ist oft interessant, wie lange ein Aufruf dauert, nachdem der Hotspot-Compiler ihn komplett kompiliert hat. Auf meiner Maschine tut er das per Default nach 10 000 Aufrufen. Und tatsächlich, die Ausgaben von -XX:+PrintCompile zeigen für n=10 000, dass UUID.randomUUID() selbst kompiliert wird. Zunächst verlangsamt das allerdin...

Neugierig geworden?

Angebote für Teams

Für Firmen haben wir individuelle Teamlizenzen. Wir erstellen Ihnen gerne ein passendes Angebot.

Das Library-Modell:
IP-Zugang

Das Company-Modell:
Domain-Zugang