Teurer Käfer

Softwareentwicklung ist ein riskantes Geschäft. Harmlos aussehende Programme können plötzlich Probleme entwickeln, die auch von erfahrenen Programmierern nur mit Einsatz von mehreren Wochen Arbeit gefunden werden können. Häufig ist die Fehlerursache im Graubereich zwischen Betriebssystem, Compiler, eingekaufte Software und selbst entwickelter Software angesiedelt. Dies nachgewiesen zu haben, nützt dem Programmierer im allgemeinen nichts. Was zählt, ist die termingerechte Ablieferung lauffähiger Programme, die im Budgetrahmen entwickelt wurden. Wenn man auf kompliziertere Bugs stösst, zählt vor allem die wirksame Käferdetektionsstrategie. Ungewöhnlich schwierig zu bewältigende Bugs sind immer teuer …

Über Programmierfehler redet man nicht gern. Während sich Tausende von Analysen mit der Technik des Programmierens befassen, ist kaum je von der Technik des Debugging die Rede. Besonders in Europa wird der Makel des Fehlers als moralisch so gravierend empfunden, dass die Aufwendungen für gegenseitige Schuldzuweisungen den Aufwand für die Fehlerbehebung ein Vielfaches übersteigen. Dieser moralische Druck verhindert naturgemäss auch oft die wirksame Fehlersuche und das Teamwork. Die Stärke der amerikanischen Software-Hersteller ist unter anderem eine Stärke des Teamworks bei der Programmentwicklung und bei der Fehlersuche.

Da ein Programmierer einen substanziellen Teil seiner Arbeitszeit mit der Suche nach Fehlern zubringt, ist es nicht abwegig, sich über Techniken des Debugging Rechenschaft abzulegen. Gerade das Debugging scheint sich Aufwandschätzungen am zähesten zu widersetzen.

Wenn in der folgenden Fallstudie auf einen selten auftretenden, aber in gewissen Fällen gravierenden Fehler im TurboVision-Kode von Turbo Pascal und Borland C++ hingewiesen wird, so soll dies nicht nur anderen TurboVision-Entwicklern den Kampf mit dem selben Problem ersparen. Der Prozess der Fehlersuche soll auch Anlass sein, Debugging-Techniken und Debugging-Fehler darzustellen. Obwohl dabei zum Teil recht verzwickte Interna der Struktur von Interrupts, undokumentiertem DOS und Assembler vorkommen, sind die gewonnenen Erfahrungen vielleicht über das spezielle Beispiel hinaus von Interesse.

Bei uns läuft's

Unsere neuentwickelte Version eines Programmpakets zur Erfassung und Auswertung von Immissionsmessdaten ist in Turbo Pascal programmiert. Der Erfassungsteil besteht einerseits aus einem robusten, residenten Treiber DATALOG, der dauernd (typischerweise alle 10 Sekunden) die Messwerte im Hintergrund von der Datenloggerhardware abholt und eventuell zwischenspeichert, und andererseits aus einer TurboVision-Anwendung DATACOLL, welche mit

dem Treiber über eine Multiplex-Interrupt-Schnittstelle (2F-Interface) kommuniziert, die Daten umrechnet, anzeigt und mittelt und diese Mittelwerte alle 30 Minuten abspeichert.

Die wichtigste Anforderung an ein solches Erfassungsprogramm ist die Verlässlichkeit der Dauermessung und die Sicherheit, dass Datenverluste auf ein Minimum beschränkt sind (etwa bei Stromausfall). Aus diesem Grund hatten wir die neue Version im Rahmen hausinterner Tests während Wochen auf verschiedenen PCs und mit verschiedenen Datenloggern getestet, bevor wir die erste Version an unseren ersten Testkunden lieferten. Dort schien das Programmpaket erst auch zur Zufriedenheit zu funktionieren. Als es dann im Messwagen eingebaut war, blieb es am dritten Tag nach Mitternacht hängen. Nach neuem Starten des PC's dauerte es wieder rund zwei Tage, bis es "einfror". Der gefürchtete Datenverlust trat ein. Das Programm wurde schleunigst wieder durch seinen weniger luxuriösen, aber zuverlässigen Vorgänger ersetzt. Wir machten uns auf die Käferjagd.

