world leader in high performance signal processing
Trace: » analyzing_traces

Analyzing Traces

One feature of the Blackfin that comes in handy is the hardware trace buffer. The cpu automatically tracks the last 16 code flow changes in this buffer. When an application crashes and the kernel catches it, the hardware buffer will automatically be displayed.

Often times there will be a lot of execution in uClibc's ldso (ld-uClibc-*) before/during a crash. This is due to how functions get looked up in shared libraries. You can workaround this by disabling lazy relocation (which tells the ldso to resolve all bindings at startup rather than during runtime). This can be done by linking with -Wl,-z,now or exporting the LD_BIND_NOW environment variable during runtime.

If the trace output by the kernel does not include symbols but just addresses, this is because you disabled the KALLSYMS option in the kernel configuration menu. You can convert the addresses by hand using the appropriate System.map file, but you should just turn back on the kernel option to make things easier. Especially if you plan on sending the dump to someone else … addresses alone are completely useless to people without knowing the symbol layout.

Null Pointer Access

For example, let's look at a program that does a null pointer access.

file: user/blkfin-test/crash_test/traps_test.c

scm failed with exit code 1:
file does not exist in git

Compile this with:

rgetz@imhotep:~/uClinux-dist> make user/blkfin-test/crash_test_only

Transfer it to the target. When we run it, the application should crash on us.

root:/> /traps_test -p -v 27

Running test 27 for exception 0x27: Data access multiple CPLB hits/Null Pointer Read
... NULL pointer access
Deferred Exception context
CURRENT PROCESS:
COMM=traps_test PID=183
CPU = 0
TEXT = 0x003f0040-0x003f8cc0        DATA = 0x003f8cc4-0x003fbd70
 BSS = 0x003fbd70-0x003fc1f4  USER-STACK = 0x003fdf70

return address: [0x003f048e]; contents of:
0x003f0460:  0a25  0000  e14a  ffc0  e800  0000  e10a  0014
0x003f0470:  e140  003f  9111  e100  a484  e801  0000  e200
0x003f0480:  0a15  0000  e800  0000  6802  e140  003f [9111]
0x003f0490:  e100  a494  e801  0000  e200  0a08  e14a  8765

ADSP-BF537-0.2 500(MHz CCLK) 100(MHz SCLK) (mpu off)
Linux version 2.6.30-ADI-2010R1-pre-svn6860 (rgetz@imhotep) (gcc version 4.3.3 (ADI-trunk/svn-3407) ) #255 Sun Jun 28 22:30:01 EDT 2009

SEQUENCER STATUS:               Not tainted
 SEQSTAT: 00062027  IPEND: 0008  IMASK: ffff  SYSCFG: 0006
  EXCAUSE   : 0x27
  physical IVG3 asserted : <0xffa006e4> { _trap + 0x0 }
 RETE: <0x00000000> /* Maybe null pointer? */
 RETN: <0x032ea000> /* kernel dynamic memory */
 RETX: <0x00000480> /* Maybe fixed code section */
 RETS: <0x003f1190> [ traps_test + 0x1150 ]
 PC  : <0x003f048e> [ traps_test + 0x44e ]
DCPLB_FAULT_ADDR: <0x00000000> /* Maybe null pointer? */
ICPLB_FAULT_ADDR: <0x003f048e> [ traps_test + 0x44e ]

PROCESSOR STATE:
 R0 : 003f01b0    R1 : 003fdd78    R2 : 00000000    R3 : 00000008
 R4 : 00000004    R5 : 00000001    R6 : 003faa14    R7 : 003fdefc
 P0 : 000001b0    P1 : 0000001f    P2 : 00000000    P3 : 00000001
 P4 : 003fdf74    P5 : 003fbb88    FP : 003fdd94    SP : 032e9f24
 LB0: 003f2c07    LT0: 003f2c06    LC0: 00000000
 LB1: 003f417b    LT1: 003f4174    LC1: 00000000
 B0 : 00000000    L0 : 00000000    M0 : 00000000    I0 : 003fdb3c
 B1 : 00000000    L1 : 00000000    M1 : 00000000    I1 : 00000000
 B2 : 00000000    L2 : 00000000    M2 : 00000000    I2 : 00000000
 B3 : 00000000    L3 : 00000000    M3 : 00000000    I3 : 00000000
A0.w: 00000000   A0.x: 00000000   A1.w: 00000000   A1.x: 00000000
USP : 003fdd94  ASTAT: 02003024

