Kapitel 4. Debugging-Techniken

Inhalt
Debugging mit Ausgaben
Debugging mit Abfragen
Debugging durch Beobachten
Debuggen von Systemfehlern
Debugger und verwandte Werkzeuge

Eines der vordringlichsten Probleme für jeden, der Kernel-Code schreibt, ist das Debugging. Kernel-Code kann nicht einfach in einem Debugger ausgeführt oder verfolgt werden, weil es sich bei Kernel-Code um Funktionalitäten handelt, die nicht zu einem spezifischen Prozeß gehören. Fehler im Kernel-Code können auch besonders schwer zu reproduzieren sein, das ganze System mit sich reißen und dabei möglicherweise Beweismittel zerstören, mit denen man das Problem hätte aufspüren können.

In diesem Kapitel werden Techniken eingeführt, mit denen Sie unter solch herausfordernden Umständen Kernel-Code beobachten und Fehler verfolgen können.

Debugging mit Ausgaben

Die gängigste Debugging-Technik ist die Überwachung des Programmablaufs. Anwendungsprogramme machen das, indem an den passenden Stellen printf eingefügt wird. Wenn Sie Kernel-Code debuggen, können Sie dasselbe mit printk erreichen.

printk

Wir haben die Funktion printk bereits in vorangegangenen Kapiteln verwendet und dabei vereinfachend angenommen, daß diese Funktion wie printf arbeitet. Jetzt ist es an der Zeit, daß wir auch auf die Unterschiede eingehen.

Einer der Unterschiede besteht darin, daß printk die Möglichkeit bietet, Meldungen nach ihrer Wichtigkeit oder Bedeutung in verschiedene Loglevel einzuteilen. Der Loglevel wird normalerweise mit einem Makro angegeben. Beispielsweise ist das Makro KERN_INFO, das wir schon bei einigen Ausgaben gesehen haben, einer der möglichen Loglevel einer Meldung. Das Loglevel-Makro wird zu einem String expandiert, der dann vom Compiler der eigentlichen Meldung vorangestellt wird. Deswegen steht auch in den folgenden Beispielen kein Komma zwischen der Priorität und dem Format-String. Hier sehen Sie zwei Beispiele für die Verwendung von printk — eine Debugging-Meldung und eine kritische Meldung:


printk(KERN_DEBUG "Hier bin ich: %s:%i\n", _ _FILE_ _, _ _LINE_& _);
printk(KERN_CRIT "Ich bin abgestuerzt bei %p\n", ptr);

Es gibt insgesamt acht Loglevel-Strings, die in der Header-Datei <linux/kernel.h> definiert sind:

KERN_EMERG

Wird für Meldungen in Notsituationen verwendet, also normalerweise kurz vor einem Absturz.

KERN_ALERT

Eine Situation, die ein unmittelbares Eingreifen erfordert.

KERN_CRIT

Kritische Zustände, oft im Zusammenhang mit schwerwiegendem Hardware- oder Software-Versagen.

KERN_ERR

Wird zum Melden von Fehlerzuständen verwendet; Gerätetreiber verwenden oft KERN_ERR, um Schwierigkeiten mit der Hardware zu melden.

KERN_WARNING

Warnungen in problematischen Situationen, die für sich allein genommen keine ernsthaften Probleme für das System mit sich bringen.

KERN_NOTICE

Situationen, die zwar normal, aber trotzdem beachtenswert sind. Eine Reihe von sicherheitsrelevanten Zuständen wird auf diesem Level gemeldet.

KERN_INFO

Informationsmeldungen. Viele Treiber geben beim Start Informationen über die vorgefundene Hardware auf diesem Level aus.

KERN_DEBUG

Wird für Debug-Meldungen verwendet.

Jedes dieser Makros wird zu einer Zeichenkette < i > mit i zwischen 0 und 7 expandiert. Kleinere Werte bedeuten höhere Prioritäten.

Eine printk-Anweisung ohne explizit angegebene Priorität hat den Default DEFAULT_MESSAGE_LOGLEVEL, einen in kernel/printk.c angegebenen Integer-Wert. Der Default-Wert ist während der Entwicklung von Linux mehrfach verändert worden, so daß wir Ihnen raten, immer einen passenden Loglevel anzugeben.

Der Kernel gibt die Meldung, basierend auf dem Loglevel, auf der aktuellen Textkonsole (einem Terminal im Textmodus, einem seriellen Drucker oder einem Paralleldrucker) aus: Wenn die Priorität kleiner als die Integer-Variable console_loglevel ist, wird die Meldung angezeigt. Wenn sowohl klogd als auch syslogd auf dem System laufen, werden Kernel-Meldungen unabhängig von console_loglevel an /var/log/messages angehängt (oder entsprechend Ihrer syslogd-Konfiguration behandelt). Wenn klogd nicht läuft, erreichen die Meldungen den User-Space nicht, sofern Sie nicht /proc/kmsg lesen.

