Diesen Artikel als PDF kaufen Weitere ADMIN-Magazin Angebote

Anwendungen tracen mit Oprofile und Systemtap

Ozapft is

Kommen die Anwendungsdaten mal wieder im Schneckentempo von der Festplatte oder der Netzwerkkarte angekrochen? Und das, obwohl sonst eigentlich kaum Aktivität auf dem Rechner oder dem Netzwerk herrscht? Tools wie Oprofile und Systemtap helfen dabei, dem Problem näher auf den Grund zu gehen.
Thorsten Scherf

Üblicherweise greift der versierte Admin auf Tools wie »ps« , »vmstat« oder ähnliches zurück, wenn es darum geht, Statistiken über einzelne Subsysteme wie Netzwerk, Speicher oder Block-IO einzuholen. Sie helfen ihm dabei, Engpässen auf Hardware- oder Software-Seite auf die Schliche zu kommen. Diese Tools sind für einen ersten Überblick sicher hilfreich, wer aber einen tieferen Blick hinter die Kulissen werfen möchte, der braucht weitere Werkzeuge. Auch hier gehören einige Tools zur Standardausrüstung. Zum Tracen von Anwendungen existiert beispielsweise das bekannte »strace« (siehe den Artikel in diesem Heft). Das Tool listet im einfachsten Fall alle System-Aufrufe (Syscalls) und deren Argumente mit Returncode für eine beliebige Anwendung auf. Durch eine Auswahl entsprechender Optionen ist eine sehr selektive Ausgabe von Strace möglich. Möchte der Administrator beispielsweise überprüfen, ob eine Anwendung auch die mit viel Mühe erzeugte Konfigurationsdatei einliest, so ruft er Strace wie folgt auf:

strace -e trace=open -o mutt.trace mutt

In der Ausgabedatei »/tmp/mutt.trace« landen nun alle Aufrufe des Syscalls »open« für die Anwendung »mutt« . Mittels »grep« lässt sich hier leicht nach der gewünschten Konfigurationsdatei suchen.

Einen Schritt weiter gehen Anwendungen aus der Kategorie "Profiler". Hierzu zählt beispielsweise das bekannte Tool OProfile [1]. Es gibt Auskunft über die Performance einzelner Anwendungen, den Kernel oder aber auch des kompletten Systems. Hierzu greift OProfile auf aktueller Hardware auf sogenannte Performance-Counter der eingesetzten CPU zurück. Diese enthalten Informationen darüber, wie oft ein bestimmtes Event stattgefunden hat. Als Event bezeichnet man in diesem Zusammenhang beispielsweise den Zugriff auf den Arbeitsspeicher oder die Anzahl von Interrupts. Diese Informationen sind zum Auffinden von Engpässen oder zum Debuggen des Systems recht hilfreich. Zur Installation von OProfile ist das Paket »kernel-debuginfo« [2] notwendig. Es enthält die Zuordnung so genannter Symbole auf den passenden Maschinencode. Wichtig dabei ist, dass die Version des Paketes »kernel-debuginfo« identisch mit der Version des eingesetzen Kernels ist.Sie installieren es ganz einfach aus dem Standard-Repository der eingesetzten Distribution, unter Fedora beispielsweise mit Yum:

yum install oprofile kernel-debuginfo

Der Aufruf von RPM sollte dann bestätigen, dass kernel und kernel-debuginfo die gleiche Versionsnummer besitzen:

rpm -q kernel-PAE kernel-PAE-debuginfo ↩
oprofile
kernel-PAE-2.6.32.10-90.fc12.i686
kernel-PAE-debuginfo-2.6.32.10-90.fc12.i686
oprofile-0.9.5-4.fc12.i686

Zum Profilen des Kernels müssen Sie OProfile den Ort des Kernel-Images mit der Option »--vmlinux« mitteilen:

opcontrol --setup --vmlinux=/usr/lib/↩
debug/lib/modules/`uname -r`/vmlinux

Bei regulären Anwendungen können Sie die Image-Angabe weglassen. Eine Übersicht der mit Oprofile zählbaren Events liefert der Befehl »opcontrol --list-events« (Listing 1).

Listing 1

Opcontrol-Events

opcontrol --list-events
oprofile: available events for CPU type "Core 2"
See Intel Architecture Developer's Manual Volume 3B, Appendix A and
Intel Architecture Optimization Reference Manual (730795-001)
INST_RETIRED_ANY_P: (counter: all))
        number of instructions retired (min count: 6000)
