Tracing von Hardware-Interfaces in Linux Was kostet mich Tracing?

Das Tracing-Framework des Linux-Kernels bietet umfangreiche Unterstützung für gängige Hardware-Interfaces wie GPIO's, I2C, SPI und MMC. Für viele Anwendungsfälle kann auf den Einsatz eines Oszilloskops zur Aufzeichnung des Busverkehrs sogar verzichtet werden. Wie funktioniert das und was kostet dies an Performance?

Anbieter zum Thema

Wie kann das Tracing-Framework des Linux-Kernels effektiv bei Aufgabenstellungen im Zusammenhang mit Hardware-Zugriffen eingesetzt werden? Und welcher Overhead kann dadurch entstehen? So kommen Sie Schritt für Schritt zum effizienten Hardware-Tracing mit Linux.
Wie kann das Tracing-Framework des Linux-Kernels effektiv bei Aufgabenstellungen im Zusammenhang mit Hardware-Zugriffen eingesetzt werden? Und welcher Overhead kann dadurch entstehen? So kommen Sie Schritt für Schritt zum effizienten Hardware-Tracing mit Linux.
(Bild: gemeinfrei / CC0 )

In der Kernel-Konfiguration findet man im Menü Kernel hacking das Untermenü Tracers. Hierunter verbergen sich die vielfältigen Möglichkeiten, welche das Tracing-Framework bietet. Für die in diesem Artikel gezeigten Anwendungsfälle sind lediglich der grundlegende Support, dynamische Tracepoints, Function- und Function-Graph-Tracer sowie die Kernel-Probes erforderlich.

Hat man das Tracing konfiguriert und einen so erstellten Kernel geladen, benötigt man den Zugriff darauf. Dies kann auf unterschiedliche Weise erfolgen. Zum einen ist der Raw-Zugriff auf die vom Tracing-Filesystem (tracefs bzw. debugfs) angebotenen Dateien möglich. Dies ist die rudimentärste Nutzung. Dazu muss entweder das debugfs oder das tracefs gemountet sein und schon kann man dort loslegen.

SEMINAR-TIPP

Embedded-Linux Woche | 28. März - 1. April 2022

Wie entwickelt man eigentlich gute Software? Software, die tolle Features hat und keine Bugs? Treiber, die das Letzte aus der Hardware herauskitzeln? GUIs mit hoher Usability? Genau abgestimmt auf Ihren Kenntnisstand geben prämierte Referenten in Einsteiger- oder Expertenkursen Antworten auf Ihre Fragen und transformieren Sie zu echten Linux-Kennern. Diese Kurse sollten Sie nicht verpassen:

  • Linux Grundlagen
  • Embedded Linux
  • Gerätetreiber
  • Security

Egal ob Sie Anfänger, Fortgeschrittener oder Experte sind, Sie können sich je nach Level ganz einfach Ihren individuellen Kursplan zusammenstellen. Jetzt informieren und anmelden!

Auf dieser Ebene bauen Tracing-Programme wie etwa trace-cmd auf. Sie nutzen das debugfs und bieten ein etwas komfortableres Interface an, indem die typischen Anwendungsfälle per Kommandozeilenargument verfügbar sind. In diesem Artikel werden wir uns auf die Verwendung von trace-cmd beschränken.

