Seminararbeit in der Vorlesung Softwareengineering Dozent: Herr Prof. Dr.-Ing. Olaf Herden zum Thema Java-Profiling Kolja Braden, Philipp Daubenschüz Studiengang Informationstechnik Berufsakademie Horb Florianstr. 15 72160 Horb a. N. [email protected] [email protected] 31. Oktober 2005 Seminararbeit – Java Profiling 1 EINFÜHRUNG......................................................................................................... 3 1.1 Begriffsdefinitionen............................................................................................................................. 3 1.1.1 Profiling ............................................................................................................................................... 3 1.1.2 Performance....................................................................................................................................... 3 1.2 Was geschieht beim Profiling? ................................................................................................................ 3 1.3 Wann Profilen?............................................................................................................................................. 4 1.4 Vorgehensweise .......................................................................................................................................... 4 2 VERSCHIEDENE PROFILINGANSÄTZE........................................................... 6 2.1 Profiling mit dem JVMPI (Java Virtual Machine Profiling Interface) .............................................. 6 2.2 Profiling durch Instrumentierung............................................................................................................ 8 2.3 Profiling durch manuelle Zeitmessung.................................................................................................. 8 3 PROFILING- WERKZEUGE ..............................................................................10 3.1 Hyades .................................................................................................................................................. 10 3.1.1 Installation............................................................................................................................................. 12 3.1.2 Strategie und Bewertung .................................................................................................................... 12 3.1.3 Profiling mit Hyades ............................................................................................................................ 13 3.1.4 Fazit ....................................................................................................................................................... 15 3.2 JRat ............................................................................................................................................................... 16 3.2.1 Installation............................................................................................................................................. 16 3.2.2 Strategie................................................................................................................................................ 16 3.2.3 Profiling mit JRat.................................................................................................................................. 16 3.2.4 Fazit ....................................................................................................................................................... 19 3.3 HP- JMeter /Xrunhprof aus dem JDK ................................................................................................... 20 3.3.1 Überblick über die Funktionalitäten................................................................................................... 23 3.3.2 Fazit ....................................................................................................................................................... 27 4 BEWERTUNG VON PERFORMANCEANALYSEN ..........................................28 Kolja Braden, Philipp Daubenschüz 2 Seminararbeit – Java Profiling 1 Einführung In der Softwareentwicklung gibt es während der Programmerstellung verschiedene Teilziele, die auf Anhieb nur sehr selten zu erreichen sind. Dazu zählen die Lesbarkeit des Codes, die Funktionalität des zu entwickelnden Programms sowie seine Leistungsfähigkeit und Ausführungszeit. Insbesondere die Abschätzung der Laufzeit und des Speicherbedarfs sind während der Erstellung nur sehr bedingt möglich. Hilfreich können hierbei ProfilingWerkzeuge sein, von denen in dieser Arbeit einige vorgestellt werden sollen. Für das grundsätzliche Verständnis ist es aber zuallererst notwendig, Begriffe zu klären und darzustellen, in welchen Situationen Profiling sinnvoll ist und welche Ansätze dazu existieren. 1.1 Begriffsdefinitionen 1.1.1 Profiling Profiling – profilieren – einer Sache, jmdm. eine besondere charakteristische, markante Prägungen geben; sich im Profil abzeichnen [Dude04] Unter „Profiling“ versteht man die Analyse der Laufzeit Performance indem während der Ausführung der Anwendung Messdaten ermittelt werden. [AdAd03] 1.1.2 Performance Performance bezeichnet in der Informatik die Effizienz von Programmen und Hardware bezüglich des Ressourcenverbrauchs und der Qualität der Ausgabe. 1.2 Was geschieht beim Profiling? Mit einem Profilingtool kann man, eine funktionierende Software über den zeitlichen Ablauf analysieren. Es können Laufzeitaussagen getroffen werden und genaue Analysen gemacht werden. Es kann lokalisiert werden, welche Programmteile die Ressourcen des Rechners Kolja Braden, Philipp Daubenschüz 3 Seminararbeit – Java Profiling wie viel Zeit, in Anspruch nehmen. Softwareentwickler haben damit die Möglichkeit so genannte Flaschenhälse im Programm zu ermitteln und in weiteren Entwicklungsschritten unter dem Performance-Aspekt zu überarbeiten. Je nach Werkzeug stehen grafische Aufbereitungsmöglichkeiten der Analyse zur Verfügung, mit denen die Analysen über das Programm übersichtlich aufbereitet werden können. 1.3 Wann Profilen? In der Software- Entwicklung arbeiten im Allgemeinen viele Personen an einem Projekt. Anfangs steht in Entwicklungsprojekten die Lesbarkeit des Codes im Vordergrund. Auf Performance- Kriterien wird wenig Wert gelegt. Dies macht Sinn, da die neu entwickelte Software am Anfang des Projektes erstmal grundsätzlich funktionieren soll. Wenn ein Programm eines Projektes die funktionale Spezifikation erfüllt, sind Profilings und Performanceanalysen sinnvoll. Mit den Ergebnissen der Analysen können Engpässe in der Software lokalisiert werden. In einem Refactoring kann die Software zu einem späteren Zeitpunkt im Projekt in den Performance- Belangen optimiert werden. Es steht bei diesem Refactoring ein Referenzstand zur Verfügung, mit dem die Funktionalität des überarbeiteten Codes überprüft werden kann. Mit einem Profiling kann man die erreichten Performanceverbesserungen bestätigen und kann damit genau dokumentieren und analysieren, wie sich einzelne Veränderungen im Code auswirken. 1.4 Vorgehensweise In einem ersten Schritt wird das zu optimierende Programm in einer Profilingumgebung gestartet. Es werden von der entsprechenden Profilingumgebung während der Ausführung Daten gesammelt. Im nächsten Schritt werden die Profiling- Daten analysiert. Wenn die performancekritischen Stellen lokalisiert sind, können alternative Algorithmen entwickelt werden. Kolja Braden, Philipp Daubenschüz 4 Seminararbeit – Java Profiling Diese Algorithmen müssen die gleiche Funktionalität haben, und schneller in ihrer Ausführung sein. Die Optimierungsschritte sollten nicht zu umfassend sein. Wenn ein Ersatzalgorithmus gefunden ist, sollte dieser eingebunden werden. Es sollte sichergestellt werden, dass der Algorithmus alle Aufgaben korrekt erfüllt. Mit einem Profiling des neu eingebundenen Algorithmus kann die genaue Performancesteigerung ermittelt werden. Ineffiziente Fehlentwicklungen können frühzeitig ausgeschlossen werden. Wenn zu große Pakete bearbeitet werden, könnten wenige ineffiziente Code- Fragmente viele Performance steigernde Maßnahmen zunichte machen. So könnten die besseren Ansätze des zu großen Entwicklungsschrittes leichtfertig verworfen werden. Kolja Braden, Philipp Daubenschüz 5 Seminararbeit – Java Profiling 2 Verschiedene Profilingansätze 2.1 Profiling mit dem JVMPI (Java Virtual Machine Profiling Interface) Das JVMPI wurde mit dem JAVA 2 SDK eingeführt und ist eine Schnittstelle, die es einem Profiler Agent ermöglicht, die Java Virtual Machine (VM) zu steuern und umgekehrt der VM ermöglicht, Ereignisse an den Profiler Agent zu senden. Die VM und der Profiler Agent laufen im selben Prozess. Durch eine Profiler- Benutzer- Schnittstelle, die in einem separaten Prozess läuft, können die Messdaten dem Benutzer zur Verfügung gestellt werden. Abbildung 2.1: Konzept des JVMPI Der Profiler Agent ist berechtigt, die VM zur Laufzeit steuern, d. h. er kann z. B. die VM zur Laufzeit benachrichtigen, über welche Ereignisse er informiert werden will. Dadurch ist der Benutzer in der Lage, nur die für ihn relevanten Daten aufzuzeichnen und unnötigen Overhead zu vermeiden. Damit ist es möglich unerwünscht große Abweichungen der Profilingdaten von der realen Performanz zu minimieren. Des Weiteren bietet das JVMPI an, die Garbage Collection zu steuern, d.h. sie entweder manuell zu starten oder aber ihre Ausführung zu verhindern. Es kann zu jedem Zeitpunkt der Zustand und Aufrufbaum einzelner Threads ermittelt werden. Auch die Dauer bzw. das Ende des Profilingvorgangs kann über das JVMPI vorgegeben werden. Umgekehrt ist auch die VM in der Lage, den Profiler Agent über eine seiner Methoden, über verschiedene Ereignisse zu benachrichtigen, zum Beispiel: • Initialisierung der VM • Methodenaufrufe oder das Verlassen von Methoden • Erstellung oder Freigabe von Objekten Kolja Braden, Philipp Daubenschüz 6 Seminararbeit – Java Profiling • Start und Ende von Threads • Laden von Klassen • Start oder Ende von Garbage Collecting Das Profiler-Front-End erhält vom Profiler-Agent die gewünschten Informationen und verarbeitet sie so, dass die Benutzer damit weiterarbeiten können (graphische Ausgabe, Speichern in Datei, usw.). Mit Hilfe dieser Informationen ist es nun möglich, verschiedene Ausgaben zu generieren: • Heap Profiling (Speicherbedarfsanalyse) • CPU-Zeit Profiling (Laufzeitanalyse) • Code Coverage Analysis (Codeabdeckung) Das Profiler-Front-End muss dabei nicht auf dem gleichem Rechner wie die VM laufen, sondern kann aufgrund des unabhängigen Protokolls auf einem remote-Rechner ausgeführt werden. Für das Profiling kann nur genau ein Profiler Agent benutzt werden. Die gleichzeitige Benutzung mehrerer verschiedener Agents zur Performancemessung eines Programms ist nicht möglich. Die Auswahl des aktuellen Profiler Agents mit Angabe der zu testenden Klasse erfolgt über die Befehlszeile java -Xrunmyprofiler ToBeProfiledClass. Eine Vielzahl von Java-Profilern basiert auf den Möglichkeiten des JVMPIs und nutzt diese. Beispiele dafür sind Hyades [hyad] und Jakarta JMeter (jakarta.apache.org/jmeter/). Zu beachten ist, dass sich durch das Profiling mit JVMPI in ungünstigen Fällen große Laufzeitverschiebungen ergeben. Ursächlich dafür ist, dass unter Umständen jeder Funktionsaufruf sowohl von benutzerdefinierten Funktionen als auch von JVM APIFunktionen ein Ereignis an den Profiler Agent meldet. Gravierende Beeinflussungen der Laufzeit zeigen sich vor allem bei kleinen Funktionen, die sehr oft aufgerufen werden. Bei längeren Berechnungen innerhalb einer Funktion minimiert sich der Fehlergrad des Ergebnisses. Mit Einführung von Java 5 wurde das bisherige JVMPI, das experimentellen Charakter hatte, unter dem Namen Java Platform Profiling Architecture offiziell in das JDK aufgenommen. Kolja Braden, Philipp Daubenschüz 7 Seminararbeit – Java Profiling 2.2 Profiling durch Instrumentierung Eine weitere Möglichkeit Profilingdaten aufzuzeichnen bietet das Konzept der Instrumentierung. Dabei wird Java-Quellcode vom Compiler in plattformunabhängigen Bytecode übersetzt, der dann von der VM ausgeführt wird. Dieser Bytecode wird mit Zählern und Zeitmessungen instrumentiert, um Ausführungshäufigkeit und Geschwindigkeit zu bestimmen. Instrumentieren bedeutet hier, dass der compilierte Bytecode nachträglich modifiziert wird. So wird an Stellen, die für die Auswertung interessant sind, vor allem am Anfang und Ende von Methoden, zusätzlicher Code eingefügt. Es wird meist jede Methode im zu testenden Programm einzeln instrumentiert, d. h. jede Methode wird gekapselt und ihre Ausführungszeit wird gemessen. Die Instrumentierung bietet den großen Vorteil, dass nicht auf das langsame JVMPI zugegriffen werden muss. Unter Benutzung von Instrumentierung ist es möglich, Ausführungsdauer und -Häufigkeit von benutzerdefinierten Methoden auszuwerten. Nicht möglich ist es hier jedoch, Objekte und Threads zu überwachen. Insbesondere die Nichterkennung von Threads kann in Multithread-Anwendungen zu erheblichen Fehlern führen, da bei Ausführung einer Methode nicht die CPU-Zeit, sondern die absolut vergangene Zeit gemessen wird. Eine weitere Schwachstelle ist, dass Java API – Aufrufe nicht dokumentiert werden, d. h. unter Umständen kann die eigentliche PerformanzSchwachstelle, die z.B., wie in einem späteren Beispiel dargestellt, vom versehentlichen Anlegen einer großen Anzahl von Objekten herrühren kann, nicht erkannt wird. Dadurch dass sich das Profiling bei Anwendung des Instrumentierungverfahrens alleine auf die Analyse von Ausführungsdauer und –Häufigkeit von Methoden beschränkt, ist eine Speicheranalyse nicht möglich. 2.3 Profiling durch manuelle Zeitmessung Für kleine Tests während der Entwicklungsphase werden vom Entwickler in der Regel Testprogramme mit Konsolenausgabe geschrieben. Es können so Codefragmente überprüft werden. Meistens wird mit der Konsolenausgabe abgeprüft, ob das Programm konsistent arbeitet. Dabei kann schon während der Entwicklung von Codefragmenten eine Performanceanalyse gemacht werden, indem mit Konsolenausgaben nicht nur die Funktionalität überprüft wird, sondern mit einer in Java integrierten Zeitmessungsfunktion die Ausführungsgeschwindigkeiten von verschiedenen Lösungsansätzen überprüft werden. Kolja Braden, Philipp Daubenschüz 8 Seminararbeit – Java Profiling So kann in einer frühen Entwicklungsphase durch den Programmierer der performantere Algorithmus zur Lösung des gestellten Problems ausgewählt werden. Java stellt für Zeitmessungen solcher Art die folgende Funktion zur Verfügung: System.currentTimeMillis(); Diese Funktion gibt die Zeit in Millisekunden zurück, die seit dem 1.1.1970 vergangen ist. Wenn man mit dieser Funktion sich die Zeit vor und nach der zu testenden Funktion zurückgeben lässt kann man durch Subtraktion die Zeit, die zum Abarbeiten gebraucht wurde berechnen. Die Ergebnisse bei dieser Methode hängen davon ab, wie viele andere Prozesse sich auf dem Rechner in Ausführung befinden. Es wird dabei die während der Ausführung absolut vergangene Zeit gemessen. Wenn sich viele andere höher- priore Prozesse und Threads momentan in der Ausführung befinden ergeben sich gewisse Abweichungen von der Realität. Hierzu ein Beispiel, bei dem zwei Möglichkeiten überprüft werden, einem String 10000 mal ein Zeichen anzufügen: public class Profiling { public static void main( String args[] ){ int MAX = 10000; long time1 = System.currentTimeMillis(); String s = ""; for ( int i = MAX; i-- > 0; ) s = s.concat( "t" ); time1 = System.currentTimeMillis() - time1; long time2 = System.currentTimeMillis(); String t = ""; for ( int i = MAX; i-- > 0; ) t += "t"; time2 = System.currentTimeMillis()- time2; System.out.println( "s.concat: " + time1 + " ms" ); System.out.println( "t+=: " + time2 + " ms" ); } } Kolja Braden, Philipp Daubenschüz 9 Seminararbeit – Java Profiling In diesem Bespiel werden die Funktionen [string]. Concat([String]) mit der Funktion [String]+=[String2] verglichen in dem beide 10000mal ausgeführt werden. Die Funktion habe exakt die gleiche Funktionalität, der String der am Ende der Funktionsschleifen ausgegeben wird ist exakt der gleiche. Die Art und Weise in dem die Bibliotheken den String manipuliert haben sind unterschiedlich(mehr dazu im Kapitel 3.1 Hyades). Man kann die Ausführungszeiten nicht als absolut betrachten, wie unten gezeigt. Die Zeiten variieren je nach Auslastung des Systems, die zu dem momentanen Zeitpunkt bestand um ca. 20%. Es wird bei jedem einzelnen Ausführen nicht exakt die gleiche Zeit gebraucht, um die Funktionsschleifen des Beispiels auszuführen. Es ist in jeder Ausführung deutlich zu erkennen, dass die Funktion Concate wesentlich performanter ist als die gleiche Funktionalität mit dem Stringoperator +=. Ecplise: s.concat: t+=: 230 ms 451 ms Start von Konsole: s.concat: t+=: 201 ms 400 ms Sehr ausgelastetes System: s.concat: t+=: 231 ms 480 ms 3 Profiling- Werkzeuge 3.1 Hyades Der Name Hyades stammt von den Hyaden, einem der größten sichtbaren Sternhaufen. Wissenschaftliche Bedeutung erlangten die Hyaden im Jahre 1919, als die Ablenkung des von den Hyaden stammenden Lichts durch das Gravitationsfeld der Sonne gemessen werden konnte. Damit konnte ein empirischer Beweis für die Richtigkeit der Relativitätstheorie erbracht werden. Kolja Braden, Philipp Daubenschüz 10 Seminararbeit – Java Profiling Hyades [hyad] ist ein Plugin für Eclipse, das Profiling-Funktionalitäten zur Verfügung stellt. Entwickelt wird Hyades vom Test & Performance Tools Platform Project (TPTP). Das TPTP wurde 2002 von IBM ins Leben gerufen, an den aktuellen Releases sind unter anderem IBM, SAP, Compuware und Intel beteiligt, die Hyades zur Performanceanalyse eigener Softwareentwicklungen nutzen. Hyades stellt verschiedene Komponenten zur Verfügung: • • Interoperable Informationsmodelle - z.B. UML2 (Codegenerierung aus UML-Modellen) - Eclipse Modelling Framework (EMF) basiert Data Collection Framework und Laufzeitumgebung - Agent Controller - Entkopplung der Kommunikation zwischen System Under Test (SUT) und Testclient • • • Test Tool Framework - automatisierte Testcases generieren - Analyse der Testergebnisse - generieren von benutzerdefinierten Reports Profiling Framework - Analyse von Performance und Ressourcennutzung - Integriert in Eclipse GUI - Profiling entfernter und lokaler (Agent Controller) Systeme möglich Log und Trace Frameworks Kolja Braden, Philipp Daubenschüz 11 Seminararbeit – Java Profiling - Modell für Log- und Trace Events - Agent Controller als Laufzeitumgebung für die Event-Konsolidierung in verteilten Systemen Die Möglichkeiten der Performanzanalyse in Hyades basieren zu großen Teilen auf dem Profiling Framework. 3.1.1 Installation Voraussetzung für eine Installation ist ein aktuelles Java-SDK sowie eine installierte EclipseEntwicklungsumgebung. Vor Installation von Hyades werden das Eclipse Modeling Framework (EMF) und der Application Server „Agent Controller (RAC)“ benötigt. Die eigentliche Installation erfolgt, wie bei Eclipse-Plugins üblich, durch Kopieren des Programms in das .../eclipse/plugin Verzeichnis. Der Agent Controller ist ein eigenständiger Application-Server. 3.1.2 Strategie und Bewertung Der Agent Controller wird als externer eigenständiger Serverprozess betrieben. In ihm laufen der zu testende Prozess und ein Hyades-Prozess, der diesen steuert und profiling-relevante Daten zurückgibt. Vorteil hierbei ist, dass der Bytecode nicht verändert werden muss. Hyades ist durch die Integration in Eclipse fast intuitiv zu bedienen. Im Gegensatz zu anderen Profilern werden nicht nur Aufrufe von benutzerdefinierten Methoden ausgegeben, sondern auch API – Methodenaufrufe bzw. Konstruktoren. Eine Schwachstelle von Hyades ist, dass sich gewisse Unterschiede zwischen realer und gemessener Laufzeit ergeben, abhängig von der Aufrufreihenfolge. Ursächlich dafür ist, dass Hyades auf dem JVMPI basiert, woraus sich auch noch weitere, bereits oben erwähnte Ungenauigkeiten ergeben können. Kolja Braden, Philipp Daubenschüz 12 Seminararbeit – Java Profiling 3.1.3 Profiling mit Hyades Als Beispiel für die Anwendung des Profilers soll hier ein Programm verwendet werden, das schrittweise eine festgelegte Anzahl von Zeichen an einen String anfügt und das Ergebnis auf der Konsole ausgibt. public class prof1a { public static String dots(int len) { String ret = ""; for (int i = 0; i < len; ++i) { ret += "."; } return ret; } public static void main(String[] args) { String s = dots(10000); System.out.println(s); } } Kolja Braden, Philipp Daubenschüz 13 Seminararbeit – Java Profiling Abbildung 3.1.1: Auswertung „+= String S“ Wie in Abbildung 3.1.1 zu erkennen ist, wird in jedem Schritt ein StringBuffer-Objekt angelegt, das dann an den „Zielstring“ angefügt wird. Diese Erstellung vergleichsweise vieler Objekte ist besonders Laufzeit- und, wie eine Memory-Analyse ergab, auch besonders Speicher intensiv. Im Folgenden wird deshalb versucht, die gleiche Funktionalität mit ressourcenschonenderen Methoden zu erreichen. public class prof1b { public static String dots(int len) { StringBuffer sb = new StringBuffer(len + 10); for (int i = 0; i < len; ++i) { sb.append('.'); } return sb.toString(); } public static void main(String[] args) { String s = dots(10000); } } Kolja Braden, Philipp Daubenschüz 14 Seminararbeit – Java Profiling Abbildung 3.1.2: Auswertung „ append“ Wie in Abbildung 3.1.2 zu erkennen, ist es gelungen, die Anzahl der erzeugten StringBufferObjekte um 99,9999% zu reduzieren. Dies schlägt sich im Vergleich zum ersten Beispiel in wesentlich kürzerer Laufzeit und geringerem Speicherbedarf nieder. 3.1.4 Fazit Im Vergleich zu anderen, insbesondere den mit Instrumentierung arbeitenden Profilern, ermöglicht Hyades eine Vielzahl an Konfigurations- und Auswertemöglichkeiten. So können hier nicht nur die konkret im Quellcode verankerten Objekte und Methoden bewertet werden, sondern auch die darunterliegende JVM-Ebene. Die Bedienbarkeit von Hyades ist aufgrund der Integration in Eclipse allen anderen getesteten Profiling- Programmen überlegen. Ungenauigkeiten basieren auf dem oben beschriebenen Wirkungsprinzip des JVMPI. Kolja Braden, Philipp Daubenschüz 15 Seminararbeit – Java Profiling 3.2 JRat 3.2.1 Installation Das Programm JRat (Java Runtime Analysis Toolkit) ist ein freies Profiling-Werkzeug. Bezogen werden kann das JRat jar-Archiv über [jrat]. Eine eigentliche Installation ist nicht nötig, es handelt sich um eine direkt ausführbare jar- Datei. 3.2.2 Strategie JRat benutzt keine in Java eingebauten Profiling-Methoden, sondern basiert auf dem Konzept der Instrumentierung, das heißt es „infiziert“ bereits kompilierte class-Dateien. Wie bereits oben beschrieben bedeutet dies, dass JRat vorkompilierte class-Dateien an geeigneten Stellen abändert und Abhängigkeiten zu sich selbst (shiftone-jrat.jar) schafft. Über diese Abhängigkeiten wird der Profiling- Vorgang gesteuert und kontrolliert. Während des eigentlichen Testvorgangs werden Profilingdaten in eine Datei *.jrat geschreiben, die dann von JRat ausgewertet werden kann. 3.2.3 Profiling mit JRat Um bestimmte class-Dateien überprüfen zu können, ist es notwendig, dass das zu testende Programm vor Beginn des Profilings bereits einmal übersetzt wurde. Das eigentliche Infizieren erfolgt im darauf folgenden Schritt über die Schaltfläche Instruments->Inject Jar- or Class-File bzw. für mehrere Dateien mit Instruments->Inject Directories Recursively. Abbildung 3.2.1 Aufgrund der durch das Infizieren geschaffenen Abhängigkeiten zu JRat ist es für einen erfolgreichen Testablauf unerlässlich, die Datei shiftone-jrat.jar in den Classpath der JVM zu übernehmen. JRat ermöglicht es, durch der JVM zu übergebende Parameter verschiedene Messmethoden festzulegen, auf die im Folgenden kurz eingegangen werden soll. Es werden jeweils die Ausgaben bei Test eines nach Quicksort sortierenden Programms dargestellt. Kolja Braden, Philipp Daubenschüz 16 Seminararbeit – Java Profiling • -Djrat.factory=org.shiftone.jrat.provider.stats.StatMethodHandlerFactory Es werden nur die manuell aufgerufenen Methoden mit Anzahl der Aufrufe und der zugehörigen Laufzeit textuell dargestellt. Abbildung 3.2.2: StatMethodHandlerFactory Kolja Braden, Philipp Daubenschüz 17 Seminararbeit – Java Profiling • Djrat.factory=org.shiftone.jrat.provider.tree.TreeMethodHandlerFactory Ausgegeben wird ein Methoden-Aufrufbaum. D.h. es wird ersichtlich gemacht, welche Methode von wo aufgerufen wurde und wie lange die jeweilige Ausführungszeit war. Besonders laufzeitintensive Methoden werden dabei farblich gekennzeichnet. Abbildung 3.2.3: TreeMethodHandlerFactory Kolja Braden, Philipp Daubenschüz 18 Seminararbeit – Java Profiling • Djrat.factory=org.shiftone.jrat.provider.log.LogMethodHandlerFactory Hier wird eine Liste erstellt über den Zeitpunkt eines Methodeneintritts, den Zeitpunkt des Wiederaustritts und die aktuelle Aufruftiefe. Abbildung 3.2.4: LogMethodHandlerFactory 3.2.4 Fazit JRat bietet Funktionalitäten, um einen groben Überblick über die ausgeführten Methoden und die Anzahl ihrer Aufrufe zu erlangen. Auch die Ausführungszeit einer beliebigen Methode wird hinreichend genau ausgegeben. Falls bestimmte Methoden unverhältnismäßig viel Laufzeit benötigen, ist es allerdings oftmals nur unzureichend möglich, nachzuvollziehen, Kolja Braden, Philipp Daubenschüz 19 Seminararbeit – Java Profiling welcher Abschnitt der evtl. viel Code umfassenden Methode diese Performanzeinschränkungen bewirkt. Im Gegensatz zu auf dem JVMPI basierenden Profilern ist es hier außerdem nicht möglich, JVM- Systemaufrufe zu beobachten. Auch ist es in JRat nicht möglich, Speicherbedarfsanalysen oder Analysen über den Grad der Codeabdeckung durchzuführen. 3.3 HP- JMeter /Xrunhprof aus dem JDK Das JDK von SUN beinhaltet einen Profiler „hprof“. Er wird mit dem Parameteraufruf xrunhprof bei der Ausführung eines Java- Programms gestartet. Mit Konsoleneingaben folgender Form wird er aktiviert. java –Xrunhprof [<option>=<value>, ...] [Programmname] Mit diesem Profiler kann das Java- Programm bis zu 50-mal langsamer laufen, da der logging Aufwand der Profilingergebnisse sehr hoch ist. Es können Optionen eingestellt werden, in denen festgehalten ist wie der Profiler das zu testende Programm überprüfen soll, z.B. : cpu= times – hprof führt über die Zahl der Aufrüfe und deren Laufzeit Buch cpu = samples – hprof wird in einem anderen Modus zu laufen, er arbeitet nicht als listener, sondern holt in regelmäßigen Abständen, von der Virtuellen Machine die Stacktraces aller Threads und speichert die Häufigkeit mit der es die verschiedenen Threads antrifft. In diesem Modus ist die Ausführungsgeschwindigkeit nur noch zweimal langsamer. file=<file> - damit kann explizit ein Dateiname angegeben werden, in den das Ergebnis geschrieben wird. Weitere Optionen: java -Xrunhprof:help Hprof usage: -Xrunhprof[:help]|[<option>=<value>, ...] Option Name and Value Description Default --------------------- ----------- ------- heap=dump|sites|all all heap profiling cpu=samples|times|old CPU usage off monitor=y|n monitor contention n format=a|b ascii or binary output a file=<file> write data to file java.hprof(.txt for ascii) net=<host>:<port> send data over a socket write to file depth=<size> stack trace depth 4 cutoff=<value> output cutoff point 0.0001 Kolja Braden, Philipp Daubenschüz 20 Seminararbeit – Java Profiling lineno=y|n line number in traces y thread=y|n thread in traces? n doe=y|n dump on exit? y Example: java -Xrunhprof:cpu=samples,file=log.txt, depth=3 FooClass Xrunhprof erstellt als Ergebnis des Profilens eine txt- Datei. Diese Datei beinhaltet eine Tabelle mit den CPU-Zeiten, in der Stacktraces als Nummer notiert sind. CPU TIME (ms) BEGIN (total = 17314) Mon Oct 17 13:35:02 2005 rank self 1 accum count trace method 52.58% 52.58% 19993 301058 java.lang.AbstractStringBuilder.expandCapacity 2 21.17% 73.74% 10002 301056 java.lang.String.<init> 3 8.50% 82.25% 10000 301020 java.lang.String.concat 4 4.80% 87.05% 3 301023 java.lang.Object.wait ….. Die Abfolge von Funktionsaufrüfen wird an anderer Stelle als die Stacktraces der Ausgabedatei festgehalten. THREAD START (obj=50000115, id = 200002, name="HPROF gc_finish watcher", group="system") THREAD START (obj=50000115, id = 200003, name="Signal Dispatcher", group="system") THREAD START (obj=50000115, id = 200001, name="main", group="main") THREAD END (id = 200001) THREAD START (obj=50000115, id = 200006, name="DestroyJavaVM", group="main") THREAD END (id = 200006) THREAD END (id = 200002) TRACE 301058: java.lang.AbstractStringBuilder.expandCapacity(<Unknown Source>:Unknown line) java.lang.AbstractStringBuilder.append(<Unknown Source>:Unknown line) java.lang.StringBuilder.append(<Unknown Source>:Unknown line) _strings.main(_strings.java:Unknown line) TRACE 301056: Kolja Braden, Philipp Daubenschüz 21 Seminararbeit – Java Profiling java.lang.String.<init>(<Unknown Source>:Unknown line) java.lang.StringBuilder.toString(<Unknown Source>:Unknown line) _strings.main(_strings.java:Unknown line) TRACE 301020: java.lang.String.concat(<Unknown Source>:Unknown line) _strings.main(_strings.java:Unknown line) TRACE 301023: java.lang.Object.wait(<Unknown Source>:Unknown line) java.lang.ref.Reference$ReferenceHandler.run(<Unknown Source>:Unknown line) TRACE 301053: java.lang.AbstractStringBuilder.append(<Unknown Source>:Unknown line) java.lang.StringBuilder.append(<Unknown Source>:Unknown line) _strings.main(_strings.java:Unknown line) TRACE 301055: ….. Kolja Braden, Philipp Daubenschüz 22 Seminararbeit – Java Profiling 3.3.1 Überblick über die Funktionalitäten Mit HP-JMeter ist es möglich Profil-Dateien zu analysieren. Es steht zum kostenlosen Download, auf der HP-Homepage, zur Verfügung. HP- JMeter bietet eine kostenlose und einfache Möglichkeit ein Programm auf die Performance zu überprüfen. Der Funktionsumfang, den HP JMeter bietet, hängt von der Benutzten Profilern ab. Der HPJMeter unterstützt Profile Dateinen von folgenden Profilern: Prof Eprof Xeprof Xrunprof Xrunhprof Diese Profiler sind in den verschiedenen VirtualMaschins integriert und müssen In dem hier dargestellten Beispiel wurde der Profiler „Xrunhprof“ des JDK 1.5 von java benutzt und auf ein Programm mit verschiedenen Stringoperationen angewandt worden. Beim Öffnen einer Log – Datei des Profilens erhält man vom Programm eone Übersich über die gestesteten Software. Es werden Werte, wie z.B.; „Running Kolja Braden, Philipp Daubenschüz 23 Seminararbeit – Java Profiling time“ und „Number of Methods“ angezeigt. Es kann mit dem HP-JMeter angezeigt werden, wie oft eine Methode aufgerufen wurde, und wie viel Rechenzeit in den Methoden insgesamt Verbraucht wurde. Diese Funktionalitäten kann man unter dem Menüpunkt „Metric“ finden. Der Funktionsumfang des HP-JMeters hängt bei den Zeitfunktionalitäten von der Profilingdatei ab. Die Dateien werden von den integrierten Profilern mit unterschiedlich umfangreichen Informationen gefüllt. Der Benutzer kann darüber hinaus mit unterschiedlichen Parametern, die dem Profiler übergeben werden, den Informationsumfang der Ausgabedatei beeinflussen. Kolja Braden, Philipp Daubenschüz 24 Seminararbeit – Java Profiling Created Objects Oft ist es hilfreich zu wissen, welche Objekte wie oft erzeugt werden, um einzuschätzen, ob die vom Programm erzeugte Anzahl auch so vom Programmiere gewünscht sind oder sich dort ein Optimierungsbedarf findet . Um die Performance in dem Beispielprogramm zu verbessern, könnte statt der vielen String ein Stringbuffer zur lösung des Problems gewählt werden. Mit dieser Maßnahme ließe sich die gleiche Aufgabe mit wesentlich weniger Objekten bearbeiten. Diese Ansicht ist wichtig, da das Erzeugen von Objekten Performances-lastig ist. In weiteren Entwicklungsschritten ist zu überdenken, ob Objekte eingespart werden können. Kolja Braden, Philipp Daubenschüz 25 Seminararbeit – Java Profiling • Call Graph Die aufgerufenen Methoden lassen sich mit den HP-JMeter als hirarchische Struktur darstellen. Diese Ansicht heißt Call Graph Tree. Durch einen Doppelklick auf die entsprechende Methode kann man, die aufrufenden Programmteile identifizieren. Die Navigation durch den Graphen ist gewöhnungsbedürftig, es sind neben den programmierten Aufrufen auch die Systemaufrufe der VirtualMaschine aufgeführt. Dadurch ist der Call Tree sehr unübersichtlich. Je nach Modus, in dem der Profiler gestartet wurde, sind die Daten nicht vollständig. Bei dem Profiler Xrunhprof sind die Daten des CallTrees nicht vollständig, wenn man die Option -cpu=samples auswählt das dort nur in regelmäßigen Abständen der Stack der JVM analysiert wird und für die Loggingdatei aufbereitet wird. Es kann dennoch erkannt werden, welche Funktion von welchem Teil des zu testenden Programms aufgerufen wird. Kolja Braden, Philipp Daubenschüz 26 Seminararbeit – Java Profiling • Thread Histogramm Mit dem „Thread Histogramm“ können die Abläufe der Threads des getesteten Programms visualisiert werden. In dem Beispiel sieht man den thread der Main-Funktion. Es kann eine Darstellung als Histogramm per Doppelklick ausgewählt werden. Das Diagramm ist je nach benutztem Profiler, und gewählten Optionen, mehr oder weniger aussagekräftig. 3.3.2 Fazit Das HP – JMeter ist ein kostenloser Profliler, an den die Erwartungen nicht zu hoch gesteckt werden sollten. Es stehen relativ wenige Anzeigemöglichkeiten zur Verfügung. Die Anzahl der Anzeigemöglichkeiten ist von dem benutzten Profiler abhängig. Mit dem im Rahmen dieser Arbeit getesteten Xrunhprof kann man nicht unbedingt viele brauchbare Informationen zur Performancesteigerung erhalten. Die Benutzeroberfläche ist in einem unübersichtlichem Design so dass man nicht alle Funktionen intuitiv findet, z.B. dass Sonderfunktionen durch Doppelklicken erscheinen. Die Mitgeloggten Aufrufe von Biliotheksfunktionen machen die Oberfläche und die Anzeigen zudem noch unübersichtlicher. Gegenüber dem Lesen der Logging- Datei, die durch einen integrierten Profiler ertstellt wurde ist es komfortabler dieses Tool zu benutzen. Mit anderen kostengünstigeren oder kostenlosen Tools ist es möglich ein komfortableres Profiling durchzuführen. Kolja Braden, Philipp Daubenschüz 27 Seminararbeit – Java Profiling 4 Bewertung von Performanceanalysen Lösungen die bei der Entwicklung von Software erstellt wird hat oft das Problem der Inperformance. Die Software arbeitet funktional korrekt, ist aber nicht durch lange Wartezeiten, die der Benutzung autreten unkomfortabel für den Benutzer. Es ist im Softwareentwicklungsprozess deshalb unbedingt notwendig, dass die Software einem Refactoring unter Gesichtspunkten der Performance einem „Refactoring“ unterzogen wird. Zu diesem Zeitpunkt haben die Entwickler von Software zur Überprüfung der Funktionalität, einen korrekt laufenden Prototypen mit dem die Funktionalitäten und Laufzeiten verglichen werden können. Einfache Zeitmessungen können mit Konsolenausgaben gemacht werden. Dies ist ungenau und kann nur einen ersten Anhaltspunkt liefern. Eine bessere Möglichkeit stellt der Einsatz vor sog. Profilern dar. Profiler sind Entwicklungstools mit denen Zeitmessungen, Funktionsaufrufe, usw. gemachte werden können. Jenach Tool stehen verschiedene Analysegrafiken zur Verfügung mit denen, der Engpass in der zu testenden Software lokalisiert werden kann. Im Rahmen dieser Arbeit sind verschiedene kostenlose Tools getestet und verglichen worden. Die Tools sind sehr vielfältig, es sind Plugins erhältlich sowie Stand-Alone Lösungen. Professionelle kostenpflichtige Tools sind nicht betrachtet worden. Jedes Tool hat Vor- und Nachteile auf die eingegangen worden sind. Beim Profiling mit den vorgestellten Tools entstehen systembedingt Messungenauigkeiten. Hierbei gibt es im allgemeinen zwei Arten, wie die Messung sich negativ und ungenau auf die Laufzeit des zu testenden Programms auswirken kann. Zum einem ist ein Overhead möglich, der durch den Profiler entsteht und dadurch verlängert sich die Laufzeit erheblich. Der Overhead entsteht dadurch, dass der Profiler die Messdaten ermitteln muss. Zum anderen entsteht ein Effekt der „Instrusion“ , d.h. dass auf die gleichen Resourcen zugegriffen wird wie das wie das zu testende Programm. Der Profiler misst auch Effekte, die er selber verursacht. Es werden zwei Konzepte verfolgt, um diesen Effekt zu minimieren. Beim Sampling wird die Laufzeit- Umgebung in festen Intervallen gestoppt und analysiert, in welcher Methode sich das Programm zu dem Zeitpunkt befindet. So wird herausgefunden in welcher Methode am meisten CPU- Zeit verbraucht wird. Kolja Braden, Philipp Daubenschüz 28 Seminararbeit – Java Profiling Es entsteht mit dieser Art zu messen.ein kleiner Overhead. Die Messdaten, der Call-Counts und Call Graphs werden nicht mehr sehr genau abgebildet. Mit dem Tracing wird bei jedem Methodenaufruf Daten ermittelt, z.B. die aufgerufene Methode und wie viel Zeit in Ihr verbracht wurde. Wenn eine Messung auf diese Art stattfindet werden die Call-Counts und Call Graphs relativ genau erfasst. Doch entsteht ein Overhead der die Ergebnisse des Timing-Datas verändert. Kolja Braden, Philipp Daubenschüz 29 Seminararbeit – Java Profiling Anhang A Beispielprogramme Stringoperationen public class _strings{ public static void main( String args[] ) { int MAX = 10000; // use static function long time1 = System.currentTimeMillis(); String s = ""; for ( int i = MAX; i-- > 0; ) s = s.concat( "t" ); time1 = System.currentTimeMillis() - time1; // use dynamic function long time2 = System.currentTimeMillis(); String t = ""; for ( int i = MAX; i-- > 0; ) t += "t"; time2 = System.currentTimeMillis()- time2; System.out.println( "1. s.concat: " + time1 + " ms" ); System.out.println( "2. t+= " + time2 + " ms" ); : } } Quicksort Algorithmus (siehe Vorlesung Programmieren 2. Semester) public class Anwendung{ public static void main (String args[]) { //run Methode fest in dem Konstruktor verankert! //"speicher" ist Speicher, mit dem Ausgaben realisiert werden sollen long time1 = System.currentTimeMillis(); int [] a1={79, 4, 66, 78, 90, 1000, 45, 50, 1, 10}; Qsort testa1 = new Qsort(a1); time1 = System.currentTimeMillis()- time1; Kolja Braden, Philipp Daubenschüz 30 Seminararbeit – Java Profiling long time2 = System.currentTimeMillis(); int [] a2={4, 4, 4, 4, 4, 4, 4, 4, 4, 4}; Qsort testa2 = new Qsort(a2); time2 = System.currentTimeMillis()- time2; long time3 = System.currentTimeMillis(); int [] a3={4, 4, 4, 4, 4, 1, 4, 4, 4, 4}; Qsort testa3 = new Qsort(a3); time3 = System.currentTimeMillis()- time3; long time4 = System.currentTimeMillis(); int[] a4= {10, 9, 8, 7, 6, 5, 4, 3, 2, 1}; Qsort testa4= new Qsort(a4); time4 = System.currentTimeMillis()- time4; long time5 = System.currentTimeMillis(); int[] a5= {50, 49, 48, 47, 46, 45, 44, 43, 42, 41, 40, 39, 38, 37, 36, 35, 34, 33, 32, 31, 30, 29, 28, 27, 26, 25, 24, 23, 22, 21, 20, 19, 18, 17, 16, 15, 14, 13, 12, 11, 10, 9, 8, 7, 6, 5, 4, 3, 2, 1}; Qsort testa5= new Qsort(a5); time5 = System.currentTimeMillis()- time5; System.out.println( "nr1: "+time1+"ms\n nr2: "+time2+"ms\n nr3: "+time3+"ms\n nr4: "+time4+"ms\n nr5: "+time5+"ms\n" ); } } Kolja Braden, Philipp Daubenschüz 31 Seminararbeit – Java Profiling B Quellenangaben [Ulle02] Java ist auch eine Insel von Christian Ullenboom Broschiert - 1239 Seiten - Galileo Press Erscheinungsdatum: Oktober 2002 ISBN: 389842331X [Flan02] Java in a Nutshell von David Flanagan Broschiert - 1104 Seiten - O'Reilly Erscheinungsdatum: November 2002 ISBN: 389721332X [Tamm04]Michael Tamm ;iX 4/2004, S.42 [Dude04]Der Duden, Bd.1 : Duden Die deutsche Rechtschreibung Bibliographisches Institut, Mannheim ISBN: 3411040130 [AdAd03] Leistungsanalyse von Java Anwendungen mit HPJMeter Björn Adam, Michael Adams, 11/03 [Stre05]Java-Performancemessung, Martin Strenge, 2005 [Hage05] Java Performance Messungen, Johannes Hagen, 2005 Websites: http://java.sun.com/developer/onlineTraining/Programming/JDCBook/perf3.html [hyad] [jrat] http://jrat.sourceforge.net Kolja Braden, Philipp Daubenschüz 32