Chapter 2 - First interpretation of a debug log. |
The aim of this first read of a debug log is to identify:
- the crash reason
- the name of the crashed program
- the location of the crash point inside the program
The reference log is "hitmania.log.num" and is available in the hitmania.lha
archive.
001> --------------------------------------------
002>
003> ASM_Exception: DAR 0x0 DSISR 0xa000000
The Data Address Register (DAR) contains 0.
That means the program did an illegal memory access to the address 0.
004> ASM_Exception: IntGPR1 0xc02fb8 SRR0 0x21240a34 SRR1 0xf030 LR 0x21240a5c
005> ASM_Exception: Type 0x3
006> ASM_Exception: Thread 0xe0e640 Name ABox
007> ASM_Exception: DAR 0x0 DSISR 0xa000000
008>
009>
010> ------------------------------------------------
011> Quark Thread:
012> TID 0000000010020010
013> Name ABox
014> Exception 3 <Illegal Data Access at 00000000 DSISR 0a000000, Store is not allowed because of protection modes>
The program did an illegal memory write ("Store") to the address 0.
015> SRR0 0x21240a34 SRR1 0x0000f030
016> LR 0x21240a5c CTR 0x10115934
017> CR 0x22002022 XER 0x20000000
018> GPR[00] 212408cc 21184ba0 21185110 00000000 00000000 fffffff7 00000004 00000004
019> GPR[08] 20850000 20850000 20850000 20850000 24002022 00000000 21184d08 087805bd
020> GPR[16] 0000000a 0000000a 00000000 226e89b4 2260ce14 226e89b0 00000001 08983385
021> GPR[24] 226e89b0 08212584 2085bcb4 20850000 20850000 20850000 20850000 2260cd30
022> FPSCR 43efff0000104050
023> FPR[00] 0000000000000000 0000000000000000 f787e60fc099915d fc6f40a94a3f1345
024> FPR[04] 0000000000000000 0000000000000000 0000000000000000 0000000000000000
025> FPR[08] 0000000000000000 3ff0000000000000 0000000000000000 3f40624dd2f1a9fc
026> FPR[12] 3ff0000000000000 4009faed64015a8b 0000000000000000 0000000000000000
027> FPR[16] 0000000000000000 0000000000000000 0000000000000000 0000000000000000
028> FPR[20] 0000000000000000 0000000000000000 0000000000000000 0000000000000000
029> FPR[24] 0000000000000000 0000000000000000 0000000000000000 0000000000000000
030> FPR[28] 0000000000000000 0000000000000000 0000000000000000 216200a000157800
031> IABR 00000000
032> DABR 00000000
033> MMCR0 00000000
034> MMCR1 00000000
035> MMCR2 00000000
036> PMC1 00000000 PMC2 00000000 PMC3 00000000 PMC4 00000000
037> SIA 00000000
038> SDA 00000000
039>
040> PPCStackFrame History:
041> StackFrame[-0].LR-> Address 0x212408cc -> hitmania Hunk 1 Offset 0x000004bc
042> StackFrame[-1].LR-> Address 0x212406ac -> hitmania Hunk 1 Offset 0x0000029c
043> StackFrame[-2].LR-> Address 0x10248f5c -> Module Hunk 0 Offset 0x00148f5c
044> StackFrame[-3].LR-> Address 0x1024d9b0 -> Module Hunk 0 Offset 0x0014d9b0
045> StackFrame[-4].LR-> Address 0x1024d6b0 -> Module Hunk 0 Offset 0x0014d6b0
046> StackFrame[-5].LR-> Address 0x102b5b1c -> Module Hunk 0 Offset 0x001b5b1c
047> StackFrame[-6].LR-> Address 0x102b20e4 -> Module Hunk 0 Offset 0x001b20e4
048> StackFrame[-7].LR-> Address 0x102b1328 -> Module Hunk 0 Offset 0x001b1328
049> StackFrame[-8].LR-> Address 0x102b0dd8 -> Module Hunk 0 Offset 0x001b0dd8
050> StackFrame[-9].LR-> Address 0x10241da0 -> Module Hunk 0 Offset 0x00141da0
051> StackFrame[-10].LR-> Address 0x10241bf0 -> Module Hunk 0 Offset 0x00141bf0
052> StackFrame[-11].LR-> Address 0x10241e64 -> Module Hunk 0 Offset 0x00141e64
053> **************************************************************
054> **************************************************************
055> ABox State
056> Hardware:
057> Openfirmware..skip for now
058> ExecBase: SysBase 0x20000c38
059> SysFlags 0x0000c000 AttnResched 0x00000000 IDNestCnt -1 TDNestCnt -1
060> ThisTask 0x2260cd30 TaskReady 0x2002b954 TaskWait 0x200359c4
061> ResModules 0x20004dd0
062> TaskTrapCode 0x10100970 TaskExceptCode 0x10100670 TaskExitCode 0x101006cc
063> TaskSigAlloc 0xffff TaskTrapAlloc 0x8000
064> IdleCount 743136
065> DispCount 3310554
066> Quantum 4
067> Elapsed 2
068> VBlankFrequency 50 PowerSupplyFrequency 50 EClockFrequency 709379
069> MainTID 0x10020010
070> SchedulerTID 0x10020012
071> SchedulerSig 0x80000000
072> OldSRR0 0x0
073> ConfigServerTID 0x10000013
074> Int0: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
075> Int1: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
076> Int2: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
077> Int3: iv_Code 0x1010055c iv_Data 0x20004ba8 iv_Node 0x00000000
078> Int4: iv_Code 0x1010055c iv_Data 0x20004bc8 iv_Node 0x00000000
079> Int5: iv_Code 0x1010055c iv_Data 0x20004bb8 iv_Node 0x00000000
080> Interrupt 0x20012e4e <graphics.library>
081> Code 0x101503bc Data 0x20012e04
082> Interrupt 0x208488ec <ixemul timer interrupt>
083> Code 0x2083c654 Data 0x00000000
084> Interrupt 0x204d213c <PPC 50Hz Timer>
085> Code 0x204d2134 Data 0x204d2028
086> Int6: iv_Code 0x101503c4 iv_Data 0x20012e04 iv_Node 0x20012e7a
087> Int7: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
088> Int8: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
089> Int9: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
090> Int10: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
091> Int11: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
092> Int12: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
093> Int13: iv_Code 0x1010055c iv_Data 0x20004bd8 iv_Node 0x00000000
094> Int14: iv_Code 0x00000000 iv_Data 0x00000000 iv_Node 0x00000000
095> Int15: iv_Code 0x1010055c iv_Data 0x20004be8 iv_Node 0x00000000
096> **************************************************************
097> **************************************************************
098> **************************************************************
099> **************************************************************
100>
101>
102> Running Task
103>
104>
105> **************************************************************
106> **************************************************************
107> Task 0x2260cd30 Name 0x226e89b4 <Shell Process> Type 13 Pri 0
The name of the crashed task is "Shell Process".
108> Flags 0x8 State 2 IDNestCnt -1 TDNestCnt -1
109> SigAlloc 0x0000ffff SigWait 0x00000100 SigRecvd 0x04008120 SigExcept 0x00000000
110> ExceptCode 0x10100670 ExceptData 0x00000000 TrapCode 0x10100970 TrapData 0x00000000
111> Switch 0x00000000 Launch 0x00000000 UserData 0x215fc21c
112> SPLower 0x21623c48 SPUpper 0x216ff7e8 SPReg 0x226e8950
113> ----------------------------------------------------------------------
114> ETask 0x2081f2b4
115> MemPool 0x205bc788 PPCLibData 0x00000000
116> PPCSPLower 0x2117d204 PPCSPUpper 0x21185200
117> PPCTrapMsgPort 0x00000000 PPCTrapMessage 0x20774fd4
118> PPCRegFrame 0x211848e0
119> Private[] 0x00000000 0x00000000 0x00000000 0x00000000
120> EmulHandle 0x00000000
121> ----------------------------------------------------------------------
122> EmulHandle 0x21185110 Type 0x00000004 Flags 0x00000001
123> SuperHandle 0x10001000 Type 0x00000000 WaitMask 0x00000000 SyncMask 0x00000000
124> USP 0x00000000 SSP 0x20004818 VBR 0x2000ded0
125> SFC 0x00000000 DFC 0x00000000 CACR 0x00000000 TC 0x00000000
126> ITT0 0x00000000 ITT1 0x00000000 DTT0 0x00000000 DTT1 0x00000000
127> URP 0x00000000 SRP 0x00000000 BUSCR 0x00000000 PCR 0x04310000
128> ----------------------------------------------------------------------
129> SRR0 0x21240a34 SRR1 0x0000f030
130> LR 0x21240a5c CTR 0x10115934
131> CR 0x22002022 XER 0x20000000
132> GPR[00] 212408cc 21184ba0 21185110 00000000 00000000 fffffff7 00000004 00000004
133> GPR[08] 20850000 20850000 20850000 20850000 24002022 00000000 21184d08 087805bd
134> GPR[16] 0000000a 0000000a 00000000 226e89b4 2260ce14 226e89b0 00000001 08983385
135> GPR[24] 226e89b0 08212584 2085bcb4 20850000 20850000 20850000 20850000 2260cd30
136> SRR0 -> hitmania Hunk 1 Offset 0x00000624
The task crashed in the "hitmania" program, at offset 0x624.
More information about the SRR0 register in the chapter 7.
137> LR -> hitmania Hunk 1 Offset 0x0000064c
The crashed function was called from another part of the code in the
"hitmania" program: around offset 0x64c. This will be explained in the
chapter 4.
More information about the LR register in the chapter 7.
138> CTR -> Module Hunk 0 Offset 0x00015934
139>
140> PPCStackFrame History:
141> StackFrame[-0].LR-> Address 0x212408cc -> hitmania Hunk 1 Offset 0x000004bc
142> StackFrame[-1].LR-> Address 0x212406ac -> hitmania Hunk 1 Offset 0x0000029c
143> StackFrame[-2].LR-> Address 0x10248f5c -> Module Hunk 0 Offset 0x00148f5c
144> StackFrame[-3].LR-> Address 0x1024d9b0 -> Module Hunk 0 Offset 0x0014d9b0
145> StackFrame[-4].LR-> Address 0x1024d6b0 -> Module Hunk 0 Offset 0x0014d6b0
146> StackFrame[-5].LR-> Address 0x102b5b1c -> Module Hunk 0 Offset 0x001b5b1c
147> StackFrame[-6].LR-> Address 0x102b20e4 -> Module Hunk 0 Offset 0x001b20e4
148> StackFrame[-7].LR-> Address 0x102b1328 -> Module Hunk 0 Offset 0x001b1328
149> StackFrame[-8].LR-> Address 0x102b0dd8 -> Module Hunk 0 Offset 0x001b0dd8
150> StackFrame[-9].LR-> Address 0x10241da0 -> Module Hunk 0 Offset 0x00141da0
151> StackFrame[-10].LR-> Address 0x10241bf0 -> Module Hunk 0 Offset 0x00141bf0
152> StackFrame[-11].LR-> Address 0x10241e64 -> Module Hunk 0 Offset 0x00141e64
The PPCStackFrame History lists previously executed code sections.
Is is mentioned more indepth in the chapter 4.
153> Full PPC mode: Last 68k context
154> PC 87654321 SR 0008
155> Dn[0] 00000014 00100000 00002000 00000000 00000000 00000000 00000000 00000000
156> An[0] 215fc0c8 00000000 00000000 00000000 00000000 00000000 20000c38 216ff7e0
157> Stack: 0x216ff7e0
158> A7[-32] 00000000 00000000 00000000 00000000
159> A7[-16] 00000000 00000000 00000000 11328720
160> A7[000] 000dbba0 226e89b0 219317a8 0008fd78
161> A7[016] 00000000 00000000 00000000 00000000
162> A7[032] 00000000 00000000 00000000 00000000
163> A7[048] 00000000 00000000 00000000 00000000
164> A7[064] 00000000 00000000 00000000 00000000
165> A7[080] 00000000 00000000 00000000 00000000
166> A7[096] 00000000 00000000 00000000 00000000
167> A7[112] 00000000 00000000 00000000 00000000
168> Last saved PPCThread State:
169> SRR0 0x25 SRR1 0x20000c38 LR 0x2260cd30 R1 0x21184cc0
170> GPR[00] 00000030 21184cc0 21185110 21030ca0 000043b0 00010001 00000000 00000000
171> GPR[08] 00000000 20000000 21030b90 20000c38 24004029 216ff7dc 80000004 00000008
172> GPR[16] 10001000 00000004 00000000 11007000 1100859c 11008348 110084c0 1100873c
173> GPR[24] 11008748 21185110 00000000 0816f1e3 20534788 21184d28 21184cc8 20000c38
174> FPSCR 43efff0024002022
175> FPR[00] 0000000000000000 0000000000000000 f787e60fc099915d fc6f40a94a3f1345
176> FPR[04] 0000000000000000 0000000000000000 0000000000000000 0000000000000000
177> FPR[08] 0000000000000000 211849f000000000 0000000000000000 21184a101100708c
178> FPR[12] 0000000000000000 21184a1064015a8b 0000000000000000 21184b70110087ec
179> FPR[16] fffffffa88002022 0000000021184d08 087805bd0000000a 0000000a00000000
180> FPR[20] 226e89b42260ce14 226e89b000000001 08983385226e89b0 082125842085bcb4
181> FPR[24] 2085000000000000 215fc0c320850000 000000082260cd30 21184c1010253218
182> FPR[28] 0000000000000000 21184a9000000000 0000000000000000 21184ac010109390
183> CTR -> Module Hunk 0 Offset 0x000098d8
184>
185> ----------------------------------------------------------------------
186> SegList 0x081dd3c6 GlobVec 0x202dbaf8
187> StackBase 0x08588f12 StackSize 0x000dbba0
188> TaskNum 0x00000006 Result2 0x00000000
189> CurrentDir 0x081dd3cd CIS 0x0878043b
190> COS 0x087804f3 CES 0x00000000
191> ConsoleTask 0x207754c0 FileSystemTask 0x200099ac
192> CLI 0x0878033d ReturnAddr 0x216ff7e0
193> PktWait 0x00000000 WindowPtr 0x00000000
194> HomeDir 0x081c99d1 Flags 0x00000024
195> ExitCode 0x00000000 ExitData 0x00000000
196> Arguments 0x2085bcb4 ShellPrivate 0x00000000
197> CmdName: <hitmania>
198> **************************************************************
199> **************************************************************
The gathered information:
- The "Shell Process" task did an illegal memory write to the address 0.
- The faulty code is located at the offset 0x624 in the "hitmania" program.
- The crashed code was called from another part of the code located around
the offset 0x64c in the "hitmania" program.
This is the basis for any debugging.
It is now possible to search for the 0x624 offset in the hitmania program and
to know which part of the source code is corresponding to it.