im nächsten Teil des Einsteigerguides werden wir ein Tool benötigen, das und dabei hilft, festzustellen, welche Funktionen aufgerufen werden, von wem sie aufgerufen werden, wie oft und vor allem: Wie viel Zeit von der gesamten Ausführungszeit in welcher Funktion zugebracht wird.
Programme von oben genannten Art nennt man Profiler. In der Linux-Welt gibt es da einige: OProfile zum Beispiel oder gprof. Ich stelle hier ein recht neues Tool vor, das vor allem von Linux-Kernel-Entwicklern entwickelt wird, aber auch für uns Normalo-Anwendungs-Entwickler sehr brauchbar ist. Es heißt perf. Ich habe es ausgewählt, weil ich es für sehr einfach zu bedienen halte. Außerdem ist der Overhead (der Aufwand, der betrieben werden muss und daher das Programm, dass man untersuchen will, verlangsamt) geringer als in den anderen Profilern.
Zuvor ein paar Worte zur Erklärung: Nein, ich glaube nicht, dass das wesentliche Problem, das man im ASC-Quellcode lösen muss, die Performance ist. Aber ich glaube, dass man mit Profilern einen guten Einblick in ein Programm bekommen kann. Zudem findet man leicht einen Einstieg in einzelne Teile des Codes. Jedenfalls geht es mir so
Die Installation ist, wie bei allen solchen Tools unter Linux, sehr einfach: Benutzt Euren Paket-Manager (apt-get oder yum oder so).
Um perf mitzuteilen, dass es ASC profilen soll, schreibt man einfach (ich setze voraus, dass Ihr Euch gerade in dem Verzeichnis ~/code/asc befindet, oder eben dort, wohin Ihr den ASC-Quellcode geclont habt):
Code: Alles auswählen
perf record source/unix/asc/asc
Code: Alles auswählen
[ perf record: Woken up 5 times to write data ]
[ perf record: Captured and wrote 1.437 MB perf.data (~62778 samples) ]
Code: Alles auswählen
perf report
Code: Alles auswählen
8,68% asc asc [.] tnbufstream::readdata(void*, int, bool)
5,17% asc libc-2.16.so [.] __memcpy_ssse3
4,89% asc asc [.] tanycompression::readlzwdata(void*, int, bool)
3,93% asc libvorbis.so.0.4.6 [.] mdct_backward
3,45% asc asc [.] tnstream::readInt()
3,01% asc libvorbis.so.0.4.6 [.] vorbis_book_decodevv_add
2,93% asc libvorbisfile.so.3.3.5 [.] ov_read_filter
2,52% asc libSDL-1.2.so.0.11.4 [.] 0x0000000000010529
2,32% asc asc [.] Surface::read(tnstream&)
2,22% asc libvorbis.so.0.4.6 [.] vorbis_synthesis_blockin
2,16% asc asc [.] tn_c_lzw_filestream::readcmpdata(void*, int, bool)
1,96% asc asc [.] tanycompression::readdata(void*, int, bool)
1,81% asc asc [.] tn_c_lzw_filestream::readdata(void*, int, bool)
1,58% asc libc-2.16.so [.] __GI___strcasecmp_l_ssse3
1,52% asc libbz2.so.1.0.6 [.] BZ2_decompress
1,41% asc asc [.] zoomSurfaceRGBA(SDL_Surface*, SDL_Surface*, bool)
1,17% asc libogg.so.0.8.0 [.] oggpack_look
1,04% asc [kernel.kallsyms] [k] clear_page
0,96% asc libvorbis.so.0.4.6 [.] vorbis_book_decodev_add
Die vorletzte Spalte zeigt den Namen der Bibliothek, aus der die Funktion ist. Wenn die Funktion in ASC selbst definiert wurde, steht da natürlich asc.
Die zweite Spalte zeigt den Namen der Binary, also des Programms, in dem die Funktion ausgeführt wurde. Bei uns ist das nur asc.
Die erste Spalte die die interessanteste für das Performance Profiling: Sie zeigt, wie viel Prozent der Gesamtzeit in eben jener Funktion verbracht wurde. Dabei wird nicht draufaddiert, wie viel Zeit in Funktionen verbracht wird, die diese Funktion aufgerufen hat.
Angenommen, wir interessieren uns nur für den Teil der Funktionen, die in ASC definiert sind, dann navigieren wir mit den Cursortasten ↓ und ↑ über eine Funktion, die in asc definiert ist, und drücken die Taste d. Damit filtern wir alle Funktionen von anderen Quellen aus.
Wollen wir Details über diese Funktion erfahren, dann drücken wir Enter oder →. Man kann sich hier ein paar Dinge anschauen, auf die ich nicht näher eingehen will. Interessant ist vorerst mal nur der erste Punkt - drücken wir wieder Enter oder →.
Hier sehen wir jede Menge Zeug, das Euch vermutlich erst einmal unverständlich ist. Das ist OK Auf was Ihr hier blickt, ist der Programmcode der Funktion zusammen mit dem Assembly des entsprechenden Codes. Assembly ist das, was auf der CPU ausgeführt wird. Jedes dieser mov, add, cmp usw. steht für einen Binärcode (01000111...), der vom Prozessor verstanden wird.
Es sei hier mal deutlich gesagt: Es gibt für Euch, wenn Ihr für ASC entwickeln wollt, überhaupt keinen Grund, Assembly zu lernen (außer natürlich, dass es Spaß macht ). Trotzdem kann diese Ausgabe hilfreich sein. Sie sagt uns, wo genau die Funktion ihre Zeit verplempert. In der ersten Zeile steht eine Zahl; sie gibt an, wie viel Prozent der Zeit, die in dieser Funktion (über alle Funktionsaufrufe hinweg gerechnet) an genau dieser Instruktion verbraucht wird. perf kennzeichnet besonders teure Instruktionen rot.
(Wer sich jetzt wundert: Brauchen nicht alle Instruktionen gleich viel Zeit? Dem sei gesagt: Seit mindestens 20 Jahren nicht mehr. Erstens entspricht heutzutage eine Instruktion nicht mehr einer Hardwareschaltung, zweitens wird die Programmperformance häufig darüber entschieden, ob Daten im CPU-Cache liegen oder nicht. Wer sich für so etwas interessiert, dem empfehle ich das hervorragende Paper von Ulrich Drepper What Every Programmer Should Know About Memory.)
Wenn man weiß, in welchen Funktionen viel Zeit zugebracht wird, kann man zwei Dinge tun, um den Programmcode zu beschleunigen - erstens: Man macht die Funktion schneller, oder zweitens: Man ruft sie nicht so oft auf. perf report verrät uns bisher aber leider nicht, von welchen Funktionen unsere problematischen Funktionen aufgerufen werden. Aber auch das geht: Machen wir eines neuerliches Profiling unseres Programmes, diesmal so:
Code: Alles auswählen
perf record -g -- source/unix/asc/asc
Code: Alles auswählen
perf report -g
Drücke ich E (also SHIFT+e), dann werden alle Callchains aller Funktionen angezeigt. Mit C schließe ich sie wieder.
Wäre es jetzt nicht nett, wenn ich den kompletten Callgraph sehen könnte? Als Grafik, mit Kästchen, Pfeilen und so? Auch dazu gibt es wieder eine Lösung, und natürlich hilft uns unsere Distro (und apt-get oder yum) mit der Installation eines netten kleines Skriptes names gprof2dot. Anders als der Name sagt kann gprof2dot nicht nur mit gprof, sondern auch mit perf oder anderen Profilern erstellte Profile lesen. gprof2dot Wandelt das dann in ein dot-File um. dot ist ein Beschreibungsformat für Graphen, und mit dem Programm dot (das wahrscheinlich mit gprof2dot mitinstalliert wurde, ansonsten müsst Ihr das selber machen). Gebt nun an der Kommandozeile folgendes ein:
Code: Alles auswählen
perf script | gprof2dot -f perf | dot -Tpng -o callgraph.png
Jetzt habt Ihr eine Datei namens callgraph.png in Eurem Ordner liegen. Das Ergebnis sieht ungefähr so aus:
http://dl.dropbox.com/u/7261613/callgraph.png
Nett, oder? Ich gehe jetzt nicht mehr im Detail auf diesen Callgraph ein, aber wenn Ihr Fragen dazu (oder zu sonstwas) habt, dann postet sie einfach.
In der nächsten Ausgabe unseres Einsteigerguides werden wir perf verwenden, um eine Funktion zu identifizieren, die wir optimieren können. Bis dahin könnt Ihr ja schon ein wenig in den Funktionen von ASC herumstöbern und Euch verschiedene Callgraphs ausgeben lassen für z.B. nur ASC starten und beenden, nur einen Zug machen, nur den Computergegner einen Zug machen lassen, ...
Viel Spaß