(6)Android Native/Tombstone Crash Log 详细分析[原创]

Android 虽然已经有好几年了，但是NDK的开放速度却非常缓慢，所以目前网络上针对对Android Native Crash的分析说明还比较少，尤其是非常详细的分析方式更难以查询。因此大部分程序员在遇到难以进行addr2line的crash log时，会一筹莫展。事实上这份log中的其他部分同样提供了非常丰富的信息可供解读，所以在这里总结一下对在这方面的一些经验，在这里以Android samples中的hello-jni为参照做了一定的修改产生的crash来进行分析说明。在深入理解错误日志的分析之后，许多难以复制或者几乎不能重现的bug也能够得到有效的解决。以下所有内容为夜莺原创。

内容主要分为一下几个部分:

• 1.Library Symbols （共享库的符号）
• 2.Analyze Tools （可用到的分析工具）
• 3.CrashLog – Header 
• 4.CrashLog – Backtrace(For most crashes)
• 5.CrashLog – Registers
• 6.CrashLog – Memory
• 7.CrashLog – Stack
• 8.Library Base Address （共享库在内存中基地址）

1.Library Symbols （共享库的符号）

ndk提供了一些工具可以供程序员直接获取到出错的文件，函数以及行数。 但是这部分工具都需要没有去符号的共享库（通常是放在out/target/product/xxx/symbols/system/lib）。而out/target/product/xxx/system/lib中的共享库是去掉了符号的，所以直接从设备上抓下来的lib是不能够通过工具来找到对应的符号（而且没有去symbol的库比去掉的空间占用会大许多）。所以如果想要分析一份native crash，那么unstripped lib几乎不可缺少，但是即使是strip过的库也同样会包含少量的symbol。

2.Analyze Tools 

即常用的辅助工具

01 addr2line  ($(ANDROID_NDK)\toolchains\arm-linux-androideabi-4.7\prebuilt\windows\bin)
02 #通过backtrace一栏提供的地址查询对应的符号，可以定位到文件，函数，行数.
03 Usage: addr2line –aCfe libs $(trace_address)
04 
05 ndk-stack (android-ndk-r8d\ndk-stack)
06 #相当于执行多次addr2line, 可以直接针对一份crash log使用，会输出所有backtrace里地址对应的symbol
07 Usage: ndk-stack –sym $(lib_directory) –dump $(crash_log_file)
08 
09 objdump (android-ndk-r8d\toolchains\arm-linux-androideabi-4.7\prebuilt\windows\bin)
10 #Dump the object file. 通过汇编代码定位错误的原因，大部分复杂的问题可以通过这种方式得到解决。
11 Usage: objdump -S $(objfile) > $(output_file)

3.Crash Log - Header

信息头，包含当前系统版本有关的信息，如果是做平台级的开发，这将有助于定位当前的系统的开发版本。

1 Time: 2014-11-28 17:40:52
2 Build description: xxxx
3 Build: xxxx
4 Hardware: xxxx
5 Revision: 0
6 Bootloader: unknown
7 Radio: unknown
8 Kernel: Linux version 3.4.5 xxxx

这部分较为容易阅读。所以不再赘述。

4.CrashLog – Backtrace(For most crashes)

即最常用的看backtrace部分，backtrace的地址可用addr2line或者ndk-stack查找对应的symbol,非常直观，大多数的crash都能够通过这种方式解决。

01 backtrace:
02    #00  pc 00026fbc  /system/lib/libc.so
03    #01  pc 000004cf  /data/app-lib/com.example.hellojni-1/libhello-jni.so (Java_com_example_hellojni_HelloJni_stringFromJNI+18)
04    #02  pc 0001e610  /system/lib/libdvm.so (dvmPlatformInvoke+112)
05    #03  pc 0004e015  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+500)
06    #04  pc 00050421  /system/lib/libdvm.so (dvmResolveNativeMethod(unsigned int const*, JValue*, Method const*, Thread*)+200)
07    #05  pc 000279e0  /system/lib/libdvm.so
08    #06  pc 0002b934  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+180)
09    #07  pc 0006175f  /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+374)
10    #08  pc 00069785  /system/lib/libdvm.so
11    #09  pc 000279e0  /system/lib/libdvm.so
12    #10  pc 0002b934  /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+180)
13    #11  pc 00061439  /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)
14    #12  pc 0004a2ed  /system/lib/libdvm.so
15    #13  pc 0004d501  /system/lib/libandroid_runtime.so
16    #14  pc 0004e259  /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+536)
17    #15  pc 00000db7  /system/bin/app_process
18    #16  pc 00020ea0  /system/lib/libc.so (__libc_init+64)
19    #17  pc 00000ae8  /system/bin/app_process