Hardware Trace:
   0 Target : <0x00004f50> { _trap_c + 0x0 }
     Source : <0xffa00678> { _exception_to_level5 + 0x94 } CALL pcrel
   1 Target : <0xffa005e4> { _exception_to_level5 + 0x0 }
     Source : <0xffa004bc> { _bfin_return_from_exception + 0x20 } RTX
   2 Target : <0xffa0049c> { _bfin_return_from_exception + 0x0 }
     Source : <0xffa00538> { _ex_trap_c + 0x4c } JUMP.S
   3 Target : <0xffa004ec> { _ex_trap_c + 0x0 }
     Source : <0xffa003c4> { _ex_workaround_261 + 0x1c } JUMP.S
   4 Target : <0xffa003a8> { _ex_workaround_261 + 0x0 }
     Source : <0xffa0074c> { _trap + 0x68 } JUMP (P4)
   5 Target : <0xffa00704> { _trap + 0x20 }
     Source : <0xffa00700> { _trap + 0x1c } IF !CC JUMP
   6 Target : <0xffa006e4> { _trap + 0x0 }
     Source : <0xffa004bc> { _bfin_return_from_exception + 0x20 } RTX
   7 Target : <0xffa0049c> { _bfin_return_from_exception + 0x0 }
     Source : <0xffa003ba> { _ex_workaround_261 + 0x12 } IF !CC JUMP
   8 Target : <0xffa003a8> { _ex_workaround_261 + 0x0 }
     Source : <0xffa0074c> { _trap + 0x68 } JUMP (P4)
   9 Target : <0xffa00704> { _trap + 0x20 }
     Source : <0xffa00700> { _trap + 0x1c } IF !CC JUMP
  10 Target : <0xffa006e4> { _trap + 0x0 }
     Source : <0x003f048a> [ traps_test + 0x44a ] 0xe140
  11 Target : <0x003f0484> [ traps_test + 0x444 ]
     Source : <0x003f118e> [ traps_test + 0x114e ] CALL (P2)
  12 Target : <0x003f117a> [ traps_test + 0x113a ]
     Source : <0x003f4150> [ traps_test + 0x4110 ] RTS
  13 Target : <0x003f4148> [ traps_test + 0x4108 ]
     Source : <0x003f41c8> [ traps_test + 0x4188 ] IF CC JUMP
  14 Target : <0x003f41c4> [ traps_test + 0x4184 ]
     Source : <0x003f13b0> [ traps_test + 0x1370 ] RTS
  15 Target : <0x003f139c> [ traps_test + 0x135c ]
     Source : <0xffa00c32> { _common_int_entry + 0xda } RTI
Userspace Stack
Stack info:
 SP: [0x003fdd94] <0x003fdd94> [ traps_test + 0xdd94 ]
 FP: (0x003fdd94)
 Memory from 0x003fdd90 to 003fe000
003fdd90: 00000001 [003fdf00]<003f1190> 00000000  0000001b  00000027  003fb10c  00000000
003fddb0: 00000000  00000000  00000000  003fde08  0000001b  0000001b  00000000  00000001
003fddd0: 00000001  00000000  00000000  00000001  00000001  00000000  00000000  0000000b
003fddf0: 00000027  00000000  003fb78c  0000001b  00000000  00000001  00000000  00000000
003fde10: 00000000  00000000  00000000  00000000  00000000  00000000  00000000  00000000
003fde30: 00000000  00000000  00000000  00000000  00000000  00000000  00000000  00000004
003fde50: 00000000  00000000  00000000  003fde9c <003f2fa8> 00000000  00000110  00000000
003fde70: 00000000  003fde78  00000500  00000005  00001cb1  00008a3b  00000005  00000000
003fde90: 00000000  00000175  00008100  00000001  00000000  00000000  00000000  00000000
003fdeb0: 00000000  00000000  00001000  00000000  45984f00  00000000  45984f00  00000000
003fded0: 45984f00  00000000  00000000  00000000  00000000  00000000  00000000  00000001
003fdef0: 00000000  003fdf14  00000000  003fdfad  003fdf30 <003f442c> 003f8cc4  003fbbc0
003fdf10: 00000004  00000000  003fdf74  003fc01c  003f8c8c  00000000  003fdf74  00000000
003fdf30: 00000000 <0021663e> 003f8cc4  032ed59c  0026262c  00000000  00000000  00000000
003fdf50: 032ed55c <003f0894> 00000000  00000000  003f8c8c  003f8c9e  00000000  032ed5a0
003fdf70: 00000004  003fdf99  003fdfa5 <003fdfa8> 003fdfab  00000000  003fdfae  003fdfb9
003fdf90: 003fdfdc  00000000  72742f00  5f737061  74736574  00702d00  3200762d  45540037
003fdfb0: 6c3d4d52  78756e69  54415000  622f3d48  2f3a6e69  2f727375  3a6e6962  6962732f
003fdfd0: 752f3a6e  732f7273  006e6962  48535548  5245565f  4e4f4953  312e313d  00322e34
003fdff0: 6172742f  745f7370  00747365  00000000  00937960
Return addresses in stack:
   frame  1 : <0x003f1190> [ traps_test + 0x1150 ]
    address : <0x003f2fa8> [ traps_test + 0x2f68 ]
   frame  2 : <0x003f442c> [ traps_test + 0x43ec ]
   frame  3 : <0x0021663e> [ sh + 0x1663e ]
    address : <0x003f0894> [ traps_test + 0x854 ]
    address : <0x003fdfa8> [ traps_test + 0xdfa8 ]