L2_RQSTS: (counter: all))
        number of L2 cache requests (min count: 500)
        Unit masks (default 0x7f)
        ----------
        0xc0: core: all cores
        0x40: core: this core
        0x30: prefetch: all inclusive
        0x10: prefetch: Hardware prefetch only
        0x00: prefetch: exclude hardware prefetch
        0x08: (M)ESI: Modified
        0x04: M(E)SI: Exclusive
        0x02: ME(S)I: Shared
        0x01: MES(I): Invalid
LLC_MISSES: (counter: all))
        L2 cache demand requests from this core that missed the L2 (min count:6000)
        Unit masks (default 0x41)
        ----------
        0x41: No unit mask
[...]

Je nachdem welche CPU zum Einsatz kommt, unterscheiden sich die Events. Im Verzeichnis »/usr/share/oprofile« existieren für die unterschiedlichen Architekturen entsprechende Listen. Ein Event setzt sich aus einem symbolischen Namen (»L2_RQSTS« ), einem Counter (500) und einer optionalen Maske (»0xc0« ) zusammen. Der Counter bestimmt die Genauigkeit eines Profiles. Je niedriger der Wert ist, desto öfter wird ein Event abgefragt. Mit Hilfe der Maske lassen sich spezielle Eigenschaften eines solchen Events abfragen. Das Event »L2_RQSTS« gibt beispielsweise Auskunft darüber, wie oft der L2-Cache der CPU abgefragt wurde. Mit der Maske »0xc0« aufgerufen liefert Oprofile den Wert für alle verfügbaren CPUs, mittels »0x40« nur für die CPU, die gerade den OProfile-Prozess ausführt.

Möchten Sie nun ein bestimmtes Event überwachen, verwenden Sie dafür den folgenden Aufruf:

Listing 2

Opcontrol-Events

opcontrol --vmlinux=/usr/lib/debug/lib/modules/`uname -r`/vmlinux --event L2_RQSTS:500
# opcontrol --reset
# opcontrol --start
Using 2.6+ OProfile kernel interface.
Reading module info.
Using log file /var/lib/oprofile/samples/oprofiled.log
Daemon started.
Profiler running.

Die Option »--event« kann hierbei durchaus mehrfach vorkommen, um mehr als ein Event zu überwachen. Um sicherzustellen, dass keine alten Daten das Ergebnis verfälschen, löscht die Option »--reset« sie bevor es mittels »--start« neue Daten sammelt. Nach einer Weile beendet die Option »--stop« das Monitoring des Systems. Die so eingesammelten Daten stehen nun im Verzeichnis »/var/lib/oprofile/samples« zur Verfügung. Um einen allgemeinen Überblick zu erhalten, rufen sie diese nun mittels »opreport« auf, entweder als gesammelte Daten für das komplette System, oder aber für eine bestimmte Anwendung:

Listing 3

Opreport für Mutt

opreport -l /usr/bin/mutt
CPU: Core 2, speed 2401 MHz (estimated)
Counted L2_RQSTS events (number of L2 cache requests) with a unit mask of 0x7f
(multiple flags) count 500
samples  %        image name               symbol name
414      10.8377  mutt                     imap_exec_msgset
162       4.2408  mutt                     parse_set
161       4.2147  mutt                     mutt_buffer_add
145       3.7958  mutt                     mutt_extract_token
126       3.2984  mutt                     ascii_strncasecmp
124       3.2461  mutt                     imap_read_headers
[...]

Je nach ausgewähltem Event ergibt sich anhand dieser Informationen ein ziemlich klares Bild davon, was so alles auf dem System los ist. Weitere Informationen zu OProfile finden sich auf der recht informativen Webseite der Tools [1].

Abbildung 1: Die OProfile-Architektur.

Systemtap

Das Tool Systemtap [3] hat den Anspruch, Funktionen der klassichen Tracing- und Profiling-Tools wie Strace und OProfile, zu vereinen und dabei eine gleichzeitig einfache und leistungsfähige Schnittstelle für den Benutzer anzubieten. Ursprünglich wurde Systemtap zum Monitoring des Linux-Kernels entwickelt, neuere Versionen unterstützen allerdings auch Userspace-Applikaktionen.

