Wenn jede Mikrosekunde zählt Echtzeit-Linux: Schnellkurs zum „Latency-Fighter"

Von Carsten Emde, OSADL *

Will man ein echtes, hartes Echtzeit-System mit Linux aufsetzen, hat jede noch so geringe Latenz kritische Konsequenzen. Spezielle „Latency-Fighter" unter den Linux-Entwicklern sind in der Lage, die gewünschte Echtzeit unter Linux sicherzustellen und unerwünschte Latenzen zu orten.

Anbieter zum Thema

Unerwartete Latenzen in Embedded-Systemen können dramatische Konsequenzen haben. Speziell ausgebildete Fachkräfte, die solche Latenzen aufspüren können - sogenannte „Latency-Fighter“ - sind enorm gefragt.
Unerwartete Latenzen in Embedded-Systemen können dramatische Konsequenzen haben. Speziell ausgebildete Fachkräfte, die solche Latenzen aufspüren können - sogenannte „Latency-Fighter“ - sind enorm gefragt.
(Bild: Clipdealer)

Genau wie eine Kette nur so stark ist wie ihr schwächstes Glied, ist ein Echtzeitsystem nur so reaktiv, wie dessen langsamste Komponente reagiert. Während man allerdings die Festigkeit einer Kette jederzeit statisch messen kann, stellt die Messung der Echtzeitfähigkeit eines Systems aus zwei Gründen eine große Herausforderung dar:

1. Echtzeitfähigkeit kann man niemals beweisen; man kann höchstens feststellen, dass ein System nicht echtzeitfähig ist.
2. Wenn ein System nicht echtzeitfähig ist, kann es extrem schwer sein, die Ursache zu finden, z.B. weil das Ereignis, das eine abnormal lange Latenz erzeugt und dadurch die Echtzeitfähigkeit vereitelt, extrem selten auftritt.

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!

Für dieses Problem werden speziell als „Latency-Fighter“ ausgebildete Fachleute benötigt. Diese verfügen über das nötige Fachwissen und die erforderlichen Hilfsmittel, um die Ursache für eine unerwartete Latenz aufzuspüren und diese zu beheben.

Die folgenden Ausführungen zu den Vorgängen bei Aufruf und Ablauf eines echtzeitfähigen Programms sind relativ unabhängig vom im Einzelfall gewählten Betriebssystem, wenn dieses über einen Prioritäts-gesteuerten Scheduler verfügt. Die einzelnen erwähnten Messmethoden sowie die angegebenen Hilfsprogramme und Kernel-Erweiterungen beziehen sich allerdings speziell auf den Linuxkernel, nachdem dieser mit dem sogenannten PREEMPT_RT-Patch in einen Echtzeitkernel umgewandelt wurde.

Bildergalerie
Bildergalerie mit 6 Bildern

Was passiert, wenn ein Echtzeit-Task lauffähig wird?

Wenn ein Echtzeit-Task (dies ist der Task in einem System, der während des gesamten Ablaufs die höchste Priorität aller lauffähigen Tasks pro Prozessorkern aufweist) lauffähig wird, wird der Echtzeit-Task in die Struktur der lauffähigen Task aufgenommen, der aktuell laufende Task so schnell wie möglich angehalten und der Prozessor in einem Kontext-Wechsel so umprogrammiert, dass von nun an der Userspace-Code des Echt-zeit-Tasks ausgeführt wird.

Bild 1: Nacheinander geschaltete Phasen, die im Kernel ablaufen, wenn ein Task von einem abgelaufenen Timer aufgeweckt und lauffähig wird
Bild 1: Nacheinander geschaltete Phasen, die im Kernel ablaufen, wenn ein Task von einem abgelaufenen Timer aufgeweckt und lauffähig wird
(Bild: OSADL)

Wenn die Ursache dafür, dass der Echtzeit-Task lauffähig wird, darin begründet ist, dass ein von diesem Prozess mit Hilfe eines Timers initialisierter Wartevorgang abgelaufen ist, steht zu Anfang die Ausführung der Interrupt-Service-Routine des Timers. Der in Bild 1 gezeigte schematische zeitliche Ablauf des Taskwechsels ist bereits mit den Namen der Protokollfunktionen der Kernelerweiterung zum „Latency-Fighting“ versehen, auf die in einem späteren Absatz eingegangen wird.