从上面这份backtrace可以看到包含一个pc地址和后面的symbol。部分错误可以通过只看这里的symbol发现问题所在。而如果想要更准确的定位，则需要借助ndk工具。

1 $addr2line -aCfe out/target/production/xxx/symbols/system/lib/libhello-jni.so 4cf
2 0x4cf
3 java_com_example_hellojni_HelloJni_stringFromJNI
4 /ANDROID_PRODUCT/hello-jni/jni/hello-jni.c:48

然后再来看看hello-jni.c

01 
17 #include
18 #include
19 
20 
26 void func_a(char *p);
27 void func_b(char *p);
28 void func_a(char *p)
29 {
30     const char* A = "AAAAAAAAA"; // len = 9
31     char* a = "dead";
32     memcpy(p, A, strlen(A));
33     memcpy(p, a, strlen(a));
34     p[strlen(a)] = 0;
35     func_b(p);
36 }
37 void func_b(char *p)
38 {
39     char* b = 0xddeeaadd;
40     memcpy(b, p, strlen(p));
41 }
42 
43 jstring
44 Java_com_example_hellojni_HelloJni_stringFromJNI( JNIEnv* env,
45                                                   jobject thiz )
46 {
47     char buf[10];
48     func_a(buf);
49     return (*env)->NewStringUTF(env, "Hello from JNI !");
50 }

可以看到现在只能看到出错在func_a(). 这里面有个比较特别的地方是为什么backtrace 中只有func_a而没有出现func_b. 这是编译器的处理部分，不过多赘述。所以现在只能从backtrace中确认#1是在func_a,然后#0是在libc中的某个函数死掉。其实symbols/system/lib中也包含有libc.so，可以通过addr2line确认是那个函数。而这里调用到libc的只有memcpy， 所以可以基本确定出错在memcpy，但是有三个memcpy，又怎么确定是哪一个呢？(当然，可以通过直接检查代码发现是在func_b里面)

5.CrashLog – Registers

寄存器信息，可以通过这部分信息基本确定系统为什么会错。

01 pid: 4000, tid: 4000, name: xample.hellojni  

02 signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr ddeeaadd
03     r0 ddeeaadd  r1 beab238c  r2 00000004  r3 beab2390
04     r4 4012b260  r5 40e1b760  r6 00000004  r7 4bdd2ca0
05     r8 beab23a8  r9 4bdd2c98  sl 40e1d050  fp beab23bc
06     ip 80000000  sp beab2380  lr 518254d3  pc 400dffbc  cpsr 80000010
07     d0  4141414141414164  d1  6e6a6f6c6c656865
08     d2  3133393766666661  d3  726f6c6f632f3c64
09     d4  3e2d2d206f646f54  d5  6f633c202020200a
10     d6  656d616e20726f6c  d7  3f8000003f800000
11     d8  0000000000000000  d9  0000000000000000
12     d10 0000000000000000  d11 0000000000000000
13     d12 0000000000000000  d13 0000000000000000
14     d14 0000000000000000  d15 0000000000000000
15     d16 000000000000019e  d17 000000000000019e
16     d18 0000000000000000  d19 000000e600000000
17     d20 e600000000000000  d21 0000000000000000
18     d22 0000000000000000  d23 090a0b0c0d0e0f10
19     d24 0000004d0000003d  d25 000000e600000000
20     d26 000000e7000000b7  d27 0000000000000000
21     d28 0000004d0000003d  d29 0000000000000000
22     d30 0000000100000001  d31 0000000100000001
23     scr 60000090

这部分信息展示了出错时的运行状态， 当前中断原因是收到SIGSEGV（通常crash也都是因为收到这个信号，也有少数是因为SIGFPE，即除0操作）。错误码是SEGV_MAPERR，常见的段错误。然后出错地址为ddeeaadd。即第39行的地址0xddeeadd。所以已经可以基本确定和指针b有关。

而代码里面接下来便是memcpy的操作。所以很明显就是在这里的memcpy有问题。

再看r0是ddeeaadd，r1是beab238c，r2是4，其实这三个寄存器刚好代表memcpy的操作参数。目的地址为ddeeaadd，源地址加偏移为beab238c，长度是4。这里有提到beab238c为源地址加偏移，原因的话会在后面解释。

通常我们需要关注的寄存器主要就是r0到pc，下面的32个寄存器的话通常是数据存取时常用，有时也会有重要信息，但一般情况下不会太关注。如果是对这部分不太了解的话，也不用担心，多看一看就自然明白了，笔者在尝试却解读之前也完全没有接触过这方面的内容。

6.CrashLog – Memory

