Wer vor der Aufgabe steht, auf einem nur schleppend dahinkriechenden Linux-Rechner die Ursache eines Performanceproblems aufzuspüren, zieht üblicherweise Tools wie iostat, top oder mpstat aus dem Werkzeuggürtel und sieht nach, was genau den Betrieb aufhält: Ist der Speicher knapp? Die Festplatte zu lahm? Die CPU überlastet? Das Netzwerkrohr zu dünn?
Nun zeigt ein Tool wie "top" zwar gerade laufende Prozesse an, kann aber zum Beispiel kurzlebige Störer, die starten und sich kurz darauf wieder beenden, nicht aufspüren, denn periodisches Abfragen der Prozessliste taugt nur zur Visualisierung von Langläufern. Aber zum Glück enthält der Linux-Kernel tausende von Testsonden, genannt "Kprobes" und "Tracepoints", an denen der User Code einschleusen kann, der Ereignisse protokolliert oder Statistiken erstellt. Ein brandheißes neues Tool für diesen Zweck ist bpftrace. Mit simplen Einzeilern kann es dem Kernel Skripts unterjubeln, die zum Beispiel in Echtzeit mitzählen, wieviele Bytes aufs Netzwerk oder die Festplatte rausgehen, oder welche Prozesse welche Dateien öffnen.
Die Abkürzung BPF steht für "Berkely Package Filter" und zeugt von seiner Herkunft aus der BSD-Welt als Tracing-Tool für Netzwerkpakete. Die Technologie, Sonden im Code zu verstreuen, die im Normalfall still schweigen, aber bei Aktivierung kleine Programmstücke ausführen, stellte sich als so praktisch heraus, dass sie bald als eBPF in die Linux-Welt einzog, den Bezug zu Netzwerkpaketen vollends verlor, und als generisches Tracing-Konzept weite Bereiche Kernel-Codes übernahm. Gute Namensgebung ist harte Arbeit, die Ingenieure oft scheuen, und deswegen benannte der Autor von eBPF sein nun Popularität gewinnendes Werk wieder in BPF um, und heutzutage finden sich Autoren von Tutorials in der unangenehmen Situation, erklären zu müssen, warum der Name gänzlich sinnlos geworden ist.
Der Ansatz, dynamisch aktivierbare Sonden im Kernel-Code zu verteilen, stammt aus der Sun-Welt, denn Solaris war lange Zeit das einzige Betriebssystem, das Systemadministratoren mittels "DTrace" erlaubte, an strategischen Stellen wie dem Einsprungpunkt von System-Calls kleine in der Sprache "D" verfasste Codestücke zu aktivieren und Zähler oder Zeitmessungen für die Performance-Analyse abzufeuern. BPF auf neueren Linux-Kerneln funktioniert ähnlich wie Dtrace, es wurde aber (auch aus Patentgründen) von Grund auf neu geschrieben und führt den Sonden zugewiesene, in der BPF-Sprache verfasste Instruktionen entweder in einem Interpreter oder per JIT-Compiler in nativem Code aus -- und zwar direkt im Kernel.
Dabei versteht bpftrace eine Programmiersprache, die stark an das Unix-Urgestein awk erinnert, allerdings kommt sie noch so ungeschliffen daher, dass sich Programmierer die Haare raufen, wenn sie nur einfachste Arbeiten erledigen wollen. Der Parser von bpftrace (implementiert mit den Unix-Urgesteinen lex und yacc) ist noch in einem Zustand, den man nur als "hanebüchen" bezeichnen kann und noch nicht einmal annähernd an die Funktionalität von awk heranreicht, aber vielleicht wird's ja noch. Der Netflixler Brandon Gregg strickt mit einigen Open-Source-Freunden mit heißer Nadel daran. Das neue Buch vom gleichen Autor zum Thema BPF [1], das im November 2019 erscheint, lag bei Redaktionsschluss als Preview vor.
Aber zurück zur eingangs erläuterten Aufgabe, wie schwer wäre es, im Kernel eine Sonde zu aktivieren, die jedesmal, wenn ein Userspace-Programm die Funktion open() zum Öffnen einer Datei anspringt, eine Nachricht ausgibt, sodass ein Performance-Spezialist in Echtzeit sehen kann, welche Prozesse welche Dateien öffnen? Listing 1 zeigt den einfachen Programmcode, Abbildung 1 die Ausgabe des Programms.
01 #!/usr/bin/bpftrace
02
03 interval:s:5
04 {
05 exit();
06 }
07
08 kprobe:do_sys_open
09 {
10 printf("%s %s\n", comm, str(arg1));
11 }
| |
| Abbildung 1: Listing 1 meldet in Echtzeit, welche Prozesse gerade welche Dateien zu öffnen versuchen. |
Die eigentliche Arbeit passiert ab Zeile 8 mit der Sonde kprobe:do_sys_open, die der nachfolgende Block mit Instruktionen bestückt. Der Kernel signalisiert dieser Sonde, welche Datei der Syscall open() öffnen soll. Im Block gibt die printf()-Anweisung das in der voreingestellten Variablen comm gespeicherte Kommando des auslösenden Unix-Prozesses aus, sowie das erste Argument arg1, in dem der Name der zu öffnenden Datei liegt. BPF speichert arg1 als Char-Pointer, aber printf() erwartet einen String, und die vordefinierte Funktion str() konvertiert den Pointer den Vorgaben gemäß.
Der Codeblock zum Event interval:s:5 ab Zeile 3 ist hingegen nur optionaler Firlefanz, der das Programm nach fünf Sekunden abbricht. Der Event definiert ein Intervall von fünf Sekunden, und bpftrace springt den Codeblock deswegen alle fünf Sekunden an. In ihm steht aber nur der Aufruf von exit(), der das Programm abbricht, sobald der Block zum ersten Mal angesprungen wird. Oft nutzen Tracing-Tools diese interval-Schnittstelle, um alle paar Sekunden konsolidierte Statistiken auszugeben.
Ist bpftrace installiert, genügt es, Listing 1 ausführbar zu machen und mit sudo aufzurufen. Es startet blitzschnell und zeigt laufend an, welche Prozesse im System gerade welche Datei zu öffnen versuchen. Der erstaunte User reibt sich verwundert die Augen, wenn er überlegt, was bei diesem unscheinbaren Aufruf gerade hinter den Kulissen abgelaufen ist: bpftrace hat die kprobe-Sonde do_sys_open im Kernel aktiviert, den Code mit der printf()-Anweisung in ein internes Format übersetzt und auf der Sonde installiert, so dass diese jedesmal, wenn der Kernel an der Sonde vorbeirauscht, eine Meldung ausgibt. Beendet sich bpftrace, deaktiviert es die Sonde und befreit sie wieder vom eingeschleusten Code.
Das Verfahren läuft nur auf relativ neuen Kerneln, die Macher empfehlen Version 4.9 oder besser die schon die 5er Serie. Auf Ubuntu 19.04 installiert die folgende Sequenz bpftrace:
$ sudo apt-get update
$ sudo apt-get install bpftraceWie funktioniert das Ganze im Detail? Es wäre offensichtlich verheerend für die Performance des Kernels, wenn dieser bei jeder Sonde prüfen würde, ob diese aktiv ist, um anschließend in fast 100% der Fälle ganz normal im Programm fortzuschreiten, da immer nur ganz wenige, wenn überhaupt irgendwelche Sonden von tausenden möglichen aktiv sind. Statt dessen bedient sich die BPF-Technik, ähnlich wie DTrace unter Solaris, eines Tricks und setzt im Normalfall, also bei abgeschalteter Sonde, eine 5 Byte lange No-Op-Instruktion in den Code, die der Prozessor zur Laufzeit praktisch verlustlos überspringt. Aktiviert der User die Sonde, zum Beispiel durch den Aufruf von bpftrace, ersetzt BPF im Kernel die No-Op-Instruktion mit einer Sprungadresse zum Interpreter, der den gewünschten Code ausführt. Dort verbrät die CPU beim Ablaufenlassen der BPF-Instruktionen zwar CPU-Zeit und verlangsamt damit den Kernel etwas, aber da der Prozessor im Kernel-Modus bleibt und nicht aufwändig jedes Mal ins Userland wechseln muss, kann die Sonde zügig die gewünschten Statistiken auffrischen und dann geht's weiter im Text mit dem eigentlichen Kernel-Code.
Würde der eingeschleuste Code den Kernel jedoch blockieren, wäre das Ergebnis verheerend, denn ein Hänger des gesamten Systems wäre die Folge und käme einem Absturz des Rechners gleich. Deshalb prüft BPF den Code vor dem Einschleusen auf Herz und Nieren, und fügt ihn nur ein, falls die Analyse ergibt, dass er sich zügig beenden wird. Darum bietet bpftrace auch keine For-Schleifen oder ähnliche Konstrukte an, von denen sich nicht sicher vorher sagen lässt, ob sie in absehbarer Zeit aufhören zu laufen.
Die Auswahl an Sonden im Kernel ist reichlich. Von vfs_read, der Funktion, die Bytes von der Festplatte liest und einer Sonde deren Anzahl mitgeben kann, über do_exe_cve fürs Überwachen neue erzeugter Unix-Prozess, bis trace_pagefault_reg, das beim Nachladen einer Memory-Seite auslöst, kann der User dem Kernel nach Belieben auf die Finger schauen und in Echtzeit sehen, was gerade abgeht und wo die Engpässe liegen. Abbildung 2 listet die Sonden auf, die bpftrace mit der Option -l ausgibt. Dabei unterscheidet BPF zwischen kprobe-Sonden, die wichtige Kernelfunktionen dem Namen nach verfolgen, und tracepoint-Sonden, die von den Kernelentwicklern auf etwas höherer logischer Ebene von Hand gewartet werden und deswegen resistenter gegen Kerneländerungen sind. Im Gegensatz zur Kernel-ABI Richtung Userland sind ja Kernel-interne Funktionen keineswegs garantiert stabil.
 |