Die Variable console_loglevel wird mit dem Wert DEFAULT_CONSOLE_LOGLEVEL initialisiert und kann dann durch den Systemaufruf sys_syslog verändert werden. Das kann zum Beispiel durch Angabe der Option –c beim Aufruf von klogd erfolgen (siehe die Man-Page von klogd). Beachten Sie, daß Sie zum Ändern des aktuellen Wertes zunächst klogd beenden und dann mit der Option –c neu starten müssen. Alternativ dazu können Sie natürlich auch ein Programm schreiben, das den Loglevel der Konsole verändert. Sie finden unsere Version eines solchen Programms in der Datei miscprogs/setlevel.c in den Quelldateien auf dem FTP-Server von O'Reilly. Der neue Level wird als Integer-Wert zwischen 1 und 8 angegeben. Bei 1 werden nur Meldungen auf Level 0 (KERN_EMERG) auf der Konsole ausgegeben, bei 8 dagegen alle, auch die Debugging-Meldungen.

Nach einem Kernel-Fehler (siehe Abschnitt “Debuggen von Systemfehlern” weiter hinten in diesem Kapitel) wollen Sie wahrscheinlich den Loglevel herabsetzen, wenn Sie auf der Konsole arbeiten und auf einen Kernel-Fehler stoßen (siehe “the Section called Debuggen von Systemfehlern” weiter hinten in diesem Kapitel), denn der Fehlerbehandlungscode setzt die Variable console_loglevel auf den Maximalwert, worauf alle weiteren Meldungen auf der Konsole erscheinen. Wenn Sie Ihre Debugging-Meldungen sehen müssen, sollten Sie den Loglevel heraufsetzen; dies ist auch nützlich, wenn Sie Kernel-Code entfernt entwickeln und die Textkonsole nicht für eine interaktive Sitzung verwendet wird.

Ab Version 2.1.31 ist es möglich, den Loglevel der Konsole mit der Textdatei /proc/sys/kernel/printk zu lesen und zu ändern. Diese Datei enthält vier Integer-Werte. Die ersten beiden sind vielleicht interessant für Sie: der aktuelle Loglevel der Konsole und der Default-Level für Meldungen. In neueren Kerneln können Sie beispielsweise mit folgendem Befehl alle Kernel-Meldungen auf der Konsole erscheinen lassen:

 # echo 8 > /proc/sys/kernel/printk

In 2.0 müssen Sie dagegen das Hilfsprogramm setlevel verwenden.

Es sollte jetzt auch klar sein, warum in hello.c die <1>-Markierungen standen: Damit wird sichergestellt, daß solche Meldungen auf jeden Fall auf der Konsole erscheinen.

Linux ist einigermaßen flexibel, was das Logging auf die Konsole angeht, indem es Ihnen gstattet, Meldungen an eine bestimmte virtuelle Konsole zu schicken (wenn sich Ihre Konsole auf einem Textbildschirm befindet). Per Default ist die Konsole das aktuelle virtuelle Terminal. Um ein anderes virtuelles Terminal als Empfänger von Meldungen auszuwählen, können Sie den Aufruf ioctl(TIOCLINUX) auf einem beliebigen Konsolengerät ausführen. Mit dem folgenden Programm setconsole, das vom Superuser ausgeführt werden muß, kann ausgewählt werden, auf welcher Konsole Kernel-Meldungen ausgegeben werden. Sie finden es im Verzeichnis misc-progs.

Und so funktioniert das Programm:


 
int main(int argc, char **argv)
{
    char bytes[2] = {11,0}; /* 11 ist die Befehlsnummer von TIOCLINUX */

    if (argc==2) bytes[1] = atoi(argv[1]); /* die ausgewaehlte Konsole */
    else {
        fprintf(stderr, "%s: nur ein Argument angeben\n",argv[0]); exit(1);
    }

    if (ioctl(STDIN_FILENO, TIOCLINUX, bytes)<0) {    /* stdin verwenden */
        fprintf(stderr,"%s: ioctl(stdin, TIOCLINUX): %s\n",
                argv[0], strerror(errno));
        exit(1);
    }
    exit(0);
}

setconsole verwendet den speziellen ioctl-Befehl TIOCLINUX, der Linux-spezifische Funktionen implementiert. Um TIOCLINUX zu verwenden, übergeben Sie einen Zeiger auf ein Byte-Feld als Argument. Das erste Byte des Feldes ist eine Zahl, die den gewünschten Subbefehl angibt. Die folgenden Bytes sind dann wiederum spezifisch für den Subbefehl. In setconsole wird der Subbefehl 11 verwendet, wobei das nächste Byte (das in bytes[1] steht) die virtuelle Konsole angibt. Die vollständige Beschreibung von TIOCLINUX steht in den Kernel-Quellen in drivers/char/tty_io.c.

