Do these look like valid JIT code?

[Tomei]

Hi,

We got a SIGILL in a dev board and it looks like JIT crashed due to
cache coherency problem. However, I am not very familiar with the JIT.
Could someone check if the code around the PC looks like valid code
pattern generated by the Dalvik JIT? Thanks a lot!

Here's the disasm from gdbjithelper. Looks like the PC points to a
valid "cmp r0, #0" Thumb instruction (CPSR T bit (bit5) is set, so we
are running in Thumb mode). Because a SIGILL is generated, it seems
very likely of an icache issue ....

0x9135 <codePC+1>: lsls r0, r0, #4
0x9137 <codePC+3>: lsls r0, r0, #4
0x9139 <codePC+5>: lsls r0, r0, #0
0x913b <codePC+7>: lsls r1, r5, #0
0x913d <codePC+9>: adds r5, #48
0x913f <codePC+11>: orrs r1, r3
0x9141 <codePC+13>: lsls r4, r1, #0
0x9143 <codePC+15>: lsls r3, r0, #4
0x9145 <codePC+17>: ldmia r0!, {r2, r4, r6, r7}
0x9147 <codePC+19>: mvns r6, r1
0x9149 <codePC+21>: ldmia r0!, {r4, r6, r7}
0x914b <codePC+23>: mvns r6, r1
0x914d <codePC+25>: ldmia r0!, {r3, r4, r6, r7}
0x914f <codePC+27>: mvns r6, r1
0x9151 <codePC+29>: lsls r0, r4, #1
0x9153 <codePC+31>: ldr r0, [r5, #4]
0x9155 <codePC+33>: cmp r0, #0 <<<<<<<< Crashing PC
0x9157 <codePC+35>: beq.n 0x918e <codePC+90>
0x9159 <codePC+37>: ldr r1, [r0, #20]
0x915b <codePC+39>: adds r0, r1, #0

Here's the logcat:

signal 4 (SIGILL), fault addr 4b520bf0
r0 4b520bef r1 43cbb8a0 r2 0000020d r3 807a13f4
r4 43cbb8a0 r5 430cbd94 r6 bee09580 r7 00000004
r8 00000000 r9 40024678 10 0000cd30 fp 00000002
ip 4d5d7008 sp bee09538 lr 00000000 pc 4b520bf0 cpsr
28000030 <<< T bit (bit 5) is set -- Thumb mode
d0 6472656767756265 d1 424e00007149f2ca
d2 0000003c00000000 d3 0068903000000000
d4 0000000000000000 d5 0000000000000000
d6 0000000100000001 d7 7149f2ca00000000
d8 43a5000043340000 d9 4214000041f00000
d10 47d649d83f000000 d11 4047800042d80002
d12 c4e006a7447a0000 d13 00000000c4e6a7b9
d14 0000000000000000 d15 0000000000000000
d16 c026000000000000 d17 c026000000000000
d18 4028000000000000 d19 0000000000000000
d20 3ff0000000000000 d21 8000000000000000
d22 c028000000000000 d23 0000000000000000
d24 bfe0000020000000 d25 bfebb67ae0000000
d26 0000000000000000 d27 bfebb67ae0000000
d28 0003bbb80003bbb8 d29 3ff0000000000000
d30 0000000000000000 d31 3ff0000000000000
scr 80000012
dalvikvm JIT unchain all for threadid=1
#00 pc 4b520bf0 /dev/ashmem/dalvik-jit-code-cache
(deleted)
#01 lr 00000000 <unknown>
code around pc:
4b520bd0 01000100 00290000 43193530 0103000c
4b520be0 43cec8d4 43cec8d0 43cec8d8 68680060
PC>>>4b520bf0 d01a2800 1c086941 68696029 68eb68aa
4b520c00 0724f2a5 d0122800 4c15c70f a20ba109
4b520c10 eabef78f e00ae012 29006cb8 6ef7dc01
code around lr:
stack:
bee094f8 0000cd30 [heap]
bee094fc 47c966c8 /dev/ashmem/mspace/dalvik-heap/2
(deleted)
bee09500 00000000
bee09504 afd10560 /system/lib/libc.so
bee09508 00000001
bee0950c 430cbbb0
bee09510 bee09580 [stack]
bee09514 8074d269 /system/lib/libdvm.so
bee09518 00000000
bee0951c 0000cd30 [heap]
bee09520 430cbb84
bee09524 8074d0ef /system/lib/libdvm.so
bee09528 43cbb8a0 /system/framework/framework.odex
bee0952c 430cbd94
bee09530 df002777
bee09534 e3a070ad
#00 bee09538 00000000
bee0953c bee09580 [stack]
bee09540 002a37f8 [heap]
bee09544 0000cd38 [heap]
bee09548 000361b0 [heap]
bee0954c 0000039c
bee09550 807a12e0 /system/lib/libdvm.so
bee09554 807a5ed8 /system/lib/libdvm.so
bee09558 bee09828 [stack]
bee0955c 80722758 /system/lib/libdvm.so
bee09560 0000cd30 [heap]
bee09564 bee09580 [stack]
bee09568 807226dc /system/lib/libdvm.so
bee0956c 00000000
bee09570 0000039c
bee09574 807215f8 /system/lib/libdvm.so
bee09578 000b6000 [heap]
bee0957c bee0957c [stack]

[Ben Cheng]

Yes it looks like what you encountered is a cache coherence problem on your platform.

First, as a side note, you probably didn't modify the following line in gdbjithelper.c:

#define START_PC_PAGE_OFFSET 0xbd0

code around pc:

    4b520bd0 01000100 00290000 43193530 0103000c

    4b520be0 43cec8d4 43cec8d0 43cec8d8 68680060

    4b520bf0 d01a2800 1c086941 68696029 68eb68aa

    4b520c00 0724f2a5 d0122800 4c15c70f a20ba109

    4b520c10 eabef78f e00ae012 29006cb8 6ef7dc01

Not doing that will make it a bit more difficult to figure out the relative code layout in the disassembly in gdb.

Now with the offset fixed the disassembly is as the following (as you listed):

(gdb) x /20i 0xbbd1

   0xbbd1: lsls r0, r0, #4

   0xbbd3: lsls r0, r0, #4

   0xbbd5: lsls r0, r0, #0

   0xbbd7: lsls r1, r5, #0

   0xbbd9: adds r5, #48 ; 0x30

   0xbbdb: orrs r1, r3

   0xbbdd: lsls r4, r1, #0

   0xbbdf: lsls r3, r0, #4

   0xbbe1: ldmia r0!, {r2, r4, r6, r7}

   0xbbe3: mvns r6, r1

   0xbbe5: ldmia r0!, {r4, r6, r7}

   0xbbe7: mvns r6, r1

   0xbbe9: ldmia r0!, {r3, r4, r6, r7}

   0xbbeb: mvns r6, r1

   0xbbed: lsls r0, r4, #1

   0xbbef: ldr r0, [r5, #4]    <<<- load v1

   0xbbf1: cmp r0, #0          <<<- SIGILL here

   0xbbf3: beq.n 0xbc2a

   0xbbf5: ldr r1, [r0, #20]

   0xbbf7: adds r0, r1, #0

A typical trace starts with a load off r5 which is the frame pointer. In this case 0xbbef is very likely the trace starting point. It is trying to load v1, do a null check, then load a field off it. It looks like the "ldr r0, [r5, #4]" at 0xbbef is not what being executed during runtime either since r0 shows 0x4b520bef, which is a reasonable pointer value.

So I'd suggest investigate the system call in the kernel to make sure that the caches are flushed cleanly.

-Ben

--
You received this message because you are subscribed to the Google Groups "android-platform" group.
To post to this group, send email to android-...@googlegroups.com.
To unsubscribe from this group, send email to android-platfo...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/android-platform?hl=en.

[Tomei]

Thanks a lot Ben for the detailed explanation.

Since r0 == 4b520bef and crashing PC == 4b520bf0, and as you said, r0
does not contain a reasonable value for an object, it seems like
someone actually used

blx r0
or
bx r0

to branch into 4b520bee

4b520bec: 0060
>>4b520bee: 6868 ldr r0, [r5, #4]
4b520bf0: 2800 cmp r0, #0

but cache incoherence caused the CPU to execute a different
instruction (probably clearing lr to 00000000), and then SIGILL on the
next instruction.

Is it true that:

(1) Does Dalvik dispatch to a trace via "bx r0" or "blx r0"?
(2) A trace could start at 4b520bee (address not 4-byte aligned)?
(and is the 0060 some sort of short field in the trace header...?)

If so, we can be 99% sure this is caused by icache issue.

Thanks again!

> > android-platfo...@googlegroups.com<android-platform%2Bunsubscrib e...@googlegroups.com>
> > .

[Ben Cheng]

Please see replies inline:

On Fri, Oct 8, 2010 at 3:09 PM, Tomei <tomei.n...@gmail.com> wrote:

Thanks a lot Ben for the detailed explanation.

Since r0 == 4b520bef and crashing PC == 4b520bf0, and as you said, r0
does not contain a reasonable value for an object, it seems like
someone actually used

    blx r0
or
    bx r0

to branch into 4b520bee

   4b520bec: 0060
>>4b520bee: 6868    ldr r0, [r5, #4]
   4b520bf0:  2800    cmp r0, #0

but cache incoherence caused the CPU to execute a different
instruction (probably clearing lr to 00000000), and then SIGILL on the
next instruction.

Is it true that:

(1) Does Dalvik dispatch to a trace via "bx r0" or "blx r0"?

 In dalvik/vm/mterp/out/InterpAsm-armv*.S, JIT'ed code is usually dispatched by the following snippet:

    mov    lr, #0

    cmp    r0,#0

    bxne   r0

(2) A trace could start at 4b520bee (address not 4-byte aligned)?
(and is the 0060 some sort of short field in the trace header...?)

Correct. Every trace has some header bytes and the starting code only needs to be half-word aligned.

 

If so, we can be 99% sure this is caused by icache issue.

Great!

-Ben