|
Abbildung 2: Ausgewählte Tracepoints und Kprobes im Linux-Kernel, die C |
Oder wie wäre es mit einem Skript, das alle auf dem System neu erzeugten Prozesse in Echtzeit ausgibt, mitsamt dem Kommando und seinen Parametern? Listing 2 zeigt diesen Einzeiler, der den Tracepoint sys_enter_execve aktiviert und dessen Argumentenliste argv in der Struktur args zusammenfasst. Hier zeigt sich jedoch, dass das Angebot an Funktionen in bpftrace noch Luft nach oben hat: So existiert zum Beispiel die Funktion join(), die die Elemente einer Kommandozeile in args->argv mittels Leerzeichen aneinanderreiht und ausgibt, aber sie lässt sich nicht dazu überreden, das Ergebnis als String zurückzugeben, auf dass es der Programmierer mit printf() formatiert ausgeben könnte. Angeblich soll eine der nächsten Versionen dies verbessern. Der BEGIN-Block ab Zeile 3 dient nur der Unterhaltung des Users. Soll das Skript nach dem Start eine Meldung ausgeben oder eine Variable initialisieren, geschieht dies wie in Listing 2 gezeigt im BEGIN-Block, ganz nach dem Vorbild Awk.
01 #!/usr/bin/bpftrace
02
03 BEGIN
04 {
05 printf("New processes with arguments\n");
06 }
07
08 tracepoint:syscalls:sys_enter_execve
09 {
10 join(args->argv);
11 }
Komplizierter wird es, wenn eine Sonde, die ein Problem feststellt, nicht die gewünschten Daten ausgeben kann, weil diese woanders liegen. Um zum Beispiel ein Auge auf Prozesse zu werfen, die versuchen, Dateien zu öffnen, die es gar nicht gibt (oder auf die sie keinen Zugriff haben), zapft Listing 3 den Tracepoint sys_exit_openat an, den der Kernel anspringt, wenn der Syscall open()-zurückkehrt. Mit der if-Bedingung
args->ret < 0prüft bpftrace, ob der Return-Code kleiner Null war, also die gewünschte Datei nicht geöffnet werden konnte. Falls ja, sollte der Code an diesem Punkt den betroffenen Prozess und den Namen der Datei ausgeben. Allerdings verfügt der exit-Tracepoint nicht über den Dateinamen, der lag lediglich beim Eintritt in die open()-Funktion vor, den der Tracepoint sys_enter_openat ("enter" statt "exit") abgehandelt hat!
01 #!/usr/bin/bpftrace
02
03 tracepoint:syscalls:sys_enter_openat
04 {
05 @filename[tid] = args->filename
06 }
07
08 tracepoint:syscalls:sys_exit_openat
09 / @filename[tid] /
10 {
11 if ( args->ret < 0 ) {
12 printf("%s %s\n", comm, str(@filename[tid]));
13 };
14 delete(@filename[tid]);
15 }
Die Lösung ist in diesem Fall, die Namen aller Dateien beim Einstieg in open(), also im Tracepoint sys_enter_openat in einer Datenstruktur vom Typ "Map" zwischenzuspeichern, und zwar unter dem Schlüssel der aktuellen Kernel-Thread-ID, die in der vorbesetzten Variablen tid vorliegt. Falls das Öffnen der Datei später fehlschlägt, kann der Tracepoint sys_exit_openat in der Map nachsehen, was denn der Name der betroffenen Datei war und diesen zusammen mit dem Kommando des betroffenen Prozesses in comm dem interessierten User mitteilen. Der in Zeile 9 gesetzte Filter
/ @filename[tid] /der Sonde stellt sicher, dass der nachfolgende Code nur zur Ausführung gelangt, falls der Kernel-Thread vorher den den Dateinamen gesetzt hat. Kam der Aufruf von woanders her als dem oben definierten sys_enter_openat, ist der Map-Eintrag leer und der Filter sperrt. Nach getaner Arbeit löscht Zeile 14 mit delete den Map-Eintrag wieder. Unterbliebe dies, würde die Map ungebremst wachsen und bei längerer Laufzeit des bpftrace-Skripts irgendwann zuviel Speicherplatz verschlingen.
Um herauszufinden, welche Prozesse die meisten Daten auf die Festplatte schreiben, hängt sich Listing 4 in den Tracepoint sys_exit_write ein und legt mit dem Filter
/ args->ret > 0 /fest, dass nur erfolgreiche Schreibvorgänge erfasst werden. Das Konstrukt
@[comm] = sum(args->ret)schnappt sich die Anzahl der geschriebenen Bytes aus args->ret, weist sie der unbenannten Map @ unter dem Schlüssel des Prozessnamens zu und bestimmt mit sum(), dass neue Werte zu eventuell vorher dort liegenden hinzuaddiert werden.
1 #!/usr/bin/bpftrace
2
3 tracepoint:syscalls:sys_exit_write
4 /args->ret > 0/
5 {
6 @[comm] = sum(args->ret)
7 }
 |