Die Käferjagd

Wie findet man einen Fehler, der alle zwei Tage einmal auftritt? Bei "normalen" Programmen, wie etwa einem Kommunikationsprogramm kann es Monate dauern, bis man 48 Stunden Laufzeit beieinander hat. Ein Fehler, der sich alle paar Monate oder gar Jahre durch "Einfrieren" des Bildschirms bemerkbar macht, wäre zwar störend, könnte aber duchaus in einem solchen Produkt in der Version 1.0 toleriert werden. Bei der Dauerbeanspruchung in einer Dauermessung sind die Ansprüche an das Programm bedeutend höher. Welche Irrwege beschreitet man bei der Jagd nach solch einem selten und unvorhersagbar auftretenden Fehler?

Man kann sich natürlich nicht im Debugger zwei Tage vor den Bildschirm setzen und darauf warten, dass das Programm abstürzt. Ausserdem ist fraglich, ob der Absturz sich nicht verschiebt oder versteckt, wenn man das Programm mit Debugger-Info ausstattet. Wenn man eine Spekulation über den Bug hat, am Programm etwas ändert, um ihn zu eliminieren, wird man frühestens nach vier Tagen eine wachsende Gewissheit haben, dass der Fehler nun behoben ist. Wenn die Änderung nichts genützt hat, ist man wieder gleich weit wie vorher. Bei einem selten und stochastisch auftretenden Fehler muss man also die gewohnte Strategie umkehren: Man darf den Bug nicht zum Verschwinden bringen, sondern man sucht minimale Programmtransformationen, die den Fehler erhalten, Auskunft über seine Lokation geben und seine Auftretenshäufigkeit möglichst steigern.

Irrwege

Wir wendeten dieses Prinzip auf unser Problem an und gingen also daran, wenig veränderte Versionen mit einer etwas informativeren Bildschirmausgabe auf möglichst vielen PCs laufen zu lassen, in der Hoffnung, auch durch diese Vielfalt die Auftretenswahrscheinlichkeit des Fehlers zu maximieren. Nachdem die verschiedenen Versionen des Programms auf fünf PCs in unserem Büro mehr als eine Woche absturzfrei überstanden hatten, versuchten wir die originale EXE anhand der originalen Quelldateien wieder herzustellen. Dabei stellte sich heraus, dass wir für uns immer mit Versionen gearbeitet hatten, die in der für das Debugging bequemeren IDE (Integrated Development Environment) kompiliert waren, während die ausgelieferte Version mit dem Kommandozeilen-Compiler TPC (Turbo Pascal Compiler) hergestellt war.

Beim Herstellen der genauen Messkonfiguration, die auch bei der Absturzinstallation vorlag, stiessen wir darauf auf einen echten Programmfehler, der sich insbesondere bei Neukonfigurationen der Messanordnung bemerkbar machte. Es handelte sich um eine Prozedur, die im Heap zwei Bytes über den Rand des allozierten Bereichs hinaus schrieb. Der ursprünglich beobachtete Absturz war mit diesem Fehler zwar nicht ganz befriedigend erklärt, wir schätzten es aber als möglich ein, dass die Fehlerursache behoben sei.

Nachdem die bereinigte Version bei uns im Büro einige Testtage absturzlos überstanden hatte, lieferten wir sie unserem Testkunden wieder aus. Nach drei absturzfreien Tagen beglückwünschten wir uns schon zum gelösten Problem, als wir dann mehrere Mal hintereinander im Abstand von 30-50 Stunden weitere Abstürze zu verzeichnen hatten.

Da wir inzwischen einige unserer PCs anders eingesetzt hatten, holten wir unseren alten XT aus dem Keller und hatten zum ersten Mal Glück: der Fehler war auf diesem XT reproduzierbar. Um die Häufigkeit der Abstürze zu erhöhen, stellten wir mit minimalen Änderungen verschiedene Versionen des Programms her, wo einzelne Aktionen sehr viel häufiger als üblich ausgeführt wurden. Dadurch konten wir die Absturzhäufigkeit auf rund einen Absturz pro Viertelstunde steigern.

