© www.a-m-i.de, Alexander Müller Informatik
EDV Sachverständiger / Gutachter
Bernhard O. Gramberg
Diplom-Informatiker
Mail: gramberg@sv-berlin.de
www.sv-gramberg.de
Analyse des Logs: Der Header
Ich habe eine kleine Beispielapplikation in C++ erstellt, die einen
Crash erzeugt, weil sie irgendwann durch Null teilt. Der Sourcecode ist
ganz simpel:
int main(int argc, char* argv[])
{
long lZaehler = 5270;
for (int i = 10; i >= 0; i--)
lZaehler = lZaehler / i;
return 0;
}
Klar, daß "i" irgendwann 0 wird, und eine "divide-by-zero-exception" kommen muß.
Wenn ich damit einen Watson - Crash provoziere, kann ich mir anschließend das Logfile ansehen (wo es
zu finden ist, habe ich schon im ersten Teil
beschrieben: Unter "Einstellungen / Protokollpfad"). Es hat normalerweise den Namen "drwtsn32.log".
Im folgenden zeige ich einen Auszug aus meinem Log, nämlich den Anfang:
Microsoft (R) DrWtsn32
Copyright (C) 1985-2001 Microsoft Corp. Alle Rechte vorbehalten.
Anwendungsausnahme aufgetreten:
Anwendung: C:\MyProjects\WatsonTest\Release\WatsonTest.exe (pid=572)
Wann: 30.08.2003 @ 10:23:10.385
Ausnahmenummer: c0000094 (Division durch Null)
*----> Systeminformationen <----*
Computername: ALXGERICOM
Benutzername: AlexMueller
Terminalsitzungskennung: 0
Prozessoranzahl: 1
Prozessortyp: x86 Family 6 Model 11 Stepping 1
Windows-Version: 5.1
Aktuelles Build: 2600
Service Pack: 1
Aktueller Typ: Uniprocessor Free
Firma:
Besitzer:
*----> Taskliste <----*
0 System Process
4 System
368 smss.exe
464 csrss.exe
500 winlogon.exe
556 services.exe
568 lsass.exe
832 svchost.exe
896 svchost.exe
1076 svchost.exe
1104 svchost.exe
1248 spoolsv.exe
1388 alg.exe
1560 NCS.EXE
1660 svchost.exe
1844 Explorer.EXE
856 qttask.exe
284 MPAPI3d.exe
868 ctfmon.exe
572 WatsonTest.exe
3336 drwtsn32.exe
*----> Modulliste <----*
(0000000000400000 - 0000000000409000: C:\MyProjects\WatsonTest\Release\WatsonTest.exe
(0000000063180000 - 00000000631e5000: C:\WINDOWS\system32\SHLWAPI.dll
(0000000077bd0000 - 0000000077bd7000: C:\WINDOWS\system32\VERSION.dll
(0000000077be0000 - 0000000077c33000: C:\WINDOWS\system32\msvcrt.dll
(0000000077c40000 - 0000000077c80000: C:\WINDOWS\system32\GDI32.dll
(0000000077d10000 - 0000000077d96000: C:\WINDOWS\system32\USER32.dll
(0000000077da0000 - 0000000077e3c000: C:\WINDOWS\system32\ADVAPI32.dll
(0000000077e40000 - 0000000077f38000: C:\WINDOWS\system32\kernel32.dll
(0000000077f40000 - 0000000077fee000: C:\WINDOWS\System32\ntdll.dll
(0000000078000000 - 000000007807e000: C:\WINDOWS\system32\RPCRT4.dll
Die Informationen in dieser Datei sind recht einfach zu verstehen. Unter der Zeile "Anwendungsausnahme
aufgetreten" erscheint der Name und die Prozeß-ID der Anwendung, in der der Crash verursacht worden ist,
in diesem Fall also meine Datei WatsonTest.exe. Datum und Uhrzeit des Crashs werden ebenso aufgeführt
wie die Nummer der Exception, die den Crash verursacht hat. Diese Nummer kann in aller Regel in der C++ -
Headerdatei WINERROR.H nachgeschlagen werden, dort steht auch beschrieben, wie sie sich zusammensetzt.
In diesem Fall steht ja sogar dabei "Division durch Null", so daß man sich diese Arbeit sparen kann.
Dann folgen einige Systeminformationen: Angaben über meinen PC, über
den oder die Prozessoren, das Betriebssystem, und den angemeldeten
Benutzer.
Dann folgt die Taskliste, eine Liste aller Prozesse, die auf dem Rechner zum Zeitpunkt des Crashes aktiv
waren. Jeder Prozeß hat eine Prozeß-ID, und diese ist jeweils mit angegeben.
Dann folgt die Modulliste, das ist die Liste aller DLL's, die mein
Crash - Prozess zum Zeitpunkt des Crashs im Speicher geladen hatte.
Dies ist unter Windows XP und Server 2003 deutlich schöner als früher,
weil unter Windows NT und 2000 häufig nur Nummern angegeben wurden, und
der DLL - Name konnte nur ermittelt werden, wenn Debug- Informationen
über diese DLL verfügbar waren. Die Zahlen vornedran geben die
Speicheradressen an (von - bis), unter der die jeweilige DLL im
Prozess-Speicher geladen war. Daraus kann man dann z.B. folgern, in
welcher DLL man gerade war, als der Crash passiert ist, weil ja weiter
unten auch der Instruction Pointer (IP-Register) angegeben wird (also
die Speicheradresse hinter dem Maschinenbefehl, der den Crash
verursacht hat).
Hinter diesem Teil folgt die eigentliche Analyse der Crash - Stelle.
|
Analyse des Logs: Die Crash - Stelle
Die Zeilen mit den Informationen zur Crash - Stelle sehen folgendermaßen aus:
*----> Statusabbild für Threadkennung 0xcf0 <----*
eax=00000000 ebx=7ffdf000 ecx=00000000 edx=00000000 esi=80000002 edi=631af1ab
eip=00401009 esp=0012ff84 ebp=0012ffc0 iopl=0 nv up ei pl zr na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000 efl=00000246
*** WARNING: Unable to verify checksum for C:\MyProjects\WatsonTest\Release\WatsonTest.exe
*** ERROR: Module load completed but symbols could not be loaded for C:\MyProjects\WatsonTest\
Release\WatsonTest.exe
Funktion: WatsonTest
00400ff4 0000 add [eax],al
00400ff6 0000 add [eax],al
00400ff8 0000 add [eax],al
00400ffa 0000 add [eax],al
00400ffc 0000 add [eax],al
00400ffe 0000 add [eax],al
00401000 6a0a push 0xa
00401002 b896140000 mov eax,0x1496
00401007 59 pop ecx
00401008 99 cdq
FEHLER ->00401009 f7f9 idiv ecx
0040100b 49 dec ecx
0040100c 79fa jns WatsonTest+0x1008 (00401008)
0040100e 33c0 xor eax,eax
00401010 c3 ret
00401011 55 push ebp
00401012 8bec mov ebp,esp
00401014 6aff push 0xff
00401016 68a0504000 push 0x4050a0
0040101b 686c1c4000 push 0x401c6c
00401020 64a100000000 mov eax,fs:[00000000]
*----> Stack Back Trace <----*
*** ERROR: Symbol file could not be found. Defaulted to export symbols for C:\WINDOWS\system32\
kernel32.dll -
WARNING: Stack unwind information not available. Following frames may be wrong.
ChildEBP RetAddr Args to Child
0012ffc0 77e614c7 631af1ab 80000002 7ffdf000 WatsonTest+0x1009
0012fff0 00000000 00401011 00000000 78746341 kernel32!GetCurrentDirectoryW+0x44
Die ersten drei Zeilen des Statusabbilds sind die Prozessorregister des
Threads, der den Crash verursacht hat, zum Zeitpunkt des Crashs.
Dahinter folgen 21 Zeilen Disassembler, nämlich der Maschinencode um
die Stelle herum, an der der Crash passiert ist. Die fehlerhafte
Anweisung ist dabei mit dem Begriff "FEHLER" gesondert hervorgehoben.
In einer Multithreading - Applikation werden für jeden Thread diese
Informationen aufgeführt, ich habe hier aber nur einen Thread laufen.
Unter "Stack Back Trace" steht dann
erstmal die Warnung, daß zu meiner Systemdatei "Kernel32.DLL" keine
Debug- Informationen verfügbar sind. Einer meiner nächsten Artikel wird
dieses Problem behandeln (wo man die entsprechenden Betriebssystem -
Debugdateien herbekommt). Entsprechend steht auch dabei "Following
frames may be wrong", was in der Tat stimmt: Der Call Stack, der
darunter aufgeführt wird, ist teilweise falsch (im Bereich KERNEL32),
und teilweise sehr dürftig (wir wissen nur, daß es in der WatsonTest
passiert ist, und statt eines Funktionsnamens steht lediglich ein
Offset dabei, nämlich 0x1009).
Ich habe also zunächst die Debugdatei
für die Kernel32.DLL besorgt, und dann meine Projekteinstellungen
verändert, um den Crash nochmal zu provozieren, und bessere
Informationen zu bekommen.
Als erstes habe ich in C++ unter der
"Release - Konfiguration" eingestellt, daß keine Optimierung erfolgen
soll ("Project / Settings / C/C++ / Optimizations" = Disable(Debug)).
Auch in Visual Basic 6 kann man unter den Projekteinstellungen die
Optimierung ausschalten ("No Optimization"). Des weiteren habe ich
eingestellt, daß eine Datei mit Debuginformationen, eine sogenannte PDB
- Datei, mit erstellt wird ("Project / Settings / C/C++ / Debug Info" =
Program Database). Auch dies geht analog in Visual Basic 6 unter den
Projekteinstellungen ("Create Symbolic Debug Info"). Beim Linker habe
ich ebenfalls noch zwei Einstellungen gemacht: "Project / Settings /
Link", dort werden die Häkchen "Gerenate debug info" und "Generate
mapfile" angekreuzt. Dies alles sorgt dafür, daß zu meiner Release -
Version zusätzliche Informationen für die Debugger mitgeliefert werden,
wobei ich zu den Nachteilen nachher noch zu sprechen komme.
Wenn ich jetzt einen neuen Crash damit erzeuge, sehen die Informationen im Dr. Watson - Log schon viel
besser aus:
*----> Statusabbild für Threadkennung 0x8ec <----*
eax=00000000 ebx=7ffdf000 ecx=00320758 edx=00000000 esi=80000002 edi=631af1ab
eip=00401029 esp=0012ff78 ebp=0012ff80 iopl=0 nv up ei pl zr na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000 efl=00000246
*** WARNING: Unable to verify checksum for C:\MyProjects\WatsonTest\Release\WatsonTest.exe
Funktion: WatsonTest!main
00401006 c745fc96140000 mov dword ptr [ebp-0x4],0x1496
0040100d c745f80a000000 mov dword ptr [ebp-0x8],0xa
00401014 eb09 jmp WatsonTest!main+0x1f (0040101f)
00401016 8b45f8 mov eax,[ebp-0x8]
00401019 83e801 sub eax,0x1
0040101c 8945f8 mov [ebp-0x8],eax
0040101f 837df800 cmp dword ptr [ebp-0x8],0x0
00401023 7c0c jl WatsonTest!main+0x31 (00401031)
00401025 8b45fc mov eax,[ebp-0x4]
00401028 99 cdq
FEHLER ->00401029 f77df8 idiv dword ptr [ebp-0x8] ss:0023:0012ff78=00000000
0040102c 8945fc mov [ebp-0x4],eax
0040102f ebe5 jmp WatsonTest!main+0x16 (00401016)
00401031 33c0 xor eax,eax
00401033 8be5 mov esp,ebp
00401035 5d pop ebp
00401036 c3 ret
WatsonTest!mainCRTStartup:
00401037 55 push ebp
00401038 8bec mov ebp,esp
0040103a 6aff push 0xff
*----> Stack Back Trace <----*
ChildEBP RetAddr Args to Child
0012ff80 004010eb 00000001 00320c00 00320c48 WatsonTest!main+0x29
0012ffc0 77e614c7 631af1ab 80000002 7ffdf000 WatsonTest!mainCRTStartup+0xb4
0012fff0 00000000 00401037 00000000 78746341 kernel32!BaseProcessStart+0x23 (FPO: [Non-Fpo])
*----> Raw Stack Dump <----*
000000000012ff78 00 00 00 00 00 00 00 00 - c0 ff 12 00 eb 10 40 00 ..............@.
000000000012ff88 01 00 00 00 00 0c 32 00 - 48 0c 32 00 ab f1 1a 63 ......2.H.2....c
000000000012ff98 02 00 00 80 00 f0 fd 7f - 94 00 00 c0 00 00 00 00 ................
000000000012ffa8 94 ff 12 00 a8 fb 12 00 - e0 ff 12 00 7c 1d 40 00 ............|.@.
000000000012ffb8 c0 60 40 00 00 00 00 00 - f0 ff 12 00 c7 14 e6 77 .`@............w
000000000012ffc8 ab f1 1a 63 02 00 00 80 - 00 f0 fd 7f 94 00 00 c0 ...c............
000000000012ffd8 c8 ff 12 00 a8 fb 12 00 - ff ff ff ff 09 48 e7 77 .............H.w
000000000012ffe8 10 12 e7 77 00 00 00 00 - 00 00 00 00 00 00 00 00 ...w............
000000000012fff8 37 10 40 00 00 00 00 00 - 41 63 74 78 20 00 00 00 7.@.....Actx ...
0000000000130008 01 00 00 00 4c 06 00 00 - 7c 00 00 00 00 00 00 00 ....L...|.......
0000000000130018 20 00 00 00 00 00 00 00 - 14 00 00 00 01 00 00 00 ...............
0000000000130028 03 00 00 00 34 00 00 00 - ac 00 00 00 01 00 00 00 ....4...........
0000000000130038 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00 ................
0000000000130048 00 00 00 00 02 00 00 00 - 00 00 00 00 00 00 00 00 ................
0000000000130058 00 00 00 00 64 01 00 00 - 90 01 00 00 00 00 00 00 ....d...........
0000000000130068 5b 49 59 2d f4 02 00 00 - 32 00 00 00 28 03 00 00 [IY-....2...(...
0000000000130078 b4 02 00 00 10 00 00 00 - 02 00 00 00 8c 00 00 00 ................
0000000000130088 02 00 00 00 01 00 00 00 - ac 00 00 00 30 05 00 00 ............0...
0000000000130098 01 00 00 00 02 00 00 00 - dc 05 00 00 70 00 00 00 ............p...
00000000001300a8 01 00 00 00 53 73 48 64 - 2c 00 00 00 01 00 00 00 ....SsHd,.......
Jetzt sieht man zum Beispiel unter dem "Stack Back Trace" den korrekten
Call Stack, also daß die Crash - Funktion "main" heißt. Des weiteren
ist der Code nicht mehr optimiert, das heißt der Assembler - Code
spiegelt exakt das wieder, was auch in C programmiert worden ist. Man
sieht jetzt in der Fehlerzeile deutlicher, was passiert ist: die IDIV -
Instruktion bekommt als Operanden (Der Nenner!) einen Wert vom Stack,
nämlich [ebp-0x8]. Wer meinen Artikel über den Stack Frame gelesen hat, weiß, daß
es sich dabei nur um die lokale Variable "i" handeln kann. Die Speicherstelle und der Wert des Operanden
sind auch explizit angegeben (0012ff78=00000000), aber bei dem Fehler "Division durch Null" war das ja schon
vorher klar.
Dieses Beispiel war sehr einfach, in einer komplizierteren Funktion
sieht die Sache schon etwas schwerer aus. Man sollte schon ein klein
wenig Assembler kennen, um noch tiefer forschen zu können. Wer meinen Stack Frame
- Artikel gelesen hat, erkennt oben sehr schnell den Prolog (ab der
ersten Zeile, Initialisierung der lokalen Variablen) und den Epilog (ab
der Zeile "mov esp,ebp"). Außerdem kann man zur Übung in dem oben
gezeigten Stack Dump ein wenig lesen, dieses könnte in komplizierteren
Fällen wichtig sein.
Wie schon versprochen, komme ich nochmal
zu den Nachteilen, die man sich mit den Debug - Informationen und dem
Verzicht auf Optimierung erkauft. Der C++ - Compiler ist in der Lage,
den Sourcecode beim Übersetzen in Maschinensprache sehr stark zu
optimieren. Dabei werden viele Zeilen aber stark umgebaut, so daß man
hinterher nur schwer oder gar nicht mehr wiedererkennt, welche
Assembler - Zeile eigentlich welcher Sourcecode - Zeile entspricht.
Deshalb ist es zur Fehlersuche vorteilhaft, nicht - optimierten Code zu
verwenden. Dieser kann jedoch deutlich langsamer sein als der
standardmäßige Release - Code. Das Ausliefern einer PDB- und MAP-Datei
zusammen mit der EXE kann dazu führen, daß der Kunde, der diese Dateien
erhält, mit etwas Ahnung den kompletten Sourcecode der Anwendung
herleiten kann. Das sollte man sich also ebenfalls genau überlegen.
|
Analyse eines Crashdumps
Im ersten Teil wurde bereits erklärt,
wo das Crashdump abgelegt wird, und wie es heißt (Einstellung "Speicherabbild").
Dieses Crashdump kann man auf dem Rechner, auf dem der Crash passiert
ist, sichern, und von einem Debugger einlesen (der kann durchaus auf
einer ganz anderen Maschine sein). Wichtig ist dabei nur, daß man
möglichst versuchen sollte, das Crashdump in denselben Ordner zu legen,
in dem auch alle Binärdateien des Projekts liegen, also zum Beispiel in
den Unterordner "Release" in einem C++ - Projekt. Dann kann sich der
Debugger alle benötigten Zusatzinformationen ebenfalls beschaffen. Auch
die Versionen (Projektdateien und abgestürzte EXE) sollten passen, weil
bei nachträglichen Änderungen am Projekt natürlich alle diese Dateien
in Tabellenform durcheinander geraten. Daher empfiehlt es sich immer,
wenn man ein Release zum Kunden nach draußen gibt, das komplette
Projekt mitsamt den Ausgabedateien separat zu sichern.
In
dem Beispiel, welches ich hier gleich zeige, habe ich auf dem Crash -
Rechner neben der EXE auch die zugehörige MAP und die PDB - Datei mit
ausgeliefert. Der Vorteil liegt darin, daß im Crashdump optimale
Informationen über alle denkbaren Details des Crashs drin enthalten
sind, und die Auswertung sehr einfach ist. Man kann auch ohne diese
beiden Dateien im Nachhinein die Crashursache analysieren, es ist nur
deutlich aufwändiger (siehe dazu den Buchtip "Debugging Applications").
Im folgenden habe ich den Debugger "WinDBG" benutzt, den man bei Microsoft frei herunterladen kann
(er gehört zu den "Debugging Tools für Windows").
Im WinDBG gehe ich einfach hin und sage "File / Open Crash Dump", und
kann dann meine Datei "user.dmp" auswählen, die auf der Crashmaschine
erstellt worden ist. Daraufhin bekomme ich folgendes zu sehen:

Da frohlockt das Herz jedes Entwicklers, denn das sind alle
Informationen, die man sich nur wünschen kann: Es wird die Stelle im
Sourcecode exakt angegeben, bei der der Crash passiert ist, und
nebenbei gibt es auch noch ein Fenster mit allen Variablenwerten zum
Crashzeitpunkt. Auch einen Call Stack könnte ich mir noch anzeigen
lassen, der sieht dann so ähnlich aus wie oben im Logfile schon gezeigt.
Wenn man den WinDBG zum ersten Mal startet, muß man ihm sagen, wo die
Debug - Symbole für das verwendete Betriebssystem liegen, damit auch
die Zeilen aus Systemfunktionen im Debugger richtig angezeigt werden.
Es empfiehlt sich, einen Microsoft Webserver dazu zu verwenden (des
sogenannten "Symbol Server"), da es sehr müßig ist, von Hand alle diese
Dateien zu besorgen (sie ändern sich bei jedem Servicepack).
Informationen hierzu findet man unter "Microsoft Symbol Server".
In Visual Studio .NET kann man ein Dumpfile ganz einfach reinladen, da
gibt es im "Datei / Öffnen" - Auswahlfenster eine extra Kategorie "Dump
Files (*.dmp, *.mdmp)". Angeblich kann man so ein Dumpfile auch in den
Visual C++ 6.0 - Debugger reinladen, ich habe es aber noch nie selbst
geschafft (man kriegt nur eine hexadezimale Bytewüste gezeigt). Wenn es
also jemand weiß, bin ich dankbar für einen Tip!
|
Buchtips

|
"Debugging Applications"
von John Robbins ist ein sehr wertvolles Buch für jeden, der unter
Windows - Betriebssystemen nach Fehlern sucht. Es ist zwar im Jahr 2000
erschienen und damit schon etwas alt (.NET kommt gar nicht vor), aber
weil es bei den Grundlagen des Windows- Debuggings ansetzt, ist es
sicher noch einige Jahre aktuell. Der Crash-Behandlung ist ein eigenes
Kapitel gewidmet. Ich habe das Buch fast in einem Zug "verschlungen",
und es ist heute eines meiner wichtigsten Nachschlagewerke.
Informationen zum Buch
John Robbins Webseite
|
 Details
|
 Details
|
"Taschenratgeber: Windows 2000 , Windows XP"
Diese Bücher sind der praktische Ratgeber für die tägliche Arbeit von
Netzwerkadministratoren in kleinen, mittleren und großen Unternehmen.
Ideal für den Arbeitsplatz oder den Einsatz unterwegs, denn diese
Bücher zeigen Ihnen sofort die Antworten auf Fragen in den
verschiedensten Situationen der Windows 2000 / XP - Administration und
des Supports. Aber auch Windows - Poweruser können von diesem Buch
profitieren. Übersichtliche Tabellen, Listen, Befehle und zahllose
Schritt-für-Schritt-Anleitungen zeichnen diese Bücher aus: kurz, klar,
präzise.
|
Win 2000
 Details
|
Win XP / 2003
 Details
|
"Windows Befehle - kurz & gut"
von Aeleen Frisch enthält praktisch alle Kommandozeilenbefehle, die man
unter Windows zur Verfügung hat. Angefangen von den klassischen DOS -
Befehlen über die Active Directory Konfiguration bis zur Prozeß- und
Threadverwaltung ist alles drin, was das Herz des Skript -
Programmierers begehrt.
Kleines, wertvolles Taschenbuch für weniger als 10 Euro: ein Muß für jeden Windows - Administrator.
|
|
Support, Feedback, Anregungen
Alles verstanden ? Oder noch Fragen ? Wir freuen uns über Feedback zu
den Tips, auch über Verbesserungsvorschläge. Schreiben Sie an support@a-m-i.de.
|
|