Systemtap setzt auf dem Kernel-Subsystem »kprobes« auf. Es ermöglicht dem Anwender, für sämtliche Events im Kernel-Space, beispielsweise einer Kernel-Funktion (»kernel.function("function")« ), einer Funktion innerhalb eines Kernel-Moduls (»module("module").function("function")« ) oder eines System-Aufrufs (»syscall.system_call« ) beliebigen Programmcode voranzustellen. Das so eingeschleuste Programm überwacht das Event und sammelt dazu Informationen. Anders als bei OProfile, das ein Event ja immer nur periodisch abfragt, ist hiermit ein wesentlich genaueres Ergebnis erzielbar.

Seit einiger Zeit unterstützt Systemtap auch die Abfrage so genannter statischer Tracepoints im Kernel (»kernel.trace("tracepoint")« ), und neuerdings auch von Userspace-Applikationen. Diese statischen Tracepoints sind von den jeweiligen Entwicklern an wichtigen Stellen im Programmcode hinterlegt. Da man wohl davon ausgehen kann, dass Entwickler ihre Programme am besten kennen, stellen diese Art von Informationen eine große Hilfe dar.

Systemtap-Programme sind in einer Awk-ähnlichen Sprache geschrieben. Ein Parser überprüft das Skript auf syntaktische Fehler bevor es in die performantere Sprache C übersetzt wird, um anschließend als Modul in den Kernel geladen zu werden (Abbildung 2). Soll das Modul auf anderen Systemen, auf denen beispielsweise kein Compiler zur Verfügung steht, zum Einsatz kommen, so ist dies auch kein Problem. Systemtap erlaubt es, Modulen auch für andere Kernel-Versionen zu übersetzen als die die auf dem aktuellen System laufende. Das so erzeugte Modul müssen Sie dann nur auf das Ziel-System kopieren und dort mittels »staprun« ausführen, dazu aber später mehr.

Abbildung 2: Nach einer syntaktischen Prüfung des Systemtap-Skiptes wird dieses in C übersetzt und dann als Modul in den Kernel geladen.

Da alle großen Linux-Distributionen Systemtap unterstützen, lässt es sich leicht über das Standard-Software-Repository installieren. Wichtig ist, as Paket »kernel-debuginfo« und diesmal auch »kernel-devel« zu installieren:

yum install kernel-debuginfo kernel-devel↩
 systemtap sytemtap-runtime

Die jeweils aktuellste Version findet sich im Git-Repository des Projekts:

git clone http://sources.redhat.com/git/↩
systemtap.git systemtap

Hat die Installation geklappt, so können Sie mit folgendem Einzeiler die korrekte Funktionsweise von Systemtap überprüfen:

stap -v -e 'probe vfs.read {printf("Daten↩
 von der Festplatte eingelesen.\n"); exit()}'

Findet nun ein Zugriff auf das VFS-Subsystem des Kernels statt, so gibt »stap« eine Nachricht auf der Standardausgabe aus und beendet sich dann selbst. Das bekannte "Hello World" sieht in Systemtap aus wie in Listing 4.

Listing 4

"Hello world" in Systemtap

#!/usr/bin/stap
probe begin {printf("Hello, world!\n");}
probe timer.sec(5) {exit();}
probe end {printf("Good-bye, world!\n");}
# stap helloword.stp
Hello, world!
<5 Sekunden später>
Good-bye, world!

Dieses simple Beispiel zeigt sehr schön den allgemeinen Aufbau eines Systemtap-Skriptes. Es besteht immer aus zwei Teilen, einem Event und einem Handler – vor beiden steht üblicherweise die Anweisung »probe« . Im oben genannten Beispiel ist das Event die Funktion »read.vfs« und der der Handler die »printf« -Anweisung, die Textausgabe auf Stdout ausgibt. Der Handler gelangt immer dann zur Ausführung, wenn das angegebene Event eintritt. Events können Kernel-Funktionen, System-Aufrufe (Syscalls) oder auch, wie im obigen Beispiel, vorgefertige Tapsets sein. Hierbei handelt es sich um vorgefertigte Code-Blöcke für bestimmte Kernel-Funktionen und System-Aufrufe.

Tapsets lassen sich prima in eigene Skripte einbauen. Diese Templates liegen üblicherweise unterhalb von »/usr/share/systemtap/tapsets« . Neben diesen, als synchron bekannten Events, existieren auch sogenannte asynchrone Events. Sie sind nicht an ein bestimmtes Ereignis im Kernel- oder Programm-Code gebunden und kommen meistens dann zum Einsatz, wenn man einen Header oder Footer für sein Skript bauen möchte. Sie sind auch geeignet, um gewisse Ereignisse wiederholt ausführen zu lassen.