Im Nachhinein wissen wir, dass der XT zufällig der einzige PC in unserem Büro war, wo, wie bei unsem Testkunden, DOS 3.3 und nicht DOS 5.0 installiert war. Die Langsamkeit des Prozessors kam uns auch zugute.

Wir hatten in dieser ersten und am längsten dauernden Phase des Debugging folgende Fehler begangen:

Jede dieser Annahmen hätte man überprüfen müssen, bevor man sich auf sie stützte. Da die Überprüfung einer jeder dieser Annahmen allerdings rund zwei bis drei Tage gedauert hätte, haben wir durch den XT-Zufall die Zeit mit Glück wieder eingeholt, die wir verloren hatten, weil wir mit den obigen Fehlannahmen das Debuggingprinzip der exakten Reproduktion des Fehlers vernachlässigt hatten. Das Festhalten an solchen unüberprüften Annahmen kann die Debuggingzeit verhundertfachen, d.h. aus Wochen Jahre machen.

In die Enge getrieben

Nachdem wir den Fehler endlich in nützlicher Zeit reproduzieren konnten (allerdings nur ohne Debugging-Info), machten wir uns an die Programmreduktion: Wir entfernten grosse Teile des Programms und überprüften, ob der Absturz immer noch reproduzierbar war. Durch eine solche binäre Suche, kann man im allgemeinen eine Fehlerquelle auch bei grossen Programmkongolmeraten schnell eingrenzen. Die totale Vorurteilslosigkeit ist für diesen Schritt absolute Voraussetzung. Als wichtigstes Debuggingprinzip ist zu berücksichtigen, dass jedes Vorurteil und jede Theorie über den Fehler den pro Versuch gewonnenen Informationsgehalt reduziert.

In unserem Fall war eins unserer Hauptziele, zu isolieren, ob der Fehler im Vordergrundprogramm DATACOLL oder im residenten Hintergrundprogramm DATALOG auftrat. Es zeigte sich nach einer beträchtlichen Reduktion von DATACOLL, die es überhaupt erst ermöglichte, diese Rumpfversion ohne kooperierendes residentes DATALOG auszuführen, dass der Fehler bei abwesendem DATALOG nicht auftrat. Ohne DATACOLL konnte man andrerseits DATALOG beliebig lange ohne Absturz betreiben.

Es gelang uns in wenigen Tagen, einen grossen Teil der Funktionalität aus dem Programm DATACOLL zu entfernen, so dass am Ende nur ein Applikationsobjekt übrig blieb, das dauernd eine Datei öffnete, schrieb und schloss. Beim Schreiben "fror" jeweils früher oder später der Bildschirm "ein".

Residente Programme

Wir hatten das residente Programm DATALOG auf unserer allgemeinen Utility PASRES aufgebaut, die wir für alle unseren residenten Pascal-Programme verwenden. Diese Utility ermöglicht die Installation einer durch den Timer angestossenen Hintergrundsaktivität und das Abfangen beliebiger weiterer Interrupts (Tastatur, RS232, Multiplex, …). Es geht hier nicht darum, die Technik der Programmierung residenter Programme zu wiederholen, die man im Buch Undocumented DOS von Schulman, Kyle, Paterson, Maxey und Brown ausführlich beschrieben findet. Information aus diesem Buch hat denn auch an vielen Stellen eingang in den Kode von PASRES gefunden.

Hier soll nur erwähnt werden, dass Programme, die DOS benutzen wollen, besonders vorsichtig sein müssen, da das Singletasking-Betriebssystem DOS nicht "reentrant" ist. In diesem speziellen Fall heisst das, dass DOS gewisse temporäre Werte an absoluten Lokationen (etwa im Code Segment) abspeichert. Wenn es also etwa mitten in der Ausführung einer WRITE-Funktion vom Timer unterbrochen wird, der sich seinerseits anschickt, etwas auf Disk zu schreiben, so überschreibt die zweite aufgerufene Version der WRITE-Funktion des DOS die temporären Variablen, die die erste gespeichert hat. Wenn das residente Programm schliesslich seinen Interrupt beendet hat, fährt die erste Version mit veränderten temporären Werten weiter, was im allgemeinen innert kurzer Zeit zu Totalabstürzen führt.