Wie Meldungen protokolliert werden

Die Funktion printk schreibt Meldungen in einen Ring-Puffer der Länge LOG_BUF_LEN (definiert in kernel/printk.c). Dann weckt sie einen Prozeß, der auf Meldungen wartet, also einen Prozeß, der im Systemaufruf syslog schläft oder /proc/kmsg liest. Diese beiden Schnittstellen zum Protokoll-System sind fast äquivalent, beachten Sie aber, daß das Lesen aus /proc/kmsg die Daten aus dem Protokoll-Puffer “verbraucht”, während der Systemaufruf syslog Protokoll-Daten optional auch wieder zurückgeben kann, so daß diese auch noch für andere Prozesse zur Verfügung stehen. Das Auslesen einer /proc-Datei ist aber einfacher, weswegen das auch das Default-Verhalten von klogd ist.

Wenn Sie Kernel-Meldungen direkt von /proc lesen, dann verhält sich die /proc-Datei nach dem Anhalten von klogd wie eine FIFO-Datei; der Leser blockiert und wartet auf weitere Daten. Natürlich können Sie keine Meldungen auf diese Weise lesen, wenn klogd oder ein anderer Prozess ebenfalls die gleichen Daten liest, weil Sie nie an die Reihe kommen.

Wenn der Ring-Puffer voll ist, fängt printk wieder vorn an und schreibt neue Daten an den Anfang des Puffers, wodurch die jeweils ältesten Daten überschrieben werden. Der Protokoll-Prozeß verliert also die ältesten Daten. Dieses Problem kann im Vergleich mit den Vorteilen eines solchen Ring-Puffers vernachlässigt werden. Zum Beispiel kann ein System sogar ohne Protokoll-Prozeß laufen, ohne daß unnötig viel Speicher verschwendet wird (indem alte Daten überschrieben werden, falls keiner sie liest). Ein weiterer Vorteil des Ansatzes von Linux ist es, daß printk überall aufgerufen werden kann, selbst aus einem Interrupt-Handler. Auch gibt es keine Beschränkungen, wie viele Daten ausgegeben werden können. Die einzige Gefahr ist der mögliche Verlust einiger Daten.

Wenn der klogd-Prozeß läuft, entnimmt er die Kernel-Meldungen und gibt sie an syslogd weiter, der wiederum /etc/syslog.conf ausliest, um zu ermitteln, was er mit den Meldungen machen soll. syslogd unterscheidet die Meldungen nach einer Quelle und einer Priorität. Die möglichen Werte sowohl für die Quelle als auch für die Priorität sind in <sys/syslog.h> definiert. Kernel-Meldungen werden unter der Quelle LOG_KERN protokolliert; die Priorität ist die bei printk angegebene (beispielsweise wird LOG_ERR für KERN_ERR-Meldungen verwendet). Wenn klogd nicht läuft, bleiben die Daten im Ring-Puffer, bis jemand diesen ausliest oder der Puffer überläuft.

Wenn Sie es vermeiden wollen, daß Ihr System-Protokoll mit Meldungen Ihres Treibers “zugemüllt” wird, können Sie entweder bei klogd die Option –f (file) angeben, um die Meldungen in eine bestimmte Datei zu schreiben, oder /etc/syslog.conf Ihren Bedürfnissen entsprechend modifizieren. Eine ziemlich rabiate, andere Möglichkeit wäre es, klogd zu beenden und alle Meldungen auf einem unbenutzten virtuellen Terminal auszugeben[1] oder aber in einem unbenutzten xterm den Befehl cat /proc/kmsg auszuführen.

Die Meldungen ein- und ausschalten

Am Anfang der Entwicklung eines Treibers kann printk ziemlich hilfreich sein, wenn neuer Code debuggt und getestet wird. Wenn Sie den Treiber aber offiziell freigeben, sollten solche Ausgabeanweisungen entfernt oder wenigstens abgeschaltet werden. Möglicherweise werden Sie aber ein neues Feature implementieren (oder einen Bug fixen) wollen und wenigstens eine der Meldungen wieder einschalten wollen, sobald Sie alle entfernt haben. Es gibt mehrere Möglichkeiten, beide Probleme zu lösen, das heißt, sowohl global Meldungen ein- und ausschalten als auch einzelne Meldungen individuell beeinflussen zu können.