日志当中也提供了出错时寄存器地址里面的临近内存信息，信息量同样很丰富。之前有提到r1是与源地址有关，所以先看看r1(0xbeab238c)附近的内存情况

1 memory near r1:
2     beab236c 4f659a18 51825532 518254a5 df0027ad  
3     beab237c 00000000 ddeeaadd 518254d3 64616564  
4     beab238c 41414100 41714641 a8616987 40e1d040  
5     beab239c 4c11cb40 40e1d040 40a2f614 4bdd2c94  
6     beab23ac 00000000 41714608 00000001 417093c4  
7     beab23bc 40a5f019 4bdd2c94 518215a3 518254bd

beab238c在第四行，但是注意在第三行末尾有一串类似ASCII的字符，64616564，这即是dead,而从这里开始，一段内存为64616564  41414100 41714641即"64,65,61,64, 00,41,41,41, 41"647141。其实不难发现这就是dead'\0'AAAA，其后位于栈上的值没有初始化，会比较随机。

所以func_b中p的起始地址应该是从64616564 的位置开始的，至于为什么r1是beab238c,解读一下汇编代码即可很容易发现。

在Android中使用的binoc实现中，查找源文件为memcpy.s（可通过addr2line 找到文件路径和行数）。看到出错点在memcpy.s +248。

这部分源码如下：

这两段的大致意思为从r1地址读取4个字节放到d0~d3，r1地址增加，然后将d0~d3中的数据存入到r0的地址去，同时r0也增加。

现在可以回过去查看d0~d3寄存器的最后一个字节，分别是64,65,61,64。为“dead“。因此当前的r1是增加后后的地址。而此时企图对r0处无效的地址0xddeeaadd写入数据，所以出错。并显示错误地址为0xddeeaadd.

objdump，到这里，再提一提objdump的部分。

可以对共享库(.so)使用或者对目标文件(.o)使用，如果共享库比较大，那还是对被编译文件的目标文件使用比较好。通常来说Android的编译会默认保存目标文件，存放在out/target/product/xxxx/obj目录下面，于是现在找到libhello-jni.o通过objdump来查看它的信息。