Um solche Probleme des gleichzeitigen Zugreifens auf globale Ressourcen zu beheben, verwendet man im allgemeinen Semaphoren. Zu dieser Lösung sah man sich auch bei Microsoft gezwungen, wenn man etwa auch nur den residenten PRINT-Treiber gefahrlos verwenden wollte. DOS markiert also durch Setzen einer INDOS-Marke die Tatsache, dass es sich jetzt im kritischen Bereich befindet, wo es temporäre Werte an absolute Lokationen geschrieben hat. Die Programmierer residenter Programme überprüfen diese Marke, bevor sie selber DOS-Funktionen etwa für die Ein- oder Ausgabe von Dateien aufrufen.

In unserer Unit PASRES wird die Adresse der INDOS-Marke in der Unit-Initialisierung berechnet. Die Überprüfung dieser Marke leistet die Funktion prdosavailable, die Umstellung des DOS auf das PSP des residenten Programms und ähnliche Abgrenzungsoperationen besorgt die Prozedur proccupy. Mit prrelease richtet man wieder die vorherige DOS-Umgebung ein.

Bei der Reduktion unseres residenten Treibers DATALOG konnten wir funktional einen grossen Teil des Programms entfernen. Sobald wir aber die Notwendigkeit, das DOS zu reservieren, entfernten, verschwand auch der Fehler. Es schien notwendig zu sein, dass das residente Programm die INDOS-Marke testete und darauf einen DOS-Funktionsaufruf (etwa vermittels der Pascal-Prozedur gettime) absetzte, um den Fehler zu präservieren.

Die beiden CLI

Die letzte Wende beim Debugging ergab sich aus einer weiteren Reduktion des Vordergrundprogramms DATACOLL. Wenn man dieses vom Gerüst des TurboVision-Objekts Application befreite, war der Fehler verschwunden!

Nicht zum ersten Mal waren wir heilfroh, die Run Time Library zu Turbo Pascal 6.0 erstanden zu haben. Dies ermöglichte uns, die Halbierungsstrategie in den TurboVision-Kode hinein weiterzuführen. Wir stellten recht schnell fest, dass der Fehler ursächlich mit der Prozedur InitSysError in TP\RTL\VISION\SYSINT.ASM zusammenhing. Sobald diese Prozedur den Int21Handler installiert hatte, stürzte unser Testprogramm ab. Selbst hier waren wir gezwungen, das Programm weiter zu reduzieren, und identifizierten den Abschnitt CheckHandle als Fehlerlokation.

Dieses Stückchen Kode analysierten wir genau:

CheckHandle:

MOV BX,SP

MOV BX,SS:[BX+2]

PUSH AX

MOV AX,4400H

CALL SaveInt21

POP AX

OR DL,DL

JNS CheckAbsDrive

JMP SHORT CheckNothing

Im wesentlichen wird hier der vorher installierte Interrupt 21 (SaveInt21) mit der IOCTL-Funktion (AX=4400) aufgerufen, um den Drive der angeforderten Dateioperation vorher zu überprüfen und somit das dumme "Abort, Retry, Ignore" des DOS zu vermeiden. Um diese löbliche Absicht zu erreichen, wird ein Interrupt 21 simuliert, indem man zuerst mit der Instruktion PUSHF die Flags pusht und dann mit CALL SaveInt21 den Interrupt anspringt. Die Simulation des Interrupts ist aber in einer Hinsicht nicht perfekt: Im Int21Handler wurde am Anfang die Instruktion STI ausgeführt. Das Interruptflag ist also beim Beginn von CheckHandle gesetzt, und somit sind Interrupts erlaubt, im Moment wenn SaveInt21 aufgerufen wird. Der Kode, der sich hinter SaveInt21 verbirgt, kann sich aber darauf verlassen, wenn er über eine Interruptinstruktion angesteuert wird, dass anfänglich das Interruptflag gelöscht ist und somit keine Interrupts stattfinden können, bis dies vom Interruptkode erlaubt wird. Um die Simulation des Interrupts zu perfektionieren, ist es also notwendig, zwischen dem PUSHF und dem CALL SaveInt21 die Instruktion CLI einzufügen, welche das Interruptflag löscht.