Woran kann es theoretisch liegen, wenn ein Echtzeit-Task nicht rechtzeitig lauffähig wird?

Wenn im Augenblick, in dem die Interrupt-Service-Routine des Timers zur Ausführung gelangen muss, ein anderer Prozess, der zu diesem Zeitpunkt nicht notwendigerweise über Echtzeit-Eigenschaften verfügen muss, im Kernel ausgeführt wird und – z.B. durch eine Fehlprogrammierung – unnötig lange die Ausführung von Interrupts oder das Neu-starten von Prozessen blockiert, kommt es zu einer Verzögerung des Ablaufs im Task-wechsel und in der Folge zu einer Latenz. Es kann sich aber auch um eine Fehlkonfiguration des Systems handeln, so dass ein anderer Prozess irrtümlicherweise eine höhere Priorität aufweist als der vermeintliche Echtzeit-Prozess.

Nicht zuletzt kann aber auch die Hardware oder Firmware des Prozessors bestimmte Instruktionen verzögern, was ebenfalls zu einer Latenz führt. Daher ist es unbedingt erforderlich, vor Freigabe eines Systems zur Verwendung als Echtzeitsystem geeignete Messungen durchzuführen.

Wie bestimmt man praktisch die maximale Latenz eines Echtzeitsystems?

Das bereits genannte Dilemma bei der Bestimmung der maximalen Latenz eines Echtzeitsystems besteht darin, dass man nicht sämtliche unter irgendwelchen Umständen möglichen Zustände eines Systems definiert erzeugen und deren Auswirkungen auf die Latenz messen kann. Also muss man Latenzmessungen über möglichst lange Zeiträume durchführen und dabei möglichst viele Funktionen gleichzeitig asynchron ablaufen las-sen – in der Hoffnung, dass der Zustand mit der höchsten Latenz dabei mindestens einmal auftritt und zu diesem Zeitpunkt von der Messung erfasst wird.

Bei der üblichen Latenzmessung mit dem Programm cyclictest wird zunächst ein Master-Prozess ohne Echtzeiteigenschaften gestartet, von dem eine definierte Anzahl an Threads aufgerufen wird. Dabei entspricht die Anzahl der Threads in der Regel der Anzahl an Kernen des verwendeten Prozessors (siehe Bild 2).

Bild 2: Schematische Darstellung der Komponenten des Programms cyclictest zur Latenzmessung
Bild 2: Schematische Darstellung der Komponenten des Programms cyclictest zur Latenzmessung
(Bild: OSADL)

Diese Threads, die vom Master-Prozess mit Echtzeiteigenschaften ausgestattet werden, initialisieren zyklisch in einem vorgegebenen Intervall (z.B. 200 µs) einen Stoppuhr-Timer, speichern die aktuelle Uhrzeit und warten darauf, dass der Timer abläuft und den Thread aus dem Wartezustand wieder aufweckt. Wenn letzteres geschieht, wird erneut die aktuelle Uhr-zeit erfasst, mit der erwarteten Aufwachzeit verglichen und an den Master-Prozess zur Auswertung übertragen.

Im Idealfall würde die Differenz zwischen der gespeicherten Startzeit und der aktuellen Uhrzeit genau der Dauer des Timer-Intervalls entsprechen. Praktisch tritt aber der Aufwachvorgang immer etwas später ein, und genau diese Verspätung geht als einzelner Messwert in die Latenzmessung ein. Eine komplette Latenzmessung beinhaltet notwendigerweise – wie bereits angesprochen – eine große Anzahl einzelner Messungen. In der OSADL QA-Farm finden Latenzmessungen z.B. zweimal täglich mit 100 Millionen Einzelmessungen statt, die bei 200 µs Zyklusintervall insgesamt 5 Stunden und 33 Minuten dauern.