SEGV

We can take this trace output and use it with the disassembled output from the application. What we're interested is the ICPLB_FAULT_ADDR relative address - [ traps_test + 0x44e ]. To get the disassembled output, we run bfin-uclinux-objdump on the traps_test.gdb file produced while compiling the application into a flat binary. Then we check out the offsets in the output that were indicated by the hardware trace.

rgetz@imhotep:~/uClinux-dist> bfin-uclinux-objdump -d user/blkfin-test/crash_test/traps_test.gdb | less
00000444 <_null_pointer_read>:
     444:       00 e8 00 00     LINK 0x0;               /* (0) */
     448:       02 68           P2 = 0x0 (X);           /*              P2=0x0(  0) */
     44a:       40 e1 00 00     R0.H = 0x0;             /* (  0)        R0=0xa440(42048) */
     44e:       11 91           R1 = [P2];
     450:       00 e1 50 a4     R0.L = 0xa450;          /* (-23472)     R0=0xa450(42064) */
     454:       01 e8 00 00     UNLINK;
     458:       00 e2 08 0a     JUMP.L 0x1868 <_GI_printf>;

rgetz@imhotep:~/uClinux-dist> bfin-linux-uclibc-addr2line -f -e user/blkfin-test/crash_test/traps_test.gdb  0x44e
null_pointer_read
/home/rgetz/blackfin/trunk/uClinux-dist/user/blkfin-test/crash_test/traps_test.c:238
rgetz@imhotep:~/uClinux-dist> awk '{print FNR “\t” $0}' /home/rgetz/blackfin/trunk/uClinux-dist/user/blkfin-test/crash_test/traps_test.c | sed -n '235,239p'
235     void null_pointer_read(void)
236     {
237             int *i = 0;
238             printf("%i", *i);
239     }

Unaligned Data Access

For example, let's look at a program that uses unaligned data access.

file: user/blkfin-test/crash_test/traps_test.c

scm failed with exit code 1:
file does not exist in git

Compile this with:

rgetz@imhotep:~/uClinux-dist> make user/blkfin-test/crash_test_only

Transfer it to the target. When we run it, the application should crash on us.

root:/> ./traps_test -p -v 19
Running test 19 for exception 0x24: Data read misaligned address violation
... Data access misaligned address violation
 - Attempted misaligned data memory or data cache access.
Deferred Exception context
CURRENT PROCESS:
COMM=traps_test PID=180
CPU = 0
TEXT = 0x003f0040-0x003f8cc0        DATA = 0x003f8cc4-0x003fbd70
 BSS = 0x003fbd70-0x003fc1f4  USER-STACK = 0x003fdf70

return address: [0x003f04cc]; contents of:
0x003f04a0:  e800  0000  e10a  4320  e140  003f  9111  e100
0x003f04b0:  a968  e801  0000  e200  09f9  0000  e14a  8765
0x003f04c0:  e800  0000  e10a  4321  e140  003f [9111] e100
0x003f04d0:  a968  e801  0000  e200  09e9  0000  05fd  e14d

ADSP-BF537-0.2 500(MHz CCLK) 100(MHz SCLK) (mpu off)
Linux version 2.6.30-ADI-2010R1-pre-svn6860 (rgetz@imhotep) (gcc version 4.3.3 (ADI-trunk/svn-3407) ) #255 Sun Jun 28 22:30:01 EDT 2009

SEQUENCER STATUS:               Not tainted
 SEQSTAT: 00062024  IPEND: 0008  IMASK: ffff  SYSCFG: 0006
  EXCAUSE   : 0x24
  physical IVG3 asserted : <0xffa006e4> { _trap + 0x0 }
 RETE: <0x00000000> /* Maybe null pointer? */
 RETN: <0x0086a000> /* kernel dynamic memory */
 RETX: <0x00000480> /* Maybe fixed code section */
 RETS: <0x003f1190> [ traps_test + 0x1150 ]
 PC  : <0x003f04cc> [ traps_test + 0x48c ]