Ein ähnlicher Fehler findet sich ein paar Zeilen weiter unten. Wenn also etwa die DOS-Funktion 21 sich darauf verlässt, dass sie durch das gelöschte Interruptflag vor Interrupts geschützt ist und temporäre Daten an absolute Lokationen schreibt, bevor sie das INDOS-Flag setzt, kann es nun passieren, dass der Timer-Interrupt das DOS an einer kritischen Stelle unterbricht, wo es schon nicht mehr "reentrant" ist. Das Einfügen zweier CLI im Kode von SYSINT.ASM hat denn auch unseren Fehler bleibend behoben:

; Check handle

CheckHandle:

MOV BX,SP

MOV BX,SS:[BX+2]

PUSH AX

MOV AX,4400H

PUSHF

CLI ;H. THOMAS

CALL SaveInt21

POP AX

OR DL,DL

JNS CheckAbsDrive

JMP SHORT CheckNothing

; Check drive

CheckDrive:

DEC DL

JNS CheckAbsDrive

; Check current drive

CheckCurDrive:

PUSH AX

MOV AH,19H

PUSHF

CLI ;H. THOMAS

CALL SaveInt21

MOV DL,AL

POP AX

Wir haben übrigens festgestellt, dass der Quellkode von Borland C++ 3.0 und 3.1 den selben Fehler enthält.

Beim neuen Herstellen der Run Time Library ist Vorsicht geboten, da die von Borland mitgelieferten Instruktionen zum Teil irreführend sind. Am besten fährt man, wenn man das MAKEFILE anschaut und die TASM- und TPC-Aufrufe entsprechend gestaltet.

Nachlese

Das Bug-Paradox der Programmierung besagt:

Es gibt keine beweisbar bugfreien Programme, die es wert sind, benutzt zu werden. Denn um sicher zu sein, dass ein Programm bugfrei ist, muss man geprüft haben, dass es auf jede mögliche Eingabe die richtige Ausgabe produziert. Dies können wir nur leisten, wenn wir schon ohne Hilfe des Programms wissen, welche Ausgabe korrekt ist und somit das Programm gar nicht benötigen, um die Ausgabe zu berechnen. Es ist also nicht wert, benutzt zu werden.

Der einzige (partielle) Ausweg aus diesem Paradox besteht darin, dass nicht bemerkbare Fehler meistens auch nicht eigentlich störend sind und dass es sehr wahrscheinlich ist, dass sich Kodierfehler störend bemerkbar machen.

Wenn man einen schwer zu identifizierenden Fehler wie den oben geschilderten endlich gefunden hat, lohnt es sich, den Fehler auch in seinen Erscheinungsformen zu verstehen. Das Verständnis erst ergibt zusammen mit dem Testen die Sicherheit, dass das Problem endgültig beseitigt ist. Sonst wäre es ja zum Beispiel möglich, dass man den Fehler nur etwa seltener gemacht hat, oder dass er von seltenen Zeit-/Datumskonstellationen abhängt …

Wir verfolgten also die Spur der DOS-Version kurz: Es zeigt sich beim Debuggen des INT 21 recht schnell, dass im Kode von DOS 5.0 relativ früh ein (eigentlich überflüssiges) CLI durchlaufen wird schon bevor überhaupt nach verschiedenen Funktionstypen verzweigt wird. Beim DOS 3.3 ist die Situation anders: die Verzweigung nach Funktionstypen kommt sofort. Der DOS-Kode verlässt sich auf das gelöschte Interrupt-Flag. So haben wir im Nachhinein verstanden, dass das gesamte oben geschilderte Problem mindestens für die uns vorliegende DOS 5.0-Version überhaupt nie aufgetreten wäre.