Wie funktioniert das ftrace-Tracing-Framework?

  • Zum einen gibt es vordefinierte Tracing-Events, welche nur aktiviert werden müssen. Im deaktivierten Zustand stehen im Kernel-Code an der Stelle des potentiellen Tracing-Events Nops. Aktiviert ein User einen Tracing-Event dann werden die Nops durch den Aufruf des Tracing-Events ersetzt. Dieses Verfahren macht das Tracing-Framework so leichtgewichtig. Nur wenn der Tracing-Event wirklich genutzt wird entsteht wesentlicher Overhead durch die Aufzeichnung (Siehe dazu auch Beschreibung der Kernel-Konfiguration zu dynamischem Tracing ein- und ausschalten; (CONFIG_DYNAMIC_FTRACE).
  • Weiter existieren sogenannte Plugins. Dabei handelt es sich um implementierte Tracing-Funktionalität mit einem speziellen Zweck, z. B. der Aufzeichnung von Kernel-Funktionen oder der Erstellung eines Funktionsgraphen.
  • Besonders mächtig sind die Kernel-Probes. Dies sind zur Laufzeit in den Kernel eingefügte Tracingpunkte, welche Registerinhalte, Stack oder Speicherbereiche auslesen und interpretieren können.

Dies ist noch lange keine vollständige Auflistung aller Möglichkeiten des Tracing-Frameworks. es sind allerdings die, die in der Regel für den Entwickler am wichtigsten sind, und sie werden auch als die in den nachfolgenden Beispielen verwendeten beschrieben.

Verwendung von Tracing-Events

Tracing-Events werden in die sogenannten Event-Systeme gegliedert. Dies sind Gruppen mit zusammengehörigen Events. Beispiele sind die Scheduling-Events (sched) oder die GPIO-Events (gpio). Eine Liste mit vorhandenen Events bekommt man mit:

# trace-cmd list -e

Möchte man sehen, welche Informationen für den betreffenden Event aufgezeichnet werden, kann man dies durch Angabe des Events sowie der Option -F erfahren:

# trace-cmd list -e schedswitch -F

Für die Aufzeichnung kann entweder das ganze Event-System mit allen enthaltenen Events oder nur der einzelne Event angegeben werden. Im Beispiel werden alle Interrupt-Events sowie die Scheduling-Wakeup- und -Switch-Events aufgezeichnet:

# trace-cmd record -e irq -e schedwakeup -e schedswitch

Die Wiedergabe erfolgt mit dem Subkommando

report: trace-cmd report

Das Tracen von GPIO-Events ist nun recht einfach. Man gibt als Tracing-System lediglich gpio an und bekommt alle GPIO's, welche sich während des Tests ändern.

# trace-cmd record -e gpio

Mit ein bisschen Skripting (z. B. awk und GNUplot) kann man dies recht einfach in eine ansprechende graphische Darstellung überführen.

Tracing von I2C-Schnittstelle

Analog funktioniert es mit anderen Schnittstellen. Bei I2C gibt man dies einfach als Tracing-System an. Durch Angabe eines Programmes erfolgt die Aufzeichnung nur, während dieser Prozess läuft. Dadurch kann die umfangreiche Ausgabe auf die relevanten Teile eingeschränkt werden. Im Beispiel wird ein Chemical-Sensor aus dem IIO-Subsystem mit dem Programm cat abgefragt. Für eine genauere Untersuchung des Sendevorganges kann man den Call-Stack ausgeben und so sehen, welcher Weg durch den Kernel genommen wird. Dafür existiert die Option -T.

# trace-cmd record -e i2c -T    cat /sys/bus/iio/devices/iio:device1/in_concentration_input482.086132CPU0 data recorded at offset=0x3e3000   4096 bytes in size# trace-cmd report   cat-1034 [000] 3467.452544: i2c_write:        i2c-0 #0 a=059 f=0000 l=8 [26-0f-83-32-28-64-ca-cb]   cat-1034 [000] 3467.452570: kernel_stack: <stack trace >=> __i2c_transfer (c086ba9c)=> i2c_transfer (c086bdd0)=> i2c_transfer_buffer_flags (c086becc)=> sgp40_measure_resistance_raw (bf01e308)=> sgp40_read_raw (bf01e474)=> iio_read_channel_info (c08ea008)=> dev_attr_show (c06f95f0)=> sysfs_kf_seq_show (c03fccb8)=> kernfs_seq_show (c03fad90)=> seq_read_iter (c037130c)=> kernfs_fop_read_iter (c03fb408)=> vfs_read (c034545c)=> ksys_read (c0345a40)=> sys_read (c0345ae0)=> __ret_fast_syscall (c0100060)=> bebe8ad0

Nun wird bei jedem Tracing-Event der Call-Stack ausgegeben und es kann diejenige Funktion gefunden werden, welche das Senden bewerkstelligt. Im Beispiel ist es die Funktion sysread().

In einem weiteren Durchlauf kann gezielt diese Funktion aufgezeichnet und somit die Laufzeit vom Userspace durch den Kernel bis zum eigentlichen Versand ermittelt werden. Dies liefert einen wertvollen Hinweis, wie viel Overhead durch das Betriebssystem entsteht:

# trace-cmd record -e i2c -p function -l sys_read       cat /sys/bus/iio/devices/iio:device1/in_concentration_input   plugin 'function'482.208132CPU0 data recorded at offset=0x3e3000      4096 bytes in size# trace-cmd report cat-1054 [000] 3581.325714: function: sys_read cat-1054 [000] 3581.326124: function: sys_read cat-1054 [000] 3581.334075: function: sys_read cat-1054 [000] 3581.334133: i2c_write:    i2c-0 #0 a=059 f=0000 l=8 [26-0f-82-0b-91-65-27-b2] cat-1054 [000] 3581.334850: i2c_result: i2c-0 n=1 ret=1 cat-1054 [000] 3581.377832: i2c_read:    i2c-0 #0 a=059 f=0001 l=3 cat-1054 [000] 3581.378153: i2c_reply:    i2c-0 #0 a=059 f=0001 l=3 [73-1b-3e] cat-1054 [000] 3581.378160: i2c_result: i2c-0 n=1 ret=1 sshd-462 [000] 3581.378684: function: sys_read

Aus der Differenz der Zeitstempel zwischen dem letzten sysread vor dem i2cwrite kann der Overhead im Betriebssystem ermittelt werden. Hier im Beispiel sind es 58 µs.

Möchte man Funktionen genauer analysieren und wissen, wie lange darin und in den davon aufgerufenen Funktionen gerechnet wird, kann man den Function-Graph-Tracer nutzen. Dabei werden alle tracebaren Funktionen aufgezeichnet und die jeweiligen Zeiten mit ausgegeben.

# trace-cmd record -p function_graph -g sys_read    -o nosleep-time    -F cat /sys/bus/iio/devices/iio:device1/in_concentration_input# trace-cmd report vim -

Durch das Pipen an den Editor vim können dort die einzelnen Funktionen durchgesprungen und nach Bottlenecks gesucht werden.

Kernel-Probes

Ein besonders flexibel einsetzbares Werkzeug sind die Kernel-Probes. Diese können zur Laufzeit dem Kernel hinzugefügt werden. Es ist möglich Register, Stack oder auch Speicherbereiche am Probe aufzuzeichnen. In der Aufzeichnung des Function-Graphes weiter oben wurde erkannt, dass die eigentliche Übertragung mit der Funktion i2ctransfer() erfolgt. Wenn man sich zu dieser Funktion den Prototypen sowie die Deklaration der verwendeten Struktur zu Hilfe nimmt (alles aus den Kernel-Sourcen), kann man beispielsweise eine Probe anlegen, welche das übertragene I2C-Telegramm ausgibt.

echo 'p:xfer __i2c_transfer len=+4(      > /sys/kernel/debug/tracing/kprobe_events# trace-cmd record -e kprobes    cat /sys/bus/iio/devices/iio:device1/in_concentration_input481.597556CPU0 data recorded at offset=0x3e3000   4096 bytes in size# trace-cmd reportcpus=1   cat-899 [000] 2703.440222: xfer: (c086b5e8) len=0x8       msg=0x26,0xf,0x7f,0xff,0x8f,0x65,0x90,0x9a

Nachfolgend die Funktion sowie die ausgegebene Datenstruktur aus den Kernel-Sourcen, um die obigen Register und Offsets verifizieren zu können:

int __i2c_transfer(struct i2c_adapter *adap,       struct i2c_msg *msgs, int num)struct i2c_msg    __u16 addr; /* slave address */   __u16 flags;   __u16 len; /* msg length */   __u8 *buf; /* pointer to msg data */;

Bis hierher wurde gezeigt, wie man mit Hardware-Interface-Tracing-Events die übertragenen Daten aufzeichnen kann, mithilfe vom Function-Plugin den Overhead vermisst, mit dem Function-Graph-Tracer die Funktionshierarchie untersucht und schließlich mit Kernel-Probes detaillierte Informationen an den meisten Stellen im Kernel zur Laufzeit einfügen kann.

SEMINAR-TIPP

Diagnose von Linux | 23. - 25. Mai 2022 in Würzburg

Eine Applikation stürzt ab, der Kernel crashed oder es treten unerklärliche Latenzen auf. Wer solche oder ähnliche Situationen aus dem Projektalltag kennt und geeignete Linux-Werkzeuge für deren Lösung kennenlernen möchte, ist in diesem Seminar von Andreas Klinger genau richtig. Jetzt informieren und anmelden.

Was kostet das Tracing?

Der Overhead des Tracings selber beinhaltet zwei Aspekte:

  • 1. Bereitstellen der Tracing-Infrastruktur: Kernel wird mit Tracing-Framework erstellt, jedoch noch keine Aufzeichnung; und
  • 2. Aktivieren von Tracing-Events: Aufzeichnung findet statt.

Für beide Messungen wurde ein sehr einfaches Verfahren gewählt. Ein Kernel-Treiber toggelt einen GPIO in einer Endlosschleife so schnell wie nur irgendwie möglich. Ein extern an den GPIO angeschlossenes Oszilloskop misst die Breite des Rechtecksignals. Aus der Differenz der Breite zweier Messungen ergibt sich der Overhead.

Overhead der Tracing-Infrastruktur

Dazu wurde der Linux-Kernel auf einem AM-335x-Prozessor einmal mit und einmal ohne Tracing übersetzt. Weitergehende Tracing-Features wie Kernel-Probes, User-Probes, Syscall-Tracing, Funktion-Tracing und so weiter waren dabei konfiguriert. Eine Unterscheidung, welches dieser Tracing-Features wie viel Overhead generiert, wurde nicht vorgenommen.

Wie aus dem Vergleich der beiden Messungen in Bild 1 und Bild 2 ersichtlich ist, beträgt der zusätzliche Overhead durch das Mitkompillieren des Tracing-Frameworks ca. 86%.

Bildergalerie
Bildergalerie mit 5 Bildern

Aktivieren von Tracing-Events

Auf einem i.MX6 wurde ein GPIO im Kernel-Treiber getoggelt und anschließend unterschiedliche Tracing-Features aktiviert.

Wie man aus dem Vergleich der Messung ohne Tracing in Bild 3 mit den Bildern 4 und 5 erkennen kann, beträgt der Overhead für den Tracing-Event ca. 3 µs und derjenige für den Kernel-Probe in etwa 8 µs.

Zusammenfassung

In der vorliegenden Messreihe wurde gezeigt, wie das Tracing-Framework des Linux-Kernels effektiv bei Aufgabenstellungen im Zusammenhang mit Hardware-Zugriffen eingesetzt werden kann und wie der Overhead durch das Tracing selber mit einfachen Mitteln abgeschätzt werden kann. Dabei geht es insgesamt weniger um die absoluten Zahlen dieser Messreihe als vielmehr um die Methodik, die in der Beschreibung der Vorgehensweise und den Listings aufgezeigt wird.

(ID:47969837)