DCPLB_FAULT_ADDR: <0x87654320> /* kernel dynamic memory */
ICPLB_FAULT_ADDR: <0x003f04cc> [ traps_test + 0x48c ]

PROCESSOR STATE:
 R0 : 003f0130    R1 : 003fdd78    R2 : 00000000    R3 : 00000008
 R4 : 00000004    R5 : 00000001    R6 : 003faa14    R7 : 003fdefc
 P0 : 00000130    P1 : 0000001f    P2 : 87654321    P3 : 00000001
 P4 : 003fdf74    P5 : 003fbb88    FP : 003fdd94    SP : 00869f24
 LB0: 003f2c07    LT0: 003f2c06    LC0: 00000000
 LB1: 003f417b    LT1: 003f4174    LC1: 00000000
 B0 : 00000000    L0 : 00000000    M0 : 00000000    I0 : 003fdb3c
 B1 : 00000000    L1 : 00000000    M1 : 00000000    I1 : 00000000
 B2 : 00000000    L2 : 00000000    M2 : 00000000    I2 : 00000000
 B3 : 00000000    L3 : 00000000    M3 : 00000000    I3 : 00000000
A0.w: 00000000   A0.x: 00000000   A1.w: 00000000   A1.x: 00000000
USP : 003fdd94  ASTAT: 02003024

Hardware Trace:
   0 Target : <0x00004f50> { _trap_c + 0x0 }
     Source : <0xffa00678> { _exception_to_level5 + 0x94 } CALL pcrel
   1 Target : <0xffa005e4> { _exception_to_level5 + 0x0 }
     Source : <0xffa004bc> { _bfin_return_from_exception + 0x20 } RTX
   2 Target : <0xffa0049c> { _bfin_return_from_exception + 0x0 }
     Source : <0xffa00538> { _ex_trap_c + 0x4c } JUMP.S
   3 Target : <0xffa004ec> { _ex_trap_c + 0x0 }
     Source : <0xffa0074c> { _trap + 0x68 } JUMP (P4)
   4 Target : <0xffa00704> { _trap + 0x20 }
     Source : <0xffa00700> { _trap + 0x1c } IF !CC JUMP
   5 Target : <0xffa006e4> { _trap + 0x0 }
     Source : <0x003f04c8> [ traps_test + 0x488 ] 0xe140
   6 Target : <0x003f04bc> [ traps_test + 0x47c ]
     Source : <0x003f118e> [ traps_test + 0x114e ] CALL (P2)
   7 Target : <0x003f117a> [ traps_test + 0x113a ]
     Source : <0x003f4150> [ traps_test + 0x4110 ] RTS
   8 Target : <0x003f4148> [ traps_test + 0x4108 ]
     Source : <0x003f41c8> [ traps_test + 0x4188 ] IF CC JUMP
   9 Target : <0x003f41c4> [ traps_test + 0x4184 ]
     Source : <0x003f13b0> [ traps_test + 0x1370 ] RTS
  10 Target : <0x003f139c> [ traps_test + 0x135c ]
     Source : <0xffa00c32> { __common_int_entry + 0xda } RTI
  11 Target : <0xffa00bd0> { __common_int_entry + 0x78 }
     Source : <0xffa00f8c> { _evt_system_call + 0x64 } JUMP.S
  12 Target : <0xffa00f8c> { _evt_system_call + 0x64 }
     Source : <0xffa008d4> { _system_call + 0xb8 } RTS
  13 Target : <0xffa008d0> { _system_call + 0xb4 }
     Source : <0xffa008c0> { _system_call + 0xa4 } IF !CC JUMP
  14 Target : <0xffa008ba> { _system_call + 0x9e }
     Source : <0xffa008aa> { _system_call + 0x8e } IF !CC JUMP
  15 Target : <0xffa00884> { _system_call + 0x68 }
     Source : <0x00022bf4> { _sys_nanosleep + 0x1c } RTS
Userspace Stack
Stack info:
 SP: [0x003fdd94] <0x003fdd94> [ traps_test + 0xdd94 ]
 FP: (0x003fdd94)
 Memory from 0x003fdd90 to 003fe000