Bild 3: Beispiel eines sogenannten Latenzplots mit Latenzklassen in linearer x-Achse und Häufigkeiten der Messwerte pro Klasse in logarithmischer y-Achse.
Bild 3: Beispiel eines sogenannten Latenzplots mit Latenzklassen in linearer x-Achse und Häufigkeiten der Messwerte pro Klasse in logarithmischer y-Achse.
(Bild: OSADL)

Das Ergebnis einer solchen Latenzmessung wird entsprechend einer allgemeinen Übereinkunft in einem halblogarithmischen Histogramm dargestellt – mit den Latenzklassen in einer Granularität von einer Mikrosekunde in der linearen x-Achse und den Häufigkeiten der Messwerte pro Mikrosekundenklasse in der logarithmischen y-Achse (siehe Bild 3). Dies ermöglicht, dass trotz einem hohen Endwert der y-Achse Klassen mit sehr wenigen Werten sichtbar gemacht werden können.

In der genannten Abbildung ist ersichtlich, dass das Messergebnis 108 µs beträgt und dass nur ein einziger Messwert für dieses Ergebnis verantwortlich ist. Es hätte durchaus sein können, dass dieser eine Messwert verpasst worden wäre oder dass eine längere Latenz von z.B. 200 µs nur alle 10 Milliarden Messwerte auftauchen könnte und daher in dieser Messung nur mit einer Wahrscheinlichkeit von 1:100 erfasst worden wäre. Entsprechend lautet die Empfehlung, dass man derartige Latenzmessungen bevorzugt über mehrere Monate oder sogar Jahre ausführen muss, um einen gewissen stochastischen Hinweis darauf zu erhalten, dass der Prüfling ein deterministisches Antwortverhalten aufweist – aber exakt messen kann man es nicht.

Bild 4: Zusammenhang zwischen Latenzmessung und Erfassung einer Latenz.
Bild 4: Zusammenhang zwischen Latenzmessung und Erfassung einer Latenz.
(Bild: OSADL)

Bei der Messung der Latenz mit Hilfe des Programms cyclictest muss außerdem berücksichtigt werden, dass die Wartezeit der Threads immer deutlich kürzer sein muss als das Messintervall, da bereits die systembedingte „normale“ Latenz großen Schwankungen unterliegt. Dadurch besteht zwischen den Wartephasen der Threads eine relative lange Zeitperiode, in der das System die Bedingungen einer Latenz erzeugen könnte, die resultierende Latenz aber nicht erfasst würde. Diese Latenzen werden „Potential latency“ genannt, während die tatsächlich teilweise oder komplett durch die Messung erfassten Latenzen „Effective latency“ genannt werden (siehe Bild 4).

Die genannten Einschränkungen sowohl der Einzelmessung als auch einer über mehrere Stunden gehenden Gesamtmessung haben – wie bereits erwähnt – zur Empfehlung geführt, wiederholte Messungen möglichst über mehrere Monate oder sogar Jahre durchzuführen. Der Prüfling sollte dabei möglichst vielfältigen Lastszenarien ausgesetzt werden.

Bild 5: Pseudo-3D-Projektion von über 450 einzelnen Latenzplots.
Bild 5: Pseudo-3D-Projektion von über 450 einzelnen Latenzplots.
(Bild: OSADL)

Als Übersichtsdarstellung empfiehlt sich hierbei, die einzelnen Latenzplots in Pseudo-3D-Projektion darzustellen und die logarithmische Darstellung der y-Achse beizubehalten, so dass sogar einzelne Ausreißer aus mehreren Milliarden Messungen quantitativ dargestellt werden können (siehe Bild 5). Der Kurvenverlauf der einzelnen Latenzplots ist erkennbar und ähnelt stark dem Einzelplot in Abbildung 3. Im Vergleich zum Messergebnis in Bild 3 beträgt hier die höchste Latenz nun aber 126 µs bei Messung Nr. 176.

Bildergalerie
Bildergalerie mit 6 Bildern

Wie findet man im Einzelfall die Ursache heraus, wenn ein Echtzeit-Task nicht rechtzeitig lauffähig wird?