| Abbildung 3: Listing 4 zählt für jeden Prozess die Anzahl der geschriebenen Bytes. |
Da bpftrace bei Programmende, in diesem Fall nachdem der User CTRL-C gedrückt hat, alle Maps mit Inhalt ausgibt, zeigt Abbildung 3 alle gerade schreibwütigen Prozesse und die Anzahl der geschriebenen Bytes. Alternativ könnte ein END-Block die Map ohne Namen mit print(@) ausgeben.
Wie sieht es mit der Länge der geschriebenen Datenblöcke aus? bpftrace könnte zwar die Bytelänge jedes Schreibvorganges protokollieren, doch das Resultat wäre aufgrund der schieren Masse der Einzeldaten unlesbar. Hinzu kommt, dass jede printf-Anweisung warten muss, bis das langsame Terminal den geschriebenen Text absorbiert hat, was in Kernelsekunden eine halbe Ewigkeit ist, und um die Verzögerung in vertretbarem Rahmen zu halten, lässt die Sonde dann öfter Mal ein Ereignis unverarbeitet passieren und druckt "Skipped xxx events" aus. Zum Glück bietet bpftrace auf Kernelebene schon statistische Verarbeitungsroutinen an, so zum Beispiel hist() in Listing 5.
1 #!/usr/bin/bpftrace
2
3 tracepoint:syscalls:sys_exit_write
4 /args->ret > 0/
5 {
6 @ = hist(args->ret)
7 }
 |