003fdd90: 00000001 [003fdf00]<003f1190> 00000000  00000013  00000024  003fb018  00000000
003fddb0: 00000000  00000000  00000000  003fde08  00000013  00000013  00000000  00000001
003fddd0: 00000001  00000000  00000000  00000001  00000001  00000000  00000000  00000007
003fddf0: 00000024  00000000  003fb70c  00000013  00000000  00000001  00000000  00000000
003fde10: 00000000  00000000  00000000  00000000  00000000  00000000  00000000  00000000
003fde30: 00000000  00000000  00000000  00000000  00000000  00000000  00000000  00000004
003fde50: 00000000  00000000  00000000  003fde9c <003f2fa8> 00000000  00000110  00000000
003fde70: 00000000  003fde78  00000500  00000005  00001cb1  00008a3b  00000005  00000000
003fde90: 00000000  00000175  00008100  00000001  00000000  00000000  00000000  00000000
003fdeb0: 00000000  00000000  00001000  00000000  45984f00  00000000  45984f00  00000000
003fded0: 45984f00  00000000  00000000  00000000  00000000  00000000  00000000  00000001
003fdef0: 00000000  003fdf14  00000000  003fdfad  003fdf30 <003f442c> 003f8cc4  003fbbc0
003fdf10: 00000004  00000000  003fdf74  003fc01c  003f8c8c  00000000  003fdf74  00000000
003fdf30: 00000000 <0021663e> 003f8cc4  032ed55c  0026262c  00000000  00000000  00000000
003fdf50: 032ed51c <003f0894> 00000000  00000000  003f8c8c  003f8c9e  00000000  032ed560
003fdf70: 00000004  003fdf99  003fdfa5 <003fdfa8> 003fdfab  00000000  003fdfae  003fdfb9
003fdf90: 003fdfdc  00000000  72742f00  5f737061  74736574  00702d00  3100762d  45540039
003fdfb0: 6c3d4d52  78756e69  54415000  622f3d48  2f3a6e69  2f727375  3a6e6962  6962732f
003fdfd0: 752f3a6e  732f7273  006e6962  48535548  5245565f  4e4f4953  312e313d  00322e34
003fdff0: 6172742f  745f7370  00747365  00000000  00937960
Return addresses in stack:
   frame  1 : <0x003f1190> [ traps_test + 0x1150 ]
    address : <0x003f2fa8> [ traps_test + 0x2f68 ]
   frame  2 : <0x003f442c> [ traps_test + 0x43ec ]
   frame  3 : <0x0021663e> [ sh + 0x1663e ]
    address : <0x003f0894> [ traps_test + 0x854 ]
    address : <0x003fdfa8> [ traps_test + 0xdfa8 ]
BUS

We can take this trace output and use it with the disassembled output from the application. What we're interested is the ICPLB_FAULT_ADDR relative address - [ traps_test + 0x48c ]. To get the disassembled output, we run bfin-uclinux-objdump on the traps_test.gdb file produced while compiling the application into a flat binary. Then we check out the offsets in the output that were indicated by the hardware trace.

$ bfin-uclinux-objdump -d user/blkfin-test/crash_test/traps_test.gdb | less
 <removed for readability>
0000047c <_data_read_odd_address>:
     47c:       4a e1 65 87     P2.H = 0x8765;          /* (-30875)     P2=0x87654320 */
     480:       00 e8 00 00     LINK 0x0;               /* (0) */
     484:       0a e1 21 43     P2.L = 0x4321;          /* (17185)      P2=0x87654321 */
     488:       40 e1 00 00     R0.H = 0x0;             /* (  0)        R0=0xa924(43300) */
     48c:       11 91           R1 = [P2];
     48e:       00 e1 24 a9     R0.L = 0xa924;          /* (-22236)     R0=0xa924(43300) */
     492:       01 e8 00 00     UNLINK;
     496:       00 e2 e9 09     JUMP.L 0x1868 <___GI_printf>;
 <removed for readability>

Indeed, we see that the register P2 is set to an unaligned value and then dereferenced.

To find the line of source code, you can use addr2line:

$ rgetz@imhotep:~/uClinux-dist> bfin-linux-uclibc-addr2line -f -e user/blkfin-test/crash_test/traps_test.gdb  0x48c
data_read_odd_address
/home/rgetz/blackfin/trunk/uClinux-dist/user/blkfin-test/crash_test/traps_test.c:182
rgetz@imhotep:~/uClinux-dist> awk '{print FNR “\t” $0}' /home/rgetz/blackfin/trunk/uClinux-dist/user/blkfin-test/crash_test/traps_test.c | sed -n '179,184p'
179     void data_read_odd_address(void)
180     {
181             int *i = (void *)0x87654321;
182             printf("%i\n", *i);
183     }
184

This indicates the file, function, and line number that the exception happened on. (which is pretty handy when you are looking in more complex examples).

addr2line will even work on the kernel, but you must have CONFIG_DEBUG_INFO turned on. (which is normally off by default).

Bad Pointers

If a pointer in an application gets corrupt (as is known to happen), this can be a little more difficult to find. Sometimes the last 16 change of flow will be in kernel, not telling you where in the application things have gone bad.

Think about the case if you have a bad pointer, that points to memory that doesn't exist. Here is a simplistic example, for illustrative purposes:

int main() {
        char *i = 0x87654321;
 
        *i = 'a';
}

If we compile this application as bfin-uclinux-gcc -mfdpic -O2 ./foo.c -o foo, and run this application on a kernel, we can get this error message:

root:~> /foo
DCPLB_FAULT_ADDR=87654321
ICPLB_FAULT_ADDR=002c0e5c
Hardware Trace:
 0 Target : <0x00004b84> { _dump_stack + 0x0 }
   Source : <0x00004e84> { _panic_cplb_error + 0x34 }
 1 Target : <0x00004e84> { _panic_cplb_error + 0x34 }
   Source : <0x0000d8bc> { _printk + 0x14 }
 2 Target : <0x0000d8b8> { _printk + 0x10 }
   Source : <0x0000d750> { _vprintk + 0x164 }
 3 Target : <0x0000d744> { _vprintk + 0x158 }
   Source : <0x0000d51c> { _release_console_sem + 0x124 }
 4 Target : <0x0000d514> { _release_console_sem + 0x11C }
   Source : <0x0000d504> { _release_console_sem + 0x10C }
 5 Target : <0x0000d47a> { _release_console_sem + 0x82 }
   Source : <0x0000d322> { __call_console_drivers + 0x5E }
 6 Target : <0x0000d31c> { __call_console_drivers + 0x58 }
   Source : <0x0000d2ec> { __call_console_drivers + 0x28 }
 7 Target : <0x0000d2c4> { __call_console_drivers + 0x0 }
   Source : <0x0000d476> { _release_console_sem + 0x7E }
 8 Target : <0x0000d470> { _release_console_sem + 0x78 }
   Source : <0x0000d53e> { _release_console_sem + 0x146 }
 9 Target : <0x0000d536> { _release_console_sem + 0x13E }
   Source : <0x0000d2c0> { ___call_console_drivers + 0x60 }
10 Target : <0x0000d2b4> { ___call_console_drivers + 0x54 }
   Source : <0x0008fc9c> { _bfin_console_write + 0x64 }
11 Target : <0x0008fc96> { _bfin_console_write + 0x5E }
   Source : <0x0008fc88> { _bfin_console_write + 0x50 }
12 Target : <0x0008fc7e> { _bfin_console_write + 0x46 }
   Source : <0x0008fc34> { _block_put_char + 0x28 }
13 Target : <0x0008fc1a> { _block_put_char + 0xE }
   Source : <0x0008fc20> { _block_put_char + 0x14 }
14 Target : <0x0008fc1a> { _block_put_char + 0xE }
   Source : <0x0008fc20> { _block_put_char + 0x14 }
15 Target : <0x0008fc1a> { _block_put_char + 0xE }
   Source : <0x0008fc20> { _block_put_char + 0x14 }

or

Data access CPLB miss
 - Used by the MMU to signal a CPLB miss on a data access.

CURRENT PROCESS:

return address: 0x0186d21e; contents of [PC-16...PC+8]:
0c42 17dc 6003 e801 0000 3003 0538 0010
0000 3212 3209 e800 0000 ad78 3218 0c42 X
bc48 b08a 1803 b051 2002 9319 0c40 1802

RETE:  00000000  RETN: 00478000  RETX: 0186d21e  RETS: 0186d2e6
IPEND: 0030  SYSCFG: 0036
SEQSTAT: 00000026    SP: 00477f24
R0: 004215cc    R1: 025d439c    R2: 00492f04    R3: 004215cc
R4: 00000029    R5: 004229e0    R6: 021403a8    R7: 00496550
P0: 00496550    P1: 025d439c    P2: 00492f04    P3: 004215cc
P4: 02140214    P5: 025d439c    FP: 003ba804
A0.w: 00000000    A0.x: 00000000    A1.w: 00000000    A1.x: 00000000
LB0: 018731a9  LT0: 0187319c  LC0: 00000000
LB1: 00711d87  LT1: 00711d44  LC1: 00000000
B0: 0000028c  L0: 00000000  M0: 00000000  I0: 00000283
B1: a00b4371  L1: 00000000  M1: 84502b1e  I1: 00000270
B2: fcccba94  L2: 00000000  M2: 6c5b5ef1  I2: 0000029c
B3: aefc9518  L3: 00000000  M3: 0abe0519  I3: 0000028b

USP: 003ba804   ASTAT: 02003004
DCPLB_FAULT_ADDR=87654321
ICPLB_FAULT_ADDR=002c0e5c