Ein durchaus relevanter Nachteil der Messungen mit cyclictest und der graphischen Auswertung der Messwerte als Histogramm besteht darin, dass die Zeitinformation, d.h. der Zeitpunkt, an dem eine bestimmte Latenz aufgetreten ist, verlorengeht. Man weiß nur, dass das System diese Latenz aufweist. Man kann die Latenz aber nicht beheben, weil man dafür wissen müsste, welcher Prozess zu diesem Zeitpunkt das System fälschlicherweise monopolisiert hat, so dass der Timer des betroffenen cyclictest-Threads diesen verzögert aufgeweckt hat. Um die fehlende Information zu erhalten, muss der Betriebssystemkernel mit zusätzlichen Protokollfunktionen nachgerüstet werden. Diese müssen bei Auftreten der bis dahin längsten Latenz das zuletzt aktive Programm („Täter“) und das aufgerufene RT-Programm („Opfer“) mit allen wesentlichen Parametern des Schedulers protokollieren und für spätere Analysen über eine Kernelschnittstelle verfügbar machen. Im Falle des Linuxkernels ist eine solche Protokollfunktion Bestand-teil der sogenannten OSADL Linux Add-on Patches, namens latency-histograms.patch. Wenn dieser Patch eingespielt ist und die entsprechenden Kernel-Konfigurationen

CONFIG_MISSED_TIMER_OFFSETS_HIST=yCONFIG_WAKEUP_LATENCY_HIST=yCONFIG_SWITCHTIME_HIST=y

in der Sektion Kernel hacking/Tracers im Konfigurationsmenü

[*] Missed Timer Offsets Histogram[*]  Scheduling Latency Tracer[*]    Scheduling Latency Histogram [*]      Context Switch Time Histogram

aktiviert wurden, können die jeweiligen Protokollfunktionen über das virtuelle Dateisystem /sys/kernel/debug im Verzeichnis latency_hist/enable eingeschaltet werden. Die fünf verfügbaren Protokollbereiche beziehen sich auf die einzelnen Kernelbereiche und deren Aufsummierung, die während eines Aufwachvorgangs eines Echtzeit-Tasks durchlaufen werden:

missed_timer_offsetsswitchtimetimerandwakeuptimerwakeupswitchwakeup

Die Zuordnung dieser Variablen zu den Kernelphasen des Taskwechsels ist bereits in Bild 1 aufgeführt. Eingeschaltet wird die Messung durch Hineinschreiben eines Wertes ungleich 0, z.B. kann die folgende Shell-Sequenz ausgeführt werden, um alle fünf Histogramme einzuschalten:

for i in wakeup missed_timer_offsets timerandwakeup switchtime \  timerwakeupswitchdo  enable=/sys/kernel/debug/latency_hist/enable/$i  if test -f $enable  then    echo 1 >$enable  fidone

In den jeweiligen Verzeichnissen findet sich für jeden Prozessorkern eine Datei mit dem Namen CPU<n> und eine Datei mit dem Namen max_latency-CPU<n>, wobei wobei <n> für die Nummer des Prozessorkerns steht.

Die Datei CPU<n> enthält ein internes Latenz-Histogramm, während die Datei max_latency-CPU<n> die für das „Latency-Fighting“ besonders wichtigen Informationen über den Schedulingvorgang mit der höchsten Latenz seit dem letzten Reset bereithält. Entsprechend gibt es in jedem Verzeichnis auch eine Datei mit dem Namen reset. Wenn in diese Datei der Wert von 1 hineingeschrieben wird, werden alle Histogramm-Zähler und alle für die Datei max_latency-CPU<n> gespeicherten Werte zurückgesetzt:

for i in wakeup missed_timer_offsets timerandwakeup switchtime \  timerwakeupswitchdo  reset=/sys/kernel/debug/latency_hist/$i/reset  if test -f $reset  then    echo 1 >$reset  fidone

Die Datei max_latency-CPU<n> enthält die Daten im Histogramm timerwakupswitch in folgendem Format:

Erster Teil („Opfer“)

PID Priorität Gesamtlatenz (Timer-Latenz, Wakeup-Latenz) Name <-

Zweiter Teil („Täter“)

PID Priorität Name Timestamp

