Tracing through the Stack Heuristically

-One way of tracing through the call stack is to assume that every word on the stack which looks like a ROM code address is a saved return -address. We say that this heuristic because: -

-
some data words may look like code addresses in ROM.
-
-
there may be saved return addresses left over from previous -function calls. For example, suppose that F() calls -A() and then B() in sequence. A() itself -calls X(), which calls Y(). If a crash occurs in -B(), the saved return addresses from the calls to X() -and Y() are still present on the stack and may be mistaken for -function calls occuring while B() is active.
-
This scenario happens frequently when B() -allocates a buffer (e.g. TBuf) on the stack which overlaps -old stack frames.
-
-
-
-

If you want to trace applications loaded into RAM, then stack -tracing is more difficult because RAM-loaded DLLs are given addresses assigned -at load time.

On ARM, the stack pointer starts at the higher address end and -moves 'down' towards the lower address end. This means that values at the top -of the memory dump are more recent. You need to look back through this for code -addresses. For ROM code this will be words with most significant byte in the -range 0xF8 to 0xFF, remembering that they are -little-endian. This can either be done manually, or automatically using the -printsym.pl perl script, which can be found in -...\epoc32\tools.

Let's follow this in an example session:

-
Decide whether the crash has been caused by a panic or an -exception using the f command:
-
.f
Fault Category: EXAMPLE Fault Reason: 0000002a
ExcId 00000000 CodeAddr 00000000 DataAddr 00000000 Extra 00000000
-
-
This shows that the crash was caused by a panic, so now use the -r command to find -the CPU mode and the stack pointer:
-
.r
MODE_USR:
R0=6571de54 R1=0000002a R2=00000002 R3=ffffffff
R4=0000002a R5=f8170414 R6=6571df14 R7=6403cba8
R8=00000001 R9=6403c41c R10=640002f8 R11=6571de70
R12=00000020 R13=00404e00 R14=f80818c0 R15=f800bfa8
CPSR=60000013
MODE_FIQ:
R8=00000000 R9=ffffffff R10=ffffffff R11=00000000
R12=00000000 R13=64000d0c R14=c080079c SPSR=e00000dc
MODE_IRQ:
R13=6400110c R14=00000013 SPSR=20000013
MODE_SVC:
R13=6571de54 R14=f80328bc SPSR=60000010
MODE_ABT:
R13=6400090c R14=ffff0010 SPSR=400000d7
MODE_UND:
R13=6400090c R14=95221110 SPSR=f000009d
-
The panic happened in supervisor mode, because CPSR & -0x1F == 0x13, so R13Svc, i.e. the value of R13 -shown under MODE_SVC: in the above display, is the stack pointer -to look at; this has the value 0x6571DE54.
-
-
Using the -m command to look -at memory starting at location 0x6571DE54 gives:
-
.m6571de54+200
6571de54: 07 00 00 10 14 04 17 f8 00 00 00 00 d4 4e 40 00 .............N@.
6571de64: e8 de 71 65 74 de 71 65 74 fb 16 f8 88 28 03 f8 ..qet.qet....(..
6571de74: 0c d4 03 f8 64 35 03 f8 00 00 00 00 00 00 00 00 ....d5..........
6571de84: d0 00 00 00 14 df 71 65 a8 cb 03 64 a8 cb 03 64 ......qe...d...d
6571de94: d0 00 00 00 14 df 71 65 1c df 71 65 ec 4e 40 00 ......qe..qe.N@.
6571dea4: 1c c4 03 64 b4 2a 03 f8 00 00 00 00 14 df 71 65 ...d.*........qe
6571deb4: d0 de 71 65 c4 de 71 65 b0 ab 03 f8 00 00 00 00 ..qe..qe........
6571dec4: e0 ba 03 64 14 df 71 65 1c df 71 65 01 00 00 00 ...d..qe..qe....
6571ded4: 1c c4 03 64 f8 02 00 64 10 df 71 65 ec de 71 65 ...d...d..qe..qe
6571dee4: 84 da 01 f8 5c fb 16 f8 00 4e 40 00 00 00 00 00 ....\....N@.....
6571def4: 00 4e 40 00 00 00 00 00 d3 00 00 00 ec 4e 40 00 .N@..........N@.
6571df04: d4 df 71 65 14 df 71 65 e0 db 01 f8 c0 d9 01 f8 ..qe..qe........
6571df14: a8 cb 03 64 e0 ba 03 64 01 00 01 00 00 00 00 00 ...d...d........
6571df24: 00 00 00 00 d4 4e 40 00 00 00 00 30 40 00 00 00 .....N@....0@...
6571df34: 13 00 00 60 98 df 71 65 48 df 71 65 f4 81 00 f8 ...`..qeH.qe....
6571df44: 8c 7a 00 f8 68 df 71 65 58 df 71 65 6c df 71 65 .z..h.qeX.qel.qe
6571df54: 60 df 71 65 0c 2b 00 f8 bc 2a 00 f8 84 df 71 65 `.qe.+...*....qe
6571df64: 70 df 71 65 e4 7d 04 f8 08 2b 00 f8 0d 00 00 00 p.qe.}...+......
6571df74: 0a 00 00 30 40 00 00 00 54 65 73 74 44 6d 61 53 ...0@...TestDmaS
6571df84: 69 6d 04 f8 a9 4b 40 00 b8 df 71 65 9c df 71 65 im...K@...qe..qe
6571df94: 2c be 00 f8 2c bd 00 f8 38 4c 40 0d 01 00 00 00 ,...,...8L@.....
6571dfa4: 00 00 00 00 84 2d 02 f8 d4 df 71 65 bc df 71 65 .....-....qe..qe
6571dfb4: b8 2d 02 f8 dc bd 00 f8 54 a4 00 f8 00 00 00 00 .-......T.......
6571dfc4: ac da 01 f8 10 00 00 60 d8 df 71 65 70 74 00 f8 .......`..qept..
6571dfd4: b8 da 01 f8 d4 4e 40 00 20 f7 16 f8 d0 4e 40 00 .....N@. ....N@.
6571dfe4: 00 00 00 00 00 00 00 00 ec 4e 40 00 40 00 00 00 .........N@.@...
-
We can look for potential ROM addresses by scanning the log and -look up the corresponding function name in the symbol file generated -using the MAKSYM tool . The first -one is 0xF8170414 at offset 4 in the memory dump. -
-
-
Alternatively, we can use the printsym.pl perl -script, passing it the dump output. The following is part of the output:
-
R:\base\e32\rombuild>perl -S printsym.pl ASSABETARM4D.symbol
ROM Symbols from ASSABETARM4D.symbol
Please enter data to be decoded
6571de54: 07 00 00 10 14 04 17 f8 00 00 00 00 d4 4e 40 00 .............N@.
= 10000007 ....
= f8170414 .... etext=. + 0x0
= 00000000 ....
= 00404ed4 .N@.
6571de64: e8 de 71 65 74 de 71 65 74 fb 16 f8 88 28 03 f8 ..qet.qet....(..
= 6571dee8 ..qe
= 6571de74 t.qe
= f816fb74 t... DDmaTestChannel::DoCreate(int, TDesC8 const *, TVersion const &
) + 0x24
= f8032888 .(.. Kern::Fault(char const *, int) + 0xc
6571de74: 0c d4 03 f8 64 35 03 f8 00 00 00 00 00 00 00 00 ....d5..........
= f803d40c .... RHeap::Alloc(int) + 0xf4
= f8033564 d5.. Kern::MutexSignal(DMutex &) + 0xc
= 00000000 ....
= 00000000 ....

[............ truncated ...............]

= f801da84 .... DLogicalDevice::ChannelCreate(DLogicalChannelBase *&, TChannelC
reateInfo &) + 0xd0
= f816fb5c \... DDmaTestChannel::DoCreate(int, TDesC8 const *, TVersion const &
) + 0xc
= 00404e00 .N@.
= 00000000 ....
6571def4: 00 4e 40 00 00 00 00 00 d3 00 00 00 ec 4e 40 00 .N@..........N@.
= 00404e00 .N@.
= 00000000 ....
= 000000d3 ....
= 00404eec .N@.
6571df04: d4 df 71 65 14 df 71 65 e0 db 01 f8 c0 d9 01 f8 ..qe..qe........
= 6571dfd4 ..qe
= 6571df14 ..qe
= f801dbe0 .... ExecHandler::ChannelCreate(TDesC8 const &, TChannelCreateInfo &
, int) + 0x134
= f801d9c0 .... DLogicalDevice::ChannelCreate(DLogicalChannelBase *&, TChannelC
reateInfo &) + 0xc

[.......................... truncated .........................]

= f8022db8 .-.. ExecHandler::DebugPrint(void *, int) + 0x34
= f800bddc .... A::UserDebugPrint(unsigned char const *, int, int) + 0xc
= f800a454 T... EpocSlowExecTable + 0xc
= 00000000 ....
6571dfc4: ac da 01 f8 10 00 00 60 d8 df 71 65 70 74 00 f8 .......`..qept..
= f801daac .... ExecHandler::ChannelCreate(TDesC8 const &, TChannelCreateInfo &
, int) + 0x0
= 60000010 ...`
= 6571dfd8 ..qe
= f8007470 pt.. __ArmVectorSwi + 0xd8
6571dfd4: b8 da 01 f8 d4 4e 40 00 20 f7 16 f8 d0 4e 40 00 .....N@. ....N@.
= f801dab8 .... ExecHandler::ChannelCreate(TDesC8 const &, TChannelCreateInfo &
, int) + 0xc
= 00404ed4 .N@.
= f816f720 ... etext=. + 0x560
= 00404ed0 .N@.
6571dfe4: 00 00 00 00 00 00 00 00 ec 4e 40 00 40 00 00 00 .........N@.@...
= 00000000 ....
= 00000000 ....
= 00404eec .N@.
= 00000040 @...
^C
R:\base\e32\rombuild>
-
There are several false positives in this output (and even more -in the truncated parts). So some study of the source code is needed to discard -the noise and find the actual call stack. Here it is (innermost frame -first):
-
- -
  Kern::Fault
  -
- -
  DDmaTestChannel::DoCreate
  -
- -
  ExecHandler::ChannelCreate
  -
- -
  __ArmVectorSwi
  -
-
Note that for the sake of the example, a call to Kern::Fault() was deliberately inserted into -DDmaTestChannel::DoCreate().
-
All other function names are false positives and should be -ignored
-

Related tasks

- + + + Tracing through the Stack Heuristically + + + +

Tracing through the Stack Heuristically

+One way of tracing through the call stack is to assume that every word on the stack which looks like a ROM code address is a saved return +address. We say that this heuristic because: +

+
some data words may look like code addresses in ROM.
+
+
there may be saved return addresses left over from previous +function calls. For example, suppose that F() calls +A() and then B() in sequence. A() itself +calls X(), which calls Y(). If a crash occurs in +B(), the saved return addresses from the calls to X() +and Y() are still present on the stack and may be mistaken for +function calls occuring while B() is active.
+
This scenario happens frequently when B() +allocates a buffer (e.g. TBuf) on the stack which overlaps +old stack frames.
+
+
+
+

If you want to trace applications loaded into RAM, then stack +tracing is more difficult because RAM-loaded DLLs are given addresses assigned +at load time.

On ARM, the stack pointer starts at the higher address end and +moves 'down' towards the lower address end. This means that values at the top +of the memory dump are more recent. You need to look back through this for code +addresses. For ROM code this will be words with most significant byte in the +range 0xF8 to 0xFF, remembering that they are +little-endian. This can either be done manually, or automatically using the +printsym.pl perl script, which can be found in +...\epoc32\tools.

Let's follow this in an example session:

+
Decide whether the crash has been caused by a panic or an +exception using the f command:
+
.f
Fault Category: EXAMPLE Fault Reason: 0000002a
ExcId 00000000 CodeAddr 00000000 DataAddr 00000000 Extra 00000000
+
+
This shows that the crash was caused by a panic, so now use the +r command to find +the CPU mode and the stack pointer:
+
.r
MODE_USR:
R0=6571de54 R1=0000002a R2=00000002 R3=ffffffff
R4=0000002a R5=f8170414 R6=6571df14 R7=6403cba8
R8=00000001 R9=6403c41c R10=640002f8 R11=6571de70
R12=00000020 R13=00404e00 R14=f80818c0 R15=f800bfa8
CPSR=60000013
MODE_FIQ:
R8=00000000 R9=ffffffff R10=ffffffff R11=00000000
R12=00000000 R13=64000d0c R14=c080079c SPSR=e00000dc
MODE_IRQ:
R13=6400110c R14=00000013 SPSR=20000013
MODE_SVC:
R13=6571de54 R14=f80328bc SPSR=60000010
MODE_ABT:
R13=6400090c R14=ffff0010 SPSR=400000d7
MODE_UND:
R13=6400090c R14=95221110 SPSR=f000009d
+
The panic happened in supervisor mode, because CPSR & +0x1F == 0x13, so R13Svc, i.e. the value of R13 +shown under MODE_SVC: in the above display, is the stack pointer +to look at; this has the value 0x6571DE54.
+
+
Using the +m command to look +at memory starting at location 0x6571DE54 gives:
+
.m6571de54+200
6571de54: 07 00 00 10 14 04 17 f8 00 00 00 00 d4 4e 40 00 .............N@.
6571de64: e8 de 71 65 74 de 71 65 74 fb 16 f8 88 28 03 f8 ..qet.qet....(..
6571de74: 0c d4 03 f8 64 35 03 f8 00 00 00 00 00 00 00 00 ....d5..........
6571de84: d0 00 00 00 14 df 71 65 a8 cb 03 64 a8 cb 03 64 ......qe...d...d
6571de94: d0 00 00 00 14 df 71 65 1c df 71 65 ec 4e 40 00 ......qe..qe.N@.
6571dea4: 1c c4 03 64 b4 2a 03 f8 00 00 00 00 14 df 71 65 ...d.*........qe
6571deb4: d0 de 71 65 c4 de 71 65 b0 ab 03 f8 00 00 00 00 ..qe..qe........
6571dec4: e0 ba 03 64 14 df 71 65 1c df 71 65 01 00 00 00 ...d..qe..qe....
6571ded4: 1c c4 03 64 f8 02 00 64 10 df 71 65 ec de 71 65 ...d...d..qe..qe
6571dee4: 84 da 01 f8 5c fb 16 f8 00 4e 40 00 00 00 00 00 ....\....N@.....
6571def4: 00 4e 40 00 00 00 00 00 d3 00 00 00 ec 4e 40 00 .N@..........N@.
6571df04: d4 df 71 65 14 df 71 65 e0 db 01 f8 c0 d9 01 f8 ..qe..qe........
6571df14: a8 cb 03 64 e0 ba 03 64 01 00 01 00 00 00 00 00 ...d...d........
6571df24: 00 00 00 00 d4 4e 40 00 00 00 00 30 40 00 00 00 .....N@....0@...
6571df34: 13 00 00 60 98 df 71 65 48 df 71 65 f4 81 00 f8 ...`..qeH.qe....
6571df44: 8c 7a 00 f8 68 df 71 65 58 df 71 65 6c df 71 65 .z..h.qeX.qel.qe
6571df54: 60 df 71 65 0c 2b 00 f8 bc 2a 00 f8 84 df 71 65 `.qe.+...*....qe
6571df64: 70 df 71 65 e4 7d 04 f8 08 2b 00 f8 0d 00 00 00 p.qe.}...+......
6571df74: 0a 00 00 30 40 00 00 00 54 65 73 74 44 6d 61 53 ...0@...TestDmaS
6571df84: 69 6d 04 f8 a9 4b 40 00 b8 df 71 65 9c df 71 65 im...K@...qe..qe
6571df94: 2c be 00 f8 2c bd 00 f8 38 4c 40 0d 01 00 00 00 ,...,...8L@.....
6571dfa4: 00 00 00 00 84 2d 02 f8 d4 df 71 65 bc df 71 65 .....-....qe..qe
6571dfb4: b8 2d 02 f8 dc bd 00 f8 54 a4 00 f8 00 00 00 00 .-......T.......
6571dfc4: ac da 01 f8 10 00 00 60 d8 df 71 65 70 74 00 f8 .......`..qept..
6571dfd4: b8 da 01 f8 d4 4e 40 00 20 f7 16 f8 d0 4e 40 00 .....N@. ....N@.
6571dfe4: 00 00 00 00 00 00 00 00 ec 4e 40 00 40 00 00 00 .........N@.@...
+
We can look for potential ROM addresses by scanning the log and +look up the corresponding function name in the symbol file generated +using the MAKSYM tool . The first +one is 0xF8170414 at offset 4 in the memory dump. +
+
+
Alternatively, we can use the printsym.pl perl +script, passing it the dump output. The following is part of the output:
+
R:\base\e32\rombuild>perl -S printsym.pl ASSABETARM4D.symbol
ROM Symbols from ASSABETARM4D.symbol
Please enter data to be decoded
6571de54: 07 00 00 10 14 04 17 f8 00 00 00 00 d4 4e 40 00 .............N@.
= 10000007 ....
= f8170414 .... etext=. + 0x0
= 00000000 ....
= 00404ed4 .N@.
6571de64: e8 de 71 65 74 de 71 65 74 fb 16 f8 88 28 03 f8 ..qet.qet....(..
= 6571dee8 ..qe
= 6571de74 t.qe
= f816fb74 t... DDmaTestChannel::DoCreate(int, TDesC8 const *, TVersion const &
) + 0x24
= f8032888 .(.. Kern::Fault(char const *, int) + 0xc
6571de74: 0c d4 03 f8 64 35 03 f8 00 00 00 00 00 00 00 00 ....d5..........
= f803d40c .... RHeap::Alloc(int) + 0xf4
= f8033564 d5.. Kern::MutexSignal(DMutex &) + 0xc
= 00000000 ....
= 00000000 ....

[............ truncated ...............]

= f801da84 .... DLogicalDevice::ChannelCreate(DLogicalChannelBase *&, TChannelC
reateInfo &) + 0xd0
= f816fb5c \... DDmaTestChannel::DoCreate(int, TDesC8 const *, TVersion const &
) + 0xc
= 00404e00 .N@.
= 00000000 ....
6571def4: 00 4e 40 00 00 00 00 00 d3 00 00 00 ec 4e 40 00 .N@..........N@.
= 00404e00 .N@.
= 00000000 ....
= 000000d3 ....
= 00404eec .N@.
6571df04: d4 df 71 65 14 df 71 65 e0 db 01 f8 c0 d9 01 f8 ..qe..qe........
= 6571dfd4 ..qe
= 6571df14 ..qe
= f801dbe0 .... ExecHandler::ChannelCreate(TDesC8 const &, TChannelCreateInfo &
, int) + 0x134
= f801d9c0 .... DLogicalDevice::ChannelCreate(DLogicalChannelBase *&, TChannelC
reateInfo &) + 0xc

[.......................... truncated .........................]

= f8022db8 .-.. ExecHandler::DebugPrint(void *, int) + 0x34
= f800bddc .... A::UserDebugPrint(unsigned char const *, int, int) + 0xc
= f800a454 T... EpocSlowExecTable + 0xc
= 00000000 ....
6571dfc4: ac da 01 f8 10 00 00 60 d8 df 71 65 70 74 00 f8 .......`..qept..
= f801daac .... ExecHandler::ChannelCreate(TDesC8 const &, TChannelCreateInfo &
, int) + 0x0
= 60000010 ...`
= 6571dfd8 ..qe
= f8007470 pt.. __ArmVectorSwi + 0xd8
6571dfd4: b8 da 01 f8 d4 4e 40 00 20 f7 16 f8 d0 4e 40 00 .....N@. ....N@.
= f801dab8 .... ExecHandler::ChannelCreate(TDesC8 const &, TChannelCreateInfo &
, int) + 0xc
= 00404ed4 .N@.
= f816f720 ... etext=. + 0x560
= 00404ed0 .N@.
6571dfe4: 00 00 00 00 00 00 00 00 ec 4e 40 00 40 00 00 00 .........N@.@...
= 00000000 ....
= 00000000 ....
= 00404eec .N@.
= 00000040 @...
^C
R:\base\e32\rombuild>
+
There are several false positives in this output (and even more +in the truncated parts). So some study of the source code is needed to discard +the noise and find the actual call stack. Here it is (innermost frame +first):
+
- +
  Kern::Fault
  +
- +
  DDmaTestChannel::DoCreate
  +
- +
  ExecHandler::ChannelCreate
  +
- +
  __ArmVectorSwi
  +
+
Note that for the sake of the example, a call to Kern::Fault() was deliberately inserted into +DDmaTestChannel::DoCreate().
+
All other function names are false positives and should be +ignored
+

Related tasks

\ No newline at end of file