diff options
Diffstat (limited to 'Master/Reference Architectures and Patterns/hjp5/html/k100315.html')
| -rw-r--r-- | Master/Reference Architectures and Patterns/hjp5/html/k100315.html | 750 |
1 files changed, 750 insertions, 0 deletions
diff --git a/Master/Reference Architectures and Patterns/hjp5/html/k100315.html b/Master/Reference Architectures and Patterns/hjp5/html/k100315.html new file mode 100644 index 0000000..704f7ff --- /dev/null +++ b/Master/Reference Architectures and Patterns/hjp5/html/k100315.html @@ -0,0 +1,750 @@ +<html>
+<head>
+<title>
+Handbuch der Java-Programmierung, 5. Auflage
+</title>
+</head>
+<body>
+<a name="startofbody"></a>
+<script language="JavaScript" src="hjp4lib.js">
+</script>
+<script language="JavaScript">
+installKbdHandler("97,#startofbody;101,#endofbody;116,cover.html;122,k100003.html;115,search.html;105,index.html;100,JDKDOCS;112,APIDOCS;104,k100312.html;106,k100314.html;107,k100316.html;108,k100317.html");
+</script>
+<table border=0 cellpadding=0 cellspacing=1 width="100%">
+<tr bgcolor="#EEFFCC">
+<td width="7%" align=center bgcolor="#DDCC99"><a href="cover.html"> Titel </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100003.html"> Inhalt </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="search.html"> Suchen </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="index.html"> Index </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="../jdkdocs/index.html" onClick="this.href=getDocIndex()"> DOC </a>
+<td align="right">Handbuch der Java-Programmierung, 5. Auflage
+<tr bgcolor="#EEFFCC">
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100312.html"> << </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100314.html"> < </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100316.html"> > </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100317.html"> >> </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="../jdkdocs/api/index.html" onClick="this.href=getApiIndex()"> API </a>
+<td align="right">Kapitel 50 - Performance-Tuning
+</table>
+<hr>
+
+
+<!-- Section -->
+<a name="profilereinsatz"></a>
+<h2>50.3 Einsatz eines Profilers </h2>
+<hr>
+<ul>
+<li><a href="k100315.html#profilereinsatz">50.3 Einsatz eines Profilers</a>
+<ul>
+<li><a href="k100315.html#sectlevel3id050003001">50.3.1 Grundlagen</a>
+<li><a href="k100315.html#sectlevel3id050003002">50.3.2 Eine Beispielsitzung mit dem Profiler</a>
+<ul>
+<li><a href="k100315.html#sectlevel4id050003002001">Erzeugen der Profiling-Informationen</a>
+<li><a href="k100315.html#sectlevel4id050003002002">Das CPU-Profile</a>
+<li><a href="k100315.html#sectlevel4id050003002003">Das Heap-Profile</a>
+<li><a href="k100315.html#sectlevel4id050003002004">Die optimierte Version des Programms</a>
+</ul>
+<li><a href="k100315.html#sectlevel3id050003003">50.3.3 Ausblick</a>
+</ul>
+</ul>
+<hr>
+
+
+<!-- Section -->
+<a name="sectlevel3id050003001"></a>
+<h3>50.3.1 Grundlagen </h3>
+
+<p>
+Die bisher vorgestellten Tipps und Tricks sind sicherlich eine Hilfe,
+um bereits während der Entwicklung eines Programms grundsätzliche
+Performance-Probleme zu vermeiden. Läuft das fertige Programm
+dann trotzdem nicht mit der gewünschten Geschwindigkeit (was
+in der Praxis häufig vorkommt), helfen pauschale Hinweise leider
+nicht weiter. Statt dessen gilt es herauszufinden, welche Teile des
+Programms für dessen schlechte Performance verantwortlich sind.
+Bei größeren Programmen, die aus vielen tausend Zeilen
+Quellcode bestehen, ist das eine komplizierte Aufgabe, die nur mit
+Hilfe eines guten <a name="ixa103670"><i>Profilers</i></a> bewältigt
+werden kann. Der Profiler ist ein Werkzeug, mit dessen Hilfe im laufenden
+Programm <i>Performanceparameter</i>, wie beispielsweise die verbrauchte
+CPU-Zeit, die Anzahl der allozierten Objekte oder die Anzahl der Aufrufe
+bestimmter Methoden, überwacht und gemessen werden können.
+Durch manuelle Inspektion der erzeugten Logdateien oder mit Hilfe
+eines Auswertungsprogramms kann dann festgestellt werden, welche Teile
+des Programms die größte Last erzeugen und daher verbesserungsbedürftig
+sind.
+<p>
+<table border=0 cellspacing=0 cellpadding=0 width=100%>
+<tr>
+<td width=1 align=left valign=top bgcolor="#FF9900"><img src="trp1_1.gif"></td>
+<td><img src="trp1_1.gif" width=1></td>
+<td width=1 align=left valign=top bgcolor="#FF9900"><img src="trp1_1.gif"></td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top width=1000>
+
+<p>
+Das Standard-JDK enthält bereits seit der Version 1.0 einen eingebauten
+Profiler, der Informationen über Laufzeit und Aufrufhäufigkeit
+von Methoden geben kann. Im JDK 1.2 wurde er erweitert und kann seither
+den Speicherverbrauch messen und Profiling-Informationen <i>threadweise</i>
+ausgeben. Mit dem JDK 1.3 wurde er erneut verbessert und mit einem
+offenen Profiler-API versehen (<a name="ixa103671"><i>JVMPI</i></a>,
+<a name="ixa103672"><i>Java Virtual Machine Profiler Interface</i></a>).
+Mit dessen Hilfe ist es möglich, eigene Profiling-Werkzeuge zu
+schreiben. Fester Bestandteil des JDK ist eine Beispielimplementierung
+<a name="ixa103673"><a href="index_h.html#ixb102749"><font color=#000080><tt>hprof</tt></font></a></a>,
+die für einfache Profiling-Aufgaben verwendet werden kann.</td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top>
+<table border=0 cellspacing=0 cellpadding=1 width=100% bgcolor="#FF9900">
+<tr>
+<td><font color="#FFFFFF"> JDK1.1-6.0 </font></td>
+</tr>
+</table>
+</td>
+<td width=1 align=left valign=top bgcolor="#FF9900"><img src="trp1_1.gif"></td>
+</tr>
+</table>
+
+<p>
+Im Vergleich zu spezialisierten Produkten sind die Fähigkeiten
+des eingebauten Profilers etwas rudimentär. Insbesondere die
+vom Profiler erzeugte Ausgabedatei erfordert einigen Nachbearbeitungsaufwand.
+Zudem gibt es keine grafischen Auswertungen wie bei kommerziellen
+Profilern. Dennoch ist der JDK-Profiler ein brauchbares und hilfreiches
+Instrument, mit dem Performanceprobleme und Speicherengpässe
+analysiert werden können. Wir wollen uns in diesem Abschnitt
+mit den Grundlagen seiner Bedienung vertraut machen.
+
+<p>
+Als Beispiel für die Anwendung des Profiler wollen wir ein Programm
+verwenden, dessen simple Aufgabe darin besteht, einen <a href="index_s.html#ixb100117"><font color=#000080><tt>String</tt></font></a>
+mit 10000 Punkten zu erzeugen und auf dem Bildschirm auszugeben. Statt
+die Ratschläge aus dem vorigen Abschnitt zu beherzigen, verwendet
+das Programm den Operator <font color="#000077"><tt>+=</tt></font>,
+um den <a href="index_s.html#ixb100117"><font color=#000080><tt>String</tt></font></a>
+zeichenweise in einer Schleife zusammenzusetzen. Auf langsameren Rechnern
+kann es durchaus einige Sekunden dauern, bis der String erzeugt und
+vollständig auf dem Bildschirm ausgegeben wurde:
+<a name="listingid050009"></a>
+
+<p>
+<table border=0 cellspacing=0 cellpadding=0 width=100% bgcolor="#DDDDDD">
+<tr>
+<td valign=top>
+<font color="#000055">
+<pre>
+<font color="#555555">001 </font><font color="#00AA00">/* ProfTest1A.java */</font>
+<font color="#555555">002 </font>
+<font color="#555555">003 </font><font color="#0000AA">import</font> java.util.*;
+<font color="#555555">004 </font>
+<font color="#555555">005 </font><font color="#0000AA">public</font> <font color="#0000AA">class</font> ProfTest1A
+<font color="#555555">006 </font>{
+<font color="#555555">007 </font> <font color="#0000AA">public</font> <font color="#0000AA">static</font> String dots(<font color="#006699">int</font> len)
+<font color="#555555">008 </font> {
+<font color="#555555">009 </font> String ret = <font color="#0000FF">""</font>;
+<font color="#555555">010 </font> <font color="#0000AA">for</font> (<font color="#006699">int</font> i = 0; i < len; ++i) {
+<font color="#555555">011 </font> ret += <font color="#0000FF">"."</font>;
+<font color="#555555">012 </font> }
+<font color="#555555">013 </font> <font color="#0000AA">return</font> ret;
+<font color="#555555">014 </font> }
+<font color="#555555">015 </font>
+<font color="#555555">016 </font> <font color="#0000AA">public</font> <font color="#0000AA">static</font> <font color="#006699">void</font> main(String[] args)
+<font color="#555555">017 </font> {
+<font color="#555555">018 </font> String s = dots(10000);
+<font color="#555555">019 </font> System.out.println(s);
+<font color="#555555">020 </font> }
+<font color="#555555">021 </font>}</pre>
+</font>
+</td>
+<td valign=top align=right>
+<a href="../examples/ProfTest1A.java"><font color="#000055" size=-1>ProfTest1A.java</font></a></td>
+</tr>
+</table>
+<i>
+Listing 50.9: Ein Beispielprogramm zum Testen des Profilers</i></p>
+
+<p>
+Nachfolgend wollen wir uns eine Beispielsitzung mit dem Profiler ansehen.
+Ähnlich wie bei einem Debugger besteht die typische Vorgehensweise
+darin, schrittweise Informationen über Rechenzeit- und Speicherverbrauch
+zu gewinnen und das Programm mit diesen Informationen nach und nach
+zu optimieren. Für gewöhnlich gibt es dabei kein Patentrezept,
+das direkt zum Erfolg führt. Statt dessen ähnelt der Umgang
+mit dem Profiler einer Detektivarbeit, bei der die einzelnen Teile
+der Lösung nach und nach gefunden werden.
+
+<!-- Section -->
+
+<a name="sectlevel3id050003002"></a>
+<h3>50.3.2 Eine Beispielsitzung mit dem Profiler </h3>
+
+
+<!-- Section -->
+<a name="sectlevel4id050003002001"></a>
+<h4>Erzeugen der Profiling-Informationen </h4>
+
+<p>
+Zunächst muss das Programm wie gewöhnlich übersetzt
+werden:
+<font color="#333300">
+<pre>
+javac ProfTest1A.java
+</pre>
+</font>
+
+<p>
+Um das Programm unter Kontrolle des Profilers zu starten, ist die
+Option <a name="ixa103674"><a href="index_0.html#ixb102750"><font color=#000080><tt>-Xrunhprof</tt></font></a></a>
+zu verwenden und nach einem Doppelpunkt mit den erforderlichen Parametrisierungen
+zu versehen. Die Parameter werden als kommaseparierte Liste von Argumenten
+der Form »Name=Wert« angegeben. Die wichtigsten Parameter
+von <a href="index_h.html#ixb102749"><font color=#000080><tt>hprof</tt></font></a>
+sind: <a name="tableid050002"></a>
+
+<p>
+<table cols=2 border width=66%>
+
+<tr>
+<td valign=top align=left width=25%><b>Name</b></td>
+<td valign=top align=left width=75%><b>Mögliche Werte</b></td></tr>
+<tr>
+<td valign=top align=left>cpu</td>
+<td valign=top align=left>samples, times, old</td></tr>
+<tr>
+<td valign=top align=left>heap</td>
+<td valign=top align=left>dump, sites, all</td></tr>
+<tr>
+<td valign=top align=left>file</td>
+<td valign=top align=left>Name der Ausgabedatei</td></tr>
+<tr>
+<td valign=top align=left>depth</td>
+<td valign=top align=left>Maximale Tiefe der Stacktraces</td></tr>
+</table>
+<p><i>
+Tabelle 50.2: Parameter von hprof</i></p>
+
+<p>
+Mit der Option <font color="#000077"><tt>cpu</tt></font> wird der
+CPU-Profiler aktiviert. Er kennt die Modi »samples«, »times«
+und »old«. Im Modus »samples« werden die Profiling-Informationen
+dadurch gewonnen, dass das laufende Programm mit Hilfe eines separaten
+Threads regelmäßig unterbrochen wird. Bei jeder Unterbrechung
+wird ein Stacktrace gezogen, der dem Profiler Auskunft darüber
+gibt, welche Methode gerade ausgeführt wird, in welcher Quelltextzeile
+das Programm steht und wie die Kette ihrer Aufrufer aussieht. Jeder
+derartige Schnappschuß wird als <i>Sample</i> bezeichnet.
+
+<p>
+Die unterschiedlichen Stacktraces werden mit einem Aufrufzähler
+versehen, der immer dann um 1 erhöht wird, wenn bei einer Unterbrechung
+ein entsprechender Stacktrace gefunden wird. Aus dem Endwert der Zähler
+kann dann abgeleitet werden, wo das Programm die meiste Rechenzeit
+verbraucht hat. Denn je höher der Zähler war, desto öfter
+wurde das Programm an der zugehörigen Programmstelle »angetroffen«
+und desto wahrscheinlicher ist es, dass dort nennenswert Rechenzeit
+verbraucht wird.
+<p>
+<table border=0 cellspacing=0 cellpadding=0 width=100%>
+<tr>
+<td width=1 align=left valign=top bgcolor="#CC0000"><img src="trp1_1.gif"></td>
+<td><img src="trp1_1.gif" width=1></td>
+<td width=1 align=left valign=top bgcolor="#CC0000"><img src="trp1_1.gif"></td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top width=1000>
+
+<p>
+Natürlich ist diese Vorgehensweise nicht sehr präzise, und
+es sind Fälle denkbar, bei denen sie ganz versagt. Aber sie ist
+einfach zu implementieren und beeinträchtigt die Laufzeit des
+Programms nur unwesentlich. In der Praxis sollten die Ergebnisse mit
+der nötigen Vorsicht betrachtet werden. Sie dürfen nicht
+als absolute Meßwerte angesehen werden, sondern sind vorwiegend
+dazu geeignet, Tendenzen zu erkennen und Programmteile mit besonders
+hoher Rechenzeit ausfindig zu machen.</td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top>
+<table border=0 cellspacing=0 cellpadding=1 width=100% bgcolor="#CC0000">
+<tr>
+<td><font color="#FFFFFF"> Warnung </font></td>
+</tr>
+</table>
+</td>
+<td width=1 align=left valign=top bgcolor="#CC0000"><img src="trp1_1.gif"></td>
+</tr>
+</table>
+
+<p>
+Der zweite Modus »times« arbeitet etwas anders. Statt lediglich
+die Anzahl der Stacktraces zu zählen, misst er tatsächlich
+die innerhalb der einzelnen Methoden verbrauchte Rechenzeit. Allerdings
+wird dadurch auch die Laufzeit des Programms stärker erhöht
+als im Modus »samples«. In der Praxis kann eine gemischte
+Vorgehensweise sinnvoll sein, bei der zunächst per »samples«
+die größten Performancefresser eliminiert werden und dann
+per »times« das Feintuning vorgenommen wird. Die Option
+»old« erstellt die Ausgabedatei in einem Format, wie sie
+von den Profilern der Prä-1.2-Versionen verwendet wurde. Wir
+wollen hier nicht weiter darauf eingehen.
+
+<p>
+Bei der Verwendung des CPU-Profilers sind weiterhin die Optionen <font color="#000077"><tt>file</tt></font>
+und <font color="#000077"><tt>depth</tt></font> von Bedeutung. Mit
+<font color="#000077"><tt>file</tt></font> kann der Name der Ausgabedatei
+angegeben werden, er ist standardmäßig <font color="#660099">java.hprof.txt</font>.
+Mit <font color="#000077"><tt>depth</tt></font> wird festgelegt, mit
+welcher maximalen Tiefe die Stacktraces aufgezeichnet werden (standardmäßig
+4). Ist die Aufrufkette einer Methode länger als der angegebene
+Wert, wird der Stacktrace abgeschnitten, und bei der Analyse ist nicht
+mehr bis ins letzte Detail erkennbar, von welcher Stelle aus der Aufruf
+erfolgte. Wird <font color="#000077"><tt>depth</tt></font> auf 1 gesetzt,
+sind nur noch die Aufrufstellen sichtbar, die Aufrufer selbst bleiben
+unsichtbar.
+
+<p>
+Wir wollen einen ersten Lauf mit dem CPU-Profiler im Modus »samples«
+und mit einer maximalen Stacktiefe von 10 machen und rufen das Programm
+daher wie folgt auf:
+<font color="#333300">
+<pre>
+java -Xint -Xrunhprof:cpu=samples,depth=10 ProfTest1A
+</pre>
+</font>
+<p>
+<table border=0 cellspacing=0 cellpadding=0 width=100%>
+<tr>
+<td width=1 align=left valign=top bgcolor="#000077"><img src="trp1_1.gif"></td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top width=1000>
+
+<p>
+Die Option <a name="ixa103675"><a href="index_0.html#ixb102751"><font color=#000080><tt>-Xint</tt></font></a></a>
+geben wir an, um das Programm im Interpreter-Modus laufen zu lassen
+und mögliche Verfälschungen durch den Hotspot-Compiler zu
+vermeiden.</td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top>
+<table border=0 cellspacing=0 cellpadding=1 width=100% bgcolor="#000077">
+<tr>
+<td><font color="#FFFFFF"> Hinweis </font></td>
+</tr>
+</table>
+</td>
+<td width=1 align=left valign=top bgcolor="#000077"><img src="trp1_1.gif"></td>
+</tr>
+</table>
+
+
+<!-- Section -->
+<a name="sectlevel4id050003002002"></a>
+<h4>Das CPU-Profile </h4>
+
+<p>
+Das Programm erzeugt nun die Ausgabedatei <font color="#660099">java.hprof.txt</font>
+mit den Profiling-Informationen. Sie besteht aus drei Teilen:
+<ul>
+<li>Im oberen Teil werden allgemeine Informationen zur Struktur der
+Datei und den darin verwendeten Einträgen gegeben
+<li>Im mittleren Teil befinden sich die Stacktraces
+<li>Im unteren Teil werden die Sampling-Ergebnisse ausgegeben
+</ul>
+
+<p>
+Die Analyse beginnt im unteren Teil. Er sieht bei unserer Beispielsitzung
+so aus (die Samples ab Position 11 wurden aus Gründen der Übersichtlichkeit
+entfernt):
+<font color="#333300">
+<pre>
+CPU SAMPLES BEGIN (total = 246) Sun Jun 18 17:56:28 2000
+rank self accum count trace method
+ 1 53.66% 53.66% 132 9 java.lang.StringBuilder.expandCapacity
+ 2 17.48% 71.14% 43 13 java.lang.System.arraycopy
+ 3 17.07% 88.21% 42 11 java.lang.System.arraycopy
+ 4 1.63% 89.84% 4 10 java.lang.StringBuilder.toString
+ 5 1.22% 91.06% 3 17 java.lang.StringBuilder.append
+ 6 0.81% 91.87% 2 19 java.lang.StringBuilder.append
+ 7 0.81% 92.68% 2 24 sun.io.CharToByteSingleByte.convert
+ 8 0.81% 93.50% 2 12 java.lang.StringBuilder.<init>
+ 9 0.41% 93.90% 1 20 java.lang.StringBuilder.append
+ 10 0.41% 94.31% 1 14 java.lang.String.getChars
+ ...
+CPU SAMPLES END
+</pre>
+</font>
+
+<p>
+Die Ausgabe ist nach Aufrufhäufigkeit geordnet. Von den insgesamt
+246 Samples, die während des Programmlaufs gezogen wurden, waren
+132 in der Methode <a name="ixa103676"><a href="index_e.html#ixb102752"><font color=#000080><tt>expandCapacity</tt></font></a></a>
+der Klasse <a href="index_s.html#ixb100545"><font color=#000080><tt>StringBuilder</tt></font></a>
+und 43 und noch einmal 42 in der Methode <a href="index_a.html#ixb100856"><font color=#000080><tt>arraycopy</tt></font></a>
+der Klasse <a href="index_s.html#ixb100435"><font color=#000080><tt>System</tt></font></a>.
+Damit fielen insgesamt 88.21 Prozent aller Samples in diese Methoden.
+
+<p>
+Da beide Methoden nicht selbstgeschrieben sind und sich damit unseren
+Optimierungsversuchen entziehen, kann eine Performance-Verbesserung
+lediglich dadurch erreicht werden, dass die Anzahl ihrer Aufrufe vermindert
+wird. Um die Aufrufer herauszufinden, müssen wir uns die in der
+fünften Spalten angegebenen Stacktraces ansehen. Der Stacktrace
+zu <a href="index_e.html#ixb102752"><font color=#000080><tt>expandCapacity</tt></font></a>
+hat die Nummer 9 und sieht so aus:
+<font color="#333300">
+<pre>
+TRACE 9:
+ java.lang.StringBuilder.expandCapacity(StringBuilder.java:202)
+ java.lang.StringBuilder.append(StringBuilder.java:401)
+ ProfTest1A.dots(ProfTest1A.java:11)
+ ProfTest1A.main(ProfTest1A.java:18)
+</pre>
+</font>
+
+<p>
+Er besagt, dass der Sample in Zeile 202 der Methode <a href="index_e.html#ixb102752"><font color=#000080><tt>expandCapacity</tt></font></a>
+der Klasse <a href="index_s.html#ixb100545"><font color=#000080><tt>StringBuilder</tt></font></a>
+erzeugt wurde. Diese wurde von <a href="index_a.html#ixb100546"><font color=#000080><tt>append</tt></font></a>
+aufgerufen, das von unserer eigenen Methode <font color="#000077"><tt>dots</tt></font>
+in Zeile 11 aufgerufen wurde. In Zeile 11 steht zwar kein Aufruf von
+<a href="index_a.html#ixb100546"><font color=#000080><tt>append</tt></font></a>,
+dort befindet sich aber der +=-Operator zur Verkettung der Strings.
+Dieser wird vom Compiler in entsprechende Methoden- und Konstruktorenaufrufe
+der Klassen <a href="index_s.html#ixb100117"><font color=#000080><tt>String</tt></font></a>
+und <a href="index_s.html#ixb100545"><font color=#000080><tt>StringBuilder</tt></font></a>
+übersetzt.
+
+<p>
+Als erste Erkenntnis stellen wir also fest, dass offensichtlich der
++=-Operator zur <a href="index_s.html#ixb100117"><font color=#000080><tt>String</tt></font></a>-Verkettung
+interne <a href="index_s.html#ixb100545"><font color=#000080><tt>StringBuilder</tt></font></a>-Objekte
+erzeugt, die einen erheblichen Teil der CPU-Zeit benötigen, um
+während des Anfügens von Zeichen vergrößert zu
+werden.
+
+<p>
+Die Stacktraces 11 und 13 der nächsten beiden Kandidaten verstärken
+den Eindruck, dass der +=-Operator in unserem Programm CPU-intensiven
+Code erzeugt:
+<font color="#333300">
+<pre>
+TRACE 11:
+ java.lang.System.arraycopy(System.java:Native method)
+ java.lang.String.getChars(String.java:553)
+ java.lang.StringBuilder.append(StringBuilder.java:402)
+ ProfTest1A.dots(ProfTest1A.java:11)
+ ProfTest1A.main(ProfTest1A.java:18)
+TRACE 13:
+ java.lang.System.arraycopy(System.java:Native method)
+ java.lang.StringBuilder.expandCapacity(StringBuilder.java:203)
+ java.lang.StringBuilder.append(StringBuilder.java:401)
+ ProfTest1A.dots(ProfTest1A.java:11)
+ ProfTest1A.main(ProfTest1A.java:18)
+</pre>
+</font>
+
+<p>
+Beide Arten von Samples gehen letztlich auf Zeile 11 unseres Programms
+zurück und zeigen Rechenzeitverbräuche, die durch die vom
++=-Operator ausgelöste Verarbeitung temporärer Strings und
+StringBuilder verursacht werden. Obwohl die Samples in beiden Fällen
+in <a href="index_a.html#ixb100856"><font color=#000080><tt>arraycopy</tt></font></a>
+gezogen wurden, gibt es zwei unterschiedliche Stacktraces, weil die
+Aufruferkette in beiden Fällen unterschiedlich ist. Einerseits
+wird <a href="index_a.html#ixb100856"><font color=#000080><tt>arraycopy</tt></font></a>
+aus <a href="index_g.html#ixb102742"><font color=#000080><tt>getChars</tt></font></a>
+aufgerufen (da Strings immutable sind, muss <a href="index_g.html#ixb102742"><font color=#000080><tt>getChars</tt></font></a>
+bei jedem Aufruf eine Kopie des Zeichenarrays erstellen), andererseits
+wird <a href="index_a.html#ixb100856"><font color=#000080><tt>arraycopy</tt></font></a>
+in <a href="index_e.html#ixb102752"><font color=#000080><tt>expandCapacity</tt></font></a>
+benötigt, um das bei einer Verlängerung des StringBuilders
+erforderliche Umkopieren der Zeichen zu erledigen.
+
+<p>
+Unsere erste Vermutung hat sich also bestätigt: Der harmlos aussehende
+Aufruf des +=-Operators in Zeile 11 unseres Programms erzeugt temporäre
+<a href="index_s.html#ixb100117"><font color=#000080><tt>String</tt></font></a>-
+und <a href="index_s.html#ixb100545"><font color=#000080><tt>StringBuilder</tt></font></a>-Objekte,
+in der ein Großteil der Rechenzeit durch das Anhängen und
+Kopieren von Zeichen und das Erhöhen der Kapazität verbraucht
+wird.
+
+<!-- Section -->
+
+<a name="sectlevel4id050003002003"></a>
+<h4>Das Heap-Profile </h4>
+
+<p>
+Einen noch deutlicheren Eindruck vermittelt ein Heap-Profile. Wir
+erstellen es, indem wir das Programm mit der Option <font color="#000077"><tt>heap=sites</tt></font>
+erneut unter Profiler-Kontrolle laufen lassen:
+<font color="#333300">
+<pre>
+java -Xint -Xrunhprof:heap=sites,depth=10 ProfTest1A
+</pre>
+</font>
+
+<p>
+Die Ausgabe besteht wie beim CPU-Profiling aus drei Teilen. Die ersten
+beiden entsprechen dem CPU-Profiler, der dritte enthält Informationen
+zur dynamischen Heap-Belegung:
+<font color="#333300">
+<pre>
+SITES BEGIN (ordered by live bytes) Sun Jun 18 18:37:28 2000
+ percent live alloc'ed stack class
+ rank self accum bytes objs bytes objs trace name
+ 1 48.27% 48.27% 189974 25 75074238 19950 471 [C
+ 2 38.00% 86.27% 149524 157 149524 157 1 [I
+ 3 4.91% 91.17% 19304 741 19364 747 1 [C
+ 4 2.44% 93.61% 9588 153 9588 153 1 [B
+ 5 2.29% 95.90% 9010 1550 9022 1552 1 <Unknown>
+ 6 1.13% 97.03% 4460 199 4460 199 1 [S
+ 7 1.06% 98.09% 4164 253 4220 260 1 [L<Unknown>;
+ 8 0.06% 98.15% 238 3 238 3 403 [B
+ 9 0.04% 98.20% 172 1 172 1 396 [B
+ 10 0.04% 98.24% 170 10 170 10 390 [C
+ ...
+SITES END
+</pre>
+</font>
+
+<p>
+Auch hier geben die erste Spalte die Rangordnung und die nächsten
+beiden die einzelnen und kumulierten Prozentanteile am Gesamtverbrauch
+an. die Spalten 4 und 5 geben einen Überblick über die aktiven
+Objekte, die nächsten beiden über die insgesamt allozierten
+Objekte (jeweils mit der Gesamtzahl allozierter Bytes und der Anzahl
+der Objekte). Die letzte Spalte stellt den Datentyp des Objekts dar.
+<a name="ixa103677"><a href="index_0.html#ixb102753"><font color=#000080><tt>[C</tt></font></a></a>
+steht beispielsweise für ein Zeichen-Array, <a name="ixa103678"><a href="index_0.html#ixb102754"><font color=#000080><tt>[I</tt></font></a></a>
+für ein Integer-Array.
+
+<p>
+Am auffälligsten ist die oberste Zeile und die darin ersichtliche
+Diskrepanz zwischen aktiven und allozierten Objekten. Dort steht,
+dass unser Programm 19950 Zeichen-Arrays mit insgesamt 75 MByte Speicher
+alloziert hat, davon aber nur noch 25 Objekte mit kaum 200 kByte Speicher
+aktiv sind. Hier wurden also in erheblichen Umfang kurzlebige Objekte
+erzeugt und anschließend wieder fallengelassen. Stacktrace 471
+sieht so aus:
+<font color="#333300">
+<pre>
+TRACE 471:
+ java.lang.StringBuilder.expandCapacity(StringBuilder.java:202)
+ java.lang.StringBuilder.append(StringBuilder.java:401)
+ ProfTest1A.dots(ProfTest1A.java:11)
+ ProfTest1A.main(ProfTest1A.java:18)
+</pre>
+</font>
+
+<p>
+Wieder liegt der Verursacher in Zeile 11 unseres Programms, und wir
+sehen, dass der +=-Operator nicht nur viel Rechenzeit verbraucht,
+sondern zudem eine große Anzahl temporärer Objekte erzeugt
+und damit das Laufzeitsystem und den Garbage Collector belastet.
+
+<!-- Section -->
+
+<a name="sectlevel4id050003002004"></a>
+<h4>Die optimierte Version des Programms </h4>
+
+<p>
+Da wir auf die Interna der Klassen <a href="index_s.html#ixb100117"><font color=#000080><tt>String</tt></font></a>
+und <a href="index_s.html#ixb100545"><font color=#000080><tt>StringBuilder</tt></font></a>
+keinen Einfluss haben, kann die Optimierung nur darin bestehen, die
+Verwendung des +=-Operators einzuschränken oder eine besser geeignete
+Alternative zu wählen. Diese ist natürlich schon aus <a href="k100314.html#tuningstring">Abschnitt 50.2.1</a>
+bekannt und besteht darin, direkt mit <a href="index_s.html#ixb100545"><font color=#000080><tt>StringBuilder</tt></font></a>-Objekten
+zu arbeiten. Die verbesserte Version unseres Programms sieht dann
+so aus:
+<a name="proftest1b"></a>
+
+<p>
+<table border=0 cellspacing=0 cellpadding=0 width=100% bgcolor="#DDDDDD">
+<tr>
+<td valign=top>
+<font color="#000055">
+<pre>
+<font color="#555555">001 </font><font color="#00AA00">/* ProfTest1B.java */</font>
+<font color="#555555">002 </font>
+<font color="#555555">003 </font><font color="#0000AA">import</font> java.util.*;
+<font color="#555555">004 </font>
+<font color="#555555">005 </font><font color="#0000AA">public</font> <font color="#0000AA">class</font> ProfTest1B
+<font color="#555555">006 </font>{
+<font color="#555555">007 </font> <font color="#0000AA">public</font> <font color="#0000AA">static</font> String dots(<font color="#006699">int</font> len)
+<font color="#555555">008 </font> {
+<font color="#555555">009 </font> StringBuilder sb = <font color="#0000AA">new</font> StringBuilder(len + 10);
+<font color="#555555">010 </font> <font color="#0000AA">for</font> (<font color="#006699">int</font> i = 0; i < len; ++i) {
+<font color="#555555">011 </font> sb.append(<font color="#0000FF">'.'</font>);
+<font color="#555555">012 </font> }
+<font color="#555555">013 </font> <font color="#0000AA">return</font> sb.toString();
+<font color="#555555">014 </font> }
+<font color="#555555">015 </font>
+<font color="#555555">016 </font> <font color="#0000AA">public</font> <font color="#0000AA">static</font> <font color="#006699">void</font> main(String[] args)
+<font color="#555555">017 </font> {
+<font color="#555555">018 </font> String s = dots(10000);
+<font color="#555555">019 </font> System.out.println(s); <a name="proftest1b.a"></a>
+<font color="#555555">020 </font> }
+<font color="#555555">021 </font>}</pre>
+</font>
+</td>
+<td valign=top align=right>
+<a href="../examples/ProfTest1B.java"><font color="#000055" size=-1>ProfTest1B.java</font></a></td>
+</tr>
+</table>
+<i>
+Listing 50.10: Das verbesserte Programm nach der Profiler-Sitzung</i></p>
+
+<p>
+Wird nun ein CPU-Profiling durchgeführt, ergibt sich ein gänzlich
+anderes Bild:
+<font color="#333300">
+<pre>
+CPU SAMPLES BEGIN (total = 15) Sun Jun 18 19:03:56 2000
+rank self accum count trace method
+ 1 26.67% 26.67% 4 9 sun.io.CharToByteSingleByte.convert
+ 2 6.67% 33.33% 1 2 java.io.InputStreamReader.<init>
+ 3 6.67% 40.00% 1 12 sun.io.CharToByteSingleByte.getNative
+ 4 6.67% 46.67% 1 11 sun.io.CharToByteSingleByte.convert
+ 5 6.67% 53.33% 1 13 java.io.FileOutputStream.writeBytes
+ 6 6.67% 60.00% 1 4 sun.security.provider.PolicyFile.getPermissions
+ 7 6.67% 66.67% 1 5 sun.net.www.protocol.file.FileURLConnection.getPermission
+ 8 6.67% 73.33% 1 10 java.io.FileOutputStream.writeBytes
+ 9 6.67% 80.00% 1 1 sun.misc.URLClassPath$FileLoader.getResource
+ 10 6.67% 86.67% 1 6 java.net.URLClassLoader.getPermissions
+ 11 6.67% 93.33% 1 3 java.security.Security.loadProviders
+ 12 6.67% 100.00% 1 8 java.lang.StringBuilder.append
+CPU SAMPLES END
+</pre>
+</font>
+
+<p>
+Statt 246 gab es nur noch 15 Samples (die Laufzeit des Programms hat
+sich also auf ein Sechzehntel reduziert), und nur noch ein einziger
+von ihnen wurde durch den Aufruf der Methode <font color="#000077"><tt>dots</tt></font>
+verursacht. Alle anderen sind auf den Aufruf von <a href="index_p.html#ixb100555"><font color=#000080><tt>println</tt></font></a>
+in <a href="k100315.html#proftest1b.a">Zeile 019</a> zurückzuführen.
+Der Heap-Profiler liefert ein ähnliches Bild: der gesamte Speicherverbrauch
+des Programms liegt nun in der Größenordnung von 150 kByte,
+und es gibt keine nennenswerten temporären Objektallokationen
+mehr.
+<p>
+<table border=0 cellspacing=0 cellpadding=0 width=100%>
+<tr>
+<td width=1 align=left valign=top bgcolor="#FF9900"><img src="trp1_1.gif"></td>
+<td><img src="trp1_1.gif" width=1></td>
+<td width=1 align=left valign=top bgcolor="#FF9900"><img src="trp1_1.gif"></td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top width=1000>
+
+<p>
+In früheren JDKs wurde der Profiler nicht mit der Option <a name="ixa103679"><a href="index_0.html#ixb102750"><font color=#000080><tt>-Xrunhprof</tt></font></a></a>,
+sondern mit <a name="ixa103680"><a href="index_0.html#ixb102755"><font color=#000080><tt>-Xprof</tt></font></a></a>
+bzw. mit <a name="ixa103681"><a href="index_0.html#ixb102756"><font color=#000080><tt>-prof</tt></font></a></a>
+aufgerufen. Zudem durfte nicht der normale Interpreter verwendet werden,
+sondern mit <a name="ixa103682"><a href="index_j.html#ixb102757"><font color=#000080><tt>java_g</tt></font></a></a>
+mußte dessen Debug-Version aufgerufen werden. Auch das Deaktivieren
+des Just-In-Time-Compilers hat sich im Laufe der Versionen geändert.
+Während es seit dem JDK 1.3 mit dem Schalter <a name="ixa103683"><a href="index_0.html#ixb102751"><font color=#000080><tt>-Xint</tt></font></a></a>
+erledigt wird, mußte zuvor die Umgebungsvariable <a name="ixa103684"><a href="index_j.html#ixb102758"><font color=#000080><tt>JAVA_COMPILER</tt></font></a></a>
+auf den Wert <font color="#000077"><tt>NONE</tt></font> gesetzt werden.
+Soll der Profiler bei einem Applet verwendet werden, kann die Aufrufoption
+mit dem Schalter <a name="ixa103685"><a href="index_0.html#ixb102759"><font color=#000080><tt>-J</tt></font></a></a>
+an den Appletviewer übergeben werden.</td>
+<td><img src="trp1_1.gif" width=2></td>
+<td valign=top>
+<table border=0 cellspacing=0 cellpadding=1 width=100% bgcolor="#FF9900">
+<tr>
+<td><font color="#FFFFFF"> JDK1.1-6.0 </font></td>
+</tr>
+</table>
+</td>
+<td width=1 align=left valign=top bgcolor="#FF9900"><img src="trp1_1.gif"></td>
+</tr>
+</table>
+
+
+<!-- Section -->
+<a name="sectlevel3id050003003"></a>
+<h3>50.3.3 Ausblick </h3>
+
+<p>
+Egal, ob mit dem eingebauten Profiler das Laufzeitverhalten oder der
+Speicherverbrauch der Anwendung untersucht werden soll, die prinzipielle
+Vorgehensweise ist stets gleich:
+<ul>
+<li>Zunächst wird das Programm mit der Option <font color="#000077"><tt>-Xrunhprof</tt></font>
+gestartet und eine Datei mit Profiling-Informationen erstellt.
+<li>Die größten Rechenzeit- und Speicherverbraucher werden
+ermittelt, und über ihre Stacktraces wird bestimmt, woher sie
+aufgerufen werden und in welcher Weise sie zum Programmergebnis beitragen.
+<li>Stehen genügend Erkenntnisse zur Verfügung, kann das
+Programm verbessert werden und ein erneuter Profilerlauf durchgeführt
+werden.
+<li>Sind die Ergebnisse zufriedenstellend, kann der Profiler deaktiviert
+werden, andernfalls beginnt das Spiel von vorne.
+</ul>
+
+<p>
+Ist der Anteil von lokalem Code am Rechenzeitverbrauch hoch, kann
+versucht werden, diesen zu verringern. Typische Ansatzpunkte dafür
+sind das Vermindern der Anzahl von Schleifendurchläufen (durch
+bessere Algorithmen), die Verwendung von Ganz- statt Fließkommazahlen,
+das Herausziehen von schleifeninvariantem Code, das Vermeiden der
+Doppelauswertung von gemeinsamen Teilausdrücken, das Wiederverwenden
+bekannter Teilergebnisse, die Verwendung alternativer Datenstrukturen,
+das Eliminieren von unbenutztem Code oder das Reduzieren der Stärke
+von Ausdrücken, indem sie durch algebraisch gleichwertige, aber
+schnellere Ausdrücke ersetzt werden. Wird ein großer Anteil
+der Rechenzeit dagegen in Aufrufen von Untermethoden verbraucht, kann
+versucht werden, deren Aufrufhäufigkeit zu vermindern, sie durch
+performantere Aufrufe zu ersetzen, oder - im Falle eigener Methoden
+- ihre Ablaufgeschwindigkeit zu erhöhen.
+
+<p>
+Der zielgerichtete Einsatz dieser Techniken erfordert gute Werkzeuge,
+namentlich einen guten Profiler. Bei kleineren Problemen mag es ausreichend
+sein, die Ablaufgeschwindigkeit mit Ausgabeanweisungen und <a name="ixa103686"><a href="index_s.html#ixb102760"><font color=#000080><tt>System.currentTimeMillis</tt></font></a></a>
+zu ermitteln, und auch der JDK-Profiler kann mit Erfolg eingesetzt
+werden. Daneben gibt es einige kommerzielle und experimentelle Produkte
+mit wesentlich erweiterten Fähigkeiten. Beispiele für solche
+Profiler sind <a name="ixa103687"><i>JProbe</i></a> (<a href="http://www.quest.com/jprobe/">http://www.quest.com/jprobe/</a>),
+der auch für Teile der Software zu diesem Buch verwendet wurde
+oder <a name="ixa103688"><i>JInsight</i></a> (<a href="http://www.alphaWorks.ibm.com">http://www.alphaWorks.ibm.com</a>).
+Zu ihren Fähigkeiten zählen beispielsweise:
+<ul>
+<li>Die grafische Darstellung der Aufrufhierarchie mit Laufzeitinformationen
+zu Methoden und Aufrufen.
+<li>Das Ermitteln von Profiling-Informationen bis auf die Ebene einzelner
+Quelltextzeilen hinab.
+<li>Das Erstellen dynamischer Profile, um die Veränderung wichtiger
+Parameter bereits während des laufenden Programms beobachten
+zu können.
+<li>Die Rückverfolgung von alloziertem Speicher sowohl zu den
+Programmstellen, die den Speicher belegt haben, als auch zu den Variablen,
+in denen die zugehörigen Objekte gehalten werden.
+<li>Das Vergleichen von Profiling-Läufen, um die Auswirkungen
+von Optimierungsversuchen studieren zu können.
+<li>Die Ausgabe von Reports und HTML-Dateien zu Vergleichs- und Dokumentationszwecken.
+</ul>
+<hr>
+<table border=0 cellpadding=0 cellspacing=1 width="100%">
+<tr bgcolor="#EEFFCC">
+<td width="7%" align=center bgcolor="#DDCC99"><a href="cover.html"> Titel </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100003.html"> Inhalt </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="search.html"> Suchen </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="index.html"> Index </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="../jdkdocs/index.html" onClick="this.href=getDocIndex()"> DOC </a>
+<td align="right">Handbuch der Java-Programmierung, 5. Auflage, Addison
+Wesley, Version 5.0.1
+<tr bgcolor="#EEFFCC">
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100312.html"> << </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100314.html"> < </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100316.html"> > </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="k100317.html"> >> </a>
+<td width="7%" align=center bgcolor="#DDCC99"><a href="../jdkdocs/api/index.html" onClick="this.href=getApiIndex()"> API </a>
+<td align="right">© 1998, 2007 Guido Krüger & Thomas
+Stark, <a href="http://www.javabuch.de">http://www.javabuch.de</a>
+</table>
+<a name="endofbody"></a>
+</body>
+</html>
|