Ein solcher Reset sollte in regelmäßigen Abständen (zum Beispiel alle fünf Minuten) durchgeführt werden, wobei die Informationen aus der Datei max_latency-CPU<n> gespeichert werden müssen. Damit erhält man die Informationen über „Opfer“ und „Täter“ der höchsten Latenz pro aufeinanderfolgendes fünfminütiges Intervall. Der Inhalt der Datei könnte in einem Normalfall z.B. so aussehen:

1210 99 23 (0,0) cyclictest <- 0 -21 swapper/0 844311.612050

Das bedeutet, dass 844311 Sekunden und 612050 Mikrosekunden nach dem letzten Bootvorgang vom Idle-Task („swapper“) mit der Prozess-ID 0 und der Default-Priorität -21 auf den Task „cyclictest“ mit der Prozess-ID 1210 und der Priorität 99 umgeschaltet wurde, und dass dieser Vorgang am längsten seit dem letzten Reset gedauert hat, nämlich 23 µs. In diesem Fall handelt es sich um einen 3.6-GHz-Prozessor.

Nach der Faustformel, dass die maximale Latenz nicht höhere Werte als 10⁵ mal Zyklusintervall des Prozessors annehmen sollte, liegt der Wert – wenn auch nur knapp – im erwarteten Bereich:

23 < 1 / (3,6 * 10⁹) * 10⁵ = 27,9 µs

Bild 6: Fehlerhafter Latenzplot mit einer großen Anzahl unerwartet hoher Latenzen.
Bild 6: Fehlerhafter Latenzplot mit einer großen Anzahl unerwartet hoher Latenzen.
(Bild: OSADL)

Es kann aber auch sein, dass das Histogramm unter bestimmten Umständen aussieht wie in Bild 6 zu sehen. In diesem Fall ergibt die Analyse der drei höchsten während der Messung registrierten „Opfer/Täter“-Einträge:

220515 99 282 (280,1) cyclictest <- 3421 -21 Xorg 94345.387012220515 99 279 (276,2) cyclictest <- 3421 -21 Xorg 94495.188413220515 99 279 (275,3) cyclictest <- 3421 -21 Xorg 95376.787354

Demzufolge lautet die wahrscheinlichste Diagnose, dass Graphik-Hardware bzw. Graphik-Treiber für die Latenzen verantwortlich sind. Dies bewahrheitete sich dadurch, dass nach Abschalten der Graphik die erhöhten Latenzen nicht mehr auftraten.

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!

Dr. Carsten Emde, Linux-Trainer und Gründungsgeschäftsführer des Open Source Automation Development Lab (OSADL) eG.
Dr. Carsten Emde, Linux-Trainer und Gründungsgeschäftsführer des Open Source Automation Development Lab (OSADL) eG.
(Bild: enjoy photography 2015)

Der Autor

* Dr. Carsten Emde blickt auf eine mehr als 25-jährige Tätigkeit als Software-Entwickler, System-Integrator und Trainer zurück. Seine Spezialgebiete sind graphische Bedienoberflächen, maschinelle Bilderkennung und Echtzeit-Betriebssysteme sowie die juristischen Aspekte bei der Verwendung und Weitergabe von Open Source-Software. Seit der Gründung der Open Source Automation Development Lab (OSADL) eG im Jahre 2005 ist er deren Geschäftsführer. Der versierte Linux-Trainer ist regelmäßig zu Gast auf dem ESE-Kongress und wurde von den Teilnehmern 2013 mit dem Speaker Award Publikumspreis ausgezeichnet. Dr. Carsten Emde doziert unter anderem regelmäßig Seminare auf der Embedded-Linux-Woche.

Dieser Beitrag stammt mit freundlicher Genehmigung des Autors aus dem Tagungsband des ESE Kongress 2020.

Jetzt Newsletter abonnieren

Verpassen Sie nicht unsere besten Inhalte

Mit Klick auf „Newsletter abonnieren“ erkläre ich mich mit der Verarbeitung und Nutzung meiner Daten gemäß Einwilligungserklärung (bitte aufklappen für Details) einverstanden und akzeptiere die Nutzungsbedingungen. Weitere Informationen finde ich in unserer Datenschutzerklärung.

Aufklappen für Details zu Ihrer Einwilligung

(ID:48089074)