Wir zeigen hier eine Möglichkeit, printk-Aufrufe zu schreiben, so daß man diese individuell oder global ein- und ausschalten kann; diese Technik beruht auf einem Makro, das zu printk (oder printf) aufgelöst wird, wenn Sie das wollen:

  • Jede Ausgabeanweisung kann durch das Weglassen oder Hinzufügen eines einzelnen Buchstabens zum Namen des Makros ein- oder ausgeschaltet werden.

  • Alle Meldungen können durch das Ändern der Variable CFLAGS vor dem Kompilieren auf einmal abgeschaltet werden.

  • Ein und dieselbe Ausgabeanweisung kann sowohl im Kernel-Code als auch im User-Space-Code verwendet werden, so daß der Treiber und die Testprogramme hinsichtlich der Meldungen gleich behandelt werden können.

ark=bullet>

Das folgende Code-Fragment implementiert diese Funktionen und stammt unmittelbar aus der Header-Datei scull.h:


 
#undef PDEBUG             /* vorsichtshalber "undefinieren" */
#ifdef SCULL_DEBUG
# ifdef _ _KERNEL_ _
   /* das hier gilt im Kernel-Space, wenn Debugging eingeschaltet ist */
#  define PDEBUG(fmt, args...) printk(KERN_DEBUG "scull: " fmt, ## args)
# else
   /* und das hier im User-Space */
#  define PDEBUG(fmt, args...) fprintf(stderr, fmt, ## args)
# endif
#else
# define PDEBUG(fmt, args...) /* kein Debugging: nichts machen */
#endif

#undef PDEBUGG
#define PDEBUGG(fmt, args...) /* nichts machen, nur ein Platzhalter */

Das Symbol PDEBUG ist davon abhängig, ob SCULL_DEBUG definiert ist oder nicht, und zeigt Informationen in einer Weise an, die zu der Umgebung, in der der Code läuft, paßt: Im Kernel wird der Kernel-Aufruf printk verwendet, und im User-Space der libc-Aufruf fprintf. Das Symbol PDEBUGG macht dagegen gar nichts; man kann damit einfach Ausgabeanweisungen “auskommentieren”, ohne sie ganz entfernen zu müssen.

Um den Prozeß weiter zu vereinfachen, können Sie die folgenden Zeilen zu Ihrem Makefile hinzufügen:


 
# Kommentieren Sie die folgende Zeile ein oder aus, um das Debugging
# ein- oder auszuschalten
DEBUG = y

#  Debugging-Flag zu CFLAGS hinzufügen oder nicht
ifeq ($(DEBUG),y)
  DEBFLAGS = -O -g -DSCULL_DEBUG # "-O" wird fuer die Expansion von
                                 # Inline-Funktionen gebraucht
else
  DEBFLAGS = -O2
endif

CFLAGS += $(DEBFLAGS)

Die in diesem Abschnitt gezeigten Makros verlassen sich auf eine gcc-Erweiterung des ANSI-C-Präprozessors, die Makros mit einer variablen Anzahl von Argumenten unterstützt. Diese Abhängigkeit vom gcc sollte kein Problem sein, weil der Kernel selbst ohnehin massiv von Features des gcc abhängt. Die gleichen Überlegungen gelten auch für die Abhängigkeit des Makefile von gmake.

Wenn Sie sich mit dem C-Präprozessor auskennen, können Sie die angegebenen Definitionen noch um das Konzept einer Debugging-Ebene erweitern. Dabei werden verschiedene Ebenen definiert, und jeder Ebene wird ein Integer-Wert (oder eine Bitmaske) zugewiesen, um zu bestimmen, wie geschwätzig dieser Wert sein soll.

Jeder Treiber hat allerdings eigene Features und Überwachungsbedürfnisse. Die Kunst guter Programmierung besteht darin, zwischen Flexibilität und Effizienz abzuwägen, und wir können Ihnen nicht sagen, was in Ihrem Fall das Beste ist. Denken Sie daran, daß Präprozessor-Bedingungen (genau wie konstante Ausdrücke im Code) während des Kompilierens ausgeführt werden, so daß Sie neu kompilieren müssen, um die Meldungen an- oder abzuschalten. Eine mögliche Alternative wäre es, C-Bedingungen zu verwenden, die zur Laufzeit ausgeführt werden und die es Ihnen ermöglichen, Meldungen während der Programmausführung an- oder abzuschalten. Diese Fähigkeit ist sehr angenehm, benötigt aber zusätzliche Verarbeitung zur Laufzeit, was die Performance selbst dann beeinflussen kann, wenn die Meldungen abgeschaltet sind. Manchmal ist dieser Performance-Verlust inakzeptabel.

Wir persönlich sind mit den obigen Makros zufrieden, auch wenn sie uns zwingen, das Modul jedesmal neu zu kompilieren und zu laden, wenn wir eine Meldung hinzufügen oder entfernen möchten.

Fußnoten

[1]

Sie können beispielsweise mit setlevel 8; setconsole 10 das Terminal 10 zum Anzeigen von Meldungen einrichten.