Messen und Optimieren Benchmarking, Profiling und Tuning von Java Anwendungen Daniel Klein Michael...
Preview:
Citation preview
- Folie 1
- Messen und Optimieren Benchmarking, Profiling und Tuning von
Java Anwendungen Daniel Klein Michael Piechullek 14. Februar
2005
- Folie 2
- bersicht BenchmarkingProfiling Tuning Strategien Profiling
Tools
- Folie 3
- Benchmarking bersicht Code-Fragmente, Programmteile oder ganze
Anwendungen werden auf bestimmte Kriterien getestet Verschiedene
Arten von Benchmarks: Mikrobenchmark, Makrobenchmark In der Regel
ist kein gutes Mittelma zu finden: Entweder testen Benchmarks
einzelne Instruktionen ganz genau oder Anwendungen und/oder Systeme
als ein ganzes.
- Folie 4
- Benchmarking Mikrobenchmarking Wird in der Regel benutzt um die
Geschwindigkeit einzelner Instruktionen oder Funktionen zu testen.
Eine Instruktion/Funktion wird oft auf Grund der Schnelligkeit
viele tausend mal ausgefhrt um zuverlssige Ergebnisse erhalten zu
knnen. Entspricht nicht unbedingt der Praxis. Mgliche Verflschungen
der Messergebnisse auf Grund einer ungenauen Zeitbasis beachten!
Zum Beispiel System.getMilliSeconds(): Laufzeit ca. 1/2 ms, also
muss der Benchmark mindestens 100 ms laufen um die
Messungenauigkeit nur fr das abfragen der Zeit auf unter 1% zu
drcken. (Besser: Laufzeiten von 1 s und mehr.) Laufzeit ca. 1/2 ms,
also muss der Benchmark mindestens 100 ms laufen um die
Messungenauigkeit nur fr das abfragen der Zeit auf unter 1% zu
drcken. (Besser: Laufzeiten von 1 s und mehr.) Auch liefert
System.getMilliSeconds() nicht immer ein aktuelles Ergebnis. Auf
manchen Systemen nur ein Update alle 10-50 ms! (Besonders kleinere
Mobilgerte wie Palm PCs oder Mobiltelefone.) Auch liefert
System.getMilliSeconds() nicht immer ein aktuelles Ergebnis. Auf
manchen Systemen nur ein Update alle 10-50 ms! (Besonders kleinere
Mobilgerte wie Palm PCs oder Mobiltelefone.)
- Folie 5
- Benchmarking Makrobenchmarking Testet in der Regel Anwendungen
als ganzes Ergebnisse sind aber auch Abhngig von Systemfaktoren:
Verfgbarer Speicher, VM, Hardware, andere Software die parallel
luft. (Fr Tests am besten Zielsystem verwenden.) Makrobenchmarks
versuchen automatisiert den Arbeitsablauf des Benutzers zu
simulieren. (Mglichst mit reellen Daten.) Laufzeit deutlich lnger
als bei Mikrobenchmark: Minuten, Stunden oder sogar Tage
blich.
- Folie 6
- Warum ist die Anwendung langsam? Was tunen? Was messen? Was man
nicht messen kann: Empfundene Geschwindigkeit Profiling
bersicht
- Folie 7
- Weil sie nicht den Erwartungen entspricht! Lsung: berprfen ob
die Erwartungen nicht evtl. zu hoch gesteckt sind. (Gerade
nicht-Techniker neigen zur bertreibung.) berprfen ob die
Erwartungen nicht evtl. zu hoch gesteckt sind. (Gerade
nicht-Techniker neigen zur bertreibung.) Vor dem optimieren ein
Soll definieren. Vor dem optimieren ein Soll definieren. Optimieren
in der richtigen Reihenfolge bis Ziel erreicht ist Optimieren in
der richtigen Reihenfolge bis Ziel erreicht ist Profiling Warum ist
die Anwendung langsam?
- Folie 8
- We should forget about small efficiencies, say about 97% of the
time: premature optimization is the root of all evil. Donald Knuth
Vorzeitiges oder bertriebenes optimieren macht es nur noch
schlimmer. berlegen ob Optimierung wirklich Sinn macht. Unwichtiges
zu optimieren braucht endlos viel Zeit und bringt so gut wie keine
Verbesserungen Stattdessen: Lokalisieren von Stellen an denen die
Anwendung Schwachstellen aufweist Profiling Was tunen?
- Folie 9
- Erster Schritt: Algorithmen (mehr dazu spter) Zweiter Schritt:
Glue Logic Engpsse (Bottlenecks) finden. Verbindungen zwischen
verschiedenen Modulen knnen die Software ausbremsen obwohl sie
einzelnen schon optimiert worden sind. Dritter Schritt: Feintuning
Nur wenn unbedingt ntig! Aufwand > Nutzen Letzte Chance:
Hardware tauschen ;-) Profiling Was tunen?
- Folie 10
- Lsst sich nicht unbedingt pauschal beantworten, jede Anwendung
ist anders. Immer sinnvoll: Ausfhrungsgeschwindigkeit
Ausfhrungsgeschwindigkeit Anzahl der Objekte Anzahl der Objekte
Speicherverbrauch Speicherverbrauch Anzahl Garbage Collections
Anzahl Garbage Collections Je nach Anwendung sinnvoll:
Datendurchsatz von/zur Festplatte Datendurchsatz von/zur Festplatte
Datendurchsatz im Netzwerk Datendurchsatz im Netzwerk Anzahl der
Netzwerk Pakete und/oder Anfragen Anzahl der Netzwerk Pakete
und/oder Anfragen Antwortzeit fr die bearbeitung einer Anfrage
(Server) Antwortzeit fr die bearbeitung einer Anfrage (Server) etc
etc Profiling Was messen?
- Folie 11
- Eine nicht zu vernachlssigende Komponente, wichtig fr alle
GUIs. Reagiert die Oberflche zu langsam macht die gesamte Anwendung
fr den Bennutzer den Eindruck langsam zu sein. Auch wichtig: Bei
lngeren Wartezeiten den Benutzer informieren. Problem: Solche
Eindrcke sind nur schwer automatisiert zu testen. Praktische Tests
mit Personen durchfhren! (Am besten mit der selben Hardware wie
spter fr den Regelbetrieb vorgesehen.) Profiling Was man nicht
messen kann: Empfundene Geschwindigkeit
- Folie 12
- Tuning Strategien bersicht Einige bliche Tuningmglichkeiten:
Bessere Algorithmen Objekterzeugung Garbage Collection
Methodenaufrufe minimieren
- Folie 13
- Tuning Strategien Bessere Algorithmen Beste Optimierungschancen
Nicht der Code wird optimiert, sondern die Logik Fragen: Ist der
verwendete Algorithmus geeignet fr die Anforderungen der Anwendung?
Ist der verwendete Algorithmus geeignet fr die Anforderungen der
Anwendung? Gibt es eine schnellere Alternative? Gibt es eine
schnellere Alternative? Wie viel Zeitaufwand bedeutet die
Implementierung einer mglichen Alternative, und wie viel
Performanceunterschied knnte Sie bringen? Wie viel Zeitaufwand
bedeutet die Implementierung einer mglichen Alternative, und wie
viel Performanceunterschied knnte Sie bringen?
- Folie 14
- Bei neueren VMs kein groes Problem mehr da schnelle O(1)
Allokation Trotzdem Erzeugung von bermig vielen Objekten vermeiden
Zum Beispiel: Objektpools verwenden, nur mit unvernderlichen
Klassen arbeiten wenn sinnvoll Das Erzeugen unntig vieler Objekte,
fhrt zur erhhter Aktivitt des Garbage Collectors Tuning Strategien
Objekterzeugung
- Folie 15
- Bei neueren VMs kein groes Problem mehr (da schneller
Generational Garbage Collector) Das Einsammeln kurzlebiger Objekte
ist schnell Trotzdem Erzeugung von bermig vielen Objekten vermeiden
Tuning Strategien Garbage Collection
- Folie 16
- Methodenaufrufe erzeugen einen (wenn auch minimalen) Overhead
Durch wiederholtes Aufrufen summiert sich der Overhead jedoch Bei
neueren VMs nicht sehr relevant, da HotSpot Compiler via inlining
optimieren kann. (In der Regel sogar deutlich besser als der
Programmierer.) Aber die Mglichkeiten sind begrenzt: Rekursive
Algorithmen, zum Beispiel, lassen sich so nicht bedeutend
beschleunigen. Tuning Strategien Methodenaufrufe minimieren
- Folie 17
- Kleinere Codeoptimierungen lohnen sich durch HotSpot Compiler
kaum noch. Bei anderen (einfacheren) VMs weiterhin sinnvoll
Generell Ressourcen schonendes Programmieren immer sinnvoll Rules
of Optimization: Rule 1: Dont do it. Rule 2: (for experts only):
Dont do it yet. M. A. Jackson Tuning Strategien Fazit
- Folie 18
- Profiling Tools bersicht Unzhlige Tools verfgbar Teilweise sehr
teure, kommerzielle Tools, aber auch kostenlose oder Open Source
Tools Umfang und Funktionalitt der Software oft ziemlich hnlich Fr
diese Prsentation: Fokus auf Techniken und Tools die jederzeit zur
Verfgung stehen, sowie ein kommerzielles Tool als Beispiel
- Folie 19
- Profiling Tools Taskmanager
- Folie 20
- Manuelles Zeit messen private static final Stack
profilingStack= new Stack(); /** * Start profiling by remembering
the actual system time. * NOTE: This profiler is NOT able to handle
multithreaded usage. */ public static final void startProfiling() {
profilingStack.push( new Long(System.currentTimeMillis()) ); } /**
* Stop profiling and return elapsed time. * @return The time
elapsed since the call of startProfiling(). */ public static final
long stopProfiling() { // first, remember the stop time, to avoid
delays long stopTime= System.currentTimeMillis(); // check if there
is at least one element left on the stack if(
profilingStack.empty() ) throw new java.lang.IllegalStateException(
"The count of profiling start and stop doesn't match!" ); // get
start value long startTime=
((Long)profilingStack.pop()).longValue(); return stopTime -
startTime; } Benutzung: profiler.startProfiling(); testMethod()
long duration= profiler.stopProfiling(); System.out.println(
duration ); Ab Java 5: Genaueres Timing mittels
System.nanoTime();
- Folie 21
- Profiling Tools static Zhler in der Klasse zum zhlen der
Instanzen public abstract class InstanceCounter { public static int
count; public InstanceCounter() { count++; } public void finalize()
{ count--; } public class StaticTest extends InstanceCounter {
public StaticTest() { System.out.println( count ); } public static
void main(String[] args ) { new StaticTest(); }
- Folie 22
- Profiling Tools Verbose Ausgabe der VM
- Folie 23
- Profiling Tools Xprof Parameter der VM (benutzt JVMPI)
C:\work\studium\Software Tools WPF>java -Xprof -jar NetFlow.jar
Flat profile of 0.36 secs (27 total ticks): main Interpreted +
native Method 7.7% 2 + 0 java.util.Hashtable.get 3.8% 0 + 1
sun.awt.windows.WDesktopProperties.init 3.8% 0 + 1
sun.awt.windows.WComponentPeer.pShow 3.8% 0 + 1
java.io.WinNTFileSystem.checkAccess 3.8% 0 + 1
java.util.zip.ZipFile.open 3.8% 0 + 1
java.util.zip.ZipFile.getEntry 3.8% 1 + 0
java.io.ExpiringCache$Entry. 3.8% 1 + 0
java.nio.ByteBufferAsShortBufferB.get 3.8% 1 + 0 java.awt.Insets.
3.8% 1 + 0 sun.java2d.loops.GraphicsPrimitiveMgr$2.compare 3.8% 1 +
0 javax.swing.JRootPane.createLayeredPane 3.8% 1 + 0
java.lang.Class.searchFields 3.8% 1 + 0
java.util.Properties.enumerate 3.8% 1 + 0 java.nio.ByteBuffer.get
3.8% 1 + 0 sun.java2d.loops.GraphicsPrimitiveMgr.register 3.8% 1 +
0 java.lang.ClassLoader.loadClass 3.8% 0 + 1
sun.awt.windows.WDesktopProperties.initIDs 3.8% 1 + 0
sun.font.CompositeFont.getSlotFont 3.8% 1 + 0
javax.swing.JTextField. 3.8% 1 + 0 java.lang.reflect.Method.invoke
3.8% 1 + 0 java.io.Win32FileSystem.normalize 3.8% 1 + 0
java.awt.Component.show 3.8% 1 + 0
sun.nio.ch.IOUtil.readIntoNativeBuffer 3.8% 1 + 0
java.awt.color.ColorSpace.getInstance 3.8% 1 + 0
sun.nio.cs.ISO_8859_1$Decoder.decodeArrayLoop 100.0% 20 + 6 Total
interpreted Thread-local ticks: 3.7% 1 Blocked (of total) Flat
profile of 36.20 secs (3332 total ticks): AWT- Windows Interpreted
+ native Method 99.9% 0 + 3329 sun.awt.windows.WToolkit.eventLoop
0.0% 1 + 0 sun.awt.AWTAutoShutdown.isReadyToShutdown 0.0% 1 + 0
java.awt.EventQueue.wakeup 0.0% 0 + 1 sun.awt.windows.WToolkit.init
100.0% 2 + 3330 Total interpreted Flat profile of 35.82 secs (3307
total ticks): DestroyJavaVM Thread-local ticks: 100.0% 3307 Blocked
(of total)
- Folie 24
- Profiling Tools Monitoring and Management Extensions (JMX/MX
Beans) Neu ab Java 5 Bietet Schnittstelle zum abfragen und setzen
von Informationen ber die virtuelle Maschine zur Laufzeit. Offene
APIs: Java Management Extensions (JSR-003) und JMX Remote API
(JSR-160) Monitoring Lokal oder Remote (+ Verschlsselung)
Management Tool(s) direkt bei JDK dabei Via Beans in eigene
Anwendung integrierbar Erweiterbar
- Folie 25
- Profiling Tools Monitoring and Management Extensions (JMX/MX
Beans) Verfgbare Standard Beans: ClassLoadingMXBean
ClassLoadingMXBean CompilationMXBean CompilationMXBean
GarbageCollectorMXBean GarbageCollectorMXBean MemoryMXBean
MemoryMXBean MemoryManagerMXBean MemoryManagerMXBean
MemoryPoolMXBean MemoryPoolMXBean OperatingSystemMXBean
OperatingSystemMXBean RuntimeMXBean RuntimeMXBean ThreadMXBean
ThreadMXBean
- Folie 26
- Profiling Tools JVM Stat (benutzt JMX)
C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe -options -class
-compiler -gc -gccapacity -gccause -gcnew -gcnewcapacity -gcold
-gcoldcapacity -gcpermcapacity -gcutil -printcompilation
C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe -class 2836 1000
Loaded Bytes Unloaded Bytes Time 30 36,4 0 0,0 0,02
C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe -compiler 2836 1000
Compiled Failed Invalid Time FailedType FailedMethod 50 0 0 0,03 0
C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe -gccapacity 2836
1000 NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC PGCMN PGCMX PGC
PC YGC FGC 640,0 4992,0 640,0 64,0 64,0 512,0 1408,0 60544,0 1408,0
1408,0 8192,0 65536,0 8192,0 8192,0 2 0 640,0 4992,0 640,0 64,0
64,0 512,0 1408,0 60544,0 1408,0 1408,0 8192,0 65536,0 8192,0
8192,0 2 0 C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe -gc 2836
1000 S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT 64,0
64,0 64,0 0,0 512,0 149,4 1408,0 390,1 8192,0 187,9 2 0,014 0 0,000
0,014 64,0 64,0 64,0 0,0 512,0 149,4 1408,0 390,1 8192,0 187,9 2
0,014 0 0,000 0,014 C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe
-gcnew 2836 1000 S0C S1C S0U S1U TT MTT DSS EC EU YGC YGCT 64,0
64,0 64,0 0,0 1 31 32,0 512,0 149,4 2 0,014
C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe -gcutil 2836 1000 S0
S1 E O P YGC YGCT FGC FGCT GCT 100,00 0,00 29,17 27,71 2,29 2 0,014
0 0,000 0,014 C:\Programme\Java\jdk1.5.0_01\bin>jstat.exe
-printcompilation 2836 1000 Compiled Size Type Method 50 104 1
java/awt/GradientPaintContext cycleFillRaster 55 111 1
java/util/HashMap get 58 30 1 java/awt/Component inside 84 468 1
sun/java2d/SunGraphics2D getCompClip 86 0 1 java/lang/Object
hashCode 90 13 1 java/util/Hashtable isEmpty 102 723 1
java/awt/Toolkit$SelectiveAWTEventListener eventDispatched 135 29 1
java/awt/EventQueue noEvents 145 11 1 java/awt/geom/LineIterator
next
- Folie 27
- Profiling Tools JConsole (benutzt JMX)
- Folie 28
- Profiling Tools JConsole
- Folie 29
- JConsole
- Folie 30
- JConsole
- Folie 31
- Visual GC (benutzt JMX)
- Folie 32
- Profiling Tools Borland OptimizeIt
- Folie 33
- Profiling Tools Borland OptimizeIt
- Folie 34
- Profiling Tools Borland OptimizeIt
- Folie 35
- Profiling Tools Borland OptimizeIt
- Folie 36
- Profiling Tools Borland OptimizeIt Code Coverage
- Folie 37
- Bcher und Artikel Schreiber, Hendrik: Performant Java
Programmieren; Addison-Wesley, 1. Auflage, 2002 (Deutsch) Shirazi,
Jack: Java Performance Tuning; OReilly, First edition, September
2000 (Englisch) So wie unzhlige Artikel im Internet (Qualitt und
Belegbarkeit oft fraglich)
- Folie 38
- Vielen Dank fr Ihre Aufmerksamkeit ! Aufmerksamkeit !