jstring
Java_com_example_hellojni_HelloJni_stringFromJNI( JNIEnv* env,
                                                 jobject thiz )
{
  a:    447c          add    r4, pc
  c:    6824          ldr    r4, [r4, #0]
  e:    6821          ldr    r1, [r4, #0]
 10:    9103          str    r1, [sp, #12]
   char buf[10];
   func_a(buf);
 12:    f7ff fffe     bl    0 <</span>Java_com_example_hellojni_HelloJni_stringFromJNI>
   return (*env)->NewStringUTF(env, "Hello from JNI !");
 16:    6828          ldr    r0, [r5, #0]
 18:    4907          ldr    r1, [pc, #28]    ; (38 <</span>Java_com_example_hellojni_HelloJni_stringFromJNI+0x38>)
 1a:    f8d0 229c     ldr.w    r2, [r0, #668]    ; 0x29c
 1e:    4628          mov    r0, r5
 20:    4479          add    r1, pc
 22:    4790          blx    r2
}

不要太在意诸如'Java_com_example_hellojni_HelloJni_stringFromJNI','{','}'之类的符号，它只是提供给我们大致的位置信息，并不是完全等同于C语言中的代码段。

之前有通过backtrace #1看到(Java_com_example_hellojni_HelloJni_stringFromJNI+18)这样的信息，将+18转换成16进制为0x12.那么对应dump 出来的文件位置就是上面的12.指令为bl 0.这是一个常见的跳转指令。从源代码里面也可以看到开始调用func_a().

再看看func_b的代码:

void func_b(char *p)
{
  0:    b510          push    {r4, lr}
  2:    4604          mov    r4, r0
  4:    f7ff fffe     bl    0 <</span>strlen>
  8:    4621          mov    r1, r4
  a:    4602          mov    r2, r0
  c:    4802          ldr    r0, [pc, #8]    ; (18 <</span>func_b+0x18>)
}
  e:    e8bd 4010     ldmia.w    sp!, {r4, lr}
 12:    f7ff bffe     b.w    0 <</span>memcpy>
 16:    bf00          nop
 18:    ddeeaadd     .word    0xddeeaadd

先将r0(p指针的值)放入r4，调用strlen,返回值默认放入r0（值为4）,再将r4取出放入r1,然后从pc+8的位置拿地址放入r0（可以看到func_b+0x18为0xddeeaadd）,再跳转到memcpy。所以r0为ddeeaadd,r1为p指针的值，r4为长度。由此进行了memcpy的调用，然后出错。

通过objdump通常可以更进一步的确定错误产生的情况，对追踪代码逻辑有极大的帮助，所以在很多情况下解决问题可以只通过阅读代码，并不需要不停地加debug打印并尝试去复制它。

7.CrashLog – Stack

当backtrace信息量极少时（没有给全函数调用栈），这是重点。

Stack一栏提供的是线程调用栈的信息。可以从右边的一些symbol大致猜测出错的位置。但由于stack上的内容可能残留未初始化或者未清空的信息，又或者存储有其他的数据，所以有时会造成一定的困惑。因此stack上的symbol虽然大部分是本次调用栈的symbol,但不一定全都是。

stack:
        beab2340  4012ac68  
        beab2344  50572968  
        beab2348  4f659a50  
        beab234c  0000002f  
        beab2350  00000038  
        beab2354  50572960  
        beab2358  beab2390  [stack]
        beab235c  4012ac68  
        beab2360  00000071  
        beab2364  400cb528  /system/lib/libc.so
        beab2368  00000208  
        beab236c  4f659a18  
        beab2370  51825532  /data/app-lib/com.example.hellojni-1/libhello-jni.so
        beab2374  518254a5  /data/app-lib/com.example.hellojni-1/libhello-jni.so (func_a+56)
        beab2378  df0027ad  
        beab237c  00000000  
   #00  beab2380  ddeeaadd  
        beab2384  518254d3  /data/app-lib/com.example.hellojni-1/libhello-jni.so (Java_com_example_hellojni_HelloJni_stringFromJNI+22)
   #01  beab2388  64616564

栈是由下往上(frame#02->#01->#00)。 现在可以大致看到从#01到#00，从Java_com_example_hellojni_HelloJni_stringFromJNI进入func_a。但是这里是不能够通过左边的地址直接addr2line得到目标symbol。它是属于在内存当中的相对地址。接下来就会提到如何去通过相对地址计算可用的addr2line地址。

8.Library Base Address （共享库在内存中基地址）

通过地址计算得出可用的addr2line地址。

addr2line需要一份未去symbol的共享库。当代码没有改变时，每次生成的.so的符号位置应该是相同的。所以如果想要得到有效的符号，必须要使用程序运行时对应的未去符号的.so。

jni在运行时可以看到在java中有load_library的动作，这个动作大致可以看做将一个库文件加载到内存当中。因此这个库在内存当中就存在一个加载的基地址，但是根据内存的情况和相应的算法，基地址每次都可能会不一样。addr2line需要的地址是相对于共享库的一个绝对地址。因此现在只要能够得到共享库在内存中的基地址就能够有办法通过stack上的地址计算出可用的addr2line地址。

在上面的stack和backtrace信息当中有(Java_com_example_hellojni_HelloJni_stringFromJNI+22)和(Java_com_example_hellojni_HelloJni_stringFromJNI+18)这两个symbol的相对地址和绝对地址。

所以基地址的计算应该为对应的地址相减：0x518254d3 - 0x000004cf - 0x4 = 0x51825000.

为了验证基地址有效性，可以尝试计算0x518254a5(func_a+56)的符号：0x518254a5 - 0x51825000 = 0x4a5。

然后使用addr2line查询0x4a5得到hello-jni.c:34。

除此之外还有另一种方法计算可用的地址，同样需要stack里提供的个别的symbol信息: 例0x518254a5(func_a+56)，然后之前有提到objdump可以直接将.so作为输入，这时会出来整个lib的汇编信息。然后可以从中找到"0xxxxxxxx <func_a>:"这样的信息，前面的0xxxxxx就代表函数的在lib中的地址，在这里是"0x46c <func_a>:" ，然后加上0x38(56) 就等于0x4a4，这个和之前有一定的差别，原因是stack上保存的会是函数返回地址，但指向的指令是相同的。

提出基地址的问题是为了进一步说明stack中的地址和backtrace中地址的不同，以及共享库被加载到内存当中指令的存在形式，但是通过比较也可以发现，在所加载的库非常大的时候（例如100M+）前一种方式得到可以用的地址会相对于后一种方式简单许多。

大多数情况下应该是不需要使用计算基地址的方式。但是也有个别的日志信息给出的backtrace不完整，导致难以解析出具体的问题所在。这个时候就需要使用基地址计算的方式得出可用的addr2line地址。

到最后看来，一般只要有一份类似于错误日志的信息文件，通常可以解决绝大部分的问题。那么如果是运行时，可以通过gdb(如果打开corefile的选项更好)，或者kill -9(同样需要打开编译选项才行)。还有就是Android系统通常内自带有debuggerd命令可以使用。详情可以从上网查阅。

最后附上本次测试的源码：http://vdisk.weibo.com/s/yVmhF5M5tTuIi

2014.12.01

[e-mail]