Fehlerbehebung bei Software
Trace-Techniken verstehen
Fortsetzung des Artikels von Teil 1
Experiment zum Vergleich
Um den Overhead der verschiedenen oben genannten Mechanismen zu vergleichen, wurde ein einfaches Testprogramm verwendet, das die ersten n Elemente einer Fibonacci-Folge berechnet [4]. Die Implementierung erfolgt rekursiv, wie in Bild 2 dargestellt, wobei bei jedem Sprung in die Funktion der Eingabewert protokolliert wird und bei jeder Rückkehr von einer Funktion der Rückgabewert (Ausgabewert) protokolliert wird. Dieser Fibonacci-Algorithmus wurde nicht mit dem Ziel ent- wickelt, besonders effizient zu sein (er weist aufgrund seiner Rekursion tatsächlich eine sehr schlechte Leistung auf), sondern vielmehr, um in einem einfachen Beispiel viele Funktionsaufrufe mit Protokollierung zu ermöglichen. Dieser Code wurde mit vier verschiedenen Ersetzungen für das Makro E_LogU32() ausgeführt:
➔ (1) Logging im Stil von printf
➔ (2) Verwendung einer auf dem Target gepufferten Protokollierung, wie sie oben erwähnt wird
➔ (3) Anwendung der Code-Instrumentierung mit einem professionellen Werkzeug
➔ (4) leeres Makro; gemessen mit Hardware-Trace
Die Zeitstempel im Fall (1) wurden mithilfe von Systemaufrufen des Betriebssystems und im Fall (2) mithilfe des Tick-Wertes des CPU System Counters ermittelt, wie oben beschrieben.
Jobangebote+ passend zum Thema
Die Tabelle 1 zeigt die Ergebnisse der 100-maligen Ausführung von fib(8) in einer Schleife. Die Ausführungszeit wird in Mikrosekunden gemessen, wobei die obere Zeile Werte mit aufgezeichneten Zeitstempeln und die untere Zeile ohne Zeitstempel zeigt.
Aus der Tabelle geht hervor, dass printf() etwa fünfmal mehr CPU-Zeit benötigt als der Ansatz der gepufferten Protokollierung. Vergleicht man dies jedoch mit dem Fall ohne Protokollierung, so ist es fast 500-mal langsamer. Deutlich wird auch, dass die Erfassung des Zeitwerts über einen Systemaufruf etwa 30-mal langsamer ist als die direkte Verwendung des virtuellen System Counters.
Man könnte sagen, dass dieses Experiment sehr künstlich ist, d. h. das Programm führt nur eine einzige Berechnung pro zwei printf()-Aufrufe aus, und ist wahrscheinlich nicht repräsentativ für einen einfachen printf()-Anwendungsfall. Das ist richtig, wenn man nur selten printf() verwendet, aber wenn man in Betracht zieht, printf()-ähnliches Tracing zu verwenden, um feinkörnige Informationen über das Ausführungs-Timing in einem echten Projekt zu erhalten, zeigen die Ergebnisse dieses Experiments deutlich, dass dies keine gute Idee ist. Eine einzige Zeile von printf() hat bereits einen signifikanten Einfluss auf die Ausführungszeit eines Programms.
Tabelle 2 zeigt die Größen von zwei Abschnitten dieses speziellen Programms, dem .text-Abschnitt (Code) und dem .bss-Abschnitt (nicht initialisierte Daten). Für die gepufferte Protokollierung benötigt man etwas mehr Code und natürlich den Puffer, in den protokolliert wird (64 KB in diesem Beispiel). Im Falle der Instrumentierung sind nur 56 Byte mehr Code (14 Instruktionen) erforderlich, damit die Protokollierung funktioniert.
Einfache Tools, wenig Effizienz
Es gibt verschiedene Ansätze, um die Ausführungssequenz eines Programms zur Fehlersuche oder zum Erhalt von Zeitinformationen zu verfolgen. Die billigste Methode im Hinblick auf die Tool-Kosten ist die Verwendung von printf() und das Sammeln von Zeitstempeln aus Betriebssystemaufrufen. Diese Methode ist etwa drei Größenordnungen langsamer als die Verwendung eines hocheffizienten Tooling-Ansatzes. Das effizienteste Tracing wird mit Hardware-Trace-Methoden erreicht, aber dies erfordert eine leistungsfähige Hardware und einen zuverlässigen Weg, um die Trace-Daten abzurufen.
Steht kein HW-Trace zur Verfügung, kann der printf()-Ansatz verwendet werden, aber er verursacht einen großen Overhead an CPU-Zeit und Port-Bandbreite. Dies kann durch die Verwendung von gepuffertem Logging auf dem Ziel optimiert werden, sofern Speicherplatz verfügbar ist. Es gibt werkzeuggestützte Instrumentierungstechniken, die eine viel effizientere Art der Protokollierung von Informationen zur Laufzeit bieten, die am effizientesten sind, wenn auf der Hardware ein gewisser Speicher vorhanden ist, in dem die Protokolle gespeichert werden können. Ohne diesen Speicher können die Daten über einen geeigneten HW-Port nach außen gestreamt werden, und das ist immer noch viel effizienter als die Verwendung von printf.
Der beste Ansatz ist die Verwendung von Hardware-Trace, und wenn dieser nicht verfügbar ist, ist die Code-Instrumentierung die beste Alternative. Printf() ist die schlechteste Wahl, also bitte nicht verwenden für »Trace«!
Literatur:
[1] https://en.wikipedia.org/wiki/Heisenbug
[2] Arm-Architektur-Register – Armv8: https://documentation-service.arm.com/static/6023d5362cb3723f202089b8
[3] ARM CoreSight Technologie System Design Guide: https://documentation-service.arm.com/static/5f10749a0daa596235e834b0
[4] https://en.wikipedia.org/wiki/Fibonacci_number
Der Autor
Andre Schmitz
begann seine berufliche Laufbahn bei der FhG im Bereich Steuerungs- und Simulationssoftware für autonome Roboter. Danach entwickelte er bei Infineon Embedded-Software für UMTS-Kommunikationssysteme. Seit 2005 ist er bei Green Hills Software für die technische Unterstützung von Kunden und die Durchführung von Schulungen zuständig. Andre Schmitz ist seitdem regelmäßig Referent bei diversen Fachkonferenzen zum Thema Embedded-Software, Safety und Security.
- Trace-Techniken verstehen
- Experiment zum Vergleich
Lesen Sie mehr zum Thema