| Abbildung 4: Listing 4 zählt für jeden Prozess die Anzahl der geschriebenen Bytes. |
Es weist die hereinkommenden Blockgrößen der Schreibvorgänge Eimern von wachsender Größe zu und die speichernde Variable vom Typ Map wird am Ende des Programms als Histogramm ausgedruckt. Abbildung 4 zeigt, dass die Länge der geschriebenen Datenblöcke von einem Byte bis 256KB variiert, dass aber die häufigsten Blocklängen zwischen 8 und 16 Bytes und 128KB und 256KB liegen. Ganz links steht jeweils das Intervall von minimaler bis maximaler Größe des Eimers, in der Mitte die Zahl der Einträge im Eimer und rechts die grafische Animation des Zählers.
Histogramme eignen sich auch schön zur Darstellung von Mittelwerten und eventuellen Ausreißern bei Zeitmessungen, wie zum Beispiel bei Paketlaufzeiten im Netzwerk. Hier ermittelt bpftrace ähnlich wie in Listing 3 die Zeitdifferenz zwischen einem enter/exit-Tracepoint-Paar, in dem es beim Eintritt die aktuellen Nanosekunden mittels der Variablen nsecs zwischenspeichert, um ihn später beim Exit-Tracepoint vom aktuellen nsecs-Wert zu subtrahieren. Anhand der grafischen Darstellung lässt sich dann sofort ermitteln, ob ein versprochenes Service Level Agreement (SLA) eingehalten wurde oder nicht, und wie häufig das gesteckte Ziel eventuell nicht erreicht wurde.
Wer also einen neuen Kernel fährt und vor entwicklungsbedingten Schwachstellen des Tracers nicht zurückschreckt, hat nun ein mächtiges neues Werkzeug zur Hand, das so ziemlich alles bisher dagewesene in den Schatten stellt, um systembedingten Engpässen seiner Linux-Server auf die Schliche zu kommen.
Listings zu diesem Artikel: http://www.linux-magazin.de/static/listings/magazin/2019/11/snapshot/
"BPF Performance Tools", Brendan Gregg, Addison-Wesley, 2019, https://www.amazon.com/BPF-Performance-Tools-Brendan-Gregg/dp/0136554822
"Insider-Job", Paul Menzel, Linux-Magazin, 02/19, S.24, https://www.linux-magazin.de/ausgaben/2019/02/perf
BPFtrace Reference Guide: https://github.com/iovisor/bpftrace/blob/master/docs/reference_guide.md
BPF Cheat Sheet: http://brendangregg.com/BPF/bpftrace-cheat-sheet.html
 |
Michael Schilliarbeitet als Software-Engineer in der San Francisco Bay Area in Kalifornien. In seiner seit 1997 laufenden Kolumne forscht er jeden Monat nach praktischen Anwendungen verschiedener Programmiersprachen. Unter mschilli@perlmeister.com beantwortet er gerne Ihre Fragen. |
Hey! The above document had some coding errors, which are explained below:
Unknown directive: =desc