Listing 5 zeigt ein einfaches Beispiel mit zwei Probes, jeweils mit einem asynchronen und einem synchronen Event. Ersteres gibt im 1-Sekunden-Intervall einen Header aus, zweiteres ruft das vorgefertigte Tapset »tcp.reveive« auf. Die Definition hierfür ist in Listing 6 zu sehen. Das Beispiel verdeutlicht, dass der Einsatz von Tapsets die Komplexität der eigenen Skripte deutlich verringert. Starten Sie das Skript aus Listing 1 nun mit »stap tcpdump.stp« , sehen Sie im 1-Sekunden-Intervall eintreffende Netzwerkpakete mit einer Reihe weiterer Informationen. Lassen Sie die Angabe von »timer.s(1)« im ersten Event weg, so erscheint der Header lediglich einmal vor der Ausgabe des ersten Netzwerkpaketes.

Listing 5

tcpdump via Systemtap

#!/usr/bin/stap
// A TCP dump like example
probe begin, timer.s(1) {
  printf("-----------------------------------------------------------------\n")
  printf("       Source IP         Dest IP  SPort  DPort  U  A  P  R  S  F
\n")
  printf("-----------------------------------------------------------------\n")
}
probe tcp.receive {
  printf(" %15s %15s  %5d  %5d  %d  %d  %d  %d  %d  %d\n",
         saddr, daddr, sport, dport, urg, ack, psh, rst, syn, fin)
}

Listing 6

Tapset tcp.stp

probe tcp.receive = kernel.function("tcp_v4_rcv") {
        iphdr = __get_skb_iphdr($skb)
        saddr = ip_ntop(__ip_skb_saddr(iphdr))
        daddr = ip_ntop(__ip_skb_daddr(iphdr))
        protocol = __ip_skb_proto(iphdr)
        tcphdr = __get_skb_tcphdr($skb)
        dport = __tcp_skb_dport(tcphdr)
        sport = __tcp_skb_sport(tcphdr)
        urg = __tcp_skb_urg(tcphdr)
        ack = __tcp_skb_ack(tcphdr)
        psh = __tcp_skb_psh(tcphdr)
        rst = __tcp_skb_rst(tcphdr)
        syn = __tcp_skb_syn(tcphdr)
        fin = __tcp_skb_fin(tcphdr)
}

Der Handler, auch als Body bezeichnet, unterstützt Anweisungen, wie sie aus vielen Programmiersprachen bekannt sind. So ist es beispielsweise möglich, Variablen und Arrays zu initialisieren, Funktionen aufzurufen oder Positionsparameter mittels »$« (Integer) oder »@« (String) abzufragen, Natürlich fehlen auch Scheifen (While, Until, For, If/Else) nicht. Hiermit lässt sich dann auch die Ausgabe eines Skriptes sehr genau steuern. Statt wie bei Strace in einem Wust von Daten nach den gewünschten Informationen zu suchen, sorgt man in Systemtap beispielsweise dafür, dass Informationen erst dann ausgegeben werden, wenn ein gewisser Schwellwert überschritten oder ein bestimmtes Ereigniss (Event) eingetreten ist. Filtermöglichkeiten existieren dank der umfangreichen Sprachkonstrukte zu Genüge.

Listing 7 zeigt ein weiteres Beispiel mit dem schon bekannten Tapset »vfs.read« . Bei der globalen Variable »total« handelt es sich in diesem Fall um ein assoziates Array. Es enthält den Prozessnamen und die Prozess-ID sämtlicher Anwendungen, die auf das VFS-Subsystem zugreifen, um Daten von der Festplatte einzulesen. Für jeden Zugriff erhöht sich der Counter um eins.

Listing 7

I/O-intensive Anwendungen finden

#!/usr/bin/stap
global totals;
probe vfs.read
{
    totals[execname(), pid()]++
}
probe end
{
    printf("** Summary ** \n")
    foreach ([name,pid] in totals-)
    printf("%s (%d): %d \n", name, pid, totals[name,pid])
}

Ist ein bestimmtes Userspace-Programm von Interesse, müssen Sie als erstes das entsprechende Debuginfo-Paket hierfür installieren. Der Einfachheit halber kommt im Beispiel das Tool »ls« zum Einsatz. Zum Tracen benötigt ist hierfür das Paket »coreutils-debuginfo« nötig. Einen Überblick aller Funktionen eines bestimmten Prozesses liefert »stap« mit dem Aufruf aus Listing 8.

Listing 8

Systemtap beim Tracen einer Userspace-Anwendung

stap -e 'probe process("ls").function("*").call {log (pp())}' -c 'ls -l'
total 20
-rw-rw-r--. 1 tscherf tscherf 17347 2010-04-12 08:43 systemtap.txt
process("/bin/ls").function("main@/usr/src/debug/coreutils-7.6/src/ls.c:1225").call
process("/bin/ls").function("set_program_name@/usr/src/debug/coreutils-7.6/lib/progname.c:35").call
process("/bin/ls").function("human_options@/usr/src/debug/coreutils-7.6/lib/human.c:462").call
process("/bin/ls").function("clone_quoting_options@/usr/src/debug/coreutils-7.6/lib/quotearg.c:99").call
process("/bin/ls").function("xmemdup@/usr/src/debug/coreutils-7.6/lib/xmalloc.c:107").call
process("/bin/ls").function("xmalloc@/usr/src/debug/coreutils-7.6/lib/xmalloc.c:43").call
process("/bin/ls").function("get_quoting_style@/usr/src/debug/coreutils-7.6/lib/quotearg.c:110").call
process("/bin/ls").function("clone_quoting_options@/usr/src/debug/coreutils-7.6/lib/quotearg.c:99").call
process("/bin/ls").function("free_pending_ent@/usr/src/debug/coreutils-7.6/src/ls.c:1132").call
[...]
process("/bin/ls").function("close_stdout@/usr/src/debug/coreutils-7.6/lib/closeout.c:107").call
process("/bin/ls").function("close_stream@/usr/src/debug/coreutils-7.6/lib/close-stream.c:57").call
process("/bin/ls").function("close_stream@/usr/src/debug/coreutils-7.6/lib/close-stream.c:57").call

Sind auch die Parameter einer bestimmten Funktionen interessant, ändern Sie den Aufruf von »stap« wie in Listing 9 ab.

Listing 9

Parameter-Tracing

stap -e 'probe process("ls").function("clone_quoting_options").call {log (probefunc() . " " . $$parms) }' -c '/bin/ls -l'
total 20
-rw-rw-r--. 1 tscherf tscherf 18216 2010-04-12 09:02 systemtap.txt
clone_quoting_options o=0x0
clone_quoting_options o=0x0

Cross Compiling

Wer das fertige Systemtap-Skript auf mehreren Systemen einsetzen möchte, will wahrscheinlich nicht auf allen den Compiler und die Debug-Informationen für den Kernel installieren. Das ist aber auch nur auf einem Build-System notwendig. Auf dem Zielsystem ist nur das RPM »systemtap-runtime« mit dem darin enthalten Programm »staprun« erforderlich. Der folgenden Befehl erzeugt ein fertig kompiliertes Kernel-Modul für das Ziel-System:

stap -r kernel-PAE-2.6.31.12-174.2.22 ↩
capt-io.stp -m read-io

Auf dem Build-System ist dazu auch das Paket »kernel-debuginfo« in der Version des Zielsystems zu installieren. Auch ist darauf zu achten, dass Build- und Targetsystem die gleiche Hardware-Architektur besitzen. Das so erzeugte Kernel-Modul kopieren Sie dann auf das Zielsystem und rufen es mit »staprun« auf:

staprun capt-io.ko

Sollen auch Nicht-Root-Benutzer die Berechtigung erhalten, dieses Kernel-Modul zu laden, müssen sie Teil der Gruppe »stapusr« sein. Mitglieder der Gruppe »stapdev« dürfen zudem eigene Skripte kompilieren.

Diesen Artikel als PDF kaufen

Als digitalen Artikel

Diesen Artikel als PDF kaufen.

Preis € 1,99



Im ADMIN Online-Archiv

Abonnieren Sie das ADMIN Online-Archiv, und Sie erhalten Zugriff auf alle ADMIN-Artikel im HTML- und/oder PDF-Format.

Kommentare

Suche

ADMIN auf Twitter, Facebook, Xing

Auf Twitter folgen   

Unsere Partner:

hackerboard.deUnixboard