Da der ungeschützte Bereich, in den keine Interrupts fallen dürfen, die ihrerseits DOS-Funktionen aufrufen, relativ kurz ist, verstehen wir die Tatsache, dass die Abstürze relativ selten auftraten. Die Wahrscheinlichtkeit, dass der Timer-Interrupt gerade im richtigen Moment eintritt, ist nicht sehr gross.

Da bei jedem Aufstarten des PC und wegen verschiedenen Diskaccesszeiten sich die Timingverhältnisse bei jeder Programmausführung subtil verschieben, kann man nicht damit rechnen, dass das unglückliche Zusammentreffen des Timer-Interrupts mit dem ungeschützten Kodebereich im DOS zu einem prognostizierbaren Zeitpunkt eintritt. Dies erklärt die Zufälligkeit des Auftretens des Fehlers.

Diese nachträglichen Abklärungen beweisen nichts, erhöhen aber unser Vertrauen in die gefundene Lösung. Wir installierten also die bereinigte Version auf allen bisher kritischen PCs und haben bis heute keinen Absturz zu vermelden.

Wer ist schuld?

Die erste Frage von Kunden und anderen Nichtprogrammierern nach einer längeren Fehlersuche ist normalerweise: Wer war schuld? Dies ist etwa die katastrophalste Frage, die man stellen kann, wenn es einem um möglichst ökonomisches Programmieren zu tun ist. Ganze Abteilungen und Hunderte von Programmierern leben heute davon, sich entweder juristisch bis auf den Tod abzusichern gegen die Fehler von anderen oder aber nachzuweisen, dass der Fehler nicht bei ihnen lag.

In einer arbeitsteiligen Welt, wo kein einzelner Programmierer mehr eine Anwendung allein in Maschinenkode kadieren kann, ohne die Verwendung fremder Compiler (wie Turbo Pascal) oder Halbfabrikate (wie TurboVision), treibt die überspitzte Suche nach Schuldigen die Entwicklungskosten in astronomische Höhen. Die emotionelle Belastung durch Schuldzuweisungen hat typischerweise zur Folge, dass auch die Debuggingkosten in die Höhe schnellen. Sie erweist sich also in jeder Hinsicht als kontraproduktiv. In unserem konkreten Fall ist nichts gewonnen, wenn wir wissen, dass es unser eigener Kode, derjenige von Borland, oder derjenige von Microsoft war.

Eine verwandte, vernünftigere Frage ist diejenige, welchen Kode man nun ändern sollte. Im geschilderten Beispiel ist dies der TurboVision-Kode. Dies zeigt, dass die Philosophie von Borland sehr zu begrüssen ist, dass der Quellkode der Halbfabrikate mitgeliefert wird. Es wäre höchstens noch zu wünschen, dass dies beim Pascal so wie beim C++ kostenlos geschieht.

Warum soll man die Änderung im TurboVision-Kode machen? Grundsätzlich könnte jedes TurboVision-Programm, das intensiv Ein- und Ausgabe auf Dateien treibt, bei gleichzeitig laufendem residentem Hintergrundsprogramm, das DOS-Ressourcen benötigt (etwa PRINT einer langen Datei), zu unvorhersehbaren Zeiten abstürzen. Nur die Änderung in SYSINT.ASM behebt das Problem an der Wurzel.

Grundsätze

Zusammenfassend haben wir aus dieser Käferjagd gelernt, dass die erfolgreiche Suche schwer detektierbarer Fehler auf den folgenden drei Grundpfeilern beruht:

17.11.92 Hartwig Thomas

Quellcode

Basismodul für DOS-residente Programme: pasres.pas

Wichtige DOS-Funktionen für DOS-residente Programme: pasres.asm

Object-Code aus dem Assemblermodul: pasres.obj

Hauptprogramm, das die Benutzung des PASRES-Moduls demonstriert: swatch.pas

Turbo-Pascal-Switches: switches.inc

Ausführbares Testhauptprogramm: swatch.exe