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

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.
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_input
482.086132
CPU0 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.208132
CPU0 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_input
481.597556
CPU0 data recorded at offset=0x3e3000
4096 bytes in size
# trace-cmd report
cpus=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.
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%.
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.
:quality(80)/images.vogel.de/vogelonline/bdb/1731900/1731947/original.jpg)
Einführung in die Linux Tracing Infrastruktur
:quality(80)/images.vogel.de/vogelonline/bdb/1747400/1747471/original.jpg)
Tools für einfacheres und effizienteres Tracing unter Linux
:quality(80)/images.vogel.de/vogelonline/bdb/1780000/1780050/original.jpg)
Linux Tracing Infrastruktur: Tiefere Funktionen und gängige Anwendungsszenarien
(ID:47969837)