30.4 Profiling

Eine andere Möglichkeit, sein Programm (oder das anderer Entwicklern) zu untersuchen, ist das Profiling. Dabei wird untersucht, wie viel Zeit ein Programm mit welchen Tätigkeiten verbringt, welche Funktionen wie oft aufgerufen werden und wie viel Zeit diese dabei benötigen. Der primäre Einsatzzweck des Profilings ist also kurz gesagt das Performance-Tuning.

30.4.1 Compiler-Option

Zum Profiling wird ein Programm, der sogenannte Profiler eingesetzt. Unter Linux und BSD ist dies standardmäßig der GNU-Profiler gprof. Um diesen jedoch zu nutzen, muss bei der Übersetzung des Quellcodes, ähnlich wie beim GNU-Debugger, die Compiler-Option für das Profiling (-gp) eingeschaltet werden.

Listing 30.24 Beispiel zur Übersetzung mit Profiling

$ gcc -o myprog myprog.c -pg

30.4.2 gprof verwenden

Führt man nun ein für das Profiling übersetztes Programm aus, erzeugt dieses im Arbeitsverzeichnis eine Datei namens gmon.out. Darin sind die Informationen enthalten, die der Profiler benötigt, um für den Entwickler einen Report zu generieren.

Um diese Datei nun zu interpretieren, verwendet man das Tool gprof. Dabei werden sehr viele Informationen auf dem Bildschirm ausgegeben, weshalb man am besten eine Ausgabeumlenkung verwendet und sich die Ausgabe mit einem Pager ansieht.

Listing 30.25 gprof aufrufen

$ gprof myprog >report

30.4.3 Profiling-Daten lesen

Nachdem man einen Profiling-Report erzeugt hat, muss man nur noch wissen, wie dieser eigentlich zu interpretieren ist. Einen Ausschnitt eines fertigen Reports zeigt Ihnen das folgende Listing:

Listing 30.26 Profiling-Report (Auszug)

                                  called/total       parents
index %time  self descendents  called+self    name        index
                                called/total       children
                                                    <spontaneous>
[1]    100.0  0.01        0.00             write [1]

-----------------------------------------------

[2]      0.0    0.00        0.00     4+4  <cycle 1 as a whole>    [2]
                0.00        0.00     5      imalloc <cycle 1> [9]
                0.00        0.00     3      malloc_bytes <cycle 1> [11]

-----------------------------------------------

[3]      0.0    0.00        0.00    12+2  <cycle 2 as a whole>    [3]
                0.00        0.00    13       vfprintf <cycle 2> [6]
                0.00        0.00     1       __sbprintf <cycle 2> [468]

-----------------------------------------------
...
...
...
 %   cumulative   self              self     total
 time   seconds   seconds calls  ms/call  ms/call  name
100.0       0.01     0.01                          write [1]
  0.0       0.01     0.00   406     0.00     0.00  mbtowc [4]
  0.0       0.01     0.00    20     0.00     0.00  __sfvwrite [457]
  0.0       0.01     0.00    20     0.00     0.00  __sprint [458]
  0.0       0.01     0.00    13     0.00     0.00  localeconv [5]
  0.0       0.01     0.00    13     0.00     0.00  vfprintf <cycle 2>
                                                   [6]
  0.0       0.01     0.00    12     0.00     0.00  __sflush [459]
  0.0       0.01     0.00    12     0.00     0.00  __swrite [460]
  0.0       0.01     0.00    12     0.00     0.00  fflush [7]
  0.0       0.01     0.00     9     0.00     0.00  printf [8]...
...

Der Report ist in zwei Teile, den Call Graph und das Flat Profile, gegliedert. Im oberen Listing ist zunächst ein Auszug aus dem Call Graph und darunter ein Auszug aus dem Flat Profile zu sehen.

Call Graph

Der Call Graph gibt dem Entwickler Aufschluss darüber, wie viel Zeit eine Funktion und die von ihr aufgerufenen Funktionen benötigt haben. Dabei kann es durchaus vorkommen, dass eine Funktion selbst nicht viel Zeit verbraucht hat, die von ihr aufgerufenen Funktionen jedoch äußerst viel Zeit benötigten. Auf diese Weise lässt sich leicht überprüfen, an welchen Stellen die Software am langsamsten ist.

Die Spalte index gibt dabei den Index einer Funktion an, und %time gibt den prozentualen Anteil an der Gesamtlaufzeit des Programms an, der für diese Funktion verwendet wurde.

self gibt die Zeit an, die die Funktion selbst benötigte, und descendents die Zeit, die für die Funktionen verwendet wurde, die von ihr aufgerufen wurden.

Die called-Spalte zeigt dem Entwickler, wie oft die Funktion aufgerufen (und dabei von sich selbst aufgerufen [self]) wurde. Die beiden letzten Spalten geben den Funktionsnamen bzw. die Namen der von der Funktion aufgerufenen Funktionen sowie deren Index-Nummer an.

Flat Profile

Das Flat Profile gibt Ihnen die gesamte Zeit an, die ein Programm zur Ausführung einer Funktion verwendet hat. Dabei sind die Funktionen in der Reihenfolge ihres Zeitbedarfs sortiert.

Die erste Spalte gibt den prozentualen Zeitanteil an, und in Spalte Nummer zwei (Cumulative Seconds) ist die dafür (und für die von dieser Funktion aufgerufenen Funktionen) notwendige Zeit in Sekunden angegeben. Die Spalte self seconds gibt hingegen nur die Zeit an, die für die Funktion selbst verbraucht wurde, was also die von ihr aufgerufenen Funktionen ausschließt.

calls ist die Anzahl der Aufrufe einer Funktion. self ms/call steht für die Millisekunden, die für einen Aufruf der Funktion selbst gebraucht wurden, und total ms/call steht für die Millisekunden, die für einen Aufruf der Funktion sowie der von ihr aufgerufenen Funktionen gebraucht wurden. Die letzte Spalte gibt wie beim Call Graph den Funktionsnamen sowie deren Call Graph-Index an.

Ihr Kommentar

Wie hat Ihnen das <openbook> gefallen? Wir freuen uns immer über Ihre freundlichen und kritischen Rückmeldungen.