Linux ·Programmierung

GCC: Profiling mit instrument-functions

So wie fast jeder guter Compiler, kann man auch unter dem GCC Profiling betreiben. Eine Möglichkeit, dies zu bewerkstelligen, sind die instrument functions. Dazu werden zwei Dinge benötigt:

  • den zusätzlichen Compilerparameter -finstrument-functions
  • Funktionen, die die instrument functions bearbeiten

Hier soll mal ein Beispiel gezeigt werden. Man hat z.B. eine C-Quelltext-Datei namen foo.c mit folgendem Inhalt:

#include <stdio.h>
 
void print_hello() {
        printf("hallo\n");
}
 
int main(int argc, char **argv) {
        print_hello();
 
        return 0;
}

Das Programm, dass daraus entsteht, soll analysiert werden, d.h. wann wird welche Funktion aufgerufen. Dazu wird eine weitere C-Quelltext-Datei erstellt:

#include <stdio.h>
#include <time.h>
 
static FILE *fp_trace;
 
void
__attribute__ ((constructor))
trace_begin (void)
{
        fp_trace = fopen("traceoutput.txt", "w");
}
 
void
__attribute__ ((destructor))
trace_end (void)
{
        if (fp_trace != NULL) {
                fclose(fp_trace);
        }
}
 
void
__cyg_profile_func_enter (void *func, void *caller)
{
        if (fp_trace != NULL) {
                fprintf(fp_trace, "ENTER %p %p %lu\n", func, caller, time(NULL) );
        }
}
 
void
__cyg_profile_func_exit (void *func, void *caller)
{
        if (fp_trace != NULL) {
                fprintf(fp_trace, "EXIT %p %p %lu\n", func, caller, time(NULL) );
        }
}

Die Funktion __cyg_profile_func_enter wird dabei aufgerufen, bevor die eigentliche Funktion aufgerufen wird und die Funktion __cyg_profile_func_exit wird aufgerufen, nach dem die eigentliche Funktion beendet ist.
Soweit mir bekannt, sollten die Funktionen __cyg_profile_func_enter und __cyg_profile_func_exit nicht anders heißen.

trace_begin wird beim Start (des Programms?) aufgrufen und trace_end sobald das Programm beendet wird.

Wie man an dem Quelltext von trace.c schon sehen kann, wird jeder Funktionsaufruf in einer Textdatei protokolliert. Nun habe ich hier noch ein dazu gehörendes Makefile geschrieben:

main: foo.o trace.o
        gcc foo.o trace.o -o main
 
foo.o: foo.c
        gcc -finstrument-functions -g -c -o foo.o foo.c
 
trace.o: trace.c
        gcc -c -o trace.o trace.c
 
clean:
        rm -vf *.o
        rm -vf main
        rm -vf traceoutput.txt

Wichtig ist hierbei, dass in diesem Beispiel nur die Datei foo.c mit dem Parameter -finstrument-functions kompiliert wird, da es wahrscheinlich zu einer Endlosschleife kommt (ich vermute das ganz stark, ich hab das aber nicht ausprobiert). Nun kann man also

make

aufrufen. Sobald make fertig ist, kann man nun auch

./main

aufrufen. Die Ausgabe sollte dann in etwa so aussehen:

hallo

und man sollte eine neu erstellte Datei traceoutput.txt finden, mit einem Inhalt, der diesem hier ähnlich aussieht:

ENTER 0x5640b5b4b879 0x7fc4930ca3f1 1485894484
ENTER 0x5640b5b4b840 0x5640b5b4b8a6 1485894484
EXIT 0x5640b5b4b840 0x5640b5b4b8a6 1485894484
EXIT 0x5640b5b4b879 0x7fc4930ca3f1 1485894484

Wie man sieht, werden hier nur Funktionsaufrufe protokolliert, die man selbst geschrieben hat bzw. man wird auch nur die Funktionsaufrufe sehen, die in einer Datei geschrieben worden sind, die später auch mit -finstrument-functions kompiliert worden ist. Sobald man die Daten hat, kann man mit der Analyse beginnen. Auf diese Weise kann man eventuell entdecken, welche Funktion z.b. der Flaschenhals ist oder welche Funktion besonders lange braucht. Die protokollierte Zeit kann man auch verfeinern.

In dieser Ausgabedatei traceoutput.txt ist die Ausgabe noch recht überschaubar. Aber wenn man viele Funktionen hat, wird die Ausgabe nicht mehr so überschaubar sein. Dann muss man Wege finden, wie man aus die Adressen in die entsprechende Funktionsnamen umwandelt oder sie direkt irgendwo rausliest und reinschreibt.