Hardware Trace:
 0 Target : <0x00004e64> { _trap_c + 0x0 }
   Source : <0x00008868> { _exception_to_level5 + 0xb4 }
 1 Target : <0x000087b4> { _exception_to_level5 + 0x0 }
   Source : <0x000087b2> { _ex_trap_c + 0x4e }
 2 Target : <0x0000870c> { _handle_bad_cplb + 0x0 }
   Source : <0x0000820c> { __cplb_hdr + 0x5c }
 3 Target : <0x0000820a> { __cplb_hdr + 0x5a }
   Source : <0x00004df6> { _panic_cplb_error + 0x16 }
 4 Target : <0x00004de0> { _panic_cplb_error + 0x0 }
   Source : <0x00008206> { __cplb_hdr + 0x56 }
 5 Target : <0x00008202> { __cplb_hdr + 0x52 }
   Source : <0x000081f2> { __cplb_hdr + 0x42 }
 6 Target : <0x000081ec> { __cplb_hdr + 0x3c }
   Source : <0x000081e6> { __cplb_hdr + 0x36 }
 7 Target : <0x000081e4> { __cplb_hdr + 0x34 }
   Source : <0x000081dc> { __cplb_hdr + 0x2c }
 8 Target : <0x000081d8> { __cplb_hdr + 0x28 }
   Source : <0x00008350> { _cplb_mgr + 0x140 }
 9 Target : <0x0000834c> { _cplb_mgr + 0x13c }
   Source : <0x000084b6> { _cplb_mgr + 0x2a6 }
10 Target : <0x000084ae> { _cplb_mgr + 0x29e }
   Source : <0x000084ba> { _cplb_mgr + 0x2aa }
11 Target : <0x000084ae> { _cplb_mgr + 0x29e }
   Source : <0x000084ca> { _cplb_mgr + 0x2ba }
12 Target : <0x000084ae> { _cplb_mgr + 0x29e }
   Source : <0x000084ca> { _cplb_mgr + 0x2ba }
13 Target : <0x000084ae> { _cplb_mgr + 0x29e }
   Source : <0x000084ca> { _cplb_mgr + 0x2ba }
14 Target : <0x000084ae> { _cplb_mgr + 0x29e }
   Source : <0x000084ca> { _cplb_mgr + 0x2ba }
15 Target : <0x000084ae> { _cplb_mgr + 0x29e }
   Source : <0x000084ca> { _cplb_mgr + 0x2ba }
Stack from 00477f04:
        00000000 0000886c 0012c790 0012c790 0012c78c 004215cc 00000029 00447e12
        0186d21e 00000030 00000026 00000000 00478000 0186d21e 0186d21e 0186d2e6
        004215cc 02003004 00711d87 018731a9 00711d44 0187319c 00000000 00000000
        00000000 00000000 00000000 00000000 aefc9518 fcccba94 a00b4371 0000028c
        00000000 00000000 00000000 00000000 0abe0519 6c5b5ef1 84502b1e 00000000
        0000028b 0000029c 00000270 00000283 003ba804 003ba804 025d439c 02140214
Call Trace:

Bus error

This may lead us to believe that the bad pointer is in kernel space, since the hardware trace is all in kernel space. However, if you think of what happens when you get a good/bad pointer:

  • hardware looks at the data access, and checks to see if it is in one of the 16 hardware CPLB enteries
    • if it is, it checks permissions (read/write userspace/kernel), and goes on it's way
    • if it is not, it signals a “Can't find CPLB table exception”
  • the exception handler takes the exception, and jumps to the kernel CPLB handler
  • the kernel CPLB handler jumps around looking for the accessed memory location in the software table.
    • if it finds it, it replaces an entry in the HW table, and jumps back, allowing the HW table to do it's job
    • if it can't find it, it jumps to an error condition
  • the error condition prints out the error.

This is the 2nd trace - You can see from here, that by the time the error condition is found, we have been in the kernel for a long time, and the HW trace is full of kernel space things, which don't have errors, and are doing their jobs properly.

In the trace, you can see the message:

DCPLB_FAULT_ADDR=87654321
ICPLB_FAULT_ADDR=002c0e5c

But, but you don't know why the bad address of 0x87654321 was being accessed, or what was running at the 0x2c0e5c in physical memory.

To reduce this problem, a kernel option of: Linux Kernel ConfigurationKernel hacking[ ]Trace user apps should be selected. The help for this option explains what it does:

Some pieces of the kernel contain a lot of flow changes which can
quickly fill up the hardware trace buffer.  When debugging crashes,
the hardware trace may indicate that the problem lies in kernel
space when in reality an application is buggy.

Say Y here to disable hardware tracing in some known "jumpy" pieces
of code so that the trace buffer will extend further back.

When this option is turned on, and the same application is run:

root:~> /foo
DCPLB_FAULT_ADDR=87654321
ICPLB_FAULT_ADDR=0357e65c
Hardware Trace:
 0 Target : <0x00008108> { _ex_dcplb + 0x0 }
   Source : <0x00008480> { _trap + 0x28 }
 1 Target : <0x00008458> { _trap + 0x0 }
   Source : <0x00008330> { _ex_single_step + 0x38 }
 2 Target : <0x0000832a> { _ex_single_step + 0x32 }
   Source : <0x00008118> { _ex_dcplb + 0x10 }
 3 Target : <0x00008108> { _ex_dcplb + 0x0 }
   Source : <0x00008480> { _trap + 0x28 }
 4 Target : <0x00008458> { _trap + 0x0 }
   Source : <0x0357e658> [ /foo + 0x658 ]
 5 Target : <0x0357e64c> [ /foo + 0x64C ]
   Source : <0x0035eda0> [ /lib/libuClibc-0.9.27.so + 0x1EDA0 ]
 6 Target : <0x0035ed8e> [ /lib/libuClibc-0.9.27.so + 0x1ED8E ]
   Source : <0x0035f054> [ /lib/libuClibc-0.9.27.so + 0x1F054 ]
 7 Target : <0x0035f048> [ /lib/libuClibc-0.9.27.so + 0x1F048 ]
   Source : <0x002f8c4a> [ /lib/ld-uClibc-0.9.27.so + 0xC4A ]
 8 Target : <0x002f8c3a> [ /lib/ld-uClibc-0.9.27.so + 0xC3A ]
   Source : <0x002fc57c> [ /lib/ld-uClibc-0.9.27.so + 0x457C ]
 9 Target : <0x002fc560> [ /lib/ld-uClibc-0.9.27.so + 0x4560 ]
   Source : <0x002fc514> [ /lib/ld-uClibc-0.9.27.so + 0x4514 ]
10 Target : <0x002fc510> [ /lib/ld-uClibc-0.9.27.so + 0x4510 ]
   Source : <0x002f9e1c> [ /lib/ld-uClibc-0.9.27.so + 0x1E1C ]
11 Target : <0x002f9e16> [ /lib/ld-uClibc-0.9.27.so + 0x1E16 ]
   Source : <0x002f9dea> [ /lib/ld-uClibc-0.9.27.so + 0x1DEA ]
12 Target : <0x002f9de6> [ /lib/ld-uClibc-0.9.27.so + 0x1DE6 ]
   Source : <0x002f9dd8> [ /lib/ld-uClibc-0.9.27.so + 0x1DD8 ]
13 Target : <0x002f9dca> [ /lib/ld-uClibc-0.9.27.so + 0x1DCA ]
   Source : <0x002f9df4> [ /lib/ld-uClibc-0.9.27.so + 0x1DF4 ]
14 Target : <0x002f9df0> [ /lib/ld-uClibc-0.9.27.so + 0x1DF0 ]
   Source : <0x002f9dc8> [ /lib/ld-uClibc-0.9.27.so + 0x1DC8 ]
15 Target : <0x002f9dc0> [ /lib/ld-uClibc-0.9.27.so + 0x1DC0 ]
   Source : <0x002f9bb4> [ /lib/ld-uClibc-0.9.27.so + 0x1BB4 ]

We can see that this error message tells us exactly where the error occured:

DCPLB_FAULT_ADDR=87654321
ICPLB_FAULT_ADDR=0357e65c

 4 Target : <0x00008458> { _trap + 0x0 }
   Source : <0x0357e658> [ /foo + 0x658 ]

The data 0x87654321 was being accessed around 0x0357e65c or 0x0357e658 or an offset of 0x658 in the file /foo. If we use bfin-uclinux-objdump -d foo | less, and goto the offset of 0x658, we can see:

0000064c <_main>:
 64c:   4a e1 65 87     P2.H=8765 <__end+0x3f5d>;
 650:   20 e1 61 00     R0=0x61 (X);
 654:   0a e1 21 43     P2.L=4321 <__ROFIXUP_END__+0x3c59>;
 658:   00 e8 00 00     LINK 0x0;
 65c:   10 9b           B[P2]=R0;
 65e:   01 e8 00 00     UNLINK;
 662:   10 00           RTS;

Here we can understand the differences in the trace buffer address, and the CPLB_FAULT_ADDR. The load instruction at 0x65c doesn't get to actually execute - so it is not saved in the trace, but since it is the instruction that caused the fault, it is the one saved in the CPLB_FAULT_ADDR.

It is in the function main, where we are writing a byte R0 or 0x61 into the memory pointed to by P2 or 0x87654321 in the instruction: B[P2]=R0. Now we have a good idea why this code is bad, and exactly where to fix it.